SFTP Logoff issue with OPENSSH

[arjunpidugu642]

trafficstars

SftpClient: IPWORKSSSH sftp client SftpServer: OpenSSH Sftp server

Getting below exception at client while connecting sftp server: "System Error: Connection reset" Checked with IPWORKSSSH sftp client team and received below response

""" The error and Wireshark trace indicate that the server decided to end the connection by resetting it (instead of gracefully ending it). It is not clear why. It could just be that this is how this specific server prefers to close the connection or perhaps it did not like/understand the last packet sent from the client. A simple way to handle this would be to catch the exception and continue on -- the connection has been closed. """ Requesting to confirm above is expected or any improvement is required at openSSH server side for graceful termination.

Please answer the following

OpenSSH version -> OpenSSH_for_Windows_7.6p1, LibreSSL 2.6.4 Server OperatingSystem -> Windows 10 Client OperatingSystem -> Windows 10 What is failing -> Getting exception while connecting to OpenSSH server Expected output -> Graceful termination Actual output -> Connection is getting abnormal termination

Attaching Wireshark trace and exception details.

[bagajjal]

@arjunpidugu642 - You are using very old OpenSSH version. Please upgrade to latest V8.6. While opening an issue, please provide relevant client and server logs. In this case, sftp client logs and sftp server logs. Without debug logs, it's almost impossible to proceed.

[arjunpidugu642]

@bagajjal Thank you very much for quick response. We have tried on latest as you suggested and facing same problem. Attaching server debug logs(sshd.log). sshd.log Below logs are at Sftp client. """ [System error: Connection reset] [connectionStatus][Remote host disconnected.] [disconnected][OK] [error][System error: Connection reset] [closeConnection][Exception in closeConnection - System error: Connection reset] ipworksssh.IPWorksSSHException: System error: Connection reset at ipworksssh.Sftp.SSHLogoff(Unknown Source) """

[bagajjal]

@arjunpidugu642 - I don't see any error in sshd.log. Can you also share sftp-server.log.

You need to have the below lines in your sshd_config. Don't forget to restart after you modify sshd_config. Subsystem sftp sftp-server.exe -l DEBUG3 -f LOCAL0

3164 2022-01-18 16:25:25.396 Received disconnect from 10.202.3.22 port 61775:11: Normal Shutdown [preauth] 3164 2022-01-18 16:25:25.396 Disconnected from 10.202.3.22 port 61775 [preauth] 3164 2022-01-18 16:25:25.396 debug1: do_cleanup [preauth] 3164 2022-01-18 16:25:25.400 debug3: mm_request_receive: entering 3164 2022-01-18 16:25:25.400 debug1: do_cleanup 3164 2022-01-18 16:25:25.400 debug1: Killing privsep child 4860 14568 2022-01-18 16:25:25.582 debug3: receive packet: type 1 [preauth] 14568 2022-01-18 16:25:25.582 Received disconnect from 172.16.121.147 port 61928:11: Normal Shutdown [preauth] 14568 2022-01-18 16:25:25.583 Disconnected from 172.16.121.147 port 61928 [preauth]

---

10080 2022-01-18 16:26:20.445 debug3: spawn_argv[0]: "c:\windows\system32\cmd.exe" /c "sftp-server.exe" 10080 2022-01-18 16:26:20.445 debug3: spawning "c:\windows\system32\cmd.exe" /c "sftp-server.exe" as subprocess 10080 2022-01-18 16:26:20.455 debug2: fd 4 setting TCP_NODELAY 10080 2022-01-18 16:26:20.455 debug3: fd 11 is O_NONBLOCK 10080 2022-01-18 16:26:20.455 debug3: fd 10 is O_NONBLOCK 10080 2022-01-18 16:26:20.455 debug3: fd 13 is O_NONBLOCK 10080 2022-01-18 16:26:20.455 debug3: send packet: type 99 10080 2022-01-18 16:26:20.582 debug3: receive packet: type 97 10080 2022-01-18 16:26:20.582 debug2: channel 0: rcvd close 10080 2022-01-18 16:26:20.582 debug2: channel 0: output open -> drain 10080 2022-01-18 16:26:20.582 debug2: chan_shutdown_read: channel 0: (i0 o1 sock -1 wfd 11 efd 13 [ignore]) 10080 2022-01-18 16:26:20.582 debug1: chan_shutdown_extended_read: channel 0: (i0 o1 sock -1 wfd -1 efd 13 [ignore]) 10080 2022-01-18 16:26:20.582 debug2: channel 0: input open -> closed 10080 2022-01-18 16:26:20.582 debug3: receive packet: type 1 10080 2022-01-18 16:26:20.582 Received disconnect from 172.16.121.147 port 62113:11: logoff 10080 2022-01-18 16:26:20.582 Disconnected from 172.16.121.147 port 62113

---

1208 2022-01-18 16:31:19.876 debug3: arg escape option: TRUE 1208 2022-01-18 16:31:19.876 debug3: spawn_argv[0]: "c:\windows\system32\cmd.exe" /c "sftp-server.exe" 1208 2022-01-18 16:31:19.877 debug3: spawning "c:\windows\system32\cmd.exe" /c "sftp-server.exe" as subprocess 1208 2022-01-18 16:31:19.884 debug2: fd 4 setting TCP_NODELAY 1208 2022-01-18 16:31:19.884 debug3: fd 11 is O_NONBLOCK 1208 2022-01-18 16:31:19.884 debug3: fd 10 is O_NONBLOCK 1208 2022-01-18 16:31:19.884 debug3: fd 13 is O_NONBLOCK 1208 2022-01-18 16:31:19.885 debug3: send packet: type 99 1208 2022-01-18 16:31:19.947 debug3: receive packet: type 97 1208 2022-01-18 16:31:19.947 debug2: channel 0: rcvd close 1208 2022-01-18 16:31:19.948 debug2: channel 0: output open -> drain 1208 2022-01-18 16:31:19.948 debug2: chan_shutdown_read: channel 0: (i0 o1 sock -1 wfd 11 efd 13 [ignore]) 1208 2022-01-18 16:31:19.948 debug1: chan_shutdown_extended_read: channel 0: (i0 o1 sock -1 wfd -1 efd 13 [ignore]) 1208 2022-01-18 16:31:19.948 debug2: channel 0: input open -> closed 1208 2022-01-18 16:31:19.948 debug3: receive packet: type 1 1208 2022-01-18 16:31:19.948 Received disconnect from 172.16.121.147 port 62782:11: logoff 1208 2022-01-18 16:31:19.948 Disconnected from 172.16.121.147 port 62782 1208 2022-01-18 16:31:19.948 debug1: do_cleanup

[arjunpidugu642]

@bagajjal sftp-server.log Attaching sftp-server.log Observed below logs in event viewer when I was trying to connect """ sftp-server: session opened for local user admin from [172.16.121.147] sftp-server: received client version 3 sftp-server: realpath "." sftp-server: stat name "/C:/Users/admin/Backup" sftp-server: session closed for local user admin from [172.16.121.147] """ Why we are getting an below exception at client side if no errors at server side? """ [error][System error: Connection reset] [closeConnection][Exception in closeConnection - System error: Connection reset] ipworksssh.IPWorksSSHException: System error: Connection reset at ipworksssh.Sftp.SSHLogoff(Unknown Source) """

[arjunpidugu642]

@bagajjal Any update on this?

[bagajjal]

@arjunpidugu642 - I don't see any error messages in the sftp-server.log / sshd.log. I suggest repro the issue with other sftp clients like win3-openssh sftp.exe / WSL sftp.exe. When you have the repro, please collect the below logs for the same connection

1. sftp client logs (sftp.exe -vvv user@ip)
2. sshd logs (With DEBUG3)
3. sftp-server.log (With DEBUG3)

[arjunpidugu642]

@bagajjal Even we have tried with WinSCP client and not able to reproduce the problem. Analyzed and found that, IPWORKSSH sftp client is invoking "SSHLogoff" as part of connecting to sftp server and Winscp client is not invoking logoff method. We have checked with IPWORKSSSH client support team and got response which I have mentioned at problem description.

[arjunpidugu642]

@bagajjal We got below error """ Starting session: subsystem 'sftp' for admin from 172.16.121.147 port 65303 id 0 debug1: chan_shutdown_extended_read: channel 0: (i0 o1 sock -1 wfd -1 efd 13 [ignore]) Received disconnect from 172.16.121.147 port 65303:11: logoff Disconnected from 172.16.121.147 port 65303 debug1: do_cleanup C:\Program Files\OpenSSH-Win64\sshd.exe exited on INKEO27382WSCT with error code 255. """

1. We have ran SSHD through command prompt
2. Tried to connect Openssh server and got above error while invoking logoff() method from sftp client.
3. Attaching command prompt output while connecting OpenSSH.

[bagajjal]

Why are you running sshd process in debug mode? When you run sshd process in debug mode, we only authenticate the current login user. In this case, the connection was not successful as you are trying to SCP with a user that's not the login user.

[arjunpidugu642]

@bagajjal Openssh.txt We cannot see error logs if we do not run with debug mode. I guess, invoking logoff() method after connect() method is causing the problem Attaching complete logs for below error """ Starting session: subsystem 'sftp' for admin from 172.16.121.147 port 65303 id 0 debug1: chan_shutdown_extended_read: channel 0: (i0 o1 sock -1 wfd -1 efd 13 [ignore]) Received disconnect from 172.16.121.147 port 65303:11: logoff Disconnected from 172.16.121.147 port 65303 debug1: do_cleanup C:\Program Files\OpenSSH-Win64\sshd.exe exited on INKEO27382WSCT with error code 255. """

[bagajjal]

@arjunpidugu642 , The default logging is ETW based. You can change it to file based logging. Follow the instructions from here