Signing a PDF in Adobe Acrobat on macOS using the brand new driver for D-TRUST 4.1 Std. Card only works once.

[gh47110815]

Problem Description

Also see: #2943 (comment)

Using the latest master commit ...
OpenSC-, rev: ccdb3cc, commit-time: 2024-02-13 14:05:22 +0100
... it is possible to sign a PDF-Document on macOS (14.3.1) using Adobes Acrobat Pro (23.8.20470.0) with a REINER SCT cyberJack RFID komfort Card-Reader and a D-TRUST 4.1 Std. Card
BUT
without restarting Acrobat it is not possible to sign a second time.
Typically an PKCS#11 Error 0x101 is shown (pkcs11-object.c:745:C_Sign: C_Sign() = CKR_USER_NOT_LOGGED_IN)
.

Proposed Resolution

Seems that the issue is based on PIN Caching

Steps to reproduce

I have been asked to document 4 different step-by-step-use-cases ...
... seems that beginning with step 4) the system was very "unstable". It was nearly impossible to really track the situation ;-( ....

1. Close Adobe between the signing operations, but keep the card inserted into the reader

• open acrobat
• signing 1 ok
• close acrobat - open acrobat
• signing 2 ok
• close acrobat

2. Close Adobe between the signing operations and remove the card from the reader and reinsert it

• open acrobat
• signing 1 ok
• close adobe - remove card - insert card - open acrobat
• signing 2 ok
• close acrobat

3. Keep Adobe open between the signing operations, but remove the card from the reader an reinsert it

• open acrobat
• signing 1 ok
• remove card - insert card - same document
• signing 2 - failed - PKCS#11 Fehler, Fehlercode: 0x5
• close acrobat

4. Keep Adobe open between the signing operations and keep the card inserted as well

• open acrobat
• signing 1 - D-Trust ID not available for signing
• close acrobat
• open acrobat
• signing 1 - ok
• signing 2 - failed - PKCS#11 Fehler, Fehlercode: 0101
• remove card - insert card
• signing 3 - D-Trust ID not available (only T-TRUST Limited Basic CA) - signing with this ID does not respond
• close acrobat
• open acrobat
• signing 4 - No D-Trust ID available
• close acrobat - remove card - open acrobat - insert card
• signing 5, 6, 7 8 with "Limited Basic" ok
• signing 9 with "" - failed - Fehlercode: 0x101
• close acrobat, remove card, insert card, open acrobat
• signing 10 - No D-Trust ID available
• remove card, insert card, refresh IDs "Wähle eine digitale ID aus, die Du zum signieren verwenden möchtest -> Aktualisieren"
• No D-Trust ID available
• close acrobat, remove card, disconnect card-reader, connect card-reader, insert card, open acrobat
• signing not possible - no D-TRUST ID available
• Setup Acrobat - detach module, attach module, refresh IDs -> no D-TRUST ID
• Close Acrobat, remove card, disconnect card reader, connect card reader, insert card, open acrobat
• signing - no D-Trust ID available
• close all apps, remove card, reboot mac, insert card, open acrobat
• signing 1 - ok
• signing 2 (new document) - failed ErrorCode: 0x101

--> my personal workaround for currently satisfying success with signing exactly ONE PDF:

• Connect card-reader, (optional) Reboot Mac, insert card, open acrobat and Sign ONE PDF - YEAH!
• Then try closing, opening acrobat, sign document, close, open, sign, close, open, sign .... until system gets unstable
• Reboot and try again

Logs

Successfully signed ....
9086 P:2912; T:0x140704450545600 21:57:14.835 [opensc-pkcs11] pkcs11-object.c:697:C_SignInit: C_SignInit() = CKR_OK
9092 P:2912; T:0x140704450545600 21:57:14.835 [opensc-pkcs11] pkcs11-object.c:745:C_Sign: C_Sign() = CKR_OK
9225 P:2912; T:0x140704450545600 21:57:15.579 [opensc-pkcs11] framework-pkcs15.c:4438:pkcs15_prkey_sign: Sign complete. Result 384.
9228 P:2912; T:0x140704450545600 21:57:15.579 [opensc-pkcs11] pkcs11-object.c:745:C_Sign: C_Sign() = CKR_OK

Signing fails ...
17800 P:2912; T:0x140704450545600 21:58:49.750 [opensc-pkcs11] pkcs11-object.c:697:C_SignInit: C_SignInit() = CKR_OK
17806 P:2912; T:0x140704450545600 21:58:49.750 [opensc-pkcs11] pkcs11-object.c:745:C_Sign: C_Sign() = CKR_OK
17913 P:2912; T:0x140704450545600 21:58:49.776 [opensc-pkcs11] pkcs15-sec.c:169:use_key: returning with: -1211 (Security status not satisfied)
17918 P:2912; T:0x140704450545600 21:58:49.776 [opensc-pkcs11] framework-pkcs15.c:4438:pkcs15_prkey_sign: Sign complete. Result -1211.
17922 P:2912; T:0x140704450545600 21:58:49.776 [opensc-pkcs11] pkcs11-object.c:745:C_Sign: C_Sign() = CKR_USER_NOT_LOGGED_IN

P.S.:

I also tried different settings in opensc.conf like

framework pkcs15 {
use_pin_caching = false;
pin_cache_counter = 1;
}

    # Parameters for the OpenSC PKCS11 module
    app opensc-pkcs11 {
            pkcs11 {
                    lock_login = true;
                    atomic = true;
            }
    }

.... but also without success.

[frankmorgner]

please run pkcs15-tool -D to see if user_consent is enabled for the key.

Debug output with level 3 is more helpful, complete logs even more! Note that there is a problem when setting app specific configuration #2999

[gh47110815]

pkcs15-tool -D
gives ....

Using reader with a card: REINER SCT cyberJack RFID komfort
Connecting to card in reader REINER SCT cyberJack RFID komfort...
Using card driver D-Trust Signature Card.
PKCS#15 Card [D-TRUST Card 4.1 Std. RSA 2ca]:
Version : 1
Serial number : 9276003211610361039f
Manufacturer ID: D-TRUST GmbH (C)
Flags : Login required, PRN generation

PIN [Card-PIN]
Object Flags : [0x03], private, modifiable
Auth ID : 04
ID : 03
Flags : [0x1811], case-sensitive, initialized, exchangeRefData
Length : min_len:6, max_len:12, stored_len:0
Pad char : 0x00
Reference : 3 (0x03)
Type : UTF-8
Tries left : 3

PIN [Card-PUK]
Object Flags : [0x03], private, modifiable
ID : 04
Flags : [0x859], case-sensitive, unblock-disabled, initialized, unblockingPin, exchangeRefData
Length : min_len:8, max_len:8, stored_len:0
Pad char : 0x00
Reference : 4 (0x04)
Type : UTF-8
Tries left : 3

PIN [Signature-PIN]
Object Flags : [0x03], private, modifiable
Auth ID : 04
ID : 07
Flags : [0x2813], case-sensitive, local, initialized, exchangeRefData
Length : min_len:6, max_len:12, stored_len:0
Pad char : 0x00
Reference : 135 (0x87)
Type : UTF-8
Path : 3f000101
Tries left : 3

Private RSA Key [Authentisierungsschluessel]
Object Flags : [0x01], private
Usage : [0x2E], decrypt, sign, signRecover, unwrap
Access Flags : [0x00]
Algo_refs : 0
ModLength : 3072
Key ref : 3 (0x03)
Native : yes
Path : 3f000102
Auth ID : 03
ID : 03
MD:guid : dd545c0b-161a-e1d3-fa74-298d5007fe10

Private RSA Key [Signaturschluessel]
Object Flags : [0x01], private
Usage : [0x200], nonRepudiation
Access Flags : [0x00]
Algo_refs : 0
ModLength : 3072
Key ref : 2 (0x02)
Native : yes
Path : 3f000101
Auth ID : 07
ID : 02
MD:guid : ce9faed0-a0be-f5f0-d8f3-6a52b0ce575a

X.509 Certificate [Authentisierungszertifikat]
Object Flags : [0x02], modifiable
Authority : no
Path : 3f0001030204
ID : 03
Encoded serial : 02 10 59916C9A2008D89CFB67B6B1DBD20AD0

X.509 Certificate [Signaturzertifikat]
Object Flags : [0x02], modifiable
Authority : no
Path : 3f0001030201
ID : 02
Encoded serial : 02 10 64287BA4A6D860DEAADD3F53F5BC3930

X.509 Certificate [CA-Zertifikat fuer Authentisierung]
Object Flags : [0x02], modifiable
Authority : yes
Path : 3f0001030205
ID : 03
Encoded serial : 02 03 0FE54B

X.509 Certificate [Root-CA-Zertifikat fuer Authentisierung]
Object Flags : [0x02], modifiable
Authority : yes
Path : 3f0001030206
ID : 03
Encoded serial : 02 03 0FE529

X.509 Certificate [CA-Zertifikat fuer Signatur]
Object Flags : [0x02], modifiable
Authority : yes
Path : 3f0001030202
ID : 02
Encoded serial : 02 10 69F4C9580F580F631488B9632371E72E

X.509 Certificate [Root-CA-Zertifikat fuer Signatur]
Object Flags : [0x02], modifiable
Authority : yes
Path : 3f0001030203
ID : 02
Encoded serial : 02 10 6BC22A5479D8EA68A9C5A27A909BA938

[frankmorgner]

Sorry, I just noticed that pkcs15-tool doesn't dump user_consent. if you use the debug level 7, then the ASN.1 properties should be printed, I think. Could you check if the string "userConsent" appears in the output of pkcs15-tool -D -vvvvvvvv?

[gh47110815]

pkcs15-tool -D -vvvvvvvvvvvvvvvvvv 2>&1 | grep -i userConsent

11 entries found
10 entries show 'userConsent' not present
1 entry (5th entry) shows "raw data:01" and "'userConsent' returned 1"

the 5th entry is ...Private RSA Key [Signaturschluessel]

P:1497; T:0x140704553469888 00:31:37.340 [pkcs15-tool] asn1.c:1748:asn1_decode: Looking for 'userConsent', tag 0x2, OPTIONAL
P:1497; T:0x140704553469888 00:31:37.340 [pkcs15-tool] asn1.c:1762:asn1_decode: 'userConsent' not present
P:1497; T:0x140704553469888 00:31:37.342 [pkcs15-tool] asn1.c:1748:asn1_decode: Looking for 'userConsent', tag 0x2, OPTIONAL
P:1497; T:0x140704553469888 00:31:37.342 [pkcs15-tool] asn1.c:1762:asn1_decode: 'userConsent' not present
P:1497; T:0x140704553469888 00:31:37.344 [pkcs15-tool] asn1.c:1748:asn1_decode: Looking for 'userConsent', tag 0x2, OPTIONAL
P:1497; T:0x140704553469888 00:31:37.344 [pkcs15-tool] asn1.c:1762:asn1_decode: 'userConsent' not present
P:1497; T:0x140704553469888 00:31:37.407 [pkcs15-tool] asn1.c:1748:asn1_decode: Looking for 'userConsent', tag 0x2, OPTIONAL
P:1497; T:0x140704553469888 00:31:37.407 [pkcs15-tool] asn1.c:1762:asn1_decode: 'userConsent' not present
P:1497; T:0x140704553469888 00:31:37.409 [pkcs15-tool] asn1.c:1748:asn1_decode: Looking for 'userConsent', tag 0x2, OPTIONAL
P:1497; T:0x140704553469888 00:31:37.409 [pkcs15-tool] asn1.c:1501:asn1_decode_entry: decoding 'userConsent', raw data:01
P:1497; T:0x140704553469888 00:31:37.409 [pkcs15-tool] asn1.c:1527:asn1_decode_entry: decoding 'userConsent' returned 1
P:1497; T:0x140704553469888 00:31:37.437 [pkcs15-tool] asn1.c:1748:asn1_decode: Looking for 'userConsent', tag 0x2, OPTIONAL
P:1497; T:0x140704553469888 00:31:37.437 [pkcs15-tool] asn1.c:1762:asn1_decode: 'userConsent' not present
P:1497; T:0x140704553469888 00:31:37.439 [pkcs15-tool] asn1.c:1748:asn1_decode: Looking for 'userConsent', tag 0x2, OPTIONAL
P:1497; T:0x140704553469888 00:31:37.439 [pkcs15-tool] asn1.c:1762:asn1_decode: 'userConsent' not present
P:1497; T:0x140704553469888 00:31:37.479 [pkcs15-tool] asn1.c:1748:asn1_decode: Looking for 'userConsent', tag 0x2, OPTIONAL
P:1497; T:0x140704553469888 00:31:37.479 [pkcs15-tool] asn1.c:1762:asn1_decode: 'userConsent' not present
P:1497; T:0x140704553469888 00:31:37.480 [pkcs15-tool] asn1.c:1748:asn1_decode: Looking for 'userConsent', tag 0x2, OPTIONAL
P:1497; T:0x140704553469888 00:31:37.480 [pkcs15-tool] asn1.c:1762:asn1_decode: 'userConsent' not present
P:1497; T:0x140704553469888 00:31:37.482 [pkcs15-tool] asn1.c:1748:asn1_decode: Looking for 'userConsent', tag 0x2, OPTIONAL
P:1497; T:0x140704553469888 00:31:37.482 [pkcs15-tool] asn1.c:1762:asn1_decode: 'userConsent' not present
P:1497; T:0x140704553469888 00:31:37.483 [pkcs15-tool] asn1.c:1748:asn1_decode: Looking for 'userConsent', tag 0x2, OPTIONAL
P:1497; T:0x140704553469888 00:31:37.483 [pkcs15-tool] asn1.c:1762:asn1_decode: 'userConsent' not present

[hamarituc]

The userConsent-field is not contained in the private key description object of the "Authentisierungsschluessel". It should be expected as an INTEGER tag between line 6-7. But for the "Signaturschluessel" it is present on line 21. For some reason the flag is not reported upward through the stack.

OpenSC [3F00/0104]> asn1 5001
30 SEQUENCE (66 bytes)
   30 SEQUENCE (35 bytes)
      0C UTF8String (26 bytes): Authentisierungsschluessel
      03 BIT STRING (2 bytes): 01
      04 OCTET STRING (1 byte): 03 .
   30 SEQUENCE (11 bytes)
      04 OCTET STRING (1 byte): 03 .
      03 BIT STRING (2 bytes): 101110
      02 INTEGER (2 bytes): 3
   A1 Context 1  (14 bytes)
      30 SEQUENCE (12 bytes)
         30 SEQUENCE (6 bytes)
            04 OCTET STRING (4 bytes): 3F 00 01 02 ?...
         02 INTEGER (2 bytes): 3072
30 SEQUENCE (62 bytes)
   30 SEQUENCE (30 bytes)
      0C UTF8String (18 bytes): Signaturschluessel
      03 BIT STRING (2 bytes): 01
      04 OCTET STRING (1 byte): 07 .
      02 INTEGER (1 byte): 1
   30 SEQUENCE (12 bytes)
      04 OCTET STRING (1 byte): 02 .
      03 BIT STRING (3 bytes): 1000000000
      02 INTEGER (2 bytes): 2
   A1 Context 1  (14 bytes)
      30 SEQUENCE (12 bytes)
         30 SEQUENCE (6 bytes)
            04 OCTET STRING (4 bytes): 3F 00 01 01 ?...
         02 INTEGER (2 bytes): 3072

[gh47110815]

@frankmorgner : by the way: I would like to give you ALL log files in ALL log levels you need to be able to analyze this issue BUT I have read a notice that I have to be careful with that, because the logs might contain sensitive information like pins etc.

And due to the fact, that I feel "overstrained" (überfordert) with tons of lines of output, I decided not to put it here by just pasting it 1:1 - sorry for that. Next time please let me know, what I have to strip/delete and I will provide all the rest. Maybe there is something like a "Beginners-Guide" to log file handling, then just sent me the link ;-)

[Jakuje]

Keep Adobe open between the signing operations, but remove the card from the reader an reinsert it

I did not read through all the comments, but from the description and if the above use case is not working, I think it is an issue of the software using the OpenSC, that it is not able to detect the card removal and re-issue login. There is nothing in the OpenSC that could do this for the application. Once the card is removed from the reader, OpenSC removes all the structures that represent the card and treat newly inserted card as a new one (because it can be completely different card with different pin and different objects).

I do not know what API is used by the Acrobat on Mac so I will not be much help regarding getting debug information from there.

[gh47110815]

Hi @Jakuje , just to clear the "API" Question....

In Adobe Acrobat (and also in Adobe Reader) you can "attach" PKCS11 Modules (by the way - that's exactly why I am landed here, because I want to sign PDFs with Acrobat or Reader using OpenSC framework ;-).
There you have to enter the path to the pkcs11 library. In my case I just entered "/usr/local/lib/opensc-pkcs11.so"
Hope this answers your question: API is provided by exactly this opensc-pkcs11.so library I build using the master branch with the brand new d-trust driver. Hope this makes sense regarding your comment what API is used.

P.S.: And removing and reinserting was just one of four tests I should do so that the developer of the d-trust card can analyze, where exactly the issue arises in my case. Currently everything is indicating that this is an issue regarding PIN-Caching, because the D-TRUST-Cards require entering a PIN every time you want to sign a document. That's because we are talking about so called "qualified digital signatures" and "eIDAS" here. So maybe, the user (me) would be able to work around just by configuring opensc.conf a way that PIN-Caching is avoided when using such a D-Trust Signature Card. That's my personal understanding of the current situation - but I might be wrong ;-)

[Jakuje]

Thank you for clarification. So in that case, I would go ahead to try to gather the PKCS#11 trace using pkcs11-spy to see what is going on there, see

https://github.com/OpenSC/OpenSC/wiki/Using-OpenSC

You will find much easier to remove the sensitive data from the pkcs11 level log. It will be likely just the pin in the C_Login() function.

My assumption is that after you remove the card, the adobe will try to use some stale handles that will not work. After that, it should try to open a new session and login again, which is either not happening or it is happening wrongly (or the opensc returns some unexpected return codes that adobe does not interpret as a need to reauthenticate. We had something similar with NSS couple of years back.

[dengert]

We had something similar with NSS couple of years back.

I asume you re referring to: opensc.conf https://github.com/OpenSC/OpenSC/blob/master/etc/opensc.conf.example.in#L941-L946