gpg-agent and putty/ssh agent bug

[Marko Božiković]

On 30/06/2015 13:38, Werner Koch wrote:
> On Mon, 29 Jun 2015 00:56, bozho at kset.org said:
> 
>> I have attached gpg-agent's debug log (gpg-agent.log)
> 
> Can you please add
> 
> --8<---------------cut here---------------start------------->8---
> verbose
> verbose
> --8<---------------cut here---------------end--------------->8---
> 
> to gpg-agent.conf, run the test again, and send the log?

Here we go...


-- 
Marko

-------------- next part --------------
2015-06-30 20:28:16 gpg-agent[8912] listening on socket 'F:\Users\bozho\.gnupg\S.gpg-agent'
2015-06-30 20:28:16 gpg-agent[8912] listening on socket 'F:\Users\bozho\.gnupg\S.gpg-agent.ssh'
2015-06-30 20:28:16 gpg-agent[8912] gpg-agent (GnuPG) 2.1.5 started
2015-06-30 20:28:16 gpg-agent[8912] putty message loop thread started
2015-06-30 20:28:26 gpg-agent[8912] DBG: ssh map file 'PageantRequest00001c88'
2015-06-30 20:28:26 gpg-agent[8912] DBG: ssh map handle 0x00000140
2015-06-30 20:28:26 gpg-agent[8912] DBG:           my sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000'
2015-06-30 20:28:26 gpg-agent[8912] DBG: ssh map file sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000'
2015-06-30 20:28:26 gpg-agent[8912] DBG: ssh IPC buffer at 0x025b0000
2015-06-30 20:28:26 gpg-agent[8912] ssh request handler for request_identities (11) started
2015-06-30 20:28:26 gpg-agent[8912] no running SCdaemon - starting it
2015-06-30 20:28:26 gpg-agent[8912] DBG: chan_0000016C <- OK GNU Privacy Guard's Smartcard server ready
2015-06-30 20:28:26 gpg-agent[8912] DBG: first connection to SCdaemon established
2015-06-30 20:28:26 gpg-agent[8912] DBG: chan_0000016C -> GETINFO socket_name
2015-06-30 20:28:26 gpg-agent[8912] DBG: chan_0000016C <- D F:\Users\bozho\.gnupg\S.scdaemon
2015-06-30 20:28:26 gpg-agent[8912] DBG: chan_0000016C <- OK
2015-06-30 20:28:26 gpg-agent[8912] DBG: additional connections at 'F:\Users\bozho\.gnupg\S.scdaemon'
2015-06-30 20:28:26 gpg-agent[8912] DBG: chan_0000016C -> OPTION event-signal=110
2015-06-30 20:28:26 gpg-agent[8912] DBG: chan_0000016C <- OK
2015-06-30 20:28:26 gpg-agent[8912] DBG: chan_0000016C -> GETATTR $AUTHKEYID
2015-06-30 20:28:26 gpg-agent[8912] DBG: chan_0000016C <- ERR 100663404 Card error <SCD>
2015-06-30 20:28:26 gpg-agent[8912] no authentication key for ssh on card: Card error
2015-06-30 20:28:26 gpg-agent[8912] ssh request handler for request_identities (11) ready
2015-06-30 20:28:26 gpg-agent[8912] sending ssh response of length 591
2015-06-30 20:28:26 gpg-agent[8912] DBG: chan_0000016C -> RESTART
2015-06-30 20:28:26 gpg-agent[8912] DBG: chan_0000016C <- OK
2015-06-30 20:28:37 gpg-agent[8912] DBG: ssh map file 'PageantRequest00001c88'
2015-06-30 20:28:37 gpg-agent[8912] DBG: ssh map handle 0x00000140
2015-06-30 20:28:37 gpg-agent[8912] DBG:           my sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000'
2015-06-30 20:28:37 gpg-agent[8912] DBG: ssh map file sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000'
2015-06-30 20:28:37 gpg-agent[8912] DBG: ssh IPC buffer at 0x025b0000
2015-06-30 20:28:37 gpg-agent[8912] ssh request handler for sign_request (13) started
2015-06-30 20:28:37 gpg-agent[8912] DBG: agent_get_cache '063CADD3BA3D11C35A055104772E6D55B8DB998B' (mode 4) ...
2015-06-30 20:28:37 gpg-agent[8912] DBG: ... miss
2015-06-30 20:28:37 gpg-agent[8912] starting a new PIN Entry
2015-06-30 20:28:37 gpg-agent[8912] DBG: connection to PIN entry established
2015-06-30 20:30:50 gpg-agent[8912] DBG: ssh map file 'PageantRequest000028b0'
2015-06-30 20:30:50 gpg-agent[8912] DBG: ssh map handle 0x00000188
2015-06-30 20:30:50 gpg-agent[8912] DBG:           my sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000'
2015-06-30 20:30:50 gpg-agent[8912] DBG: ssh map file sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000'
2015-06-30 20:30:50 gpg-agent[8912] DBG: ssh IPC buffer at 0x025c0000
2015-06-30 20:30:50 gpg-agent[8912] ssh request handler for request_identities (11) started
2015-06-30 20:30:50 gpg-agent[8912] new connection to SCdaemon established (reusing)
2015-06-30 20:30:50 gpg-agent[8912] DBG: chan_0000016C -> GETATTR $AUTHKEYID
2015-06-30 20:30:50 gpg-agent[8912] DBG: chan_0000016C <- ERR 100663404 Card error <SCD>
2015-06-30 20:30:50 gpg-agent[8912] no authentication key for ssh on card: Card error
2015-06-30 20:30:50 gpg-agent[8912] ssh request handler for request_identities (11) ready
2015-06-30 20:30:50 gpg-agent[8912] sending ssh response of length 591
2015-06-30 20:30:50 gpg-agent[8912] DBG: chan_0000016C -> RESTART
2015-06-30 20:30:50 gpg-agent[8912] DBG: chan_0000016C <- OK
2015-06-30 20:31:01 gpg-agent[8912] DBG: ssh map file 'PageantRequest000028b0'
2015-06-30 20:31:01 gpg-agent[8912] DBG: ssh map handle 0x00000188
2015-06-30 20:31:01 gpg-agent[8912] DBG:           my sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000'
2015-06-30 20:31:01 gpg-agent[8912] DBG: ssh map file sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000'
2015-06-30 20:31:01 gpg-agent[8912] DBG: ssh IPC buffer at 0x025c0000
2015-06-30 20:31:01 gpg-agent[8912] ssh request handler for sign_request (13) started
2015-06-30 20:31:01 gpg-agent[8912] DBG: agent_get_cache '063CADD3BA3D11C35A055104772E6D55B8DB998B' (mode 4) ...
2015-06-30 20:31:01 gpg-agent[8912] DBG: ... miss
2015-06-30 20:31:06 gpg-agent[8912] DBG: agent_put_cache '063CADD3BA3D11C35A055104772E6D55B8DB998B' (mode 4) requested ttl=0
2015-06-30 20:31:06 gpg-agent[8912] ssh request handler for sign_request (13) ready
2015-06-30 20:31:06 gpg-agent[8912] sending ssh response of length 276