Attachment 1829 Details for Bug 1736 – Debug command output 3

Debug command output 3

cmdout (text/plain), 14.43 KB, created by Daniel Benoy on 2010-04-09 06:21:06 AEST

(hide)

Description:

Filename:

MIME Type:

Creator: Daniel Benoy

Created: 2010-04-09 06:21:06 AEST

Size: 14.43 KB

patch

obsolete

>$ ssh -vvvI /usr/lib/pkcs11-spy.so root@jackson
>OpenSSH_5.4p1, OpenSSL 0.9.8l 5 Nov 2009
>debug1: Reading configuration data /etc/ssh/ssh_config
>debug2: hash dir '/home/dbenoy/.ssh/crt' added to x509 store
>debug2: hash dir '/home/dbenoy/.ssh/crl' added to x509 revocation store
>debug2: hash dir '/etc/ssh/ca/crt' added to x509 store
>debug2: hash dir '/etc/ssh/ca/crl' added to x509 revocation store
>debug1: ssh_set_validator: ignore responder url
>debug2: ssh_connect: needpriv 0
>debug1: Connecting to jackson [2001:470:1d:160:224:8cff:fe92:3230] port 22.
>debug1: Connection established.
>
>
>*************** OpenSC PKCS#11 spy *****************
>Loaded: "/usr/local/lib/libmusclepkcs11.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.11
>      manufacturerID:         'SCHLUMBERGER                    '
>      flags:                   0
>      libraryDescription:     'SLB PKCS #11 module             '
>      libraryVersion:          1.0
>Returned:  0 CKR_OK
>debug1: manufacturerID <SCHLUMBERGER> cryptokiVersion 2.11 libraryDescription <SLB PKCS #11 module> libraryVersion 1.0
>
>
>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:                  'MuscleCard Applet               '
>      manufacturerID:         'Unknown MFR                     '
>      model:                  'Unknown Model   '
>      serialNumber:           '1               '
>      ulMaxSessionCount:       0
>      ulSessionCount:          0
>      ulMaxRwSessionCount:     0
>      ulRwSessionCount:        0
>      ulMaxPinLen:             8
>      ulMinPinLen:             4
>      ulTotalPublicMemory:     32767
>      ulFreePublicMemory:      24956
>      ulTotalPrivateMemory:    32767
>      ulFreePrivateMemory:     24956
>      hardwareVersion:         7.0
>      firmwareVersion:         1.0
>      time:                   '0000000000000000'
>      flags:                   40d
>        CKF_RNG                          
>        CKF_LOGIN_REQUIRED               
>        CKF_USER_PIN_INITIALIZED         
>        CKF_TOKEN_INITIALIZED            
>Returned:  0 CKR_OK
>debug1: label <MuscleCard Applet> manufacturerID <Unknown MFR> model <Unknown Model> serial <1> flags 0x40d
>
>
>6: C_OpenSession
>[in] slotID = 0x1
>[in] flags = 0x6
>pApplication=(nil)
>Notify=(nil)
>[out] *phSession = 0x1
>Returned:  0 CKR_OK
>
>
>7: C_FindObjectsInit
>[in] hSession = 0x1
>[in] pTemplate[1]: 
>    CKA_CLASS             CKO_PUBLIC_KEY       
>Returned:  0 CKR_OK
>
>
>8: C_FindObjects
>[in] hSession = 0x1
>[in] ulMaxObjectCount = 0x1
>[out] ulObjectCount = 0x1
>Object 134989608 Matches
>Returned:  0 CKR_OK
>
>
>9: C_GetAttributeValue
>[in] hSession = 0x1
>[in] hObject = 0x80bc728
>[in] pTemplate[3]: 
>    CKA_ID                requested with 0 buffer
>    CKA_MODULUS           requested with 0 buffer
>    CKA_PUBLIC_EXPONENT   requested with 0 buffer
>[out] pTemplate[3]: 
>    CKA_ID                has size 20
>    CKA_MODULUS           has size 128
>    CKA_PUBLIC_EXPONENT   has size -1
>Returned:  18 CKR_ATTRIBUTE_TYPE_INVALID
>C_GetAttributeValue failed: 18
>
>
>10: C_FindObjects
>[in] hSession = 0x1
>[in] ulMaxObjectCount = 0x1
>[out] ulObjectCount = 0x1
>Object 134989080 Matches
>Returned:  0 CKR_OK
>
>
>11: C_GetAttributeValue
>[in] hSession = 0x1
>[in] hObject = 0x80bc518
>[in] pTemplate[3]: 
>    CKA_ID                requested with 0 buffer
>    CKA_MODULUS           requested with 0 buffer
>    CKA_PUBLIC_EXPONENT   requested with 0 buffer
>[out] pTemplate[3]: 
>    CKA_ID                has size 20
>    CKA_MODULUS           has size 128
>    CKA_PUBLIC_EXPONENT   has size 3
>Returned:  0 CKR_OK
>
>
>12: C_GetAttributeValue
>[in] hSession = 0x1
>[in] hObject = 0x80bc518
>[in] pTemplate[3]: 
>    CKA_ID                requested with 20 buffer
>    CKA_MODULUS           requested with 128 buffer
>    CKA_PUBLIC_EXPONENT   requested with 3 buffer
>[out] pTemplate[3]: 
>    CKA_ID                [size : 0x14 (20)]
>    E088440D 3F9C9EAD 2345A3B3 0551D0E4 DE079A56
>    CKA_MODULUS           [size : 0x80 (128)]
>    D65EBCD2 26DB21DF 649B0718 CB9B1764 EF249415 0F9A32C5 5D54A5EA 36A6ADAC
>    156994AF C783A1F2 A1D8A038 5EDDBBDB 695E84CF 1F87F970 61ACB40E 1BD07AC8
>    609F6B4A D41FFB19 8259F7DA 43B9C8D8 FD1E2D2D 8D2A42C6 FFCE1841 6EF6D785
>    FF7A61BF 0FAEEA96 10249B34 C8289614 A4769666 B7714CD4 B663C43E 181E8C01
>    CKA_PUBLIC_EXPONENT   [size : 0x3 (3)]
>    010001
>Returned:  0 CKR_OK
>debug1: have 1 keys
>
>
>13: C_FindObjects
>[in] hSession = 0x1
>[in] ulMaxObjectCount = 0x1
>[out] ulObjectCount = 0x1
>Object 134988392 Matches
>Returned:  0 CKR_OK
>
>
>14: C_GetAttributeValue
>[in] hSession = 0x1
>[in] hObject = 0x80bc268
>[in] pTemplate[3]: 
>    CKA_ID                requested with 0 buffer
>    CKA_MODULUS           requested with 0 buffer
>    CKA_PUBLIC_EXPONENT   requested with 0 buffer
>[out] pTemplate[3]: 
>    CKA_ID                has size 20
>    CKA_MODULUS           has size 128
>    CKA_PUBLIC_EXPONENT   has size -1
>Returned:  18 CKR_ATTRIBUTE_TYPE_INVALID
>C_GetAttributeValue failed: 18
>
>
>15: C_FindObjects
>[in] hSession = 0x1
>[in] ulMaxObjectCount = 0x1
>[out] ulObjectCount = 0x1
>Object 134988280 Matches
>Returned:  0 CKR_OK
>
>
>16: C_GetAttributeValue
>[in] hSession = 0x1
>[in] hObject = 0x80bc1f8
>[in] pTemplate[3]: 
>    CKA_ID                requested with 0 buffer
>    CKA_MODULUS           requested with 0 buffer
>    CKA_PUBLIC_EXPONENT   requested with 0 buffer
>[out] pTemplate[3]: 
>    CKA_ID                has size 20
>    CKA_MODULUS           has size 128
>    CKA_PUBLIC_EXPONENT   has size 3
>Returned:  0 CKR_OK
>
>
>17: C_GetAttributeValue
>[in] hSession = 0x1
>[in] hObject = 0x80bc1f8
>[in] pTemplate[3]: 
>    CKA_ID                requested with 20 buffer
>    CKA_MODULUS           requested with 128 buffer
>    CKA_PUBLIC_EXPONENT   requested with 3 buffer
>[out] pTemplate[3]: 
>    CKA_ID                [size : 0x14 (20)]
>    24B19864 96CB599E 52DA591F F46C98CD 8DD74418
>    CKA_MODULUS           [size : 0x80 (128)]
>    B996ACCF 57A1E1AD C83101A7 9CAF35FB 09F0E79A F5BBAE89 AA6674E4 230DEFAF
>    8789E62F 2066ED70 059FF2C1 15FC389A 4484F43C 46C3FE5F 7CD526C3 B1F0204B
>    21E2CB50 3F0F5397 B432E72C D7D64462 53C755AE 824973A8 6D38BB12 838F8103
>    ACD1497D 5D083811 FD606B39 C0D572E1 0B9645A1 CD12599D 484380A0 59B3736D
>    CKA_PUBLIC_EXPONENT   [size : 0x3 (3)]
>    010001
>Returned:  0 CKR_OK
>debug1: have 2 keys
>
>
>18: C_FindObjects
>[in] hSession = 0x1
>[in] ulMaxObjectCount = 0x1
>[out] ulObjectCount = 0x0
>Returned:  0 CKR_OK
>
>
>19: C_FindObjectsFinal
>[in] hSession = 0x1
>Returned:  0 CKR_OK
>debug3: key_load_public(/home/dbenoy/.ssh/id_rsa,...)
>debug1: identity file /home/dbenoy/.ssh/id_rsa type -1
>debug3: key_load_public(/home/dbenoy/.ssh/id_rsa-cert,...)
>debug1: identity file /home/dbenoy/.ssh/id_rsa-cert type -1
>debug3: key_load_public(/home/dbenoy/.ssh/id_dsa,...)
>debug1: identity file /home/dbenoy/.ssh/id_dsa type -1
>debug3: key_load_public(/home/dbenoy/.ssh/id_dsa-cert,...)
>debug1: identity file /home/dbenoy/.ssh/id_dsa-cert type -1
>debug1: Remote protocol version 2.0, remote software version OpenSSH_5.2
>debug1: match: OpenSSH_5.2 pat OpenSSH*
>debug1: Enabling compatibility mode for protocol 2.0
>debug1: Local version string SSH-2.0-OpenSSH_5.4
>debug2: fd 3 setting O_NONBLOCK
>debug1: SSH2_MSG_KEXINIT sent
>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: x509v3-sign-rsa,x509v3-sign-dss,ssh-rsa-cert-v00@openssh.com,ssh-dss-cert-v00@openssh.com,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@lysator.liu.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@lysator.liu.se
>debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
>debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
>debug2: kex_parse_kexinit: none,zlib@openssh.com,zlib
>debug2: kex_parse_kexinit: none,zlib@openssh.com,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@lysator.liu.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@lysator.liu.se
>debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
>debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96
>debug2: kex_parse_kexinit: none,zlib@openssh.com
>debug2: kex_parse_kexinit: none,zlib@openssh.com
>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
>debug2: dh_gen_key: priv key bits set: 129/256
>debug2: bits set: 508/1024
>debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
>debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
>debug3: key_from_blob(..., 149)
>debug3: x509key_from_blob: We have 149 bytes available in BIO
>debug3: x509key_from_blob: read X509 from BIO fail error:0D0680A8:asn1 encoding routines:ASN1_CHECK_TLEN:wrong tag
>debug3: key_from_blob(..., ...) ktype=ssh-rsa
>debug3: check_host_in_hostfile: host jackson filename /home/dbenoy/.ssh/known_hosts
>debug3: check_host_in_hostfile: host jackson filename /home/dbenoy/.ssh/known_hosts
>debug3: x509key_from_subject: 1 is not x509 key
>debug3: key_from_blob(..., 149)
>debug3: x509key_from_blob: We have 149 bytes available in BIO
>debug3: x509key_from_blob: read X509 from BIO fail error:0D0680A8:asn1 encoding routines:ASN1_CHECK_TLEN:wrong tag
>debug3: key_from_blob(..., ...) ktype=ssh-rsa
>debug3: check_host_in_hostfile: match line 15
>debug3: check_host_in_hostfile: host 2001:470:1d:160:224:8cff:fe92:3230 filename /home/dbenoy/.ssh/known_hosts
>debug3: check_host_in_hostfile: host 2001:470:1d:160:224:8cff:fe92:3230 filename /home/dbenoy/.ssh/known_hosts
>debug3: x509key_from_subject: 1 is not x509 key
>debug3: key_from_blob(..., 149)
>debug3: x509key_from_blob: We have 149 bytes available in BIO
>debug3: x509key_from_blob: read X509 from BIO fail error:0D0680A8:asn1 encoding routines:ASN1_CHECK_TLEN:wrong tag
>debug3: key_from_blob(..., ...) ktype=ssh-rsa
>debug3: check_host_in_hostfile: match line 70
>debug1: Host 'jackson' is known and matches the RSA host key.
>debug1: Found key in /home/dbenoy/.ssh/known_hosts:15
>debug2: bits set: 514/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
>debug2: set_newkeys: mode 0
>debug1: SSH2_MSG_NEWKEYS received
>debug1: Roaming not allowed by server
>debug1: SSH2_MSG_SERVICE_REQUEST sent
>debug2: service_accept: ssh-userauth
>debug1: SSH2_MSG_SERVICE_ACCEPT received
>debug2: preparing keys
>debug2: key: /usr/lib/pkcs11-spy.so (0x80bd5d8)
>debug2: key: /usr/lib/pkcs11-spy.so (0x80bde80)
>debug2: key: /home/dbenoy/.ssh/id_rsa ((nil))
>debug2: key: /home/dbenoy/.ssh/id_dsa ((nil))
>debug1: Authentications that can continue: publickey,keyboard-interactive
>debug3: start over, passed a different list publickey,keyboard-interactive
>debug3: preferred publickey,keyboard-interactive,password
>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/lib/pkcs11-spy.so
>debug3: send_pubkey_test
>debug2: we sent a publickey packet, wait for reply
>debug1: Authentications that can continue: publickey,keyboard-interactive
>debug1: Offering public key: /usr/lib/pkcs11-spy.so
>debug3: send_pubkey_test
>debug2: we sent a publickey packet, wait for reply
>debug1: Server accepts key: pkalg ssh-rsa blen 151
>debug3: key_from_blob(..., 151)
>debug3: x509key_from_blob: We have 151 bytes available in BIO
>debug3: x509key_from_blob: read X509 from BIO fail error:0D0680A8:asn1 encoding routines:ASN1_CHECK_TLEN:wrong tag
>debug3: key_from_blob(..., ...) ktype=ssh-rsa
>debug2: input_userauth_pk_ok: fp 29:90:04:47:7d:a3:96:5b:4a:d4:86:27:f2:52:35:87
>debug3: sign_and_send_pubkey
>Enter PIN for 'MuscleCard Applet': 
>
>
>20: C_Login
>[in] hSession = 0x1
>[in] userType = CKU_USER
>[in] pPin[ulPinLen] [size : 0x8 (8)]
>    <PIN WAS HERE>
>Returned:  0 CKR_OK
>
>
>21: C_FindObjectsInit
>[in] hSession = 0x1
>[in] pTemplate[3]: 
>    CKA_CLASS             CKO_PRIVATE_KEY      
>    CKA_ID                [size : 0x14 (20)]
>    24B19864 96CB599E 52DA591F F46C98CD 8DD74418
>    CKA_SIGN              True
>Returned:  0 CKR_OK
>
>
>22: C_FindObjects
>[in] hSession = 0x1
>[in] ulMaxObjectCount = 0x1
>[out] ulObjectCount = 0x0
>Returned:  0 CKR_OK
>C_FindObjects failed (0 nfound): 0
>
>
>23: C_FindObjectsFinal
>[in] hSession = 0x1
>Returned:  0 CKR_OK
>ssh_rsa_sign: RSA_sign failed: error:00000000:lib(0):func(0):reason(0)
>debug1: Trying private key: /home/dbenoy/.ssh/id_rsa
>debug3: no such identity: /home/dbenoy/.ssh/id_rsa
>debug1: Trying private key: /home/dbenoy/.ssh/id_dsa
>debug3: no such identity: /home/dbenoy/.ssh/id_dsa
>debug2: we did not send a packet, disable method
>debug3: authmethod_lookup keyboard-interactive
>debug3: remaining preferred: password
>debug3: authmethod_is_enabled keyboard-interactive
>debug1: Next authentication method: keyboard-interactive
>debug2: userauth_kbdint
>debug2: we sent a keyboard-interactive packet, wait for reply
>debug2: input_userauth_info_req
>debug2: input_userauth_info_req: num_prompts 1
>Password: 
>

Actions: View

Attachments on bug 1736: 1812 | 1813 | 1814 | 1829 | 1835 | 1836 | 1837