CKR_OPERATION_ACTIVE on sequential signing

[Ulterior]

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]

@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]

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]

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]

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

[microshine]

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]

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!