search

kenh / keychain-pkcs11

A shared library that implements a PKCS#11 interface to the Apple Security framework
100 stars 10 forks source link

using for ssh key from a smartcard times out in a weird way #13

Open bernstei opened 1 year ago

bernstei commented 1 year ago

I'm using keychain-pkcs11 to authenticate to SSH using a smartcard-derived key by doing ssh-add -s /usr/local/lib/keychain-pkcs11.dylib. This works fine initially, but if some time passes, the PIN seems to time out, because when I try to make an ssh connection using that key it pops up a GUI pin entry window. The GUI appears to accept the pin, but this always leads to a failed ssh login (next time it happens I'll save the error message and post here). I then have to re-init the ssh agent by doing ssh-add -e /usr/lib...pkcs11.dylib; ssh-add -s /usr/lib...pkcs11.dylib. During this reinit it again asks for my CAC pin, but with a text prompt, not a GUI window popup, and then the ssh works.

bernstei commented 1 year ago 
sign_and_send_pubkey: signing failed: agent refused operation
git@<FQDN>: Permission denied (publickey).
keychain-pkcs11-popup
kenh commented 1 year ago

"Hm".

So the whole dynamics between "text PIN prompts" and the GUI popup is a little weird. The PKCS#11 API assumes that you're going to pass in the PIN via the API, but the Apple API doesn't QUITE support that in an obvious way. So I use a non-obvious way to do that (which I gleaned from the Apple old PKCS#11 ssh plug-in). And the type of error messages you can pass back via the PKCS#11 API is very limited.

If you run this command (listed in man keychain-pkcs11) when this happens, you should get a bunch of debugging output from the library. Could you send it to me? You need to start this command before you try the ssh command. You MIGHT need to be root to run it; if so, just use sudo. Also probably best to redirect the output to a file as I imagine there will be a lot of it.

log stream --predicate 'subsystem = "mil.navy.nrl.cmf.pkcs11"' --level debug
bernstei commented 1 year ago

I've attached the log stream output.

Filtering the log data using "subsystem == "mil.navy.nrl.cmf.pkcs11"" Timestamp Thread Type Activity PID TTL
2022-12-02 12:41:24.831372-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Looking for identities for token com.apple.pivtoken:4B8564CB5FCF45FEBA2D0F6BD4DDBFB1 2022-12-02 12:41:24.838637-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] 3 identities found 2022-12-02 12:41:24.838751-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copying identity 1 2022-12-02 12:41:24.845768-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Identity label: Certificate For PIV Authentication (BERNSTEIN.NOAM.1241958279) 2022-12-02 12:41:24.845861-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] This is a RSA Key 2022-12-02 12:41:24.845916-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Sign is set to true 2022-12-02 12:41:24.845963-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Decrypt is set to false 2022-12-02 12:41:24.859262-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Verify is set to true 2022-12-02 12:41:24.859331-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Encrypt is set to true 2022-12-02 12:41:24.859374-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Wrap is set to false 2022-12-02 12:41:24.859414-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copying identity 2 2022-12-02 12:41:24.864407-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Identity label: Certificate For Digital Signature (BERNSTEIN.NOAM.1241958279) 2022-12-02 12:41:24.864461-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] This is a RSA Key 2022-12-02 12:41:24.864499-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Sign is set to true 2022-12-02 12:41:24.864532-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Decrypt is set to false 2022-12-02 12:41:24.865571-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Verify is set to true 2022-12-02 12:41:24.865624-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Encrypt is set to true 2022-12-02 12:41:24.865663-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Wrap is set to true 2022-12-02 12:41:24.865698-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copying identity 3 2022-12-02 12:41:24.870513-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Identity label: Certificate For Key Management (BERNSTEIN.NOAM.1241958279) 2022-12-02 12:41:24.870567-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] This is a RSA Key 2022-12-02 12:41:24.870605-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Sign is set to false 2022-12-02 12:41:24.870638-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Decrypt is set to true 2022-12-02 12:41:24.871751-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Verify is set to false 2022-12-02 12:41:24.871795-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Encrypt is set to false 2022-12-02 12:41:24.871829-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Wrap is set to true 2022-12-02 12:41:24.874937-0500 0x46e9d3 Debug 0x5b6f61 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Adding new token at slot 0 2022-12-02 12:41:32.425281-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsInit called 2022-12-02 12:41:32.425458-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, template = 0x16b3739b0, count = 3 2022-12-02 12:41:32.425560-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Search template: CKA_CLASS: CKO_PRIVATE_KEY 2022-12-02 12:41:32.425644-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Search template: CKA_ID, len = 1, val = 0x148117b30 2022-12-02 12:41:32.425726-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Search template: CKA_SIGN, len = 1, val = 0x14810fc10 2022-12-02 12:41:32.425803-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsInit returning CKR_OK 2022-12-02 12:41:32.425877-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects called 2022-12-02 12:41:32.426030-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, objhandle = 0x16b373988, maxcount = 1, count = 0x16b3738e8 2022-12-02 12:41:32.426208-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Found 1 object 2022-12-02 12:41:32.426434-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects returning CKR_OK 2022-12-02 12:41:32.426584-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsFinal called 2022-12-02 12:41:32.426771-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 0 2022-12-02 12:41:32.426938-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsFinal returning CKR_OK 2022-12-02 12:41:32.427066-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_SignInit called 2022-12-02 12:41:32.427185-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, mechanism = CKM_RSA_PKCS, object = 3 2022-12-02 12:41:32.427388-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Signing algorithm chosen: algid:sign:RSA:digest-PKCS1v15 2022-12-02 12:41:32.427561-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Digest signing algorithm chosen: (null) 2022-12-02 12:41:32.427748-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Digest algorithm chosen: CKM_RSA_PKCS_KEY_PAIR_GEN 2022-12-02 12:41:32.427962-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_SignInit returning CKR_OK 2022-12-02 12:41:32.428096-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:32.428326-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 3, template = 0x16b373990, count = 1 2022-12-02 12:41:32.428460-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 2 (CKO_PRIVATE_KEY) 2022-12-02 12:41:32.428637-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_ALWAYS_AUTHENTICATE 2022-12-02 12:41:32.428860-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (1, 1) 2022-12-02 12:41:32.428997-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:32.429144-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_Sign called 2022-12-02 12:41:32.429358-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, indata = 0x148124570, inlen = 51, outdata = 0x1481349c0, outlen = 256 2022-12-02 12:41:36.221764-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] SecKeyCreateSignature failed: Error Domain=CryptoTokenKit Code=-5 "(null)" 2022-12-02 12:41:36.221850-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_Sign returning CKR_GENERAL_ERROR 2022-12-02 12:41:40.053833-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_CloseSession called 2022-12-02 12:41:40.054988-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1 2022-12-02 12:41:40.055199-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] slot_entry_free for slot com.apple.pivtoken:4B8564CB5FCF45FEBA2D0F6BD4DDBFB1 (refcount 1) 2022-12-02 12:41:40.057995-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_CloseSession returning CKR_OK 2022-12-02 12:41:40.058100-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_Finalize called 2022-12-02 12:41:40.058251-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] slot_entry_free for slot com.apple.pivtoken:4B8564CB5FCF45FEBA2D0F6BD4DDBFB1 (refcount 1) 2022-12-02 12:41:40.059711-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_Finalize returning CKR_OK 2022-12-02 12:41:43.804690-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetFunctionList called 2022-12-02 12:41:43.804771-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetFunctionList returning CKR_OK 2022-12-02 12:41:43.804810-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_Initialize called 2022-12-02 12:41:43.804848-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] init was set to NULL 2022-12-02 12:41:43.805581-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Program "ssh-pkcs11-helper" is NOT set to ask for PIN, will let Security ask for the PIN 2022-12-02 12:41:43.805643-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Program "ssh-pkcs11-helper" has the Keychain Certificate slot DISABLED 2022-12-02 12:41:43.808399-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Looking for identities for token com.apple.setoken 2022-12-02 12:41:43.809086-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] No identities found 2022-12-02 12:41:43.809139-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Looking for identities for token com.apple.setoken:aks 2022-12-02 12:41:43.809597-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] No identities found 2022-12-02 12:41:43.809644-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Looking for identities for token com.apple.pivtoken:4B8564CB5FCF45FEBA2D0F6BD4DDBFB1 2022-12-02 12:41:43.814468-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] 3 identities found 2022-12-02 12:41:43.814553-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copying identity 1 2022-12-02 12:41:43.821463-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Identity label: Certificate For PIV Authentication (BERNSTEIN.NOAM.1241958279) 2022-12-02 12:41:43.821575-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] This is a RSA Key 2022-12-02 12:41:43.821627-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Sign is set to true 2022-12-02 12:41:43.821676-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Decrypt is set to false 2022-12-02 12:41:43.835616-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Verify is set to true 2022-12-02 12:41:43.835723-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Encrypt is set to true 2022-12-02 12:41:43.835767-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Wrap is set to false 2022-12-02 12:41:43.835807-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copying identity 2 2022-12-02 12:41:43.840891-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Identity label: Certificate For Digital Signature (BERNSTEIN.NOAM.1241958279) 2022-12-02 12:41:43.840975-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] This is a RSA Key 2022-12-02 12:41:43.841049-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Sign is set to true 2022-12-02 12:41:43.841091-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Decrypt is set to false 2022-12-02 12:41:43.842914-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Verify is set to true 2022-12-02 12:41:43.843374-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Encrypt is set to true 2022-12-02 12:41:43.843431-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Wrap is set to true 2022-12-02 12:41:43.843566-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copying identity 3 2022-12-02 12:41:43.850657-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Identity label: Certificate For Key Management (BERNSTEIN.NOAM.1241958279) 2022-12-02 12:41:43.850795-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] This is a RSA Key 2022-12-02 12:41:43.850840-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Sign is set to false 2022-12-02 12:41:43.850882-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Decrypt is set to true 2022-12-02 12:41:43.852483-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Verify is set to false 2022-12-02 12:41:43.852573-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Encrypt is set to false 2022-12-02 12:41:43.852614-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Wrap is set to true 2022-12-02 12:41:43.855871-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Adding new token at slot 0 2022-12-02 12:41:43.856026-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_Initalize returning CKR_OK 2022-12-02 12:41:43.856071-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetInfo called 2022-12-02 12:41:43.856112-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetInfo returning CKR_OK 2022-12-02 12:41:43.856151-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetSlotList called 2022-12-02 12:41:43.856186-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] tokens_present = true, slot_list = 0x146f3d8c0, slot_num = 0 2022-12-02 12:41:43.856223-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetSlotList returning CKR_OK 2022-12-02 12:41:43.856258-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetSlotList called 2022-12-02 12:41:43.856293-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] tokens_present = true, slot_list = 0x146f3d8c0, slot_num = 1 2022-12-02 12:41:43.856330-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetSlotList returning CKR_OK 2022-12-02 12:41:43.856365-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetTokenInfo called 2022-12-02 12:41:43.856401-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] slot_id = 0, token_info = 0x146f413c0 2022-12-02 12:41:43.856470-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] We ARE setting the flag CKF_PROTECTED_AUTHENTICATION_PATH 2022-12-02 12:41:43.856512-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetTokenInfo returning CKR_OK 2022-12-02 12:41:43.856547-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_OpenSession called 2022-12-02 12:41:43.856582-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] slot_id = 0, flags = 0x6, app_callback = 0x0, notify_callback = 0x0, session_handle = 0x16b373a38 2022-12-02 12:41:43.856627-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_OpenSession returning CKR_OK 2022-12-02 12:41:43.856665-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_Login called 2022-12-02 12:41:43.856702-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, user_type = 1 2022-12-02 12:41:43.856741-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Setting PIN for identity 0, slot 0 2022-12-02 12:41:43.895095-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Setting PIN for identity 1, slot 0 2022-12-02 12:41:43.902151-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Setting PIN for identity 2, slot 0 2022-12-02 12:41:43.907800-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_Login returning CKR_OK 2022-12-02 12:41:43.907882-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsInit called 2022-12-02 12:41:43.907921-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, template = 0x16b373910, count = 1 2022-12-02 12:41:43.907973-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Search template: CKA_CLASS: CKO_PUBLIC_KEY 2022-12-02 12:41:43.908010-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsInit returning CKR_OK 2022-12-02 12:41:43.908045-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects called 2022-12-02 12:41:43.908080-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, objhandle = 0x16b373900, maxcount = 1, count = 0x16b3738f8 2022-12-02 12:41:43.908122-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Found 1 object 2022-12-02 12:41:43.908158-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects returning CKR_OK 2022-12-02 12:41:43.908192-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.908226-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 2, template = 0x16b373910, count = 1 2022-12-02 12:41:43.908271-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 1 (CKO_PUBLIC_KEY) 2022-12-02 12:41:43.908309-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_KEY_TYPE 2022-12-02 12:41:43.908345-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (8, 8) 2022-12-02 12:41:43.908381-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.908513-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.908648-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 2, template = 0x16b373928, count = 3 2022-12-02 12:41:43.908715-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 1 (CKO_PUBLIC_KEY) 2022-12-02 12:41:43.908754-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_ID 2022-12-02 12:41:43.908790-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (1) 2022-12-02 12:41:43.908829-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_MODULUS 2022-12-02 12:41:43.908863-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (256) 2022-12-02 12:41:43.908911-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_PUBLIC_EXPONENT 2022-12-02 12:41:43.909056-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (3) 2022-12-02 12:41:43.909199-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.909374-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.909554-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 2, template = 0x16b373928, count = 3 2022-12-02 12:41:43.909600-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 1 (CKO_PUBLIC_KEY) 2022-12-02 12:41:43.909687-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_ID 2022-12-02 12:41:43.909731-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (1, 1) 2022-12-02 12:41:43.909770-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_MODULUS 2022-12-02 12:41:43.909807-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (256, 256) 2022-12-02 12:41:43.909848-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_PUBLIC_EXPONENT 2022-12-02 12:41:43.909884-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (3, 3) 2022-12-02 12:41:43.909923-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.909973-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects called 2022-12-02 12:41:43.910010-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, objhandle = 0x16b373900, maxcount = 1, count = 0x16b3738f8 2022-12-02 12:41:43.910051-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Found 1 object 2022-12-02 12:41:43.910087-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects returning CKR_OK 2022-12-02 12:41:43.910123-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.910157-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 5, template = 0x16b373910, count = 1 2022-12-02 12:41:43.910195-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 4 (CKO_PUBLIC_KEY) 2022-12-02 12:41:43.910253-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_KEY_TYPE 2022-12-02 12:41:43.910325-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (8, 8) 2022-12-02 12:41:43.910363-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.910398-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.910480-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 5, template = 0x16b373928, count = 3 2022-12-02 12:41:43.910528-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 4 (CKO_PUBLIC_KEY) 2022-12-02 12:41:43.910568-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_ID 2022-12-02 12:41:43.910604-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (1) 2022-12-02 12:41:43.910645-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_MODULUS 2022-12-02 12:41:43.910748-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (256) 2022-12-02 12:41:43.910793-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_PUBLIC_EXPONENT 2022-12-02 12:41:43.910854-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (3) 2022-12-02 12:41:43.910892-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.910928-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.910963-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 5, template = 0x16b373928, count = 3 2022-12-02 12:41:43.911001-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 4 (CKO_PUBLIC_KEY) 2022-12-02 12:41:43.911038-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_ID 2022-12-02 12:41:43.911074-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (1, 1) 2022-12-02 12:41:43.911110-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_MODULUS 2022-12-02 12:41:43.911145-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (256, 256) 2022-12-02 12:41:43.911181-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_PUBLIC_EXPONENT 2022-12-02 12:41:43.911216-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (3, 3) 2022-12-02 12:41:43.911252-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.911296-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects called 2022-12-02 12:41:43.911331-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, objhandle = 0x16b373900, maxcount = 1, count = 0x16b3738f8 2022-12-02 12:41:43.911369-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Found 1 object 2022-12-02 12:41:43.911406-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects returning CKR_OK 2022-12-02 12:41:43.911440-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.911476-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 8, template = 0x16b373910, count = 1 2022-12-02 12:41:43.911513-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 7 (CKO_PUBLIC_KEY) 2022-12-02 12:41:43.911631-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_KEY_TYPE 2022-12-02 12:41:43.911668-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (8, 8) 2022-12-02 12:41:43.911702-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.911735-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.911769-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 8, template = 0x16b373928, count = 3 2022-12-02 12:41:43.911805-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 7 (CKO_PUBLIC_KEY) 2022-12-02 12:41:43.911841-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_ID 2022-12-02 12:41:43.911914-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (1) 2022-12-02 12:41:43.911952-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_MODULUS 2022-12-02 12:41:43.912031-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (256) 2022-12-02 12:41:43.912067-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_PUBLIC_EXPONENT 2022-12-02 12:41:43.912102-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (3) 2022-12-02 12:41:43.912138-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.912174-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.912226-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 8, template = 0x16b373928, count = 3 2022-12-02 12:41:43.912267-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 7 (CKO_PUBLIC_KEY) 2022-12-02 12:41:43.912305-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_ID 2022-12-02 12:41:43.912341-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (1, 1) 2022-12-02 12:41:43.912380-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_MODULUS 2022-12-02 12:41:43.912417-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (256, 256) 2022-12-02 12:41:43.912454-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_PUBLIC_EXPONENT 2022-12-02 12:41:43.912491-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (3, 3) 2022-12-02 12:41:43.912527-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.912569-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects called 2022-12-02 12:41:43.912670-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, objhandle = 0x16b373900, maxcount = 1, count = 0x16b3738f8 2022-12-02 12:41:43.912712-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Found 0 objects 2022-12-02 12:41:43.912750-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects returning CKR_OK 2022-12-02 12:41:43.912785-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsFinal called 2022-12-02 12:41:43.912821-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 0 2022-12-02 12:41:43.912972-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsFinal returning CKR_OK 2022-12-02 12:41:43.913006-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsInit called 2022-12-02 12:41:43.913039-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, template = 0x16b373910, count = 1 2022-12-02 12:41:43.913086-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Search template: CKA_CLASS: CKO_CERTIFICATE 2022-12-02 12:41:43.913123-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsInit returning CKR_OK 2022-12-02 12:41:43.913158-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects called 2022-12-02 12:41:43.913223-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, objhandle = 0x16b3738f0, maxcount = 1, count = 0x16b3738e8 2022-12-02 12:41:43.913264-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Found 1 object 2022-12-02 12:41:43.913302-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects returning CKR_OK 2022-12-02 12:41:43.913339-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.913382-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 1, template = 0x16b373910, count = 1 2022-12-02 12:41:43.913440-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 0 (CKO_CERTIFICATE) 2022-12-02 12:41:43.913483-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_CERTIFICATE_TYPE 2022-12-02 12:41:43.913520-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (8, 8) 2022-12-02 12:41:43.913556-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.913591-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.913626-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 1, template = 0x16b373928, count = 3 2022-12-02 12:41:43.913662-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 0 (CKO_CERTIFICATE) 2022-12-02 12:41:43.913699-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_ID 2022-12-02 12:41:43.913734-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (1) 2022-12-02 12:41:43.913770-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_SUBJECT 2022-12-02 12:41:43.913805-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (119) 2022-12-02 12:41:43.913842-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_VALUE 2022-12-02 12:41:43.913878-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (1337) 2022-12-02 12:41:43.913915-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.913951-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.913987-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 1, template = 0x16b373928, count = 3 2022-12-02 12:41:43.914024-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 0 (CKO_CERTIFICATE) 2022-12-02 12:41:43.914060-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_ID 2022-12-02 12:41:43.914095-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (1, 1) 2022-12-02 12:41:43.914134-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_SUBJECT 2022-12-02 12:41:43.914170-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (119, 119) 2022-12-02 12:41:43.914207-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_VALUE 2022-12-02 12:41:43.914242-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (1337, 1337) 2022-12-02 12:41:43.914279-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.914529-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects called 2022-12-02 12:41:43.914572-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, objhandle = 0x16b3738f0, maxcount = 1, count = 0x16b3738e8 2022-12-02 12:41:43.914613-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Found 1 object 2022-12-02 12:41:43.914651-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects returning CKR_OK 2022-12-02 12:41:43.914687-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.914722-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 4, template = 0x16b373910, count = 1 2022-12-02 12:41:43.914759-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 3 (CKO_CERTIFICATE) 2022-12-02 12:41:43.914796-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_CERTIFICATE_TYPE 2022-12-02 12:41:43.914832-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (8, 8) 2022-12-02 12:41:43.914868-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.914904-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.914939-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 4, template = 0x16b373928, count = 3 2022-12-02 12:41:43.914976-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 3 (CKO_CERTIFICATE) 2022-12-02 12:41:43.915014-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_ID 2022-12-02 12:41:43.915052-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (1) 2022-12-02 12:41:43.915088-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_SUBJECT 2022-12-02 12:41:43.915124-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (119) 2022-12-02 12:41:43.915160-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_VALUE 2022-12-02 12:41:43.915195-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (1276) 2022-12-02 12:41:43.915231-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.915267-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.915303-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 4, template = 0x16b373928, count = 3 2022-12-02 12:41:43.915341-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 3 (CKO_CERTIFICATE) 2022-12-02 12:41:43.915378-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_ID 2022-12-02 12:41:43.915414-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (1, 1) 2022-12-02 12:41:43.915452-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_SUBJECT 2022-12-02 12:41:43.915487-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (119, 119) 2022-12-02 12:41:43.915524-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_VALUE 2022-12-02 12:41:43.915560-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (1276, 1276) 2022-12-02 12:41:43.915596-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.915777-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects called 2022-12-02 12:41:43.915821-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, objhandle = 0x16b3738f0, maxcount = 1, count = 0x16b3738e8 2022-12-02 12:41:43.915862-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Found 1 object 2022-12-02 12:41:43.915899-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects returning CKR_OK 2022-12-02 12:41:43.915935-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.915971-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 7, template = 0x16b373910, count = 1 2022-12-02 12:41:43.916008-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 6 (CKO_CERTIFICATE) 2022-12-02 12:41:43.916046-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_CERTIFICATE_TYPE 2022-12-02 12:41:43.916082-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (8, 8) 2022-12-02 12:41:43.916119-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.916154-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.916194-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 7, template = 0x16b373928, count = 3 2022-12-02 12:41:43.916232-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 6 (CKO_CERTIFICATE) 2022-12-02 12:41:43.916270-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_ID 2022-12-02 12:41:43.916305-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (1) 2022-12-02 12:41:43.916342-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_SUBJECT 2022-12-02 12:41:43.916377-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (119) 2022-12-02 12:41:43.916415-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_VALUE 2022-12-02 12:41:43.916451-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] pValue was NULL, just returning length (1204) 2022-12-02 12:41:43.916487-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.916522-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 12:41:43.916558-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 7, template = 0x16b373928, count = 3 2022-12-02 12:41:43.916597-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 6 (CKO_CERTIFICATE) 2022-12-02 12:41:43.916633-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_ID 2022-12-02 12:41:43.916669-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (1, 1) 2022-12-02 12:41:43.916706-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_SUBJECT 2022-12-02 12:41:43.916742-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (119, 119) 2022-12-02 12:41:43.916785-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_VALUE 2022-12-02 12:41:43.916823-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (1204, 1204) 2022-12-02 12:41:43.916870-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 12:41:43.917140-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects called 2022-12-02 12:41:43.917185-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, objhandle = 0x16b3738f0, maxcount = 1, count = 0x16b3738e8 2022-12-02 12:41:43.917224-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Found 0 objects 2022-12-02 12:41:43.917261-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects returning CKR_OK 2022-12-02 12:41:43.917299-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsFinal called 2022-12-02 12:41:43.917352-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 0 2022-12-02 12:41:43.917393-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsFinal returning CKR_OK 2022-12-02 12:41:46.037145-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsInit called 2022-12-02 12:41:46.037303-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-p

kenh commented 1 year ago

It looks like the critical error is:

2022-12-02 12:41:36.221764-0500 0x3136fc   Debug       0x0                  45841  0    ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] SecKeyCreateSignature failed: Error Domain=CryptoTokenKit Code=-5 "(null)"

Which is ... NOT HELPFUL.

I believe it might be possible to extract some debugging from CryptoTokenKit. I'll look into that and get back to you.

kenh commented 1 year ago

Alright, try this command:

sudo log stream --level debug --predicate 'subsystem = "com.apple.CryptoTokenKit" || subsystem = "mil.navy.nrl.cmf.pkcs11"'

It should produce the same output as above but with more stuff that will hopefully shed some details on the real error.

kenh commented 1 year ago

As a follow-up, I did find this in TKError.h:

TKErrorCodeAuthenticationFailed  = -5

Which, okay, I could have guessed that. But there is probably a deeper error that would be useful to see.

Do you have a time frame for when that PIN entry stops working? I am just wondering what it would take for me to reproduce it here.

I can think of some workarounds that could possibly work if I have an idea what is going wrong.

bernstei commented 1 year ago

On Dec 2, 2022, at 5:12 PM, Ken Hornstein @.**@.>> wrote:

As a follow-up, I did find this in TKError.h:

TKErrorCodeAuthenticationFailed = -5

Which, okay, I could have guessed that. But there is probably a deeper error that would be useful to see.

Do you have a time frame for when that PIN entry stops working? I am just wondering what it would take for me to reproduce it here.

Tens of minutes? I use it to connect to spork.nre.navy.mil with git+ssh

I can think of some workarounds that could possibly work if I have an idea what is going wrong.

— Reply to this email directly, view it on GitHubhttps://github.com/kenh/keychain-pkcs11/issues/13#issuecomment-1335915022, or unsubscribehttps://github.com/notifications/unsubscribe-auth/AAJFRNNB3X4WTALPHXG4GWLWLJX6VANCNFSM6AAAAAASQ43XUE. You are receiving this because you authored the thread.Message ID: @.***>

    U.S. NAVAL

    RESEARCH

    LABORATORY

Noam Bernstein, Ph.D. Center for Materials Physics and Technology U.S. Naval Research Laboratory T +1 202 404 8628 F +1 202 404 7546 https://www.nrl.navy.mil

kenh commented 1 year ago

Hm, 10s of minutes? What version of MacOS X are you using?

bernstei commented 1 year ago

Actually, I think that if you pull the card out and put it back in, and do not remove and re-add the pkcs11 module to the ssh agent, the first time you try to connect with ssh it'll trigger the GUI, and then the login will fail. Here's output from doing that, followed by an ssh-agent pkcs11 library remove and re-add, a text PIN entry, and a successful ssh.

Filtering the log data using "subsystem == "com.apple.CryptoTokenKit" OR subsystem == "mil.navy.nrl.cmf.pkcs11"" Timestamp Thread Type Activity PID TTL
2022-12-02 17:15:19.152559-0500 0x490ef5 Debug 0x0 88820 0 setoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:token] Idle time detected in extension (<SETokenDriver: 0x143614960>), shutting down the context <EXExtensionContextImplementation: 0x143610500> - UUID: E9DA6DCE-2A73-4CDC-9B5F-E0EC850C7A3D - _isHost: NO _isDummyExtension:NO inputItems: ( "<NSExtensionItem: 0x14360d5e0> - userInfo: {\n NSExtensionItemAttachmentsKey = (\n );\n avoidInitialKeepAlive = 0;\n idleTimeout = 5;\n}" ) 2022-12-02 17:15:19.152688-0500 0x490ef5 Debug 0x0 88820 0 setoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:token] Driver shut down all endpoints 2022-12-02 17:15:19.152940-0500 0x490ef5 Debug 0x0 88820 0 setoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:token] Extension request cancelled 2022-12-02 17:15:19.153046-0500 0x490ef5 Debug 0x0 88820 0 setoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:token] Destroying driver <SETokenDriver: 0x143614960> 2022-12-02 17:15:19.153504-0500 0x490c71 Debug 0x5d56a0 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] com.apple.setoken extension request E9DA6DCE-2A73-4CDC-9B5F-E0EC850C7A3D cancelled, removing driver from cache 2022-12-02 17:15:19.153554-0500 0x490c71 Debug 0x5d56a0 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] com.apple.setoken: removing from cache 2022-12-02 17:15:19.153668-0500 0x490c71 Debug 0x5d56a0 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] <TKHostTokenDriver:0x13d40b600 com.apple.CryptoTokenKit.setoken(E9DA6DCE-2A73-4CDC-9B5F-E0EC850C7A3D)>: invalidating 2022-12-02 17:15:22.742443-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsInit called 2022-12-02 17:15:22.742597-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, template = 0x16b3739b0, count = 3 2022-12-02 17:15:22.742698-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Search template: CKA_CLASS: CKO_PRIVATE_KEY 2022-12-02 17:15:22.742782-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Search template: CKA_ID, len = 1, val = 0x146e23d80 2022-12-02 17:15:22.742864-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Search template: CKA_SIGN, len = 1, val = 0x146e284e0 2022-12-02 17:15:22.742940-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsInit returning CKR_OK 2022-12-02 17:15:22.743113-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects called 2022-12-02 17:15:22.743242-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, objhandle = 0x16b373988, maxcount = 1, count = 0x16b3738e8 2022-12-02 17:15:22.743977-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Found 1 object 2022-12-02 17:15:22.744078-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjects returning CKR_OK 2022-12-02 17:15:22.744159-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsFinal called 2022-12-02 17:15:22.744237-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 0 2022-12-02 17:15:22.744318-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_FindObjectsFinal returning CKR_OK 2022-12-02 17:15:22.744393-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_SignInit called 2022-12-02 17:15:22.744472-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, mechanism = CKM_RSA_PKCS, object = 3 2022-12-02 17:15:22.744886-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Signing algorithm chosen: algid:sign:RSA:digest-PKCS1v15 2022-12-02 17:15:22.745120-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Digest signing algorithm chosen: (null) 2022-12-02 17:15:22.745234-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Digest algorithm chosen: CKM_RSA_PKCS_KEY_PAIR_GEN 2022-12-02 17:15:22.746152-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_SignInit returning CKR_OK 2022-12-02 17:15:22.746276-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue called 2022-12-02 17:15:22.746825-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, object = 3, template = 0x16b373990, count = 1 2022-12-02 17:15:22.746974-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Object 2 (CKO_PRIVATE_KEY) 2022-12-02 17:15:22.747114-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Retrieving attribute: CKA_ALWAYS_AUTHENTICATE 2022-12-02 17:15:22.747685-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copied over attribute (1, 1) 2022-12-02 17:15:22.747768-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetAttributeValue returning CKR_OK 2022-12-02 17:15:22.747826-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_Sign called 2022-12-02 17:15:22.747881-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, indata = 0x14805d730, inlen = 51, outdata = 0x14805d570, outlen = 256 2022-12-02 17:15:22.749422-0500 0x488f32 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:22.749487-0500 0x488f32 Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:22.749608-0500 0x488f32 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x14371f8e0>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:22.756504-0500 0x490c71 Debug 0x5d56a1 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:22.756577-0500 0x490c71 Debug 0x5d56a1 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:22.758660-0500 0x490cd4 Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:22.758738-0500 0x490cd4 Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: querying slot for the session, proto=0001, counter=0 2022-12-02 17:15:22.759301-0500 0x480198 Debug 0x5c9899 629 0 com.apple.ifdreader: (CryptoTokenKit) [com.apple.CryptoTokenKit:token] Dell Dell Smart Card Reader Keyboard: connectCardSession:proto=0001, sensitive=0 2022-12-02 17:15:22.759362-0500 0x480198 Debug 0x5c9899 629 0 com.apple.ifdreader: (CryptoTokenKit) [com.apple.CryptoTokenKit:token] Dell Dell Smart Card Reader Keyboard: connect:_state=4,_power=0,_proto=1 2022-12-02 17:15:22.759406-0500 0x480198 Debug 0x5c9899 629 0 com.apple.ifdreader: (CryptoTokenKit) [com.apple.CryptoTokenKit:token] Dell Dell Smart Card Reader Keyboard: card reset 2022-12-02 17:15:22.759515-0500 0x480198 Debug 0x5c9899 629 0 com.apple.ifdreader: (CryptoTokenKit) [com.apple.CryptoTokenKit:token] Dell Dell Smart Card Reader Keyboard: broadcasting state change { atr = {length = 15, bytes = 0x3b7a18000073667465206364313434}; power = 0; prevstate = 4; share = 0; state = 2;} 2022-12-02 17:15:22.759887-0500 0x488f32 Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:2 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.760122-0500 0x49112d Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x14364bf90 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:2 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.760283-0500 0x49112d Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x1437085f0 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:2 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.760600-0500 0x490c71 Debug 0x5c9899 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x13d516c40 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:2 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.760677-0500 0x490e3d Debug 0x5c9899 81758 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x12ce10e30 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:2 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.761175-0500 0x490ed7 Debug 0x5c9899 88818 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x155110210 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:2 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.761246-0500 0x4629cd Debug 0x5c9899 643 0 com.apple.ifdbundle: [com.apple.CryptoTokenKit:smartcard] -> IFDHPowerICC(00000000, action=502) 2022-12-02 17:15:22.819969-0500 0x4629cd Debug 0x5c9899 643 0 com.apple.ifdbundle: [com.apple.CryptoTokenKit:smartcard] <- IFDHPowerICC(atr={length = 15, bytes = 0x3b7a18000073667465206364313434}) = 0 2022-12-02 17:15:22.820391-0500 0x480198 Debug 0x5c9899 629 0 com.apple.ifdreader: (CryptoTokenKit) [com.apple.CryptoTokenKit:token] Dell Dell Smart Card Reader Keyboard: card reset done -> <TKSmartCardATR: 0x14a80a6b0 3b 180000;73667465206364313434> 2022-12-02 17:15:22.820589-0500 0x480198 Debug 0x5c9899 629 0 com.apple.ifdreader: (CryptoTokenKit) [com.apple.CryptoTokenKit:token] Dell Dell Smart Card Reader Keyboard: broadcasting state change { atr = {length = 15, bytes = 0x3b7a18000073667465206364313434}; power = 1; prevstate = 2; share = 0; state = 4;} 2022-12-02 17:15:22.820960-0500 0x488f32 Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:4 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.821216-0500 0x488f32 Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x14364bf90 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:4 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.821060-0500 0x490e3d Debug 0x5c9899 81758 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x12ce10e30 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:4 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.821340-0500 0x49112d Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x1437085f0 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:4 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.821379-0500 0x4629cd Debug 0x5c9899 643 0 com.apple.ifdbundle: [com.apple.CryptoTokenKit:smartcard] -> IFDHSetProtocolParameters(00000000, proto=00000001) 2022-12-02 17:15:22.821485-0500 0x490c71 Debug 0x5c9899 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x13d516c40 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:4 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.821131-0500 0x490ed7 Debug 0x5c9899 88818 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x155110210 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:4 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.821085-0500 0x480198 Debug 0x5c9899 629 0 com.apple.ifdreader: (CryptoTokenKit) [com.apple.CryptoTokenKit:token] Dell Dell Smart Card Reader Keyboard: set protocol 0001 2022-12-02 17:15:22.834027-0500 0x4629cd Debug 0x5c9899 643 0 com.apple.ifdbundle: [com.apple.CryptoTokenKit:smartcard] <- IFDHSetProtocolParameters() = 0 2022-12-02 17:15:22.834295-0500 0x480198 Debug 0x5c9899 629 0 com.apple.ifdreader: [com.apple.CryptoTokenKit:smartcard] chosen proto 1 (mask: 1, protos ( 1 )) 2022-12-02 17:15:22.834369-0500 0x480198 Debug 0x5c9899 629 0 com.apple.ifdreader: (CryptoTokenKit) [com.apple.CryptoTokenKit:token] Dell Dell Smart Card Reader Keyboard: used protocol 0001 2022-12-02 17:15:22.834506-0500 0x480198 Debug 0x5c9899 629 0 com.apple.ifdreader: (CryptoTokenKit) [com.apple.CryptoTokenKit:token] Dell Dell Smart Card Reader Keyboard: broadcasting state change { atr = {length = 15, bytes = 0x3b7a18000073667465206364313434}; power = 2; prevstate = 4; share = 0; state = 4;} 2022-12-02 17:15:22.834869-0500 0x49112d Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:4 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.835080-0500 0x49112d Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x14364bf90 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:4 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.834868-0500 0x490e3d Debug 0x5c9899 81758 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x12ce10e30 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:4 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.834985-0500 0x480198 Debug 0x5c9899 629 0 com.apple.ifdreader: (CryptoTokenKit) [com.apple.CryptoTokenKit:token] Dell Dell Smart Card Reader Keyboard: connectCardSession did RESET & PPS 2022-12-02 17:15:22.834934-0500 0x490ed7 Debug 0x5c9899 88818 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x155110210 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:4 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.835107-0500 0x488f32 Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x1437085f0 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:4 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.835304-0500 0x490c71 Debug 0x5c9899 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardSlot: 0x0x13d516c40 'Dell Dell Smart Card Reader Keyboard'>: stateChangedTo:4 atr:{length = 15, bytes = 0x3b7a18000073667465206364313434} 2022-12-02 17:15:22.835371-0500 0x490cd4 Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: slot answered session <_NSXPCDistantObject: 0x14364bf40> (protocol=0x0001, counter=1) 2022-12-02 17:15:22.835511-0500 0x490cd4 Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] req: a4 0400 le:(null) 2022-12-02 17:15:22.835940-0500 0x4629cd Debug 0x5c9899 643 0 com.apple.ifdbundle: [com.apple.CryptoTokenKit:smartcard] -> IFDHTransmitICC(00000000, proto=0, in=) 2022-12-02 17:15:22.835594-0500 0x490cd4 Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: transmitRequest: 2022-12-02 17:15:23.456127-0500 0x4629cd Debug 0x5c9899 643 0 com.apple.ifdbundle: [com.apple.CryptoTokenKit:smartcard] <- IFDHTransmitICC(out=) = 0 2022-12-02 17:15:23.456436-0500 0x490cd4 Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: transmitRequest got reply (err=(null)) 2022-12-02 17:15:23.456559-0500 0x490cd4 Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] rsp: 9000 len:0: 2022-12-02 17:15:25.822364-0500 0x49112d Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: transmitRequest: 2022-12-02 17:15:25.822942-0500 0x4629cd Debug 0x5c9899 643 0 com.apple.ifdbundle: [com.apple.CryptoTokenKit:smartcard] -> IFDHTransmitICC(00000000, proto=0, in=) 2022-12-02 17:15:25.862907-0500 0x4629cd Debug 0x5c9899 643 0 com.apple.ifdbundle: [com.apple.CryptoTokenKit:smartcard] <- IFDHTransmitICC(out=) = 0 2022-12-02 17:15:25.863293-0500 0x49112d Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: transmitRequest got reply (err=(null)) 2022-12-02 17:15:25.863976-0500 0x490c71 Debug 0x5c9899 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.864283-0500 0x49112d Debug 0x5c9899 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.865003-0500 0x490cd4 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.865076-0500 0x490cd4 Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:25.865235-0500 0x490cd4 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x1437223b0>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:25.871227-0500 0x490c71 Debug 0x5d56a2 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:25.871333-0500 0x490c71 Debug 0x5d56a2 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:25.873005-0500 0x49112d Debug 0x5c989b 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.873650-0500 0x490c71 Debug 0x5c989b 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.873880-0500 0x49112d Debug 0x5c989b 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.874228-0500 0x488f32 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.874262-0500 0x488f32 Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:25.874315-0500 0x488f32 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x1427dadf0>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:25.878002-0500 0x490c71 Debug 0x5d56a3 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:25.878158-0500 0x490c71 Debug 0x5d56a3 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:25.880401-0500 0x49112d Debug 0x5c989d 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.880878-0500 0x490c71 Debug 0x5c989d 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.881023-0500 0x49112d Debug 0x5c989d 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.881382-0500 0x49112d Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.881416-0500 0x49112d Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:25.881522-0500 0x49112d Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x143650f50>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:25.884801-0500 0x490c71 Debug 0x5d56a4 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:25.884869-0500 0x490c71 Debug 0x5d56a4 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:25.886268-0500 0x490cd4 Debug 0x5c989f 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.886744-0500 0x490c71 Debug 0x5c989f 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.886886-0500 0x490cd4 Debug 0x5c989f 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.887194-0500 0x490cd4 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.887225-0500 0x490cd4 Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:25.887276-0500 0x490cd4 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x1427dadf0>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:25.890124-0500 0x490c71 Debug 0x5d56a5 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:25.890162-0500 0x490c71 Debug 0x5d56a5 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:25.891309-0500 0x488f32 Debug 0x5d5791 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.891799-0500 0x490c71 Debug 0x5d5791 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.892016-0500 0x488f32 Debug 0x5d5791 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.892309-0500 0x488f32 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.892342-0500 0x488f32 Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:25.892393-0500 0x488f32 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x143723c40>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:25.895871-0500 0x490c71 Debug 0x5d56a6 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:25.895925-0500 0x490c71 Debug 0x5d56a6 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:25.898174-0500 0x488f32 Debug 0x5d5793 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.898719-0500 0x490c71 Debug 0x5d5793 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.898867-0500 0x488f32 Debug 0x5d5793 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.899195-0500 0x488f32 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.899228-0500 0x488f32 Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:25.899292-0500 0x488f32 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x1427daec0>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:25.902429-0500 0x490c71 Debug 0x5d56a7 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:25.902470-0500 0x490c71 Debug 0x5d56a7 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:25.903696-0500 0x488f32 Debug 0x5d5795 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.904125-0500 0x490c71 Debug 0x5d5795 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.904267-0500 0x488f32 Debug 0x5d5795 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.904552-0500 0x488f32 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.904584-0500 0x488f32 Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:25.904684-0500 0x488f32 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x1430a3790>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:25.907426-0500 0x490c71 Debug 0x5d56a8 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:25.907476-0500 0x490c71 Debug 0x5d56a8 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:25.908679-0500 0x488f32 Debug 0x5d5797 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.909088-0500 0x490c71 Debug 0x5d5797 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.909223-0500 0x488f32 Debug 0x5d5797 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.909524-0500 0x488f32 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.909556-0500 0x488f32 Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:25.909624-0500 0x488f32 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x143651e00>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:25.913079-0500 0x490c71 Debug 0x5d56a9 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:25.913134-0500 0x490c71 Debug 0x5d56a9 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:25.915112-0500 0x490cd4 Debug 0x5d5799 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.915615-0500 0x490c71 Debug 0x5d5799 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.915763-0500 0x490cd4 Debug 0x5d5799 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.916090-0500 0x49112d Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.916122-0500 0x49112d Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:25.916175-0500 0x49112d Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x1427dc460>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:25.919239-0500 0x490c71 Debug 0x5d56aa 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:25.919278-0500 0x490c71 Debug 0x5d56aa 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:25.920459-0500 0x490cd4 Debug 0x5d579b 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.920912-0500 0x490c71 Debug 0x5d579b 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.921065-0500 0x490cd4 Debug 0x5d579b 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.921401-0500 0x490cd4 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.921434-0500 0x490cd4 Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:25.921552-0500 0x490cd4 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x1427dc460>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:25.924892-0500 0x490eef Debug 0x5d56ab 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:25.924939-0500 0x490eef Debug 0x5d56ab 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:25.926510-0500 0x488f32 Debug 0x5d579d 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.927145-0500 0x490eef Debug 0x5d579d 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.927383-0500 0x488f32 Debug 0x5d579d 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.928040-0500 0x490cd4 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.928131-0500 0x490cd4 Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:25.928282-0500 0x490cd4 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x1430a4870>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:25.931861-0500 0x490eef Debug 0x5d56ac 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:25.931911-0500 0x490eef Debug 0x5d56ac 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:25.933278-0500 0x488f32 Debug 0x5d579f 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.933728-0500 0x490eef Debug 0x5d579f 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.933871-0500 0x488f32 Debug 0x5d579f 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.934180-0500 0x49112d Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.934213-0500 0x49112d Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:25.934345-0500 0x49112d Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x1437255b0>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:25.937137-0500 0x490eef Debug 0x5d56ad 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:25.937176-0500 0x490eef Debug 0x5d56ad 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:25.938278-0500 0x488f32 Debug 0x5d57a1 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.938697-0500 0x490eef Debug 0x5d57a1 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.938821-0500 0x488f32 Debug 0x5d57a1 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.939085-0500 0x490cd4 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.939117-0500 0x490cd4 Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:25.939164-0500 0x490cd4 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x143654930>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:25.942279-0500 0x490eef Debug 0x5d56ae 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:25.942323-0500 0x490eef Debug 0x5d56ae 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:25.944129-0500 0x488f32 Debug 0x5d57a3 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.945470-0500 0x490eef Debug 0x5d57a3 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.945629-0500 0x488f32 Debug 0x5d57a3 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.945989-0500 0x488f32 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.946022-0500 0x488f32 Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:25.946077-0500 0x488f32 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x143654950>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:25.949347-0500 0x490eef Debug 0x5d56af 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:25.949388-0500 0x490eef Debug 0x5d56af 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:25.950688-0500 0x49112d Debug 0x5d57a5 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.951091-0500 0x490eef Debug 0x5d57a5 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.951209-0500 0x49112d Debug 0x5d57a5 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.951527-0500 0x490cd4 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.951561-0500 0x490cd4 Info 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: an attempt to begin session with invalidated (removed) card 2022-12-02 17:15:25.951610-0500 0x490cd4 Debug 0x5d565e 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCardWithError: 0x1427dd1c0>: connected to slot <TKSmartCardSlot: 0x0x1427cdce0 'Dell Dell Smart Card Reader Keyboard'> 2022-12-02 17:15:25.954273-0500 0x490eef Debug 0x5d57c0 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:25.954313-0500 0x490eef Debug 0x5d57c0 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:25.955422-0500 0x49112d Debug 0x5d57a7 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:25.955833-0500 0x490eef Debug 0x5d57a7 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:25.955963-0500 0x49112d Debug 0x5d57a7 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:25.956171-0500 0x3136fc Fault 0x5d565f 45841 0 ssh-pkcs11-helper: (CryptoTokenKit) [com.apple.CryptoTokenKit:client] authentication failed repeatedly: tkid=com.apple.pivtoken:4B8564CB5FCF45FEBA2D0F6BD4DDBFB1, ac=<SecAccessControlRef: tkid(com.apple.pivtoken:4B8564CB5FCF45FEBA2D0F6BD4DDBFB1);osgn(PIN)>, op=osgn 2022-12-02 17:15:25.956267-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] SecKeyCreateSignature failed: Error Domain=CryptoTokenKit Code=-5 "(null)" 2022-12-02 17:15:25.956335-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_Sign returning CKR_GENERAL_ERROR 2022-12-02 17:15:37.191148-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_CloseSession called 2022-12-02 17:15:37.191341-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1 2022-12-02 17:15:37.191429-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] slot_entry_free for slot com.apple.pivtoken:4B8564CB5FCF45FEBA2D0F6BD4DDBFB1 (refcount 1) 2022-12-02 17:15:37.193191-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_CloseSession returning CKR_OK 2022-12-02 17:15:37.193312-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_Finalize called 2022-12-02 17:15:37.193488-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] slot_entry_free for slot com.apple.pivtoken:4B8564CB5FCF45FEBA2D0F6BD4DDBFB1 (refcount 1) 2022-12-02 17:15:37.195011-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_Finalize returning CKR_OK 2022-12-02 17:15:38.893627-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetFunctionList called 2022-12-02 17:15:38.893706-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetFunctionList returning CKR_OK 2022-12-02 17:15:38.893745-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_Initialize called 2022-12-02 17:15:38.893782-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] init was set to NULL 2022-12-02 17:15:38.893840-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Program "ssh-pkcs11-helper" is NOT set to ask for PIN, will let Security ask for the PIN 2022-12-02 17:15:38.894030-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Program "ssh-pkcs11-helper" has the Keychain Certificate slot DISABLED 2022-12-02 17:15:38.897260-0500 0x4913a2 Debug 0x0 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] returning 1 extensions (1 enumerated) (filter classid=com.apple.setoken) 2022-12-02 17:15:38.897322-0500 0x4913a2 Debug 0x0 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] <TKHostTokenDriver:0x13d3cf770 com.apple.CryptoTokenKit.setoken((null))>: created new 2022-12-02 17:15:38.897566-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Looking for identities for token com.apple.setoken 2022-12-02 17:15:38.898521-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] No identities found 2022-12-02 17:15:38.898586-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Looking for identities for token com.apple.setoken:aks 2022-12-02 17:15:38.899029-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] No identities found 2022-12-02 17:15:38.899081-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Looking for identities for token com.apple.pivtoken:4B8564CB5FCF45FEBA2D0F6BD4DDBFB1 2022-12-02 17:15:38.903650-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] 3 identities found 2022-12-02 17:15:38.903751-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copying identity 1 2022-12-02 17:15:38.910996-0500 0x4913a2 Debug 0x5d57c2 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:38.911071-0500 0x4913a2 Debug 0x5d57c2 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:38.913922-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Identity label: Certificate For PIV Authentication (BERNSTEIN.NOAM.1241958279) 2022-12-02 17:15:38.914211-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] This is a RSA Key 2022-12-02 17:15:38.914279-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Sign is set to true 2022-12-02 17:15:38.914363-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Decrypt is set to false 2022-12-02 17:15:38.929530-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Verify is set to true 2022-12-02 17:15:38.929632-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Encrypt is set to true 2022-12-02 17:15:38.929673-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Wrap is set to false 2022-12-02 17:15:38.929712-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copying identity 2 2022-12-02 17:15:38.934368-0500 0x4913a2 Debug 0x5d57c3 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:38.934422-0500 0x4913a2 Debug 0x5d57c3 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:38.936235-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Identity label: Certificate For Digital Signature (BERNSTEIN.NOAM.1241958279) 2022-12-02 17:15:38.936345-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] This is a RSA Key 2022-12-02 17:15:38.936389-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Sign is set to true 2022-12-02 17:15:38.936429-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Decrypt is set to false 2022-12-02 17:15:38.937950-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Verify is set to true 2022-12-02 17:15:38.938044-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Encrypt is set to true 2022-12-02 17:15:38.938088-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Wrap is set to true 2022-12-02 17:15:38.938127-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Copying identity 3 2022-12-02 17:15:38.942845-0500 0x4913a2 Debug 0x5d57c4 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:38.942909-0500 0x4913a2 Debug 0x5d57c4 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:38.944793-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Identity label: Certificate For Key Management (BERNSTEIN.NOAM.1241958279) 2022-12-02 17:15:38.944905-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] This is a RSA Key 2022-12-02 17:15:38.944947-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Sign is set to false 2022-12-02 17:15:38.944986-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Decrypt is set to true 2022-12-02 17:15:38.946555-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Verify is set to false 2022-12-02 17:15:38.946639-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Encrypt is set to false 2022-12-02 17:15:38.946677-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Can-Wrap is set to true 2022-12-02 17:15:38.950170-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Adding new token at slot 0 2022-12-02 17:15:38.950320-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_Initalize returning CKR_OK 2022-12-02 17:15:38.950364-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetInfo called 2022-12-02 17:15:38.950405-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetInfo returning CKR_OK 2022-12-02 17:15:38.950444-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetSlotList called 2022-12-02 17:15:38.950480-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] tokens_present = true, slot_list = 0x146f3d8c0, slot_num = 0 2022-12-02 17:15:38.950518-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetSlotList returning CKR_OK 2022-12-02 17:15:38.950554-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetSlotList called 2022-12-02 17:15:38.950589-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] tokens_present = true, slot_list = 0x146f3d8c0, slot_num = 1 2022-12-02 17:15:38.950626-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetSlotList returning CKR_OK 2022-12-02 17:15:38.950662-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetTokenInfo called 2022-12-02 17:15:38.950698-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] slot_id = 0, token_info = 0x146f413c0 2022-12-02 17:15:38.950765-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] We ARE setting the flag CKF_PROTECTED_AUTHENTICATION_PATH 2022-12-02 17:15:38.950807-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_GetTokenInfo returning CKR_OK 2022-12-02 17:15:38.950844-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_OpenSession called 2022-12-02 17:15:38.950878-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] slot_id = 0, flags = 0x6, app_callback = 0x0, notify_callback = 0x0, session_handle = 0x16b373a38 2022-12-02 17:15:38.950931-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_OpenSession returning CKR_OK 2022-12-02 17:15:38.950969-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] C_Login called 2022-12-02 17:15:38.951005-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] session = 1, user_type = 1 2022-12-02 17:15:38.951040-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Setting PIN for identity 0, slot 0 2022-12-02 17:15:38.955178-0500 0x4913a2 Debug 0x5d57c5 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:38.955230-0500 0x4913a2 Debug 0x5d57c5 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:38.956695-0500 0x4913a0 Debug 0x5d57a9 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:38.957468-0500 0x4913a0 Debug 0x5d57a9 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: transmitRequest: 2022-12-02 17:15:38.957708-0500 0x4629cd Debug 0x5d57a9 643 0 com.apple.ifdbundle: [com.apple.CryptoTokenKit:smartcard] -> IFDHTransmitICC(00000000, proto=0, in=) 2022-12-02 17:15:38.989362-0500 0x4629cd Debug 0x5d57a9 643 0 com.apple.ifdbundle: [com.apple.CryptoTokenKit:smartcard] <- IFDHTransmitICC(out=) = 0 2022-12-02 17:15:38.989758-0500 0x4913a0 Debug 0x5d57a9 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: transmitRequest got reply (err=(null)) 2022-12-02 17:15:38.990176-0500 0x4913a2 Debug 0x5d57a9 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:38.990406-0500 0x4913a0 Debug 0x5d57a9 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] <TKSmartCard: 0x14371fd00>: endSession: counter=0, someoneWantsSession=0 2022-12-02 17:15:38.990744-0500 0x3136fc Debug 0x0 45841 0 ssh-pkcs11-helper: (keychain-pkcs11.dylib) [mil.navy.nrl.cmf.pkcs11:general] Setting PIN for identity 1, slot 0 2022-12-02 17:15:38.994626-0500 0x49136f Debug 0x5d57c6 1330 0 ctkd: (CryptoTokenKit) [com.apple.CryptoTokenKit:token_access_registry] Platform rule matched 2022-12-02 17:15:38.994678-0500 0x49136f Debug 0x5d57c6 1330 0 ctkd: [com.apple.CryptoTokenKit:tkserver] Request from: '(null)' to access '' was granted 2022-12-02 17:15:38.996615-0500 0x4913bc Debug 0x5d57ab 10889 0 pivtoken: (CryptoTokenKit) [com.apple.CryptoTokenKit:smartcard] Dell Dell Smart Card Reader Keyboard: begin exclusive SmartCard session 2022-12-02 17:15:38.997247-0500 0x49136f Debug 0x5d57ab 1330 0 ctkd: [com.apple.CryptoTokenKit:tokenhost] auditAuthOperation infoText: sucess: 1 2022-12-02 17:15:38.997486-0500 0x4913bc Debug 0x5d57ab 10889 0 pivtoken: (C

bernstei commented 1 year ago

On Dec 2, 2022, at 5:16 PM, Ken Hornstein @.**@.>> wrote:

Hm, 10s of minutes? What version of MacOS X are you using?

Big Sur 11.7.1

kenh commented 1 year ago

Actually, I think that if you pull the card out and put it back in, and do not remove and re-add the pkcs11 module to the ssh agent, the first time you try to connect with ssh it'll trigger the GUI, and then the login will fail.

Okay, THAT I could believe.

From the PKCS#11 side, you're supposed to detect the card has been removed and then re-login in again and ssh may not be doing that. Although I kind of wonder why you get a GUI pop-up and then a failure.

But ... I just tested this on Catalina and while I do get a GUI pop-up for the PIN after I re-insert the card it then succeeds. Silly question: are you using your PIV key with this repo, or your email key? I realize it may not be obvious to tell which one you are using. I might have to try it on Big Sur.

bernstei commented 1 year ago

On Dec 2, 2022, at 5:27 PM, Ken Hornstein @.**@.>> wrote:

Actually, I think that if you pull the card out and put it back in, and do not remove and re-add the pkcs11 module to the ssh agent, the first time you try to connect with ssh it'll trigger the GUI, and then the login will fail.

Okay, THAT I could believe.

I don't even know this is in fact at a low level the same behavior as when some time passes, but superficially it behaves the same.

From the PKCS#11 side, you're supposed to detect the card has been removed and then re-login in again and ssh may not be doing that. Although I kind of wonder why you get a GUI pop-up and then a failure

It makes sense that it asks for the pin again, it's just that the GUI pin popup leads to a failed ssh login, and the library remove/re-add to the agent works.

But ... I just tested this on Catalina and while I do get a GUI pop-up for the PIN after I re-insert the card it then succeeds. Silly question: are you using your PIV key with this repo, or your email key? I realize it may not be obvious to tell which one you are using. I might have to try it on Big Sur.

Good question. I'll try to figure it out.

bernstei commented 1 year ago

I tried to re-add the one that's definitely the PIV key, and it appears that it's the same as the one I've been using all along.