Error: "Cannot Close Remote File" uploading files larger then around 100K :: Support Forum

richwink
Joined:: 2015-12-08
Posts:: 5

Error: "Cannot Close Remote File" uploading files larger then around 100K

2015-12-08 02:28

Using WinSCP Version 5.7.5 (Build 5665)
Protocol: SFTP
Port: 22

Error occurs Uploading file to NetApp server
Error occurs both using WINSCP GUI and command line interface
No errors occur downloading files

File size is relevant to the error:
Files under 10K: Error never occurs
Files 10K – 50K: Error is intermittent, occurring more frequently as the file gets larger.
Files 50K-100K: Error occurs almost all the time
Files > 100K: Error occurs all the time.
Whether the file is uploaded as binary or text is not relevant.

When the WinSCP GUI displays the error window, I click “Abort” and the file transfer operation completes.
The error is associated with the server handling of the SSH_FXP_CLOSE command. The server returns the status message: “no such file”, so the client logs: “Cannot Close Remote File”.
After I click “Abort” to the error, the server returns a directory listing (that includes the uploaded filename) without error.

NOTE: I have turned off temporary file renaming from the client to prevent uploading to a temporary filename and then renaming at the end of the transfer. That was a problem in the past because the FTS server does not allow file renaming.

Here is the relevant part of the log for upload of a 300K file that generated the error
(The log for an upload that generated no error follows this one)
I bolded relevant lines and also translated the HEX status messages – see the lines beginning with “RWINKLER”

(These first 8 lines show the end of the file upload):

…
> 2015-11-09 16:38:38.220 75,72,65,20,73,68,6F,77,73,20,74,68,65,20,66,69,6C,65,20,77,61,73,20,6E,6F,
> 2015-11-09 16:38:38.220 74,20,66,6F,75,6E,64,2E,20,20,49,20,6E,65,65,64,20,74,6F,20,73,65,65,20,74,
> 2015-11-09 16:38:38.220 68,65,20,65,72,72,6F,72,20,61,73,73,6F,63,69,61,74,65,64,20,77,69,74,68,20,
> 2015-11-09 16:38:38.220 61,63,74,75,61,6C,20,74,72,61,6E,73,66,65,72,20,69,74,73,65,6C,66,2E,20,49,
> 2015-11-09 16:38:38.220 66,20,70,6F,73,73,69,62,6C,65,20,74,72,79,20,74,6F,20,63,61,70,74,75,72,65,
> 2015-11-09 16:38:38.220 20,61,20,77,69,72,65,73,68,61,72,6B,20,66,72,6F,6D,20,74,68,65,20,73,65,72,
> 2015-11-09 16:38:38.220 76,65,72,20,77,68,69,6C,65,20,74,68,65,20,66,61,69,6C,75,72,65,20,69,73,20,
> 2015-11-09 16:38:38.220 68,61,70,70,65,69,6E,67,2E,20,54,68,61,6E,6B,73,2C,20,53,74,65,76,65,0D,0A,
. 2015-11-09 16:38:38.220 Sent 24554 bytes
. 2015-11-09 16:38:38.220 There are 0 bytes remaining in the send buffer
. 2015-11-09 16:38:38.220 Looking for network events
. 2015-11-09 16:38:38.220 Detected network event
. 2015-11-09 16:38:38.220 Enumerating network events for socket 1116
. 2015-11-09 16:38:38.220 Enumerated 1 network events making 1 cumulative events for socket 1116
. 2015-11-09 16:38:38.220 Handling network read event on socket 1116 with error 0
. 2015-11-09 16:38:38.220 Received 28 bytes (0)
. 2015-11-09 16:38:38.220 Read 4 bytes (24 pending)
. 2015-11-09 16:38:38.220 Read 24 bytes (0 pending)
< 2015-11-09 16:38:38.220 Type: SSH_FXP_STATUS, Size: 24, Number: 5382
< 2015-11-09 16:38:38.220 65,00,00,15,06,00,00,00,00,00,00,00,07,53,75,63,63,65,73,73,00,00,00,00,
RWINKLER: Translation: e Success
< 2015-11-09 16:38:38.220 Status code: 0
> 2015-11-09 16:38:38.220 Type: SSH_FXP_CLOSE, Size: 13, Number: 5892
> 2015-11-09 16:38:38.220 04,00,00,17,04,00,00,00,04,00,00,00,00,
. 2015-11-09 16:38:38.220 Sent 17 bytes
. 2015-11-09 16:38:38.220 There are 0 bytes remaining in the send buffer
. 2015-11-09 16:38:38.220 Looking for network events
. 2015-11-09 16:38:38.220 Timeout waiting for network events
> 2015-11-09 16:38:38.220 Type: SSH_FXP_SETSTAT, Size: 82, Number: 2313
> 2015-11-09 16:38:38.220 09,00,00,09,09,00,00,00,3D,2F,76,6F,6C,2F,64,63,32,66,31,33,63,31,5F,73,66,
> 2015-11-09 16:38:38.220 74,70,5F,61,75,74,68,6B,62,66,73,31,70,72,5F,76,6F,6C,31,2F,54,65,73,74,5F,
> 2015-11-09 16:38:38.220 33,30,30,4B,42,79,74,65,73,20,2D,20,43,6F,70,79,2E,74,78,74,00,00,00,08,56,
> 2015-11-09 16:38:38.220 41,1D,FB,56,41,1E,0A,
RWINKLER: Translation: =/vol/dc2f13c1_sftp_authkbfs1pr_vol1/Test_300KBytes - Copy.txtVAûVA
. 2015-11-09 16:38:38.220 Sent 86 bytes
. 2015-11-09 16:38:38.220 There are 0 bytes remaining in the send buffer
. 2015-11-09 16:38:38.220 Looking for network events
. 2015-11-09 16:38:38.220 Timeout waiting for network events
. 2015-11-09 16:38:38.220 Waiting for another 4 bytes
. 2015-11-09 16:38:38.220 Looking for incoming data
. 2015-11-09 16:38:38.220 Looking for network events
. 2015-11-09 16:38:38.220 Detected network event
. 2015-11-09 16:38:38.220 Enumerating network events for socket 1116
. 2015-11-09 16:38:38.220 Enumerated 1 network events making 1 cumulative events for socket 1116
. 2015-11-09 16:38:38.220 Handling network read event on socket 1116 with error 0
. 2015-11-09 16:38:38.220 Received 89 bytes (0)
. 2015-11-09 16:38:38.220 Read 4 bytes (85 pending)
. 2015-11-09 16:38:38.220 Read 24 bytes (61 pending)
< 2015-11-09 16:38:38.220 Type: SSH_FXP_STATUS, Size: 24, Number: 5638
< 2015-11-09 16:38:38.220 65,00,00,16,06,00,00,00,00,00,00,00,07,53,75,63,63,65,73,73,00,00,00,00,
RWINKLER: Translation: eSuccess
. 2015-11-09 16:38:38.220 Read 4 bytes (57 pending)
. 2015-11-09 16:38:38.220 Read 29 bytes (28 pending)
< 2015-11-09 16:38:38.220 Type: SSH_FXP_STATUS, Size: 29, Number: 5892
< 2015-11-09 16:38:38.220 65,00,00,17,04,00,00,00,02,00,00,00,0C,4E,6F,20,73,75,63,68,20,66,69,6C,65,
< 2015-11-09 16:38:38.220 00,00,00,00,
RWINKLER: Translation: e
________________________________________
[1]No such file
< 2015-11-09 16:38:38.220 Status code: 2, Message: 5892, Server: No such file, Language:  
* 2015-11-09 16:38:38.220 (ETerminal) No such file or directory.
* 2015-11-09 16:38:38.220 Error code: 2
* 2015-11-09 16:38:38.220 Error message from server: No such file
. 2015-11-09 16:38:38.220 Asking user:
. 2015-11-09 16:38:38.220 Cannot close remote file 'Test_300KBytes - Copy.txt'. ("No such file or directory.
. 2015-11-09 16:38:38.220 Error code: 2
. 2015-11-09 16:38:38.220 Error message from server: No such file")

After clicking “Abort” to the error, the upload finishes and the file appears on the FTP server with the correct size. When I download the file I am able to verify that the entire file transferred OK.

HERE IS Part of log for a file < 10K that did not generate the error:

> 2015-11-09 18:01:46.057 6F,20,74,68,65,20,63,61,73,65,20,6C,6F,6F,6B,65,64,20,74,6F,20,62,65,20,61,
> 2015-11-09 18:01:46.057 20,6A,6F,62,20,6C,6F,67,2E,20,54,68,65,20,66,61,69,6C,69,75,72,65,20,73,68,
> 2015-11-09 18:01:46.057 6F,77,73,20,74,68,65,20,66,69,6C,65,20,77,61,73,20,6E,6F,74,20,66,6F,75,6E,
> 2015-11-09 18:01:46.057 64,2E,20,20,49,20,6E,65,65,64,20,74,6F,20,73,65,65,20,74,68,65,20,65,72,72,
> 2015-11-09 18:01:46.057 6F,72,20,61,73,73,6F,63,69,61,74,65,64,20,77,69,74,68,20,61,63,74,75,61,6C,
> 2015-11-09 18:01:46.057 20,74,72,61,6E,73,66,65,72,20,69,74,73,65,6C,66,2E,20,49,66,20,70,6F,73,73,
> 2015-11-09 18:01:46.057 69,62,6C,65,20,74,72,79,20,74,6F,20,63,61,70,74,75,72,65,20,61,20,77,69,72,
> 2015-11-09 18:01:46.057 65,73,68,61,72,6B,20,66,72,6F,6D,20,74,68,65,20,73,65,72,76,65,72,20,77,68,
> 2015-11-09 18:01:46.057 69,6C,65,20,74,68,65,20,66,61,69,6C,75,72,65,20,69,73,20,68,61,70,70,65,69,
> 2015-11-09 18:01:46.057 6E,67,2E,20,54,68,61,6E,6B,73,2C,20,53,74,65,76,65,0D,0A,
. 2015-11-09 18:01:46.057 Sent 1323 bytes
. 2015-11-09 18:01:46.057 There are 0 bytes remaining in the send buffer
. 2015-11-09 18:01:46.057 Looking for network events
. 2015-11-09 18:01:46.057 Timeout waiting for network events
> 2015-11-09 18:01:46.057 Type: SSH_FXP_CLOSE, Size: 13, Number: 3332
> 2015-11-09 18:01:46.057 04,00,00,0D,04,00,00,00,04,00,00,00,00,
. 2015-11-09 18:01:46.057 Sent 17 bytes
. 2015-11-09 18:01:46.057 There are 0 bytes remaining in the send buffer
. 2015-11-09 18:01:46.057 Looking for network events
. 2015-11-09 18:01:46.057 Timeout waiting for network events
> 2015-11-09 18:01:46.057 Type: SSH_FXP_SETSTAT, Size: 74, Number: 2313
> 2015-11-09 18:01:46.057 09,00,00,09,09,00,00,00,35,2F,76,6F,6C,2F,64,63,32,66,31,33,63,31,5F,73,66,
> 2015-11-09 18:01:46.057 74,70,5F,61,75,74,68,6B,62,66,73,31,70,72,5F,76,6F,6C,31,2F,54,65,73,74,5F,
> 2015-11-09 18:01:46.057 31,30,4B,42,79,74,65,73,2E,74,78,74,00,00,00,08,56,41,1C,E3,56,41,1D,39,
RWINKLER: TRANSLATION: 5/vol/dc2f13c1_sftp_authkbfs1pr_vol1/Test_10KBytes.txtVA ãVA9
. 2015-11-09 18:01:46.057 Sent 78 bytes
. 2015-11-09 18:01:46.057 There are 0 bytes remaining in the send buffer
. 2015-11-09 18:01:46.057 Looking for network events
. 2015-11-09 18:01:46.057 Timeout waiting for network events
. 2015-11-09 18:01:46.057 Waiting for another 4 bytes
. 2015-11-09 18:01:46.057 Looking for incoming data
. 2015-11-09 18:01:46.057 Looking for network events
. 2015-11-09 18:01:46.073 Detected network event
. 2015-11-09 18:01:46.073 Enumerating network events for socket 1120
. 2015-11-09 18:01:46.073 Enumerated 1 network events making 1 cumulative events for socket 1120
. 2015-11-09 18:01:46.073 Handling network read event on socket 1120 with error 0
. 2015-11-09 18:01:46.073 Received 28 bytes (0)
. 2015-11-09 18:01:46.073 Read 4 bytes (24 pending)
. 2015-11-09 18:01:46.073 Read 24 bytes (0 pending)
< 2015-11-09 18:01:46.073 Type: SSH_FXP_STATUS, Size: 24, Number: 3078
< 2015-11-09 18:01:46.073 65,00,00,0C,06,00,00,00,00,00,00,00,07,53,75,63,63,65,73,73,00,00,00,00,
RWINKLER: TRANSLATION: eSuccess
. 2015-11-09 18:01:46.073 Waiting for another 4 bytes
. 2015-11-09 18:01:46.073 Looking for incoming data
. 2015-11-09 18:01:46.073 Looking for network events
. 2015-11-09 18:01:46.073 Detected network event
. 2015-11-09 18:01:46.073 Enumerating network events for socket 1120
. 2015-11-09 18:01:46.073 Enumerated 1 network events making 1 cumulative events for socket 1120
. 2015-11-09 18:01:46.073 Handling network read event on socket 1120 with error 0
. 2015-11-09 18:01:46.073 Received 28 bytes (0)
. 2015-11-09 18:01:46.073 Read 4 bytes (24 pending)
. 2015-11-09 18:01:46.073 Read 24 bytes (0 pending)
< 2015-11-09 18:01:46.073 Type: SSH_FXP_STATUS, Size: 24, Number: 3332
< 2015-11-09 18:01:46.073 65,00,00,0D,04,00,00,00,00,00,00,00,07,53,75,63,63,65,73,73,00,00,00,00,
RWINKLER: TRANSLATION: e
________________________________________
Success
< 2015-11-09 18:01:46.073 Status code: 0
. 2015-11-09 18:01:46.073 Preserving timestamp [2015-11-09T22:24:57.000Z]
. 2015-11-09 18:01:46.073 Waiting for another 4 bytes
. 2015-11-09 18:01:46.073 Looking for incoming data
. 2015-11-09 18:01:46.073 Looking for network events
. 2015-11-09 18:01:46.275 Detected network event
. 2015-11-09 18:01:46.275 Enumerating network events for socket 1120
. 2015-11-09 18:01:46.275 Enumerated 1 network events making 1 cumulative events for socket 1120
. 2015-11-09 18:01:46.275 Handling network read event on socket 1120 with error 0
. 2015-11-09 18:01:46.275 Received 28 bytes (0)
. 2015-11-09 18:01:46.275 Read 4 bytes (24 pending)
. 2015-11-09 18:01:46.275 Read 24 bytes (0 pending)
< 2015-11-09 18:01:46.275 Type: SSH_FXP_STATUS, Size: 24, Number: 2313
< 2015-11-09 18:01:46.275 65,00,00,09,09,00,00,00,00,00,00,00,07,53,75,63,63,65,73,73,00,00,00,00,
RWINKLER: TRANSLATION: e                      Success
< 2015-11-09 18:01:46.275 Status code: 0
. 2015-11-09 18:01:46.275 Transfer done: 'F:\Temp\Test_10KBytes.txt' [9486]

Reply with quote

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

Re: Error: "Cannot Close Remote File" uploading files larger then around 100K

2015-12-10

The error comes from the server, when WinSCP tries to update file timestamp and/or permissions.

I cannot know why the server fails the request.

Maybe there's some process that takes the file away when the upload finishes or something similar.

In that case, try to disable preserving timestamp/setting permissions.

Reply with quote

richwink
Joined:: 2015-12-08
Posts:: 5

2015-12-10 17:13

Hello @martin – thank you for your reply,
I tried your suggestions: "disable preserving timestamp/setting permissions" (please see attached)
and still get the error.
The error does not occur with other clients e.g. CoreFTP.

TransferPresets.png (30.94 KB)

Description: Transfer Presets

Reply with quote

martin◆ Site Admin

2015-12-14

Please post a new log file.

Reply with quote

richwink
Joined:: 2015-12-08
Posts:: 5

2015-12-17 00:32

Hello @martin here is the log file your requested. I unchecked all the "Common options" including "Preserve timestamp" and also unchecked all "Upload Options". I did this for the "Transfer Settings" of all "Presets" i.e. "default", "Text"...etc.
I get the exact same error.
I have attached the entire log from startup of WinSCP to after the file is uploaded.
Below I've pasted a truncated portion of the log from the end of the file upload to after I click "Abort" to the error message and the file finishes uploading.

> 2015-12-16 17:06:54.340 69,73,20,68,61,70,70,65,69,6E,67,2E,20,54,68,61,6E,6B,73,2C,20,53,74,65,76,
> 2015-12-16 17:06:54.340 65,41,52,52,4F,57,45,4C,45,43,54,52,4F,4E,49,43,0A,54,52,49,4D,41,53,0A,49,
> 2015-12-16 17:06:54.340 20,64,6F,6E,92,74,20,6D,69,6E,64,20,6F,70,65,6E,69,6E,67,20,61,20,63,61,73,
> 2015-12-16 17:06:54.340 65,20,77,69,74,68,20,6E,65,74,61,70,70,20,62,75,74,20,49,20,6E,65,65,64,20,
> 2015-12-16 17:06:54.340 6D,6F,72,65,20,64,61,74,61,20,66,6F,72,20,74,68,61,74,2E,20,49,20,73,65,65,
> 2015-12-16 17:06:54.340 20,77,65,20,68,61,76,65,20,69,6E,74,65,72,6D,69,74,74,65,6E,74,20,69,73,73,
> 2015-12-16 17:06:54.340 75,65,73,20,72,65,67,61,72,64,6C,65,73,73,20,6F,66,20,66,69,6C,65,20,73,69,
> 2015-12-16 17:06:54.340 7A,65,20,61,63,63,6F,72,64,69,6E,67,20,74,6F,20,74,68,65,20,65,6D,61,69,6C,
> 2015-12-16 17:06:54.340 20,74,68,72,65,61,64,2E,20,20,41,6C,73,6F,20,79,6F,75,20,73,61,79,20,69,74,
> 2015-12-16 17:06:54.340 20,68,61,73,20,66,61,69,6C,65,64,20,77,69,74,68,20,77,69,6E,73,63,70,3F,20,
> 2015-12-16 17:06:54.340 54,68,65,20,6C,6F,67,20,74,68,61,74,20,77,61,73,20,61,74,74,61,63,68,65,64,
> 2015-12-16 17:06:54.340 20,74,6F,20,74,68,65,20,63,61,73,65,20,6C,6F,6F,6B,65,64,20,74,6F,20,62,65,
> 2015-12-16 17:06:54.340 20,61,20,6A,6F,62,20,6C,6F,67,2E,20,54,68,65,20,66,61,69,6C,69,75,72,65,20,
> 2015-12-16 17:06:54.340 73,68,6F,77,73,20,74,68,65,20,66,69,6C,65,20,77,61,73,20,6E,6F,74,20,66,6F,
> 2015-12-16 17:06:54.340 75,6E,64,2E,20,20,49,20,6E,65,65,64,20,74,6F,20,73,65,65,20,74,68,65,20,65,
> 2015-12-16 17:06:54.340 72,72,6F,72,20,61,73,73,6F,63,69,61,74,65,64,20,77,69,74,68,20,61,63,74,75,
> 2015-12-16 17:06:54.340 61,6C,20,74,72,61,6E,73,66,65,72,20,69,74,73,65,6C,66,2E,20,49,66,20,70,6F,
> 2015-12-16 17:06:54.340 73,73,69,62,6C,65,20,74,72,79,20,74,6F,20,63,61,70,74,75,72,65,20,61,20,77,
> 2015-12-16 17:06:54.340 69,72,65,73,68,61,72,6B,20,66,72,6F,6D,20,74,68,65,20,73,65,72,76,65,72,20,
> 2015-12-16 17:06:54.340 77,68,69,6C,65,20,74,68,65,20,66,61,69,6C,75,72,65,20,69,73,20,68,61,70,70,
> 2015-12-16 17:06:54.340 65,69,6E,67,2E,20,54,68,61,6E,6B,73,2C,20,53,74,65,76,65,0D,0A,
. 2015-12-16 17:06:54.340 Sent 28650 bytes
. 2015-12-16 17:06:54.340 There are 0 bytes remaining in the send buffer
. 2015-12-16 17:06:54.340 Looking for network events
. 2015-12-16 17:06:54.340 Detected network event
. 2015-12-16 17:06:54.340 Enumerating network events for socket 1116
. 2015-12-16 17:06:54.340 Enumerated 1 network events making 1 cumulative events for socket 1116
. 2015-12-16 17:06:54.340 Handling network read event on socket 1116 with error 0
. 2015-12-16 17:06:54.340 Received 28 bytes (0)
. 2015-12-16 17:06:54.340 Read 4 bytes (24 pending)
. 2015-12-16 17:06:54.340 Read 24 bytes (0 pending)
< 2015-12-16 17:06:54.340 Type: SSH_FXP_STATUS, Size: 24, Number: 5126
< 2015-12-16 17:06:54.340 65,00,00,14,06,00,00,00,00,00,00,00,07,53,75,63,63,65,73,73,00,00,00,00,
< 2015-12-16 17:06:54.340 Status code: 0
> 2015-12-16 17:06:54.340 Type: SSH_FXP_CLOSE, Size: 13, Number: 5636
> 2015-12-16 17:06:54.340 04,00,00,16,04,00,00,00,04,00,00,00,00,
. 2015-12-16 17:06:54.340 Sent 17 bytes
. 2015-12-16 17:06:54.340 There are 0 bytes remaining in the send buffer
. 2015-12-16 17:06:54.340 Looking for network events
. 2015-12-16 17:06:54.340 Timeout waiting for network events
. 2015-12-16 17:06:54.340 Waiting for another 4 bytes
. 2015-12-16 17:06:54.340 Looking for incoming data
. 2015-12-16 17:06:54.356 Looking for network events
. 2015-12-16 17:06:54.356 Detected network event
. 2015-12-16 17:06:54.356 Enumerating network events for socket 1116
. 2015-12-16 17:06:54.356 Enumerated 1 network events making 1 cumulative events for socket 1116
. 2015-12-16 17:06:54.356 Handling network read event on socket 1116 with error 0
. 2015-12-16 17:06:54.356 Received 61 bytes (0)
. 2015-12-16 17:06:54.356 Read 4 bytes (57 pending)
. 2015-12-16 17:06:54.356 Read 24 bytes (33 pending)
< 2015-12-16 17:06:54.356 Type: SSH_FXP_STATUS, Size: 24, Number: 5382
< 2015-12-16 17:06:54.356 65,00,00,15,06,00,00,00,00,00,00,00,07,53,75,63,63,65,73,73,00,00,00,00,
. 2015-12-16 17:06:54.356 Read 4 bytes (29 pending)
. 2015-12-16 17:06:54.356 Read 29 bytes (0 pending)
< 2015-12-16 17:06:54.356 Type: SSH_FXP_STATUS, Size: 29, Number: 5636
< 2015-12-16 17:06:54.356 65,00,00,16,04,00,00,00,02,00,00,00,0C,4E,6F,20,73,75,63,68,20,66,69,6C,65,
< 2015-12-16 17:06:54.356 00,00,00,00,
< 2015-12-16 17:06:54.356 Status code: 2, Message: 5636, Server: No such file, Language:  
* 2015-12-16 17:06:54.356 (ETerminal) No such file or directory.
* 2015-12-16 17:06:54.356 Error code: 2
* 2015-12-16 17:06:54.356 Error message from server: No such file
. 2015-12-16 17:06:54.356 Asking user:
. 2015-12-16 17:06:54.356 Cannot close remote file 'Test_300KBytes.txt'. ("No such file or directory.
. 2015-12-16 17:06:54.356 Error code: 2
. 2015-12-16 17:06:54.356 Error message from server: No such file")
. 2015-12-16 17:07:22.546 Session upkeep
. 2015-12-16 17:07:22.546 Looking for network events
. 2015-12-16 17:07:22.546 Timeout waiting for network events
* 2015-12-16 17:07:22.842 (EScpSkipFile) Cannot close remote file 'Test_300KBytes.txt'.
* 2015-12-16 17:07:22.842 No such file or directory.
* 2015-12-16 17:07:22.842 Error code: 2
* 2015-12-16 17:07:22.842 Error message from server: No such file
. 2015-12-16 17:07:22.842 Listing directory "/vol/dc2f13c1_sftp_authkbfs1pr_vol1".
> 2015-12-16 17:07:22.858 Type: SSH_FXP_OPENDIR, Size: 44, Number: 5899
> 2015-12-16 17:07:22.858 0B,00,00,17,0B,00,00,00,23,2F,76,6F,6C,2F,64,63,32,66,31,33,63,31,5F,73,66,
> 2015-12-16 17:07:22.858 74,70,5F,61,75,74,68,6B,62,66,73,31,70,72,5F,76,6F,6C,31,
. 2015-12-16 17:07:22.858 Sent 48 bytes
. 2015-12-16 17:07:22.858 There are 0 bytes remaining in the send buffer
. 2015-12-16 17:07:22.858 Looking for network events
. 2015-12-16 17:07:22.858 Timeout waiting for network events
. 2015-12-16 17:07:22.858 Waiting for another 4 bytes
. 2015-12-16 17:07:22.858 Looking for incoming data
. 2015-12-16 17:07:22.858 Looking for network events
. 2015-12-16 17:07:22.858 Detected network event
. 2015-12-16 17:07:22.858 Enumerating network events for socket 1116
. 2015-12-16 17:07:22.858 Enumerated 1 network events making 1 cumulative events for socket 1116
. 2015-12-16 17:07:22.858 Handling network read event on socket 1116 with error 0
. 2015-12-16 17:07:22.858 Received 17 bytes (0)
. 2015-12-16 17:07:22.858 Read 4 bytes (13 pending)
. 2015-12-16 17:07:22.858 Read 13 bytes (0 pending)
< 2015-12-16 17:07:22.858 Type: SSH_FXP_HANDLE, Size: 13, Number: 5899
< 2015-12-16 17:07:22.858 66,00,00,17,0B,00,00,00,04,00,00,00,01,
> 2015-12-16 17:07:22.858 Type: SSH_FXP_READDIR, Size: 13, Number: 6156
> 2015-12-16 17:07:22.858 0C,00,00,18,0C,00,00,00,04,00,00,00,01,
. 2015-12-16 17:07:22.858 Sent 17 bytes
. 2015-12-16 17:07:22.858 There are 0 bytes remaining in the send buffer
. 2015-12-16 17:07:22.858 Looking for network events
. 2015-12-16 17:07:22.858 Timeout waiting for network events
. 2015-12-16 17:07:22.858 Waiting for another 4 bytes
. 2015-12-16 17:07:22.858 Looking for incoming data
. 2015-12-16 17:07:22.858 Looking for network events
. 2015-12-16 17:07:22.858 Detected network event
. 2015-12-16 17:07:22.858 Enumerating network events for socket 1116
. 2015-12-16 17:07:22.858 Enumerated 1 network events making 1 cumulative events for socket 1116
. 2015-12-16 17:07:22.858 Handling network read event on socket 1116 with error 0
. 2015-12-16 17:07:22.858 Received 477 bytes (0)
. 2015-12-16 17:07:22.858 Read 4 bytes (473 pending)
. 2015-12-16 17:07:22.858 Read 473 bytes (0 pending)
< 2015-12-16 17:07:22.858 Type: SSH_FXP_NAME, Size: 473, Number: 6156
< 2015-12-16 17:07:22.858 68,00,00,18,0C,00,00,00,04,00,00,00,01,2E,00,00,00,3A,64,72,77,78,72,77,78,
< 2015-12-16 17:07:22.858 72,77,78,20,20,20,20,20,32,20,72,6F,6F,74,20,20,20,20,30,20,20,20,20,20,20,
< 2015-12-16 17:07:22.858 20,20,20,20,20,20,20,34,30,39,36,20,44,65,63,20,31,36,20,31,37,3A,30,34,20,
< 2015-12-16 17:07:22.858 2E,00,00,00,0F,00,00,00,00,00,00,10,00,00,00,00,00,00,00,00,00,00,00,41,FF,
< 2015-12-16 17:07:22.858 55,24,9A,26,56,71,EE,1B,00,00,00,02,2E,2E,00,00,00,3B,64,72,77,78,72,77,78,
< 2015-12-16 17:07:22.858 72,77,78,20,20,20,20,20,33,20,72,6F,6F,74,20,20,20,20,30,20,20,20,20,20,20,
< 2015-12-16 17:07:22.858 20,20,20,20,20,20,20,34,30,39,36,20,44,65,63,20,31,36,20,31,37,3A,30,30,20,
< 2015-12-16 17:07:22.858 2E,2E,00,00,00,0F,00,00,00,00,00,00,10,00,00,00,00,00,00,00,00,00,00,00,41,
< 2015-12-16 17:07:22.858 FF,55,24,9A,26,56,71,ED,0B,00,00,00,11,54,65,73,74,5F,31,30,4B,42,79,74,65,
< 2015-12-16 17:07:22.858 73,2E,74,78,74,00,00,00,4A,2D,72,77,78,72,77,78,72,77,78,20,20,20,20,20,31,
< 2015-12-16 17:07:22.858 20,72,6F,6F,74,20,20,20,20,30,20,20,20,20,20,20,20,20,20,20,20,20,20,39,34,
< 2015-12-16 17:07:22.858 38,36,20,4E,6F,76,20,32,35,20,31,30,3A,31,36,20,54,65,73,74,5F,31,30,4B,42,
< 2015-12-16 17:07:22.858 79,74,65,73,2E,74,78,74,00,00,00,0F,00,00,00,00,00,00,25,0E,00,00,00,00,00,
< 2015-12-16 17:07:22.858 00,00,00,00,00,81,FF,56,55,DE,E3,56,55,DE,E3,00,00,00,12,54,65,73,74,5F,33,
< 2015-12-16 17:07:22.858 30,30,4B,42,79,74,65,73,2E,74,78,74,00,00,00,4B,2D,72,77,78,72,77,78,72,77,
< 2015-12-16 17:07:22.858 78,20,20,20,20,20,31,20,72,6F,6F,74,20,20,20,20,30,20,20,20,20,20,20,20,20,
< 2015-12-16 17:07:22.858 20,20,20,33,33,31,34,36,34,20,44,65,63,20,31,36,20,31,37,3A,30,36,20,54,65,
< 2015-12-16 17:07:22.858 73,74,5F,33,30,30,4B,42,79,74,65,73,2E,74,78,74,00,00,00,0F,00,00,00,00,00,
< 2015-12-16 17:07:22.858 05,0E,C8,00,00,00,00,00,00,00,00,00,00,81,FF,56,71,EE,1B,56,71,EE,8E,
> 2015-12-16 17:07:22.904 Type: SSH_FXP_READDIR, Size: 13, Number: 6412
> 2015-12-16 17:07:22.904 0C,00,00,19,0C,00,00,00,04,00,00,00,01,
. 2015-12-16 17:07:22.904 Sent 17 bytes
. 2015-12-16 17:07:22.904 There are 0 bytes remaining in the send buffer
. 2015-12-16 17:07:22.904 Looking for network events
. 2015-12-16 17:07:22.904 Timeout waiting for network events
. 2015-12-16 17:07:22.904 Read file '.' from listing
. 2015-12-16 17:07:22.904 Read file '..' from listing
. 2015-12-16 17:07:22.904 Read file 'Test_10KBytes.txt' from listing
. 2015-12-16 17:07:22.904 Read file 'Test_300KBytes.txt' from listing
. 2015-12-16 17:07:22.904 Waiting for another 4 bytes
. 2015-12-16 17:07:22.904 Looking for incoming data
. 2015-12-16 17:07:22.904 Looking for network events
. 2015-12-16 17:07:22.904 Detected network event
. 2015-12-16 17:07:22.904 Enumerating network events for socket 1116
. 2015-12-16 17:07:22.904 Enumerated 1 network events making 1 cumulative events for socket 1116
. 2015-12-16 17:07:22.904 Handling network read event on socket 1116 with error 0
. 2015-12-16 17:07:22.904 Received 32 bytes (0)
. 2015-12-16 17:07:22.904 Read 4 bytes (28 pending)
. 2015-12-16 17:07:22.904 Read 28 bytes (0 pending)
< 2015-12-16 17:07:22.904 Type: SSH_FXP_STATUS, Size: 28, Number: 6412
< 2015-12-16 17:07:22.904 65,00,00,19,0C,00,00,00,01,00,00,00,0B,45,6E,64,20,6F,66,20,66,69,6C,65,00,
< 2015-12-16 17:07:22.904 00,00,00,
< 2015-12-16 17:07:22.904 Status code: 1
> 2015-12-16 17:07:22.951 Type: SSH_FXP_CLOSE, Size: 13, Number: 6660
> 2015-12-16 17:07:22.951 04,00,00,1A,04,00,00,00,04,00,00,00,01,
. 2015-12-16 17:07:22.951 Sent 17 bytes
. 2015-12-16 17:07:22.951 There are 0 bytes remaining in the send buffer
. 2015-12-16 17:07:22.951 Looking for network events
. 2015-12-16 17:07:22.951 Timeout waiting for network events
. 2015-12-16 17:07:22.951 ..;d;0;2015-12-16T23:00:27.000Z;"root" [0];"0" [0];rwxrwxrwx;1
. 2015-12-16 17:07:22.951 Test_10KBytes.txt;-;9486;2015-11-25T16:16:35.000Z;"root" [0];"0" [0];rwxrwxrwx;1
. 2015-12-16 17:07:22.951 Test_300KBytes.txt;-;331464;2015-12-16T23:06:54.000Z;"root" [0];"0" [0];rwxrwxrwx;1
. 2015-12-16 17:07:23.060 Session upkeep
. 2015-12-16 17:07:23.060 Looking for network events
. 2015-12-16 17:07:23.060 Detected network event
. 2015-12-16 17:07:23.060 Enumerating network events for socket 1116
. 2015-12-16 17:07:23.060 Enumerated 1 network events making 1 cumulative events for socket 1116
. 2015-12-16 17:07:23.060 Handling network read event on socket 1116 with error 0
. 2015-12-16 17:07:23.060 Received 28 bytes (0)
. 2015-12-16 17:07:23.575 Session upkeep
. 2015-12-16 17:07:23.575 Looking for network events
. 2015-12-16 17:07:23.575 Timeout waiting for network events
. 2015-12-16 17:07:24.090 Session upkeep
. 2015-12-16 17:07:24.090 Looking for network events
. 2015-12-16 17:07:24.090 Timeout waiting for network events

WinSCP_Log_CannotCloseFileError_20151216.txt (1.37 MB)

Description: WinSCP log showing everything from launch of WinSCP to end of file upload

Reply with quote

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

2015-12-18

Sorry, I was wrong. The error comes in a response to closing the uploaded file. You have actually found that yourself, I didn't read your initial post carefully.

As I wrote already, these kind of problems typically occur, when there's some process running on the server that is moving the uploaded files away. Though this typically happens only with operations after closing the file (such as updating file timestamp/permissions, hence my first incorrect analysis).

If the file is moved away before the file is closed, it's simply a bug in the process. The process is possibly triggered by a time interval since file creation. So it happens, if you do not manage to finish uploading the file within the interval. That would explain why it is happening with large files only.

Reply with quote

richwink

2015-12-23 19:08

Hello @martin,
Thank you for your last reply. There is no process running on the server that is moving the file. After I acknowledge the error the file finishes uploading and it appears in the folder it was originally uploaded to. We are not having this issue with two other clients CoreFTP and FileZilla, but I would like to continue using WinSCP as we have a lot of time invested in it.

Reply with quote

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

2015-12-28

FileZilla ignores errors for SSH_FXP_CLOSE request. So it silently hides away any problems.

This is relevant FileZilla code. Note how the return value of fxp_got_status is not even read in fxp_close_recv.

static int fxp_got_status(struct sftp_packet *pktin)
{
    ...
 
    if (fxp_errtype == SSH_FX_OK)
   return 1;
    else if (fxp_errtype == SSH_FX_EOF)
   return 0;
    else
   return -1;
}
 
void fxp_close_recv(struct sftp_packet *pktin, struct sftp_request *req)
{
    sfree(req);
    fxp_got_status(pktin);
    sftp_pkt_free(pktin);
}

I do not know CoreFTP good enough.

Reply with quote

richwink
Joined:: 2015-12-08
Posts:: 5

2015-12-28 18:39

Hello @martin,
Regarding your last reply:

FileZilla ignores errors for SSH_FXP_CLOSE request. So it silently hides away any problems.

I wrote similar code in the wrapper I built for WinSCPnet.dll. The error generates an exception which is caught in the exception handler and then ignored. This works for our automated uploads as the file upload does complete even after the exception.

But there is no workaround, that I can see, for manual uploads using the WinSCP GUI, except to click "Abort" or "Skip" in the error window popup.

Is there a setting in the WinSCP configuration that can be set to bypass this error? If not, would it be a good idea to add one to a future release on WinSCP?

Thanks - Richard

Reply with quote

martin◆ Site Admin

2016-01-04

richwink wrote:

If not, would it be a good idea to add one to a future release on WinSCP?

I do not think so. It's clearly a bug in the server. So, it should be fixed on the server.

Reply with quote

zoupie Guest

Getting same error

2023-06-01 14:01

Getting same error. What can we do?

Reply with quote

martin◆ Site Admin

Re: Getting same error

2023-06-05

@zoupie: Sorry, your post does not include enough information.

Please read how to troubleshoot problems with WinSCP. If it turns out that you are not able to help yourself, read how to ask for support or report bugs efficiently, so others can help you.

Reply with quote

Error: "Cannot Close Remote File" uploading files larger then around 100K