Forum » Support and Bug Reports »

WinSCP gets disconnected without showing any error message.

paulo2019%% Guest

WinSCP gets disconnected without showing any error message.

2020-08-28 17:44

Hi. We are using WinSCP to upload continuously a file into an SFTP site, The process of keeping the file updated works well most of the time, but frequently (once or twice a week) WinSCP gets disconnected without showing any error message. We star again WinSCP and the connection gets back. But some hours or days after, the issue happens again.
Win SCP: Version 5.17.6 (Compilation 10516)
We are using Windows 7 on the PC
Screenshot attached

Thanks and Regards
Paulo Aravena

WinSCP after get disconnected.jpg (321.09 KB)

Description: The names of the attached files show what are they for.

WinSCP version.jpg (319.44 KB, Private file)

Description: The names of the attached files show what are they for.

Reply with quote

martin◆ Site Admin
Joined:: 2002-12-10
Posts:: 41,441
Location:: Prague, Czechia

Re: WinSCP gets disconnected without showing any error message.

2020-09-01

What does the "gets disconnected" look like? Does the dialog close? And session tab as well? Or does WinSCP close completely? Can you post a session log file for that?

Reply with quote

paulo2019
Joined:: 2020-08-28
Posts:: 1
Location:: Chile

Re: WinSCP gets disconnected without showing any error message.

2020-09-01 16:35

Hi Martin. Thanks for your reply. I mean that WinSCP stops working without showing an error message. Just the windows showed in the screenshot above. I am afraid that I can`t get the log file.

Reply with quote

Guest

Re: WinSCP gets disconnected without showing any error message.

2020-09-02 15:08

One more thing. I am not a specialist in this area. If you can tell me where to get the log file, then I can post it. Thanks.

Reply with quote

martin◆ Site Admin
Joined:: 2002-12-10
Posts:: 41,441
Location:: Prague, Czechia

Re: WinSCP gets disconnected without showing any error message.

2020-09-08

And what happens then? Does the interface freeze? Or does it disappear?

To generate the session log file, enable logging, log in to your server and do the operation and only the operation that causes the error. Submit the log with your post as an attachment. Note that passwords and passphrases not stored in the log. You may want to remove other data you consider sensitive though, such as host names, IP addresses, account names or file names (unless they are relevant to the problem). If you do not want to post the log publicly, you can mark the attachment as private.

Reply with quote

martin1234guest Guest

Same problem happens to me.

2020-10-06 11:51

Intro/Environment:
Same problem happens to me. It often closes the whole client in "/keepuptodate" mode without visible notification.
- Updated to native portable (with local WinSCP.ini) WinSCP 5.17.6 and *.7 on Win10-1809. Applies also to at least 5.13.9 (tested). Does NOT apply to 5.11.3 (works fine, my previous "stable" in use).
- Using a connection via SFTP-3 to a Linux server (no admin access). As the server closes idle sessions, I use SSH NUll packetes each 60sec. in my profiles.
- I am running WinSCP from command line:

start "" "winscp.exe" "mysession" /keepuptodate // "%LOCALPATH%" "%REMOTEPATH%"

Problem:
The older WinSCP version 5.11.3 worked fine so that after any server-timeout the client stayed open in the background with disconnected state and as soon as a new change in the local directory was recognized, the auto-reconnect kicked in (incl. Win10 Notification-Bar Message). You can see this in the screenshot - notice the red message indicating an auto-reconnect. But this does not work any more since at least the mentioned versions or even since 5.12 (not tested). Instead the client disappears/closes without any notice, which is annoying if you need stable "realtime" sync of the remote location.

Do I miss any (command-line) option with the new version(s)? I have enabled "Debug 2" logging and noticed, that during a common session via standard GUI the client logs the network event lookups each second incl. the SSH keepalive (NULL) packets each 60 sec. Those connections never die. But using the dedicated "/keepuptodate" GUI from command-line with the same saved session-config (60sec. NULL keepalives) there is no logging of any SSH keepalives. So I assume there are no SSH keepalives sent in this mode (Why by the way??). However, this is just a side effect I noticed. The main problem is as described before, that the client closes silently on disconnects without waiting in disconnected state and doing an auto-reconnect on the next local filesystem change.

So... bug or feature? :D

Here are some logs before the client GUI terminates. I won't be able to provide full logs due to to much confidential data in it. But these snippets should tell you where to look for the issue, I hope. :)

## 5.17.7 - lines after last directory listing and before unexpected GUI termination.

. 2020-10-05 11:01:27.009 Startup conversation with host finished.
. 2020-10-05 11:01:27.412 Closing connection.
. 2020-10-05 11:01:27.412 Sending special code: 1
. 2020-10-05 11:01:27.412 Looking for network events
. 2020-10-05 11:01:27.416 Detected network event
. 2020-10-05 11:01:27.416 Enumerating network events for socket 2444
. 2020-10-05 11:01:27.416 Enumerated 1 network events making 1 cumulative events for socket 2444
. 2020-10-05 11:01:27.416 Handling network read event on socket 2444 with error 0
. 2020-10-05 11:01:27.416 Looking for network events
. 2020-10-05 11:01:27.416 Session sent command exit status 0
. 2020-10-05 11:01:27.416 Main session channel closed
. 2020-10-05 11:01:27.417 All channels closed
. 2020-10-05 11:01:27.417 Timeout waiting for network events
. 2020-10-05 11:01:27.417 Selecting events 0 for socket 2444
## GUI terminated!

## 5.13.9 - lines after last directory listing and before unexpected GUI termination.

. 2020-10-06 10:06:28.288 Startup conversation with host finished.
. 2020-10-06 10:06:28.666 Closing connection.
. 2020-10-06 10:06:28.666 Sending special code: 12
. 2020-10-06 10:06:28.666 Sent EOF message
. 2020-10-06 10:06:28.666 Selecting events 0 for socket 2340
## GUI terminated!

## 5.11.3 - working fine! lines after new sync attempt, detecting lost connection and doing reconnect. Then sync kicks in (not in log).

. 2020-10-06 12:09:26.233 Looking for network events
. 2020-10-06 12:09:26.233 Detected network event
. 2020-10-06 12:09:26.233 Enumerating network events for socket 1856
. 2020-10-06 12:09:26.233 Enumerated 33 network events making 33 cumulative events for socket 1856
. 2020-10-06 12:09:26.233 Handling network close event on socket 1856 with error 0
. 2020-10-06 12:09:26.233 Received 28 bytes (0)
. 2020-10-06 12:09:26.233 Selecting events 0 for socket 1856
. 2020-10-06 12:09:26.233 Server unexpectedly closed network connection
. 2020-10-06 12:09:26.233 Connection was lost, asking what to do.
## !!!!!!!!!!! Reconnect kicks in... !!!!!!!!!!!
. 2020-10-06 12:09:26.233 Asking user:
. 2020-10-06 12:09:26.233 Server unexpectedly closed network connection. ()
. 2020-10-06 12:09:26.286 Keep up to date: Server unexpectedly closed network connection.
. 2020-10-06 12:09:26.449 Looking up host "xxx.xxx.xxx.xxx" for SSH connection
. 2020-10-06 12:09:26.449 Connecting to xxx.xxx.xxx.xxx port 22
## !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
. 2020-10-06 12:09:26.503 Selecting events 63 for socket 2288
. 2020-10-06 12:09:26.503 We claim version: SSH-2.0-WinSCP_release_5.11.3
. 2020-10-06 12:09:26.503 Waiting for the server to continue with the initialization
. 2020-10-06 12:09:26.503 Looking for incoming data
. 2020-10-06 12:09:26.503 Looking for network events
. 2020-10-06 12:09:26.518 Detected network event
. 2020-10-06 12:09:26.518 Enumerating network events for socket 2288
. 2020-10-06 12:09:26.518 Enumerated 18 network events making 18 cumulative events for socket 2288
. 2020-10-06 12:09:26.518 Handling network write event on socket 2288 with error 0
. 2020-10-06 12:09:26.518 Handling network connect event on socket 2288 with error 0
. 2020-10-06 12:09:26.518 Looking for network events
. 2020-10-06 12:09:26.534 Detected network event
. 2020-10-06 12:09:26.534 Enumerating network events for socket 2288
. 2020-10-06 12:09:26.534 Enumerated 1 network events making 1 cumulative events for socket 2288
. 2020-10-06 12:09:26.534 Handling network read event on socket 2288 with error 0
. 2020-10-06 12:09:26.534 Server version: SSH-2.0-OpenSSH_5.3
. 2020-10-06 12:09:26.534 We believe remote version has SSH-2 channel request bug
. 2020-10-06 12:09:26.534 Using SSH protocol version 2
. 2020-10-06 12:09:26.550 Have a known host key of type rsa2
. 2020-10-06 12:09:26.550 Waiting for the server to continue with the initialization
. 2020-10-06 12:09:26.550 Looking for incoming data
. 2020-10-06 12:09:26.550 Looking for network events
. 2020-10-06 12:09:26.589 Detected network event
. 2020-10-06 12:09:26.589 Enumerating network events for socket 2288
. 2020-10-06 12:09:26.589 Enumerated 1 network events making 1 cumulative events for socket 2288
. 2020-10-06 12:09:26.589 Handling network read event on socket 2288 with error 0
. 2020-10-06 12:09:26.589 Doing Diffie-Hellman group exchange
. 2020-10-06 12:09:26.589 Waiting for the server to continue with the initialization
. 2020-10-06 12:09:26.589 Looking for incoming data
. 2020-10-06 12:09:26.589 Looking for network events
. 2020-10-06 12:09:26.620 Detected network event
. 2020-10-06 12:09:26.620 Enumerating network events for socket 2288
. 2020-10-06 12:09:26.620 Enumerated 1 network events making 1 cumulative events for socket 2288
. 2020-10-06 12:09:26.620 Handling network read event on socket 2288 with error 0
. 2020-10-06 12:09:26.620 Doing Diffie-Hellman key exchange with hash SHA-256
. 2020-10-06 12:09:26.995 Waiting for the server to continue with the initialization
. 2020-10-06 12:09:26.995 Looking for incoming data
. 2020-10-06 12:09:26.995 Looking for network events
. 2020-10-06 12:09:27.117 Detected network event
. 2020-10-06 12:09:27.117 Enumerating network events for socket 2288
. 2020-10-06 12:09:27.117 Enumerated 1 network events making 1 cumulative events for socket 2288
. 2020-10-06 12:09:27.117 Handling network read event on socket 2288 with error 0
. 2020-10-06 12:09:27.503 Server also has ssh-dss host key, but we don't know it
. 2020-10-06 12:09:27.503 Host key fingerprint is:
. 2020-10-06 12:09:27.503 ssh-rsa 2048 d9:0b:29:91:64:9b:35:8b:67:8c:1f:56:f5:e1:5b:11
. 2020-10-06 12:09:27.503 Verifying host key rsa2 0x23,...<snip>... with fingerprint ssh-rsa 2048 d9:...<snip>...
. 2020-10-06 12:09:27.503 Host key matches cached key
. 2020-10-06 12:09:27.503 Selecting events 63 for socket 2288
. 2020-10-06 12:09:27.503 Initialised AES-256 SDCTR client->server encryption
. 2020-10-06 12:09:27.503 Initialised HMAC-SHA1 client->server MAC algorithm
. 2020-10-06 12:09:27.503 Initialised AES-256 SDCTR server->client encryption
. 2020-10-06 12:09:27.503 Initialised HMAC-SHA1 server->client MAC algorithm
. 2020-10-06 12:09:27.503 Waiting for the server to continue with the initialization
. 2020-10-06 12:09:27.503 Looking for incoming data
. 2020-10-06 12:09:27.503 Looking for network events
. 2020-10-06 12:09:27.641 Detected network event
. 2020-10-06 12:09:27.641 Enumerating network events for socket 2288
. 2020-10-06 12:09:27.641 Enumerated 1 network events making 1 cumulative events for socket 2288
. 2020-10-06 12:09:27.641 Handling network read event on socket 2288 with error 0
! 2020-10-06 12:09:27.641 Using username "pakosch.martin".
. 2020-10-06 12:09:27.641 Waiting for the server to continue with the initialization
. 2020-10-06 12:09:27.641 Looking for incoming data
. 2020-10-06 12:09:27.641 Looking for network events
. 2020-10-06 12:09:27.672 Detected network event
. 2020-10-06 12:09:27.672 Enumerating network events for socket 2288
. 2020-10-06 12:09:27.672 Enumerated 1 network events making 1 cumulative events for socket 2288
. 2020-10-06 12:09:27.672 Handling network read event on socket 2288 with error 0
. 2020-10-06 12:09:27.672 Server offered these authentication methods: publickey,gssapi-keyex,gssapi-with-mic,password
. 2020-10-06 12:09:27.672 Using SSPI from SECUR32.DLL
. 2020-10-06 12:09:27.672 Attempting GSSAPI authentication
. 2020-10-06 12:09:27.672 Waiting for the server to continue with the initialization
. 2020-10-06 12:09:27.672 Looking for incoming data
. 2020-10-06 12:09:27.672 Looking for network events
. 2020-10-06 12:09:27.704 Detected network event
. 2020-10-06 12:09:27.704 Enumerating network events for socket 2288
. 2020-10-06 12:09:27.704 Enumerated 1 network events making 1 cumulative events for socket 2288
. 2020-10-06 12:09:27.704 Handling network read event on socket 2288 with error 0
. 2020-10-06 12:09:27.704 GSSAPI authentication request refused
. 2020-10-06 12:09:27.704 Server offered these authentication methods: publickey,gssapi-keyex,gssapi-with-mic,password
. 2020-10-06 12:09:27.704 Prompt (password, "SSH password", <no instructions>, "&Password: ")
. 2020-10-06 12:09:27.704 Using remembered password.
. 2020-10-06 12:09:27.704 Sent password
. 2020-10-06 12:09:27.704 Waiting for the server to continue with the initialization
. 2020-10-06 12:09:27.704 Looking for incoming data
. 2020-10-06 12:09:27.704 Looking for network events
. 2020-10-06 12:09:27.973 Detected network event
. 2020-10-06 12:09:27.973 Enumerating network events for socket 2288
. 2020-10-06 12:09:27.973 Enumerated 1 network events making 1 cumulative events for socket 2288
. 2020-10-06 12:09:27.973 Handling network read event on socket 2288 with error 0
. 2020-10-06 12:09:27.973 Access granted
. 2020-10-06 12:09:27.973 Opening session as main channel
. 2020-10-06 12:09:27.973 Waiting for the server to continue with the initialization
. 2020-10-06 12:09:27.973 Looking for incoming data
. 2020-10-06 12:09:27.973 Looking for network events
. 2020-10-06 12:09:28.005 Detected network event
. 2020-10-06 12:09:28.005 Enumerating network events for socket 2288
. 2020-10-06 12:09:28.005 Enumerated 1 network events making 1 cumulative events for socket 2288
. 2020-10-06 12:09:28.005 Handling network read event on socket 2288 with error 0
. 2020-10-06 12:09:28.005 Opened main channel
. 2020-10-06 12:09:28.005 Waiting for the server to continue with the initialization
. 2020-10-06 12:09:28.005 Looking for incoming data
. 2020-10-06 12:09:28.005 Looking for network events
. 2020-10-06 12:09:28.105 Detected network event
. 2020-10-06 12:09:28.105 Enumerating network events for socket 2288
. 2020-10-06 12:09:28.105 Enumerated 1 network events making 1 cumulative events for socket 2288
. 2020-10-06 12:09:28.105 Handling network read event on socket 2288 with error 0
. 2020-10-06 12:09:28.105 Started a shell/command
. 2020-10-06 12:09:28.121 Doing startup conversation with host.
## continues with sync operation.

winscp.txt (12.12 KB)

Description: Screenshot of working version 5.11.3. Notice the red message indicating an auto-reconnect. Missing behaviour in newer versions.

Reply with quote

martin1234guest Guest

Re: Same problem happens to me. - sorry, wrong attachment...

2020-10-06 11:58

martin1234guest wrote:

Intro/Environment:
Same problem happens to me. It often closes the whole client in "/keepuptodate" mode without visible notification.
...

Here the correct attachment.

winscp_working.png (31.73 KB)

Description: Screenshot of working version 5.11.3. Notice the red message indicating an auto-reconnect. Missing behaviour in newer versions.

Reply with quote

martin◆ Site Admin
Joined:: 2002-12-10
Posts:: 41,441
Location:: Prague, Czechia

Re: Same problem happens to me.

2020-10-09

martin1234guest wrote:

The older WinSCP version 5.11.3 worked fine so that after any server-timeout the client stayed open in the background with disconnected state and as soon as a new change in the local directory was recognized, the auto-reconnect kicked in (incl. Win10 Notification-Bar Message). You can see this in the screenshot - notice the red message indicating an auto-reconnect. But this does not work any more since at least the mentioned versions or even since 5.12 (not tested). Instead the client disappears/closes without any notice, which is annoying if you need stable "realtime" sync of the remote location.

Thanks for your report.

This bug has been added to the tracker:
https://winscp.net/tracker/1913

Can you send me an email, so I can send you back a development version of WinSCP for testing? Please include a link back to this topic in your email. Also note in this topic that you have sent the email. Thanks.

You will find my address (if you log in) in my forum profile.

Reply with quote

martin1234
Joined:: 2020-10-14
Posts:: 2
Location:: Germany

2020-10-15 08:11

Hi Martin,

I've send the mail as requested, but via my company mail account. Subject contains "Bug 1913". :) Awaiting your fixed dev. version for testing. Will it be a fixed 5.17.7 or a an 5.18 RC? Asking in case of side effects... :)

_________________
Kind regards, Martin

Reply with quote

martin1234
Joined:: 2020-10-14
Posts:: 2
Location:: Germany

2020-10-16 08:08

Hi Martin,

as written today in my latest mail it seems, that you have fixed the issue successfully. I could reproduce the issue "1913" with 5.17.7, whereas running my tests also with your debug version of 5.18 was successful. So thank you for the fix and waiting for the next release. For now sticking with 5.11.3. :D

_________________
Kind regards, Martin

Reply with quote

martin◆ Site Admin

2020-10-16

Thanks for your tests!

WinSCP 5.17.8 with the fix was released yesterday.

Reply with quote

passuff
Joined:: 2021-05-26
Posts:: 15

2021-06-01 08:39

I still have the issue with 5.17.10.

Startup conversation with host finished.
. 2021-06-01 07:11:51.058 Closing connection.
. 2021-06-01 07:11:51.058 Sending special code: 1
. 2021-06-01 07:11:51.077 Detected network event
. 2021-06-01 07:11:51.077 Session sent command exit status 0
. 2021-06-01 07:11:51.077 Main session channel closed
. 2021-06-01 07:11:51.077 All channels closed

These are the last messages before the GUI closed...

Find the full log attached. Here is my thread:
https://winscp.net/forum/viewtopic.php?p=106753#106753

log_upload.zip (2.03 KB)

Reply with quote

martin◆ Site Admin

2021-06-01

Thanks for your report.
I have sent you an email with a debug version of WinSCP to the address you have used to register on this forum.

Reply with quote

passuff
Joined:: 2021-05-26
Posts:: 15

2021-06-07 11:13

I tried with your debug version and was wondering why it did not crash for several day. Then I checked the files and realized sync is not working anymore even though the "keep folder up to date" window was still active. When stopping the service I realized the remote session (right window) was frozen while the left window (local dir) was still working. I closed the app and restarted it. When connecting to the remote server again, a certificate change on the server side was realized and I was asked if I trust that change. I guess this caused the crash.
Maybe you could add an option to allow automatic handling of server side certificate change?
Unfortunately the log files are too new (old ones get deleted). The trace files are still there. Each one has 1Gb - not sure which one could be helpful.
For the other issue (GUI shutdown) I will report again soon.

Reply with quote

martin◆ Site Admin
Joined:: 2002-12-10
Posts:: 41,441
Location:: Prague, Czechia

2021-06-10

passuff wrote:

I tried with your debug version and was wondering why it did not crash for several day. Then I checked the files and realized sync is not working anymore even though the "keep folder up to date" window was still active. When stopping the service I realized the remote session (right window) was frozen while the left window (local dir) was still working.

It was possibly due to this problem that might have prevented an automatic reconnect:
https://winscp.net/tracker/1991

Reply with quote

martin◆ Site Admin
Joined:: 2002-12-10
Posts:: 41,441
Location:: Prague, Czechia

2021-06-16

I've added an improvement that should help you:
https://winscp.net/tracker/1994

I have also fixed more related issues:
https://winscp.net/eng/docs/history?a=5.19

I'm sending you an email with a development version of WinSCP.

Reply with quote

You can post new topics in this forum