Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

CKR_OPERATION_ACTIVE on sequential signing #53

Open
Ulterior opened this issue Dec 10, 2019 · 6 comments
Open

CKR_OPERATION_ACTIVE on sequential signing #53

Ulterior opened this issue Dec 10, 2019 · 6 comments

Comments

@Ulterior
Copy link

Ulterior commented Dec 10, 2019

I am getting CKR_OPERATION_ACTIVE error when signing multiple documents. If I add a delay of at least 500ms between each signing call, it succeeds.


        const sign = async function(inputXml, getkeys, outputXml) {

            const hash = "SHA-256";
            const alg = {
                name: "RSASSA-PKCS1-v1_5",
                hash,
            };

            var keys = await getkeys(alg);

            let signature = new xadesjs.SignedXml();
            var data = fs.readFileSync(inputXml);
            await signature.Sign(
                    alg, // algorithm
                    keys.privateKey, // key
                    xadesjs.Parse('<EDoc>' + data.toString().replace(/<\?xml.+\?\>/g, '') + '</EDoc>'), { // document
                        // options
                        keyValue: keys.publicKey,
                        references: [{
                            hash: "SHA-256",
                            uri: "",
                            transforms: ["enveloped", "c14n"]
                        }],
                        productionPlace: {
                            country: "Country",
                            state: "State",
                            city: "City",
                            code: "Code",
                        },
                        signerRole: {
                            claimed: ["Some role"]
                        },
                        signingTime: {
                            format: "isoDateTime"
                        }
                    })
                .then(() => {
                    //fs.writeFileSync(outputXml, '<?xml version="1.0" encoding="UTF-8"?>\n' + signature.toString());
                }).catch(e => console.log(e));
        
        };
        async function asyncForEach(array, callback) {
            for (let index = 0; index < array.length; index++) {
                await callback(array[index], index, array);
            }
        }

        const signFiles = async(dirName) => {

            var keys = null;

            await asyncForEach(files, async(file) => {

                const waitFor = (ms) => new Promise(r => setTimeout(r, ms));

                await sign(path.join(dirName, file), async function(algorithm) {
                    if (null == keys) {
                        keys = await get_keys_from_card(algorithm);
                    }
                    return keys;
                }, path.join(__dirname, "test_signed.xml")).then(async() => {
                    console.log('signing completed');
                    //await waitFor(500);

                }).catch(e => console.log(e));

            });
            console.log('Done');
        };
        signFiles("my-dir-with-files");

signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
Error: CKR_OPERATION_ACTIVE:144
at Error (native) PKCS11::C_DigestInit:724
at Digest.init (..\node_modules\graphene-pk11\build\crypto\digest.js:43:18)
at new Digest (....\node_modules\graphene-pk11\build\crypto\digest.js:10:14)
at Session.createDigest (....\node_modules\graphene-pk11\build\session.js:208:16)
at ....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:12:25
at new Promise ()
at Function. (....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:11:20)
at Generator.next ()
at ....\node_modules\tslib\tslib.js:110:75
at new Promise ()
at Object.__awaiter (....\node_modules\tslib\tslib.js:106:16)
signing completed
Error: CKR_OPERATION_ACTIVE:144
at Error (native) PKCS11::C_DigestInit:724
at Digest.init (....\node_modules\graphene-pk11\build\crypto\digest.js:43:18)
at new Digest (....\node_modules\graphene-pk11\build\crypto\digest.js:10:14)
at Session.createDigest (....\node_modules\graphene-pk11\build\session.js:208:16)
at ....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:12:25
at new Promise ()
at Function. (....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:11:20)
at Generator.next ()
at ....\node_modules\tslib\tslib.js:110:75
at new Promise ()
at Object.__awaiter (....\node_modules\tslib\tslib.js:106:16)
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
Error: CKR_OPERATION_ACTIVE:144
at Error (native) PKCS11::C_DigestInit:724
at Digest.init (....\node_modules\graphene-pk11\build\crypto\digest.js:43:18)
at new Digest (....\node_modules\graphene-pk11\build\crypto\digest.js:10:14)
at Session.createDigest (....\node_modules\graphene-pk11\build\session.js:208:16)
at ....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:12:25
at new Promise ()
at Function. (....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:11:20)
at Generator.next ()
at ....\node_modules\tslib\tslib.js:110:75
at new Promise ()
at Object.__awaiter (....\node_modules\tslib\tslib.js:106:16)
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
Error: CKR_OPERATION_ACTIVE:144
at Error (native) PKCS11::C_DigestInit:724
at Digest.init (....\node_modules\graphene-pk11\build\crypto\digest.js:43:18)
at new Digest (....\node_modules\graphene-pk11\build\crypto\digest.js:10:14)
at Session.createDigest (....\node_modules\graphene-pk11\build\session.js:208:16)
at ....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:12:25
at new Promise ()
at Function. (....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:11:20)
at Generator.next ()
at ....\node_modules\tslib\tslib.js:110:75
at new Promise ()
at Object.__awaiter (....\node_modules\tslib\tslib.js:106:16)
signing completed
signing completed
signing completed
signing completed
Error: CKR_OPERATION_ACTIVE:144
at Error (native) PKCS11::C_DigestInit:724
at Digest.init (....\node_modules\graphene-pk11\build\crypto\digest.js:43:18)
at new Digest (....\node_modules\graphene-pk11\build\crypto\digest.js:10:14)
at Session.createDigest (....\node_modules\graphene-pk11\build\session.js:208:16)
at ....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:12:25
at new Promise ()
at Function. (....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:11:20)
at Generator.next ()
at ....\node_modules\tslib\tslib.js:110:75
at new Promise ()
at Object.__awaiter (....\node_modules\tslib\tslib.js:106:16)
signing completed
Error: CKR_OPERATION_ACTIVE:144
at Error (native) PKCS11::C_DigestInit:724
at Digest.init (....\node_modules\graphene-pk11\build\crypto\digest.js:43:18)
at new Digest (....\node_modules\graphene-pk11\build\crypto\digest.js:10:14)
at Session.createDigest (....\node_modules\graphene-pk11\build\session.js:208:16)
at ....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:12:25
at new Promise ()
at Function. (....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:11:20)
at Generator.next ()
at ....\node_modules\tslib\tslib.js:110:75
at new Promise ()
at Object.__awaiter (....\node_modules\tslib\tslib.js:106:16)
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
Error: CKR_OPERATION_ACTIVE:144
at Error (native) PKCS11::C_DigestInit:724
at Digest.init (....\node_modules\graphene-pk11\build\crypto\digest.js:43:18)
at new Digest (....\node_modules\graphene-pk11\build\crypto\digest.js:10:14)
at Session.createDigest (....\node_modules\graphene-pk11\build\session.js:208:16)
at ....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:12:25
at new Promise ()
at Function. (....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:11:20)
at Generator.next ()
at ....\node_modules\tslib\tslib.js:110:75
at new Promise ()
at Object.__awaiter (....\node_modules\tslib\tslib.js:106:16)
signing completed
Error: CKR_OPERATION_ACTIVE:144
at Error (native) PKCS11::C_DigestInit:724
at Digest.init (....\node_modules\graphene-pk11\build\crypto\digest.js:43:18)
at new Digest (....\node_modules\graphene-pk11\build\crypto\digest.js:10:14)
at Session.createDigest (....\node_modules\graphene-pk11\build\session.js:208:16)
at ....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:12:25
at new Promise ()
at Function. (....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:11:20)
at Generator.next ()
at ....\node_modules\tslib\tslib.js:110:75
at new Promise ()
at Object.__awaiter (....\node_modules\tslib\tslib.js:106:16)
signing completed
Error: CKR_OPERATION_ACTIVE:144
at Error (native) PKCS11::C_DigestInit:724
at Digest.init (....\node_modules\graphene-pk11\build\crypto\digest.js:43:18)
at new Digest (....\node_modules\graphene-pk11\build\crypto\digest.js:10:14)
at Session.createDigest (....\node_modules\graphene-pk11\build\session.js:208:16)
at ....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:12:25
at new Promise ()
at Function. (....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:11:20)
at Generator.next ()
at ....\node_modules\tslib\tslib.js:110:75
at new Promise ()
at Object.__awaiter (....\node_modules\tslib\tslib.js:106:16)
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
Error: CKR_OPERATION_ACTIVE:144
at Error (native) PKCS11::C_DigestInit:724
at Digest.init (....\node_modules\graphene-pk11\build\crypto\digest.js:43:18)
at new Digest (....\node_modules\graphene-pk11\build\crypto\digest.js:10:14)
at Session.createDigest (....\node_modules\graphene-pk11\build\session.js:208:16)
at ....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:12:25
at new Promise ()
at Function. (....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:11:20)
at Generator.next ()
at ....\node_modules\tslib\tslib.js:110:75
at new Promise ()
at Object.__awaiter (....\node_modules\tslib\tslib.js:106:16)
signing completed
signing completed
signing completed
Error: CKR_OPERATION_ACTIVE:144
at Error (native) PKCS11::C_DigestInit:724
at Digest.init (....\node_modules\graphene-pk11\build\crypto\digest.js:43:18)
at new Digest (....\node_modules\graphene-pk11\build\crypto\digest.js:10:14)
at Session.createDigest (....\node_modules\graphene-pk11\build\session.js:208:16)
at ....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:12:25
at new Promise ()
at Function. (....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:11:20)
at Generator.next ()
at ....\node_modules\tslib\tslib.js:110:75
at new Promise ()
at Object.__awaiter (....\node_modules\tslib\tslib.js:106:16)
signing completed
signing completed
signing completed
signing completed
Error: CKR_OPERATION_ACTIVE:144
at Error (native) PKCS11::C_DigestInit:724
at Digest.init (....\node_modules\graphene-pk11\build\crypto\digest.js:43:18)
at new Digest (....\node_modules\graphene-pk11\build\crypto\digest.js:10:14)
at Session.createDigest (....\node_modules\graphene-pk11\build\session.js:208:16)
at ....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:12:25
at new Promise ()
at Function. (....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:11:20)
at Generator.next ()
at ....\node_modules\tslib\tslib.js:110:75
at new Promise ()
at Object.__awaiter (....\node_modules\tslib\tslib.js:106:16)
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
Error: CKR_OPERATION_ACTIVE:144
at Error (native) PKCS11::C_DigestInit:724
at Digest.init (....\node_modules\graphene-pk11\build\crypto\digest.js:43:18)
at new Digest (....\node_modules\graphene-pk11\build\crypto\digest.js:10:14)
at Session.createDigest (....\node_modules\graphene-pk11\build\session.js:208:16)
at ....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:12:25
at new Promise ()
at Function. (....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:11:20)
at Generator.next ()
at ....\node_modules\tslib\tslib.js:110:75
at new Promise ()
at Object.__awaiter (....\node_modules\tslib\tslib.js:106:16)
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
Error: CKR_OPERATION_ACTIVE:144
at Error (native) PKCS11::C_DigestInit:724
at Digest.init (....\node_modules\graphene-pk11\build\crypto\digest.js:43:18)
at new Digest (....\node_modules\graphene-pk11\build\crypto\digest.js:10:14)
at Session.createDigest (....\node_modules\graphene-pk11\build\session.js:208:16)
at ....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:12:25
at new Promise ()
at Function. (....\node_modules\node-webcrypto-p11\build\mechs\sha\crypto.js:11:20)
at Generator.next ()
at ....\node_modules\tslib\tslib.js:110:75
at new Promise ()
at Object.__awaiter (....\node_modules\tslib\tslib.js:106:16)
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
signing completed
Done

@microshine
Copy link
Contributor

@Ulterior Thank you. I can reproduce that error

This is my app source code

const { Crypto } = require("node-webcrypto-p11");
const xadesjs = require("xadesjs");
const fs = require("fs");
const path = require("path");

const crypto = new Crypto({
  library: "/usr/local/lib/softhsm/libsofthsm2.so",
  slot: 0,
  pin: "12345",
});
const files = [
  "xmldata.xml", "xmldata2.xml",
  "xmldata.xml", "xmldata2.xml",
  "xmldata.xml", "xmldata2.xml",
  "xmldata.xml", "xmldata2.xml",
  "xmldata.xml", "xmldata2.xml",
  "xmldata.xml", "xmldata2.xml",
  "xmldata.xml", "xmldata2.xml",
  "xmldata.xml", "xmldata2.xml",
  "xmldata.xml", "xmldata2.xml",
  "xmldata.xml", "xmldata2.xml",
  "xmldata.xml", "xmldata2.xml",
  "xmldata.xml", "xmldata2.xml",
  "xmldata.xml", "xmldata2.xml",
  "xmldata.xml", "xmldata2.xml",
  "xmldata.xml", "xmldata2.xml",
  "xmldata.xml", "xmldata2.xml",
];
xadesjs.Application.setEngine("PKCS#11", crypto);

const hash = "SHA-256";
const alg = {
  name: "RSASSA-PKCS1-v1_5",
  hash,
};
const keyGenAlg = {
  ...alg,
  publicExponent: new Uint8Array([1, 0, 1]),
  modulusLength: 2048,
}

async function get_keys_from_card() {
  const keys = await crypto.subtle.generateKey(keyGenAlg, false, ["sign", "verify"]);
  return keys;
}

async function sign(inputXml, getKeys, outputXml) {

  var keys = await getKeys(alg);

  let signature = new xadesjs.SignedXml();
  var data = fs.readFileSync(inputXml);
  await signature.Sign(
    alg, // algorithm
    keys.privateKey, // key
    xadesjs.Parse('<EDoc>' + data.toString().replace(/<\?xml.+\?\>/g, '') + '</EDoc>'), { // document
    // options
    keyValue: keys.publicKey,
    references: [{
      hash,
      uri: "",
      transforms: ["enveloped", "c14n"]
    }],
    productionPlace: {
      country: "Country",
      state: "State",
      city: "City",
      code: "Code",
    },
    signerRole: {
      claimed: ["Some role"]
    },
    signingTime: {
      format: "isoDateTime"
    }
  });
}

async function asyncForEach(array, callback) {
  for (let index = 0; index < array.length; index++) {
    await callback(array[index], index, array);
  }
}

async function signFiles(dirName) {

  let keys = null;

  await asyncForEach(files, async (file) => {
    try {
      await sign(path.join(dirName, file), async (algorithm) => {
        if (null == keys) {
          keys = await get_keys_from_card(algorithm);
        }
        return keys;
      }, path.join(__dirname, "test_signed.xml"))

      console.log('signing completed');
    } catch (e) {
      console.error(e);
    }
  });
  console.log('Done');
};

async function main() {


  await signFiles(__dirname);
}

main().catch((e) => {
  console.error(e);
});

@microshine
Copy link
Contributor

I think the problem is in xmldsig and xades implementations. Those modules use Promise instead of async/await. It's hard to find out place where promise works without awaiting. I've created a ticket to apply async/await

PeculiarVentures/xmldsigjs#33

@rkaw92
Copy link

rkaw92 commented Dec 12, 2019

Hi, async/await and promises are literally the same thing, just with syntax sugar. Perhaps the underlying library has problems when concurrent operations are triggered? If so, this should be solved using a task queue - just adding the "await" keyword will not help if the caller misbehaves.

@microshine
Copy link
Contributor

xmldsigjs uses Promise.all. I think this is why it calls operations in the same time

@microshine
Copy link
Contributor

That script allows to test signing with asyc/await for..of and Promise.all

I tried that script with SoftHSM. It doesn't throw CKR_OPERATION_ACTIVE exception

import { Crypto } from "./src";

async function main() {
  const crypto = new Crypto({
    library: "/usr/local/lib/softhsm/libsofthsm2.so",
    name: "SoftHSMv2",
    slot: 0,
    readWrite: true,
    pin: "12345",
  });

  const alg: RsaHashedKeyGenParams = {
    name: "RSASSA-PKCS1-v1_5",
    hash: "SHA-256",
    publicExponent: new Uint8Array([1, 0, 1]),
    modulusLength: 2048,
  }
  const keys = await crypto.subtle.generateKey(alg, false, ["verify", "sign"]) as CryptoKeyPair;
  const data = new Uint8Array(1024);
  const list = Array(50);

  for (const item of list) {
    await crypto.subtle.sign(alg, keys.privateKey, data);
  }

  await Promise.all<ArrayBuffer>(list.map(() => crypto.subtle.sign(alg, keys.privateKey, data)));

  crypto.close();
}

main().catch(e => console.error(e));

@ValentinViennot
Copy link

Hi @microshine & al,

I’ve revisited this issue using "node-webcrypto-p11" version 2.6.6, and I wanted to clarify a few points regarding the Promise.all approach for parallel signing.

In your previous comment (from Nov 25, 2020!), you suggested a method using Promise.all with Array(50), which appeared to work, likely because the empty array wasn’t actually processed in Promise.all. Without valid data elements, the operations within Promise.all weren’t executed, so no error (CKR_OPERATION_ACTIVE) was triggered. This could give the impression that parallel signing was succeeding, though in reality, the Promise.all loop didn’t fully execute the signing tasks.

Here’s the code I’m using, which more closely mirrors actual signing requirements:

import 'dotenv/config';
import { Crypto as CryptoP11 } from 'node-webcrypto-p11';

const logSignatures = (signatures: ArrayBuffer[]) => {
    console.log(
        signatures.map((r) =>
            r !== undefined ? Buffer.from(r).toString('hex') : 'undefined',
        ),
    );
};

async function main() {
    const HSM_CONFIG = JSON.parse(process.env.HSM_CONFIG!);
    const crypto = new CryptoP11(HSM_CONFIG);
    // Note that using the globalThis implementation shows that the error is indeed coming from node-webcrypto-p11
    // const crypto = globalThis.crypto;

    const alg: RsaHashedKeyGenParams = {
        name: 'RSASSA-PKCS1-v1_5',
        hash: 'SHA-256',
        publicExponent: new Uint8Array([1, 0, 1]),
        modulusLength: 2048,
    };

    const keys = (await crypto.subtle.generateKey(alg, false, [
        'verify',
        'sign',
    ])) as CryptoKeyPair;
    const data = [new Uint8Array(1024), new Uint8Array(1024)];

    let signatures: ArrayBuffer[];

    // Sequential signing - WORKS without errors
    signatures = [];
    for (const dataToSign of data) {
        signatures.push(
            await crypto.subtle.sign(alg, keys.privateKey, dataToSign),
        );
    }
    logSignatures(signatures);

    // Parallel signing - Throws CKR_OPERATION_ACTIVE error
    try {
        signatures = await Promise.all(
            data.map((dataToSign) =>
                crypto.subtle.sign(alg, keys.privateKey, dataToSign),
            ),
        );
        logSignatures(signatures);
    } catch (e) {
        console.error('Parallel signing error:', e);
    }
}

main()
    .then(() => console.log('done'))
    .catch((e) => console.error(e));

When using Promise.all with valid data (not an empty array), the CKR_OPERATION_ACTIVE error occurs consistently, which suggests an issue with handling simultaneous signing operations. This error doesn’t appear in sequential signing, where each signing operation completes fully before the next begins.

Is there a recommended workaround, such as a task queue, to handle simultaneous signing tasks, or any configuration adjustments within "node-webcrypto-p11" that might prevent this error? Thanks in advance for your guidance!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants