Bug 1299994

Summary: ssh client checks only the first certificate on a smartcard when the card has multiple certs
Product: Red Hat Enterprise Linux 6 Reporter: Roshni <rpattath>
Component: sssdAssignee: SSSD Maintainers <sssd-maint>
Status: CLOSED DUPLICATE QA Contact: Steeve Goveas <sgoveas>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 6.8CC: grajaiya, jhrozek, jjelen, ksiddiqu, lslebodn, mkosek, mzidek, pbrezina, plautrba, rpattath, sbose, tmraz
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: sssd-1.13.3-39.el6 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-12-07 17:43:49 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
ssh output none

Description Roshni 2016-01-19 17:19:36 UTC 
Description of problem:
ssh client checks only the first certificate on a smartcard when the card has multiple certs. If the first certificate is revoked and ocsp checking is enabled ssh to smartcard user fails eventhough the card has other certificates that are valid.

Version-Release number of selected component (if applicable):
openssh-5.3p1-113.el6

How reproducible:
always

Steps to Reproduce:
1. A smartcard has a revoked certificate and a valid certificate generated by IPA
2. ssh-add -s <location of pkcs11 lib>
3. ssh -I
/usr/lib64/pkcs11/opensc-pkcs11.so -l ipasmartcarduser5 localhost

Actual results:

Output of step 2:

[rpattath@dhcp123-129 ~]$ ssh-add -s /usr/lib64/pkcs11/opensc-pkcs11.so
Enter passphrase for PKCS#11:
SSH_AGENT_FAILURE
Could not add card: /usr/lib64/pkcs11/opensc-pkcs11.so

Output of step 3:
Prompts for user password and not smartcard pin

Expected results:

Step 2 should add the key of the valid cert on the card to ssh-agent

step 3 should prompt for smartcard pin (by detecting the vaild certificate on the smartcard)

Additional info:
Comment 2 Jakub Jelen 2016-01-20 09:28:22 UTC 
This sounds interesting. Looks like ssh is touching only the first private key found in the smartcard when trying to authenticate, even though it prints all public keys. I am able to reproduce it even with this simplified case using opencryptoki soft token:

 * create two keypairs
 * copy the second public key to the authorized_keys
 * try to authenticate with smartcard
   * asks for PIN for the first key
   * rejects connection

The same happens with upstream openssh version in Fedora 23.

If I understand well, revoked certificate is on the server side so from the ssh side, it does not differ from the others on the card.
Comment 4 Sumit Bose 2016-01-21 12:00:53 UTC 
(In reply to Jakub Jelen from comment #2)
> 
> If I understand well, revoked certificate is on the server side so from the
> ssh side, it does not differ from the others on the card.

Even it is revoked on the server the client can validate them. But I think for the ssh client it would be easier to just generate ssh-keys for all keys found on the card an see if one is accepted by the server. Otherwise if there are multiple valid certificates on the card the ssh client must ask the user which keys should be used which would be odd.
Comment 5 Jakub Jelen 2016-01-22 09:56:26 UTC 
> Even it is revoked on the server the client can validate them. 
Yes, but I don't think it is way to go for openssh to validate X.509 certificates. It might help, but it would not solve the case with two valid keys.

> [...] generate ssh-keys for all keys found on the card an see if one is accepted by the server.
Yes. It would be the correct solution.

Verbose log:

debug1: manufacturerID <IBM> cryptokiVersion 2.20 libraryDescription <Meta PKCS11 LIBRARY> libraryVersion 3.4
debug1: label <swtoken> manufacturerID <IBM Corp.> model <IBM SoftTok> serial <123> flags 0x80044d
debug1: have 1 keys
debug1: have 2 keys
[...]
debug1: Offering RSA public key: /usr/lib64/pkcs11/libopencryptoki.so
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password
debug1: Offering RSA public key: /usr/lib64/pkcs11/libopencryptoki.so
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug1: Server accepts key: pkalg ssh-rsa blen 279
debug2: input_userauth_pk_ok: fp SHA256:YKgplC11MKGi4l74Gl3Qxslo0hMS8AX6cvN63vaPf7U
debug3: sign_and_send_pubkey: RSA SHA256:YKgplC11MKGi4l74Gl3Qxslo0hMS8AX6cvN63vaPf7U
Enter PIN for 'swtoken': 
debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password


As you can see, in the first part the public keys are read, but sshkey structure does not have any reference to the original key identifier (CKA_ID) [1].

In the second part all the public keys are offered and if some is accepted, then the signature from the card is requested. But there is not maintained the key id (CKA_ID) and the signature is made with the first key found on the card.

I will check if there is way to do it better and fill  upstream bug.

[1] https://github.com/openssh/openssh-portable/blob/master/ssh-pkcs11.c#L541
Comment 6 Roshni 2016-02-01 16:31:56 UTC 
Jakub,

Are you waiting for anymore informtion from me about this bug?
Comment 7 Jakub Jelen 2016-02-02 08:09:02 UTC 
I believe we have already enough information about the bug itself, including reproducer with swtoken. I filled upstream bug describing the problem. But fixing would require some more structural changes that I don't want to do without them.

Devel phase for rhel-6.8 is over so I moved the bug to rhel-6.9 if there is no significant demand for the fix. Do you have any customer relying on this feature. That might help us to prioritize it.
Comment 8 Sumit Bose 2016-02-02 08:54:44 UTC 
I'm not aware of an urgent need or a customer relying on it. The issue was found internally while testing the Smartcard support of SSSD.

Do you think it is realistic to fix the issue for 7.3?
Comment 9 Jakub Jelen 2016-02-03 14:58:30 UTC 
Clean solution using something like PKCS #11 URI Scheme would need more changes, as I described in the upstream bug. It also has to work with card added to ssh-agent and to the client itself (both are broken now).

I will try to "hack" some solution that would actually work, but I can't promise it will be good enough nor that it will be accepted upstream. And I don't think we want diverge from upstream too much in RHEL.

If we will not apply this, we should document it as a known issue (though there is no workaround for us case "I want to authenticate with the second key and I don't want to remove the first one").
Comment 10 Jakub Jelen 2016-02-04 09:40:22 UTC 
OK. Another test passed and I found working if properly configured with two keys (different ID). Before I tried keys with same ID, which obviously failed.

What is the output from pkcs11-tool?

    pkcs11-tool --list-objects --slot SLOT_ID --login --module=/path/to/your/lib

Are you sure your keys on card have different IDs?

Can you post the verbose log from your testing? There might be something else I missed.
Comment 11 Jakub Jelen 2016-02-24 09:50:50 UTC 
Can you provide the logs and more information as requested in the previous comment? Otherwise I have no idea _what_ to fix, since my initial reproducer attempt appeared as wrong.
It might be also interesting to see the trace from pkcs11-spy.so
Comment 12 Jakub Jelen 2016-06-23 13:54:37 UTC 
Any update on this? If we would like to see this in RHEL7.3, it is high time to move on. Do we have reliable reproducer?
Comment 13 Roshni 2016-06-23 13:56:13 UTC 
Jakub,

I can reproduce it tomorrow and provide you the information. Sorry for the delay.
Comment 14 Roshni 2016-07-05 20:21:29 UTC 
[rpattath@dhcp129-123 ~]$ pkcs11-tool --list-objects --slot 01 --login --module=/usr/lib64/pkcs11/opensc-pkcs11.so 
Logging in to "OpenSC Card (ipasmartcarduser)".
Please enter User PIN: 
Private Key Object; RSA 
  label:      Certificate
  ID:         4d785d8097e2d77496367ac346e047e6c7476170
  Usage:      sign
Public Key Object; RSA 1024 bits
  label:      Private Key
  ID:         4d785d8097e2d77496367ac346e047e6c7476170
  Usage:      verify
Certificate Object, type = X.509 cert
  label:      Certificate
  ID:         4d785d8097e2d77496367ac346e047e6c7476170
Private Key Object; RSA 
  label:      Certificate
  ID:         8bdc4539cd17f746d139a8e5b201bd0087e2a0d9
  Usage:      sign
Public Key Object; RSA 1024 bits
  label:      Private Key
  ID:         8bdc4539cd17f746d139a8e5b201bd0087e2a0d9
  Usage:      verify
Certificate Object, type = X.509 cert
  label:      Certificate
  ID:         8bdc4539cd17f746d139a8e5b201bd0087e2a0d9
Comment 15 Jakub Jelen 2016-07-07 08:35:33 UTC 
This list looks pretty OK.

If I see right from the original report, the failure comes during the adding of a smartcard to the agent and not during the connection.

During the connection the smartcard is ignored? Can you provide verbose log from

    ssh -vvv -I /usr/lib64/pkcs11/opensc-pkcs11.so -l ipasmartcarduser5 localhost

Are both public keys/certificates visible in the output of

    ssh-keygen -D /usr/lib64/pkcs11/opensc-pkcs11.so

About the ocsp checking, I don't think ssh does that (unless it is done somehow in the background of opensc. SSH just takes public keys and certificates what it is able to find.

Can you also try to see what does the agent do with that card? In one terminal

    export PKCS11SPY=/usr/lib64/pkcs11/opensc-pkcs11.so 
    ssh-agent -d

Coy the SSH_AUTH_SOCK env. variable to the new terminal, and try to add the card using

    ssh-add -s /usr/lib64/pkcs11/opensc-pkcs11.so

It should give some idea what is going on there. Unfortunately I don't have this smartcard to test (and I can't reproduce it with the ones I have).

Does it work with RHEL7?
Comment 16 Roshni 2016-07-07 19:49:55 UTC 
Created attachment 1177438 [details]
ssh output
Comment 17 Roshni 2016-07-07 19:58:32 UTC 
(In reply to Jakub Jelen from comment #15)
> This list looks pretty OK.
> 
> If I see right from the original report, the failure comes during the adding
> of a smartcard to the agent and not during the connection.
> 
> During the connection the smartcard is ignored? Can you provide verbose log
> from
> 
>     ssh -vvv -I /usr/lib64/pkcs11/opensc-pkcs11.so -l ipasmartcarduser5
> localhost
attached the output to the bug
> 
> Are both public keys/certificates visible in the output of
> 
>     ssh-keygen -D /usr/lib64/pkcs11/opensc-pkcs11.so
[rpattath@dhcp129-123 ~]$ ssh-keygen -D /usr/lib64/pkcs11/opensc-pkcs11.so 
ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAAAgQC/0p4qN8c2c71F9N1jVzpmwW0vSleuZCfGRGUzbInNPii+HQHNUW4mfVeam4wCeKfDyOxxgZ/3O3u590c0wu0ZMuIn8hodZD61eOM0gJSe6rH+9Sm5Z05/1V6VTu0ul36Zkacol3ShWpSNkYDam9Pe/4gZwJ4pUn8ZAMo+9RJ06w==
ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAAAgQDM7bn4aFS+rGK7aPyckFwRJ3/mEMyy337pJB2CcyExtvXePyJ8l4ruyLXq+QL+N1Eh8LHo3GeoH6sFX1O3rN1sgj5gSXlEJKDUZo7sKRtTZYDme2fbON93WVWvUbS1ag3RbRBW7Zk1S4lgdUDJUwM/wMal3p9M8JN7V+NFc7t9AQ==
> 
> About the ocsp checking, I don't think ssh does that (unless it is done
> somehow in the background of opensc. SSH just takes public keys and
> certificates what it is able to find.
> 
> Can you also try to see what does the agent do with that card? In one
> terminal
> 
>     export PKCS11SPY=/usr/lib64/pkcs11/opensc-pkcs11.so 
>     ssh-agent -d
> 
> Coy the SSH_AUTH_SOCK env. variable to the new terminal, and try to add the
> card using
> 
>     ssh-add -s /usr/lib64/pkcs11/opensc-pkcs11.so
terminal 1:

[rpattath@dhcp129-123 ~]$ export PKCS11SPY=/usr/lib64/pkcs11/opensc-pkcs11.so 
[rpattath@dhcp129-123 ~]$ ssh-agent -d
SSH_AUTH_SOCK=/tmp/ssh-WZskQa3447/agent.3447; export SSH_AUTH_SOCK;
echo Agent pid 3447;
^[[Adebug1: type 20
debug1: XXX shrink: 3 < 4

terminal2:

[rpattath@dhcp129-123 ~]$ export SSH_AUTH_SOCK=/tmp/ssh-WZskQa3447/agent.3447
[rpattath@dhcp129-123 ~]$ ssh-add -s /usr/lib64/pkcs11/opensc-pkcs11.so
Enter passphrase for PKCS#11: 
Card added: /usr/lib64/pkcs11/opensc-pkcs11.so
> 
> It should give some idea what is going on there. Unfortunately I don't have
> this smartcard to test (and I can't reproduce it with the ones I have).
> 
> Does it work with RHEL7?
On RHEL 7 su, gdm login and ssh login were not supported in this scenario https://bugzilla.redhat.com/show_bug.cgi?id=1267656

Let me know if you need access to my machine for further debugging.
Comment 18 Jakub Jelen 2016-07-11 07:37:25 UTC 
> debug1: Next authentication method: publickey
> debug1: Offering public key: /usr/lib64/pkcs11/opensc-pkcs11.so
> debug3: send_pubkey_test
> debug2: we sent a publickey packet, wait for reply
> debug3: Wrote 256 bytes for a total of 1549
> debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password
> debug1: Offering public key: /usr/lib64/pkcs11/opensc-pkcs11.so
> debug3: send_pubkey_test
> debug2: we sent a publickey packet, wait for reply

This looks ok. It offers both of them and both of them are rejected by server.

> [rpattath@dhcp129-123 ~]$ ssh-add -s /usr/lib64/pkcs11/opensc-pkcs11.so

This should have been 

    ssh-add -s /usr/lib64/pkcs11/pkcs11-spy.so

to get the PKCS#11 transcript.

But from the ssh client side it looks ok (note that the card was successfully added in this case, unlike in the original report. With the original case, you were running  ssh-agent  or some gnome-keyring/seahorse?

Does IPA/sshd server report why the authentication was rejected? When you set up the server LogLevel=DEBUG3 ?
Comment 19 Roshni 2016-07-14 19:10:38 UTC 
(In reply to Jakub Jelen from comment #18)
> > debug1: Next authentication method: publickey
> > debug1: Offering public key: /usr/lib64/pkcs11/opensc-pkcs11.so
> > debug3: send_pubkey_test
> > debug2: we sent a publickey packet, wait for reply
> > debug3: Wrote 256 bytes for a total of 1549
> > debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password
> > debug1: Offering public key: /usr/lib64/pkcs11/opensc-pkcs11.so
> > debug3: send_pubkey_test
> > debug2: we sent a publickey packet, wait for reply
> 
> This looks ok. It offers both of them and both of them are rejected by
> server.
> 
> > [rpattath@dhcp129-123 ~]$ ssh-add -s /usr/lib64/pkcs11/opensc-pkcs11.so
> 
> This should have been 
> 
>     ssh-add -s /usr/lib64/pkcs11/pkcs11-spy.so
> 
> to get the PKCS#11 transcript.

terminal 1

[rpattath@dhcp129-123 ~]$ ssh-agent -d
\SSH_AUTH_SOCK=/tmp/ssh-pXStJf3287/agent.3287; export SSH_AUTH_SOCK;
echo Agent pid 3287;
debug1: type 20


*************** OpenSC PKCS#11 spy *****************
Loaded: "/usr/lib64/pkcs11/opensc-pkcs11.so"


0: C_GetFunctionList
Returned:  0 CKR_OK


1: C_Initialize
[in] pInitArgs = (nil)
Returned:  0 CKR_OK


2: C_GetInfo
[out] pInfo: 
      cryptokiVersion:         2.20
      manufacturerID:         'OpenSC (www.opensc-project.org) '
      flags:                   0
      libraryDescription:     'Smart card PKCS#11 API          '
      libraryVersion:          0.0
Returned:  0 CKR_OK


3: C_GetSlotList
[in] tokenPresent = 0x1
[out] pSlotList: 
Count is 1
[out] *pulCount = 0x1
Returned:  0 CKR_OK


4: C_GetSlotList
[in] tokenPresent = 0x1
[out] pSlotList: 
Slot 1
[out] *pulCount = 0x1
Returned:  0 CKR_OK


5: C_GetTokenInfo
[in] slotID = 0x1
[out] pInfo: 
      label:                  'OpenSC Card (ipasmartcarduser)  '
      manufacturerID:         'OpenSC Project                  '
      model:                  'PKCS#15         '
      serialNumber:           '0C0A54802121381B'
      ulMaxSessionCount:       0
      ulSessionCount:          0
      ulMaxRwSessionCount:     0
      ulRwSessionCount:        0
      ulMaxPinLen:             16
      ulMinPinLen:             4
      ulTotalPublicMemory:     -1
      ulFreePublicMemory:      -1
      ulTotalPrivateMemory:    -1
      ulFreePrivateMemory:     -1
      hardwareVersion:         0.0
      firmwareVersion:         0.0
      time:                   '                '
      flags:                   40c
        CKF_LOGIN_REQUIRED               
        CKF_USER_PIN_INITIALIZED         
        CKF_TOKEN_INITIALIZED            
Returned:  0 CKR_OK


6: C_OpenSession
[in] slotID = 0x1
[in] flags = 0x6
pApplication=(nil)
Notify=(nil)
[out] *phSession = 0x7fb68e0b9720
Returned:  0 CKR_OK


7: C_Login
[in] hSession = 0x7fb68e0b9720
[in] userType = CKU_USER
[in] pPin[ulPinLen] 00007fb68e0a10d0 / 6
    72656468 6174
Returned:  0 CKR_OK


8: C_FindObjectsInit
[in] hSession = 0x7fb68e0b9720
[in] pTemplate[1]: 
    CKA_CLASS             CKO_PUBLIC_KEY       
Returned:  0 CKR_OK


9: C_FindObjects
[in] hSession = 0x7fb68e0b9720
[in] ulMaxObjectCount = 0x1
[out] ulObjectCount = 0x1
Object 0x7fb68e0b3b00 matches
Returned:  0 CKR_OK


10: C_GetAttributeValue
[in] hSession = 0x7fb68e0b9720
[in] hObject = 0x7fb68e0b3b00
[in] pTemplate[3]: 
    CKA_ID                0000000000000000 / 0
    CKA_MODULUS           0000000000000000 / 0
    CKA_PUBLIC_EXPONENT   0000000000000000 / 0
[out] pTemplate[3]: 
    CKA_ID                0000000000000000 / 20
    CKA_MODULUS           0000000000000000 / 128
    CKA_PUBLIC_EXPONENT   0000000000000000 / 3
Returned:  0 CKR_OK


11: C_GetAttributeValue
[in] hSession = 0x7fb68e0b9720
[in] hObject = 0x7fb68e0b3b00
[in] pTemplate[3]: 
    CKA_ID                00007fb68e0b97f0 / 20
    CKA_MODULUS           00007fb68e0b9810 / 128
    CKA_PUBLIC_EXPONENT   00007fb68e0b99e0 / 3
[out] pTemplate[3]: 
    CKA_ID                00007fb68e0b97f0 / 20
    4D785D80 97E2D774 96367AC3 46E047E6 C7476170
    CKA_MODULUS           00007fb68e0b9810 / 128
    BFD29E2A 37C73673 BD45F4DD 63573A66 C16D2F4A 57AE6427 C6446533 6C89CD3E
    28BE1D01 CD516E26 7D579A9B 8C0278A7 C3C8EC71 819FF73B 7BB9F747 34C2ED19
    32E227F2 1A1D643E B578E334 80949EEA B1FEF529 B9674E7F D55E954E ED2E977E
    9991A728 9774A15A 948D9180 DA9BD3DE FF8819C0 9E29527F 1900CA3E F51274EB
    CKA_PUBLIC_EXPONENT   00007fb68e0b99e0 / 3
    010001
Returned:  0 CKR_OK


12: C_FindObjects
[in] hSession = 0x7fb68e0b9720
[in] ulMaxObjectCount = 0x1
[out] ulObjectCount = 0x1
Object 0x7fb68e0b1820 matches
Returned:  0 CKR_OK


13: C_GetAttributeValue
[in] hSession = 0x7fb68e0b9720
[in] hObject = 0x7fb68e0b1820
[in] pTemplate[3]: 
    CKA_ID                0000000000000000 / 0
    CKA_MODULUS           0000000000000000 / 0
    CKA_PUBLIC_EXPONENT   0000000000000000 / 0
[out] pTemplate[3]: 
    CKA_ID                0000000000000000 / 20
    CKA_MODULUS           0000000000000000 / 128
    CKA_PUBLIC_EXPONENT   0000000000000000 / 3
Returned:  0 CKR_OK


14: C_GetAttributeValue
[in] hSession = 0x7fb68e0b9720
[in] hObject = 0x7fb68e0b1820
[in] pTemplate[3]: 
    CKA_ID                00007fb68e0b99e0 / 20
    CKA_MODULUS           00007fb68e0b9810 / 128
    CKA_PUBLIC_EXPONENT   00007fb68e0b97f0 / 3
[out] pTemplate[3]: 
    CKA_ID                00007fb68e0b99e0 / 20
    8BDC4539 CD17F746 D139A8E5 B201BD00 87E2A0D9
    CKA_MODULUS           00007fb68e0b9810 / 128
    CCEDB9F8 6854BEAC 62BB68FC 9C905C11 277FE610 CCB2DF7E E9241D82 732131B6
    F5DE3F22 7C978AEE C8B5EAF9 02FE3751 21F0B1E8 DC67A81F AB055F53 B7ACDD6C
    823E6049 794424A0 D4668EEC 291B5365 80E67B67 DB38DF77 5955AF51 B4B56A0D
    D16D1056 ED99354B 89607540 C953033F C0C6A5DE 9F4CF093 7B57E345 73BB7D01
    CKA_PUBLIC_EXPONENT   00007fb68e0b97f0 / 3
    010001
Returned:  0 CKR_OK


15: C_FindObjects
[in] hSession = 0x7fb68e0b9720
[in] ulMaxObjectCount = 0x1
[out] ulObjectCount = 0x0
Returned:  0 CKR_OK


16: C_FindObjectsFinal
[in] hSession = 0x7fb68e0b9720
Returned:  0 CKR_OK
debug1: XXX shrink: 3 < 4


terminal 2:

[rpattath@dhcp129-123 ~]$ export SSH_AUTH_SOCK=/tmp/ssh-pXStJf3287/agent.3287
[rpattath@dhcp129-123 ~]$ ssh-add -s /usr/lib64/pkcs11/pkcs11-spy.so 
Enter passphrase for PKCS#11: 
Card added: /usr/lib64/pkcs11/pkcs11-spy.so

> 
> But from the ssh client side it looks ok (note that the card was
> successfully added in this case, unlike in the original report. With the
> original case, you were running  ssh-agent  or some gnome-keyring/seahorse?
> 
> Does IPA/sshd server report why the authentication was rejected? When you
> set up the server LogLevel=DEBUG3 ?

After setting LogLevel=DEBUG3 in sshd_config I see the following

[rpattath@dhcp129-123 ~]$ ssh -vvv -I /usr/lib64/pkcs11/opensc-pkcs11.so -l ipasmartcarduser localhost
OpenSSH_5.3p1, OpenSSL 1.0.1e-fips 11 Feb 2013
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Applying options for *
debug2: ssh_connect: needpriv 0
debug1: Executing proxy command: exec /usr/bin/sss_ssh_knownhostsproxy -p 22 localhost
debug1: permanently_drop_suid: 500
debug1: manufacturerID <OpenSC (www.opensc-project.org)> cryptokiVersion 2.20 libraryDescription <Smart card PKCS#11 API> libraryVersion 0.0
debug1: label <OpenSC Card (ipasmartcarduser)> manufacturerID <OpenSC Project> model <PKCS#15> serial <0C0A54802121381> flags 0x40c
debug1: have 1 keys
debug1: have 2 keys
debug1: identity file /home/rpattath/.ssh/identity type -1
debug1: identity file /home/rpattath/.ssh/identity-cert type -1
debug1: identity file /home/rpattath/.ssh/id_rsa type -1
debug1: identity file /home/rpattath/.ssh/id_rsa-cert type -1
debug1: identity file /home/rpattath/.ssh/id_dsa type -1
debug1: identity file /home/rpattath/.ssh/id_dsa-cert type -1
debug1: identity file /home/rpattath/.ssh/id_ecdsa type -1
debug1: identity file /home/rpattath/.ssh/id_ecdsa-cert type -1
debug1: Remote protocol version 2.0, remote software version OpenSSH_5.3
debug1: match: OpenSSH_5.3 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.3
debug2: fd 5 setting O_NONBLOCK
debug2: fd 4 setting O_NONBLOCK
debug1: SSH2_MSG_KEXINIT sent
debug3: Wrote 960 bytes for a total of 981
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa-cert-v01,ssh-dss-cert-v01,ssh-rsa-cert-v00,ssh-dss-cert-v00,ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc.se
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc.se
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib,zlib
debug2: kex_parse_kexinit: none,zlib,zlib
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: first_kex_follows 0 
debug2: kex_parse_kexinit: reserved 0 
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc.se
debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc.se
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64,hmac-sha2-256,hmac-sha2-512,hmac-ripemd160,hmac-ripemd160,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: first_kex_follows 0 
debug2: kex_parse_kexinit: reserved 0 
debug2: mac_setup: found hmac-md5
debug1: kex: server->client aes128-ctr hmac-md5 none
debug2: mac_setup: found hmac-md5
debug1: kex: client->server aes128-ctr hmac-md5 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
debug3: Wrote 24 bytes for a total of 1005
debug2: dh_gen_key: priv key bits set: 135/256
debug2: bits set: 530/1024
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug3: Wrote 144 bytes for a total of 1149
debug3: check_host_in_hostfile: host localhost filename /home/rpattath/.ssh/known_hosts
debug3: check_host_in_hostfile: host localhost filename /home/rpattath/.ssh/known_hosts
debug3: check_host_in_hostfile: match line 2
debug1: Host 'localhost' is known and matches the RSA host key.
debug1: Found key in /home/rpattath/.ssh/known_hosts:2
debug2: bits set: 510/1024
debug1: ssh_rsa_verify: signature correct
debug2: kex_derive_keys
debug2: set_newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug3: Wrote 16 bytes for a total of 1165
debug2: set_newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug3: Wrote 48 bytes for a total of 1213
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug2: key: /usr/lib64/pkcs11/opensc-pkcs11.so (0x7f41081802b0)
debug2: key: /usr/lib64/pkcs11/opensc-pkcs11.so (0x7f41081805d0)
debug2: key: /home/rpattath/.ssh/identity ((nil))
debug2: key: /home/rpattath/.ssh/id_rsa ((nil))
debug2: key: /home/rpattath/.ssh/id_dsa ((nil))
debug2: key: /home/rpattath/.ssh/id_ecdsa ((nil))
debug3: Wrote 80 bytes for a total of 1293
debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password
debug3: start over, passed a different list publickey,gssapi-keyex,gssapi-with-mic,password
debug3: preferred gssapi-keyex,gssapi-with-mic,publickey,keyboard-interactive,password
debug3: authmethod_lookup gssapi-keyex
debug3: remaining preferred: gssapi-with-mic,publickey,keyboard-interactive,password
debug3: authmethod_is_enabled gssapi-keyex
debug1: Next authentication method: gssapi-keyex
debug1: No valid Key exchange context
debug2: we did not send a packet, disable method
debug3: authmethod_lookup gssapi-with-mic
debug3: remaining preferred: publickey,keyboard-interactive,password
debug3: authmethod_is_enabled gssapi-with-mic
debug1: Next authentication method: gssapi-with-mic
debug1: Unspecified GSS failure.  Minor code may provide more information
Credentials cache file '/tmp/krb5cc_500' not found

debug1: Unspecified GSS failure.  Minor code may provide more information
Credentials cache file '/tmp/krb5cc_500' not found

debug1: Unspecified GSS failure.  Minor code may provide more information


debug1: Unspecified GSS failure.  Minor code may provide more information
Credentials cache file '/tmp/krb5cc_500' not found

debug2: we did not send a packet, disable method
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Offering public key: /usr/lib64/pkcs11/opensc-pkcs11.so
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug3: Wrote 256 bytes for a total of 1549
debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password
debug1: Offering public key: /usr/lib64/pkcs11/opensc-pkcs11.so
debug3: send_pubkey_test
debug2: we sent a publickey packet, wait for reply
debug3: Wrote 256 bytes for a total of 1805
debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password
debug1: Trying private key: /home/rpattath/.ssh/identity
debug3: no such identity: /home/rpattath/.ssh/identity
debug1: Trying private key: /home/rpattath/.ssh/id_rsa
debug3: no such identity: /home/rpattath/.ssh/id_rsa
debug1: Trying private key: /home/rpattath/.ssh/id_dsa
debug3: no such identity: /home/rpattath/.ssh/id_dsa
debug1: Trying private key: /home/rpattath/.ssh/id_ecdsa
debug3: no such identity: /home/rpattath/.ssh/id_ecdsa
debug2: we did not send a packet, disable method
debug3: authmethod_lookup password
debug3: remaining preferred: ,password
debug3: authmethod_is_enabled password
debug1: Next authentication method: password
ipasmartcarduser@localhost's password:
Comment 20 Jakub Jelen 2016-07-15 08:01:53 UTC 
> After setting LogLevel=DEBUG3 in sshd_config I see the following

It is a client-side log. It shows that both keys are offered and rejected as in the comment #16. Server log should be stored in /var/log/secure. It should say why the keys were rejected.

It looks like a problem in the IPA/sssd on the server side, checking for the validity of a key.
Comment 21 Sumit Bose 2016-07-15 09:15:47 UTC 
Roshni, do you have the invalid certificate stored in the IPA user entry as well? There was a bug in the 7.2 version which prevented that any ssh-key is returned if only one certificate was invalid. But this should be fixed in the 7.3 build.
Comment 22 Jakub Jelen 2016-07-15 09:24:36 UTC 
(In reply to Sumit Bose from comment #21)
> There was a bug in the 7.2 version which prevented that any ssh-key is
> returned if only one certificate was invalid. But this should be fixed in
> the 7.3 build.

This is about RHEL6 if I understand well. But the problem now looks completely different than when the bug was filled.
Comment 23 Sumit Bose 2016-07-15 09:42:30 UTC 
SSSD on RHEL-6.8 will have the same issue. If Roshni can confirm that the invalid sticket was stored in the IPA server and well and removing it will make ssh work again (after invalidation the cache on the client with sss_cache -E to get rid of the invalid certificate in SSSD's cache as well) the ticket can be moved to the SSSD component.
Comment 24 Sumit Bose 2016-07-15 09:43:35 UTC 
sorry, I meant 'invalid certificate' not 'invalid sticket'.
Comment 25 Roshni 2016-07-15 14:00:44 UTC 
Sumit,

I added 2 certificates to the smartcard/ipa user and revoked one of them.
Comment 26 Sumit Bose 2016-07-15 14:24:07 UTC 
Roshin confirmed that removing the revoked certificate from the IPA user entry make Smartcard based ssh authentication working. So I pretty sure the real issue is https://fedorahosted.org/sssd/ticket/2977. Moving ticket to SSSD component.
Comment 27 Sumit Bose 2016-07-15 14:28:00 UTC 
SSSD upstream patches:
 - ecd48ae244dbb6490989752fba99b58d84babfa6
 - 60787fb44924e84a0c7ddfe9d5e62e64ea1edcd1

fix the issue.
Comment 32 Roshni 2016-12-07 17:43:49 UTC 

*** This bug has been marked as a duplicate of bug 1372681 ***