Hi all, I think I've found a bug with gpg-agent acting as a putty pageant.
System details ============== Windows 7 x64 Ultimate UAC disabled logged in as a member of Administrators GnuPG details ============= a primary 4096 bit RSA key, with SC capabilities 3 2048 bit RSA keys - one for each: S, E, A A key's keygrip added to the sshcontrol file, with TTL set to 0 and no additional flags options file ------------ cipher-algo AES256 digest-algo SHA512 s2k-cipher-algo AES256 s2k-digest-algo SHA512 no-comments no-emit-version gpg-agent.conf file ------------------- enable-putty-support debug-level expert gpg-agent command line ---------------------- gpg-agent.exe --homedir F:\Users\bozho\.gnupg --use-standard-socket --daemon Steps to reproduce ------------------ 1. Start gpg-agent (either directly, or using gpg-connect-agent, makes no difference). No other instance of gpg-agent is running. 2. Start putty, enter server IP address. When asked for the login, enter it and press ENTER. After a bit, a default pinetry dialog pops up. Enter key password and click OK. After some time, putty shows an error dialog with the message: "Server unexpectedly closed network connection." 3. Close putty, start it again. Enter the server IP address again and connect. Enter the login when asked. The pientry dialog pops up *again*. Enter key password and click OK. Putty connects normally. 4. Every subsequent putty connection attempt works as expected (no pinentry, connects to the server fine) 5. Restarting gpg-agent reproduces steps 1-4 every time. Using ssh-pageant as an ssh-agent "bridge" exhibits a similar behaviour: 1. Set an environment variable SSH_AUTH_SOCK to "/tmp/.ssh-pageant-bozho" 2. Start gpg-agent as before 3. start ssh-pagenat: ssh-pageant.exe -r -a /tmp/.ssh-pageant-bozho 4. Try to connect to the server using Cygwin's ssh 5. Pinentry dialog pops up, enter password. 6. After a while, ssh reports an error and exits: Error reading response length from authentication socket. Permission denied (publickey). 7. ssh-pageant has crashed. 8. Restart ssh-pagenat. 9. Run ssh again, enter the password in the pinentry dialog, ssh connects fine. Additional notes ---------------- I have attached gpg-agent's debug log (gpg-agent.log) I have also used Spy++ to log WM_COPYDATA messages from gpg-agent (gpg-agent-messages.log) The first four lines (2 WM_COPYDATA messages) are from the unsuccessful attempt (notice that fProcessed is False in the second message) The last four lines are from the second, successful attempt. Additionally, all four messages seem to have the same message parameters: wParam: 00000000 lParam: 028CFE84 dwData: 804E50BA cbData: 23 lpData: 0039E7C0 I hope this helps in locating the bug :) Thank you, -- Marko
2015-06-28 23:07:04 gpg-agent[7576] listening on socket 'F:\Users\bozho\.gnupg\S.gpg-agent' 2015-06-28 23:07:04 gpg-agent[7576] listening on socket 'F:\Users\bozho\.gnupg\S.gpg-agent.ssh' 2015-06-28 23:07:04 gpg-agent[7576] gpg-agent (GnuPG) 2.1.5 started 2015-06-28 23:07:04 gpg-agent[7576] putty message loop thread started 2015-06-28 23:07:15 gpg-agent[7576] DBG: ssh map file 'PageantRequest00002418' 2015-06-28 23:07:15 gpg-agent[7576] DBG: ssh map handle 0x00000140 2015-06-28 23:07:15 gpg-agent[7576] DBG: my sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000' 2015-06-28 23:07:15 gpg-agent[7576] DBG: ssh map file sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000' 2015-06-28 23:07:15 gpg-agent[7576] DBG: ssh IPC buffer at 0x025c0000 2015-06-28 23:07:15 gpg-agent[7576] ssh request handler for request_identities (11) started 2015-06-28 23:07:15 gpg-agent[7576] no running SCdaemon - starting it 2015-06-28 23:07:15 gpg-agent[7576] DBG: chan_0000016C <- OK GNU Privacy Guard's Smartcard server ready 2015-06-28 23:07:15 gpg-agent[7576] DBG: first connection to SCdaemon established 2015-06-28 23:07:15 gpg-agent[7576] DBG: chan_0000016C -> GETINFO socket_name 2015-06-28 23:07:15 gpg-agent[7576] DBG: chan_0000016C <- D F:\Users\bozho\.gnupg\S.scdaemon 2015-06-28 23:07:15 gpg-agent[7576] DBG: chan_0000016C <- OK 2015-06-28 23:07:15 gpg-agent[7576] DBG: additional connections at 'F:\Users\bozho\.gnupg\S.scdaemon' 2015-06-28 23:07:15 gpg-agent[7576] DBG: chan_0000016C -> OPTION event-signal=110 2015-06-28 23:07:15 gpg-agent[7576] DBG: chan_0000016C <- OK 2015-06-28 23:07:15 gpg-agent[7576] DBG: chan_0000016C -> GETATTR $AUTHKEYID 2015-06-28 23:07:15 gpg-agent[7576] DBG: chan_0000016C <- ERR 100663404 Card error <SCD> 2015-06-28 23:07:15 gpg-agent[7576] no authentication key for ssh on card: Card error 2015-06-28 23:07:15 gpg-agent[7576] ssh request handler for request_identities (11) ready 2015-06-28 23:07:15 gpg-agent[7576] DBG: chan_0000016C -> RESTART 2015-06-28 23:07:15 gpg-agent[7576] DBG: chan_0000016C <- OK 2015-06-28 23:07:26 gpg-agent[7576] DBG: ssh map file 'PageantRequest00002418' 2015-06-28 23:07:26 gpg-agent[7576] DBG: ssh map handle 0x00000140 2015-06-28 23:07:26 gpg-agent[7576] DBG: my sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000' 2015-06-28 23:07:26 gpg-agent[7576] DBG: ssh map file sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000' 2015-06-28 23:07:26 gpg-agent[7576] DBG: ssh IPC buffer at 0x025c0000 2015-06-28 23:07:26 gpg-agent[7576] ssh request handler for sign_request (13) started 2015-06-28 23:07:26 gpg-agent[7576] DBG: agent_get_cache '3F8FFAB15E8B51DF57F1274CEDEE8E8FF3D77E5A' (mode 4) ... 2015-06-28 23:07:26 gpg-agent[7576] DBG: ... miss 2015-06-28 23:07:26 gpg-agent[7576] starting a new PIN Entry 2015-06-28 23:07:26 gpg-agent[7576] DBG: connection to PIN entry established 2015-06-28 23:12:29 gpg-agent[7576] DBG: ssh map file 'PageantRequest00001eac' 2015-06-28 23:12:29 gpg-agent[7576] DBG: ssh map handle 0x00000188 2015-06-28 23:12:29 gpg-agent[7576] DBG: my sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000' 2015-06-28 23:12:29 gpg-agent[7576] DBG: ssh map file sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000' 2015-06-28 23:12:29 gpg-agent[7576] DBG: ssh IPC buffer at 0x025d0000 2015-06-28 23:12:29 gpg-agent[7576] ssh request handler for request_identities (11) started 2015-06-28 23:12:29 gpg-agent[7576] new connection to SCdaemon established (reusing) 2015-06-28 23:12:29 gpg-agent[7576] DBG: chan_0000016C -> GETATTR $AUTHKEYID 2015-06-28 23:12:29 gpg-agent[7576] DBG: chan_0000016C <- ERR 100663404 Card error <SCD> 2015-06-28 23:12:29 gpg-agent[7576] no authentication key for ssh on card: Card error 2015-06-28 23:12:29 gpg-agent[7576] ssh request handler for request_identities (11) ready 2015-06-28 23:12:29 gpg-agent[7576] DBG: chan_0000016C -> RESTART 2015-06-28 23:12:29 gpg-agent[7576] DBG: chan_0000016C <- OK 2015-06-28 23:12:40 gpg-agent[7576] DBG: ssh map file 'PageantRequest00001eac' 2015-06-28 23:12:40 gpg-agent[7576] DBG: ssh map handle 0x00000188 2015-06-28 23:12:40 gpg-agent[7576] DBG: my sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000' 2015-06-28 23:12:40 gpg-agent[7576] DBG: ssh map file sid: 'S-1-5-21-1972494145-3003797530-3302421020-1000' 2015-06-28 23:12:40 gpg-agent[7576] DBG: ssh IPC buffer at 0x025d0000 2015-06-28 23:12:40 gpg-agent[7576] ssh request handler for sign_request (13) started 2015-06-28 23:12:40 gpg-agent[7576] DBG: agent_get_cache '3F8FFAB15E8B51DF57F1274CEDEE8E8FF3D77E5A' (mode 4) ... 2015-06-28 23:12:40 gpg-agent[7576] DBG: ... miss 2015-06-28 23:12:48 gpg-agent[7576] DBG: agent_put_cache '3F8FFAB15E8B51DF57F1274CEDEE8E8FF3D77E5A' (mode 4) requested ttl=0 2015-06-28 23:12:48 gpg-agent[7576] ssh request handler for sign_request (13) ready
<000001> 004D0794 S WM_COPYDATA hwndFrom:(null) pcds:028CFE84 <000002> 004D0794 R WM_COPYDATA fProcessed:True <000003> 004D0794 S WM_COPYDATA hwndFrom:(null) pcds:028CFE84 <000004> 004D0794 R WM_COPYDATA fProcessed:False <000005> 004D0794 S WM_COPYDATA hwndFrom:(null) pcds:028CFE84 <000006> 004D0794 R WM_COPYDATA fProcessed:True <000007> 004D0794 S WM_COPYDATA hwndFrom:(null) pcds:028CFE84 <000008> 004D0794 R WM_COPYDATA fProcessed:True
_______________________________________________ Gnupg-users mailing list [email protected] http://lists.gnupg.org/mailman/listinfo/gnupg-users
