Skip to content

Instantly share code, notes, and snippets.

@w-vi
Created April 12, 2022 19:02
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save w-vi/0e6925d7a44d135b7597fe2fcff5b69d to your computer and use it in GitHub Desktop.
Save w-vi/0e6925d7a44d135b7597fe2fcff5b69d to your computer and use it in GitHub Desktop.

Debugging ssh

Connection

First thing is to get the debug output from ssh.

$ ssh -vvv <host>

There will be a lot of output so maybe start with just -v.

Invalid key

If you see Load key "/home/user/.ssh/id_rsa": invalid format try the following:

  1. Verify that it really fails on key:
$ ssh-add ~/.ssh/id_rsa
Load key "/home/user/.ssh/id_rsa": invalid format
  1. Identify the file with
$ file ~/.ssh/id_rsa
id_rsa: OpenSSH private key

If it says ASCII text or stuff like that it is borken somehow.

  1. Verify that there are no hidden characters on bad places
$ grep '^-----' id_rsa
-----BEGIN RSA PRIVATE KEY-----
-----END RSA PRIVATE KEY-----

Unless you see this it has some issue maybe UTF-8 BOM?

  1. Attempt fix by
$ tail -c +4 ~/.ssh/id_rsa > new_shiny_rsa
  1. Verify and if not OK then it is time to try searching the internet more.

Using Yubikey

If you see your SSH agent offering the key from your Yubikey, you're off to a good start. It looks like this:

debug1: Will attempt key: /usr/lib64/pkcs11/opensc-pkcs11.so RSA SHA256:5G5BG1/im52IUcKYYYAD+COzfEvAmYOSNtWv8U agent
debug1: Will attempt key: /usr/lib64/pkcs11/opensc-pkcs11.so RSA SHA256:6F6ZG2imJLQScAHTnwDWuS5H/FZJiyd+OI31Sc agent
debug1: Will attempt key: /usr/lib64/pkcs11/opensc-pkcs11.so RSA SHA256:b/Ebc6SfBNBVtWy6s0iPXaByxAybZ16XnyDcLU agent
debug1: Will attempt key: /usr/lib64/pkcs11/opensc-pkcs11.so RSA SHA256:SpkYBTzWNx1y/lsPqnkBdrq8oCGKyo2vG/zS00 agent
debug1: Will attempt key: /home/user/.ssh/id_rsa RSA SHA256:O2ZGKznTtlBCTLa+cOuHCpdRzFT9cDi0yTiqad/0
debug1: Will attempt key: /home/user/.ssh/id_dsa
debug1: Will attempt key: /home/user/.ssh/id_ecdsa
debug1: Will attempt key: /home/user/.ssh/id_ed25519
debug1: Will attempt key: /home/user/.ssh/id_xmss

If you don't see output similar to the above, check that you've added the OpenSC provider to your ssh-agent. You can see it successfully added below:

$ ssh-add -l
2048` `SHA256:5G5BG1/im52IUcKYYYAD+CKTbNoOzfEvAmYOSNtWv8U /usr/lib64/pkcs11/opensc-pkcs11.so (RSA)
2048` `SHA256:6F6ZG2imJLQScAHTnwDWuSr5H/BmUcFZJiyd+OI31Sc /usr/lib64/pkcs11/opensc-pkcs11.so (RSA)
2048` `SHA256:b/Ebc6SfBNBVtWy6s0iPXaC1BywPOxAybZ16XnyDcLU /usr/lib64/pkcs11/opensc-pkcs11.so (RSA)
2048` `SHA256:SpkYBTzWNx1y/lsPqnkBdrQOZq8oC2oGKyo2vG/zS00 /usr/lib64/pkcs11/opensc-pkcs11.so (RSA)

If you don't have that output, try to add the provider to your agent:

$ ssh-add -s /usr/lib64/pkcs11/opensc-pkcs11.so     # Note: the path to the provider may be different on your platform.

Going Further

  1. In one terminal, run an SSH agent in the foreground with the debug option set:

    $ ssh-agent -d
    SSH_AUTH_SOCK=/tmp/ssh-XXXXXXXcmFRb/agent.43255; export SSH_AUTH_SOCK;
    echo Agent pid 43255;
    debug1: new_socket: type = SOCKET
    debug2: fd 3 setting O_NONBLOCK
    
  2. Copy the line beginning with SSH_AUTH_SOCK and in a second terminal add the PKCS11 provider to the agent and run ssh:

    $ SSH_AUTH_SOCK=/tmp/ssh-RCDyzky0cJnn/agent.2738429; export SSH_AUTH_SOCK;
    $ ssh-add -s /usr/lib64/pkcs11/opensc-pkcs11.so   # note: this path may vary based on your OS
    $ ssh my.host.com        # optionally, include -v, -vv, or -vvv to emit verbose output
    
  3. On the first terminal, you should see lower level detail from the agent which may be helpful in debugging further.

  4. Additionally, you can go further by enabling OpenSC debug output. Repeat the process starting at step 1, but set OPENSC_DEBUG:

    $ OPENSC_DEBUG=9 ssh-agent -d
    SSH_AUTH_SOCK=/tmp/ssh-RCDyzky0cJnn/agent.2738429; export SSH_AUTH_SOCK;
    echo Agent pid 2738429;
    debug2: fd 3 setting O_NONBLOCK
    
    

Further Still

Using the pkcs11-spy module will log your pin in clear to the logfile you specify. Please put the logfile in a safe place.

Still no luck? Try loading up the pkcs11-spy provider:

$ export PKCS11SPY=/usr/lib64/pkcs11/opensc-pkcs11.so     # Path to the real provider
$ export PKCS11SPY_OUTPUT=/home/uid/log                   # Logfile path
$ export OPENSC_DEBUG=9                                   # Optional
$ ssh-agent -d
SSH_AUTH_SOCK=/tmp/ssh-GQudnHffOwR8/agent.2754160; export SSH_AUTH_SOCK;
echo Agent pid 2754160;
debug2: fd 3 setting O_NONBLOCK

Now load the pkcs11-spy provider, and try to connect to a host using the ssh-agent auth socket provided above:

$ SSH_AUTH_SOCK=/tmp/ssh-GQudnHffOwR8/agent.2754160; export SSH_AUTH_SOCK;
$ ssh-add -s /usr/lib64/pkcs11/pkcs11-spy.so
Enter passphrase for PKCS#11:
Card added: /usr/lib64/pkcs11/pkcs11-spy.so

$ ssh-add -l
2048` `SHA256:5G5BG1/im52IUcKYYYAD+CKTbNoOzfEvAmYOSNtWv8U /usr/lib64/pkcs11-spy.so (RSA)
2048` `SHA256:6F6ZG2imJLQScAHTnwDWuSr5H/BmUcFZJiyd+OI31Sc /usr/lib64/pkcs11-spy.so (RSA)
2048` `SHA256:b/Ebc6SfBNBVtWy6s0iPXaC1BywPOxAybZ16XnyDcLU /usr/lib64/pkcs11-spy.so (RSA)
2048` `SHA256:SpkYBTzWNx1y/lsPqnkBdrQOZq8oC2oGKyo2vG/zS00 /usr/lib64/pkcs11-spy.so (RSA)

$ ssh -v my.host.com

Check the log file you set in the PKCS11SPY_OUTPUT variable for additional detail.

Common Issues

If you see output like the following, check to be sure you don't have PKCS11Provider set in your SSH client configuration at the same time that you are using an SSH agent.

P:2741194; T:0x139640099902656 12:08:52.153 [opensc-pkcs11] apdu.c:382:sc_single_transmit: returning with: 0 (Success)
P:2741194; T:0x139640099902656 12:08:52.154 [opensc-pkcs11] apdu.c:535:sc_transmit: returning with: 0 (Success)
P:2741194; T:0x139640099902656 12:08:52.154 [opensc-pkcs11] card.c:523:sc_unlock: called
P:2741194; T:0x139640099902656 12:08:52.154 [opensc-pkcs11] iso7816.c:128:iso7816_check_sw: Security status not satisfied
P:2741194; T:0x139640099902656 12:08:52.154 [opensc-pkcs11] card-piv.c:577:piv_general_io: Card returned error
P:2741194; T:0x139640099902656 12:08:52.154 [opensc-pkcs11] card.c:523:sc_unlock: called
P:2741194; T:0x139640099902656 12:08:52.154 [opensc-pkcs11] card-piv.c:596:piv_general_io: returning with: -1211 (Security status not satisfied)
P:2741194; T:0x139640099902656 12:08:52.154 [opensc-pkcs11] card-piv.c:2404:piv_validate_general_authentication: returning with: -1211 (Security status not satisfied)
P:2741194; T:0x139640099902656 12:08:52.154 [opensc-pkcs11] card-piv.c:2481:piv_compute_signature: returning with: -1211 (Security status not satisfied)
P:2741194; T:0x139640099902656 12:08:52.154 [opensc-pkcs11] sec.c:63:sc_compute_signature: returning with: -1211 (Security status not satisfied)
P:2741194; T:0x139640099902656 12:08:52.154 [opensc-pkcs11] pkcs15-pin.c:797:sc_pkcs15_pincache_revalidate: called
P:2741194; T:0x139640099902656 12:08:52.154 [opensc-pkcs11] card.c:523:sc_unlock: called
P:2741194; T:0x139640099902656 12:08:52.154 [opensc-pkcs11] pkcs15-sec.c:707:sc_pkcs15_compute_signature: use_key() failed: -1211 (Security status not satisfied)
P:2741194; T:0x139640099902656 12:08:52.154 [opensc-pkcs11] card.c:523:sc_unlock: called
P:2741194; T:0x139640099902656 12:08:52.154 [opensc-pkcs11] reader-pcsc.c:709:pcsc_unlock: called
P:2741194; T:0x139640099902656 12:08:52.159 [opensc-pkcs11] framework-pkcs15.c:4068:pkcs15_prkey_sign: Sign complete. Result -1211.
P:2741194; T:0x139640099902656 12:08:52.159 [opensc-pkcs11] misc.c:71:sc_to_cryptoki_error_common: libopensc return value: -1211 (Security status not satisfied)
P:2741194; T:0x139640099902656 12:08:52.159 [opensc-pkcs11] mechanism.c:478:sc_pkcs11_signature_final: returning with: 257
P:2741194; T:0x139640099902656 12:08:52.159 [opensc-pkcs11] mechanism.c:336:sc_pkcs11_sign_final: returning with: 257
P:2741194; T:0x139640099902656 12:08:52.159 [opensc-pkcs11] pkcs11-object.c:727:C_Sign: C_Sign() = CKR_USER_NOT_LOGGED_IN
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment