I have a Problem with the putty tool pscp.
I check if Linux VM (Red Hat Enterprise Linux Server 7.4) "TARGET" is alive and store a timestamp on the TARGET in a file. I do this all 10s from a Windows VM (windows server 2016) "SOURCE". The process is being started in Java by the following code:
// get a Process executing the instruction with cmd and
terminate the process after 5s.
String instruction = "pscp.exe -batch -i C:\\User\\Me
\\keys \\privatekey_Me.ppk -sshlog >C:\\User\\Me
\\putty.log -scp TARGET:~/dir/file.txt file.txt"
Process p = Runtime.getRuntime().exec(instruction,null,dir);
if(!p.waitFor(3, TimeUnit.MINUTES)) { //I want this to be
5s instead of 3m, but for the question on >stackoverflow
3m is clearer.
p.destroy();
throw new Exception("Connection took too long.");
}
In general it works.
But it also fails consistently after 2m-10m (absolute max 20m – an extreme outlier, median is 4m). For 5s-2m pscp hangs, not crashes, hangs, eventually it recovers and carries on like nothing happened. This behaviour can be observed also by manually starting a pscp.exe – both the batch script and manual connection will then succeed at the same time.
For clarity:
>10:00:00 start, connection & copy success
>10:00:10 start, connection & copy success
>10:00:20 start, hanging
>10:00:30 hanging
>…
>10:01:30 connection & copy success
>10:01:40 start, connection & copy success
During this hanging periods, I pinged both directions (TARGET SOURCE, SOURCE TARGET) and there was no observable change in roundtriptime.
Here are two log files, the first from a successful manual connection (I terminated it when reaching the point where I would need to supply the passwort) and a log for a hanging connection (extracted before the connection recovered).
success
Event Log: Writing new session log (SSH packets mode) to file: C:\Users\Me\putty.log Event Log: Looking up host "TARGET" Event Log: Connecting to XXX.XXX.XXX.XXX port YYYY Event Log: We claim version: SSH-2.0-PuTTY_Release_0.64 Event Log: Server version: SSH-2.0-OpenSSH_7.4 Event Log: Using SSH protocol version 2 Outgoing packet #0x0, type 20 / 0x14 (SSH2_MSG_KEXINIT) Incoming packet #0x0, type 20 / 0x14 (SSH2_MSG_KEXINIT) Event Log: Using Diffie-Hellman with standard group "group14" Event Log: Doing Diffie-Hellman key exchange with hash SHA-1 Outgoing packet #0x1, type 30 / 0x1e (SSH2_MSG_KEXDH_INIT) Incoming packet #0x1, type 31 / 0x1f (SSH2_MSG_KEXDH_REPLY) Event Log: Host key fingerprint is: Event Log: ssh-rsa 2048 XX:XX:XX:XX:XX:XX:XX:XX:XX:XX:XX:XX:XX:XX:XX:XX Outgoing packet #0x2, type 21 / 0x15 (SSH2_MSG_NEWKEYS) Event Log: Initialised AES-256 SDCTR client->server encryption Event Log: Initialised HMAC-SHA-256 client->server MAC algorithm Incoming packet #0x2, type 21 / 0x15 (SSH2_MSG_NEWKEYS) Event Log: Initialised AES-256 SDCTR server->client encryption Event Log: Initialised HMAC-SHA-256 server->client MAC algorithm Outgoing packet #0x3, type 5 / 0x05 (SSH2_MSG_SERVICE_REQUEST) Incoming packet #0x3, type 6 / 0x06 (SSH2_MSG_SERVICE_ACCEPT) Outgoing packet #0x4, type 50 / 0x32 (SSH2_MSG_USERAUTH_REQUEST) Incoming packet #0x4, type 51 / 0x33 (SSH2_MSG_USERAUTH_FAILURE) Event Log: Using SSPI from SECUR32.DLL Event Log: Attempting GSSAPI authentication Outgoing packet #0x5, type 50 / 0x32 (SSH2_MSG_USERAUTH_REQUEST) Incoming packet #0x5, type 60 / 0x3c (SSH2_MSG_USERAUTH_GSSAPI_RESPONSE) Event Log: GSSAPI authentication initialisation failed Event Log: The target was not recognized. Outgoing packet #0x6, type 50 / 0x32 (SSH2_MSG_USERAUTH_REQUEST) Event Log: Attempting keyboard-interactive authentication Incoming packet #0x6, type 60 / 0x3c (SSH2_MSG_USERAUTH_INFO_REQUEST)
Failure
Event Log: Writing new session log (SSH packets mode) to file: C:\Users\Me\putty.log Event Log: Looking up host "TARGET" Event Log: Connecting to XXX.XXX.XXX.XXX port YYYY Event Log: We claim version: SSH-2.0-PuTTY_Release_0.64 Event Log: Server version: SSH-2.0-OpenSSH_7.4 Event Log: Using SSH protocol version 2 Outgoing packet #0x0, type 20 / 0x14 (SSH2_MSG_KEXINIT) Incoming packet #0x0, type 20 / 0x14 (SSH2_MSG_KEXINIT) Event Log: Using Diffie-Hellman with standard group "group14" Event Log: Doing Diffie-Hellman key exchange with hash SHA-1 Outgoing packet #0x1, type 30 / 0x1e (SSH2_MSG_KEXDH_INIT) Incoming packet #0x1, type 31 / 0x1f (SSH2_MSG_KEXDH_REPLY) Event Log: Host key fingerprint is: Event Log: ssh-rsa 2048 XX:XX:XX:XX:XX:XX:XX:XX:XX:XX:XX:XX:XX:XX:XX:XX Outgoing packet #0x2, type 21 / 0x15 (SSH2_MSG_NEWKEYS) Event Log: Initialised AES-256 SDCTR client->server encryption Event Log: Initialised HMAC-SHA-256 client->server MAC algorithm Incoming packet #0x2, type 21 / 0x15 (SSH2_MSG_NEWKEYS) Event Log: Initialised AES-256 SDCTR server->client encryption Event Log: Initialised HMAC-SHA-256 server->client MAC algorithm Outgoing packet #0x3, type 5 / 0x05 (SSH2_MSG_SERVICE_REQUEST) Incoming packet #0x3, type 6 / 0x06 (SSH2_MSG_SERVICE_ACCEPT) Outgoing packet #0x4, type 50 / 0x32 (SSH2_MSG_USERAUTH_REQUEST) Incoming packet #0x4, type 51 / 0x33 (SSH2_MSG_USERAUTH_FAILURE) Event Log: Using SSPI from SECUR32.DLL Event Log: Attempting GSSAPI authentication Outgoing packet #0x5, type 50 / 0x32 (SSH2_MSG_USERAUTH_REQUEST) Incoming packet #0x5, type 60 / 0x3c (SSH2_MSG_USERAUTH_GSSAPI_RESPONSE) Event Log: GSSAPI authentication initialisation failed Event Log: The target was not recognized. Outgoing packet #0x6, type 50 / 0x32 (SSH2_MSG_USERAUTH_REQUEST) Event Log: Attempting keyboard-interactive authentication
Long log short: the two are identical, except for the last Line which is only in the succes log:
Incoming packet #0x6, type 60 / 0x3c (SSH2_MSG_USERAUTH_INFO_REQUEST)
It appears this packet causes the problem. Maybe it gets lost sometimes? (but then it should not be so consistently after 2m-10m, right?) I hope anyone can help me with this issue, as I have not a deep enouth understanding of the process to continue debuging.
For security reasons I may not use 'just any library'. Nativ features and well established programms are my main options.
