File content is truncated after exceed 34kb

Hi Admin/team,

I recently faced an issue in which I was trying to transfer my file from 1 server to another. A file with 38779kb size successfully uploaded to the server from the client. But when I want to download the file from the server to another client, the size became 34kb (34000). The last few records were unable to retrieve.

I have attached the log and my transfer mode setting for your references.

Please attach a full session log file on Debug 2 level.

Hi Admin,

I am the owner of this question.

I just enabled the logging option just now. Do we have to wait until this issue happens again only we can capture the related session log? This truncation issue is happening intermittently. I am not sure when will this issue happen again.

We need the log file for the session, when the problem happens.

I see. We are actually using a batch file to run WinSCP and i noticed it will not be logged. It is not possible for us to stay there all the time to check when was the issue happened. Has your team heard of this issue before? We are only transferring text files only.

Why it won't be logged? I do not remember such issue.

Hi admin, I am running the WinSCP by batch job using a windows service account. When I use my user account to login and launch WinSCP manually, I can see the logging. But when I use a batch job to open and login WinSCP. It is not logged.

Hi Admin, I manage to get the session log when the issue happened. Please find the attached file for the session log. The truncation part is at row 200 which the file originally has 148817kb then became 34000kb.

Please advise.

Hi team,

Is there any update on the investigation? Appreciate it if you could respond as soon as possible as this is affecting our production system..

I believe that WinSCP did not truncate anything. It was reading the remote file until the server announced the end of the file:

< 2020-10-27 04:00:03.910 Status code: 1

A log file Debug level 2 can reveal more information. But I'm quite sure it's a server-side problem.

You can try to mitigate the problem by either reducing the download speed using the -speed switch of the get command. See https://winscp.net/eng/docs/scriptcommand_get#speed
Or it might help to reduce the download request queue using -rawsettings SFTPDownloadQueue=1 in the open command.
But either will be unreliable at best.

If you want us to investigate further, please post the Debug 2 log file. But you better contact your server administrator or vendor.

Hi team,

I have obtained the debug 2 logs during the truncation happened. Please refer to line 1676 to 3513. The files originally were 43448kb and became 34000kb. Please assist.

Imo, the server is clearly buggy. My guess is that once it reaches the end of the file, it fails all other read requests, even if those refer to existing portions of the file.

Summary of the log:
A> WinSCP requests 34987 bytes starting as the beginning of the file B> WinSCP requests another 34987 bytes starting as the offset 34987
A< The server returns only 34000 bytes as a response to the (first) request A
C> WinSCP requests another 34987 bytes starting as the offset 69974
D> WinSCP requests missing 987 bytes starting as the offset 34000
B< The server returns 8461 bytes as a response to the second request B
C< The server indicates that end of the file was reached as a response to C
D< The server indicates that end of the file was reached as a response to D

There's definitely some issue going on. Based on your information, it seems like the server doesn't wait for all the files to finish. Once the first file finished, it will close the connection and thus result in truncation for the subsequent file. It might take a lot of time to investigate what's going on in the server. Would like to ask, is there any short term way I can do or configure in WinSCP to eliminate this issue?

Will it be possible that this issue is due to files transferring concurrently? So if I change the setting E.g. Next file will only start the transferring process after the previous file finished the transfer process. Will it help? Is there any way to configure this?

garyvoo wrote:

Would like to ask, is there any short term way I can do or configure in WinSCP to eliminate this issue?

I've posted some suggestions above already.

Hi Admin,

Thanks for the explanation. Can we check with you whether are you looking at Logs.log (341.41 KB)?

#1
Do you mind explaining in details what happens in between 1676 to 3513? As we are unable to determine whether is there a fail at all other read requests upon reaching end of file. From the logs itself, it seems like it is reading the file one at a time instead of concurrently.


#2

Summary of the log:
A> WinSCP requests 34987 bytes starting as the beginning of the file B> WinSCP requests another 34987 bytes starting as the offset 34987
A< The server returns only 34000 bytes as a response to the (first) request A
C> WinSCP requests another 34987 bytes starting as the offset 69974
D> WinSCP requests missing 987 bytes starting as the offset 34000
B< The server returns 8461 bytes as a response to the second request B
C< The server indicates that end of the file was reached as a response to C
D< The server indicates that end of the file was reached as a response to D

Can we understand the above explanation is based from which line to which line?

Thanks in advance.

Thanks for the explanation. Can we check with you whether are you looking at Logs.log (341.41 KB)?

Yes.

Do you mind explaining in details what happens in between 1676 to 3513? As we are unable to determine whether is there a fail at all other read requests upon reaching end of file.

I do not understand what you ask for.

From the logs itself, it seems like it is reading the file one at a time instead of concurrently.

Yes. WinSCP scripting does not support concurrent transfers.

Can we understand the above explanation is based from which line to which line?

It refers to the transfer of the file that gets truncated from 43448 to 34000 – Audit_**Server**101P_20201125_060002.log. Lines 1675–3513

Hi Martin, I managed to eliminate the file truncation issue by reducing the download speed from unlimited to 64kbps. But I cannot find any reason or proper explanation of why reducing the speed will fix the issue.

Could you advise?

The faster the connection (transfer speed) is, the larger chunks of the file WinsCP asks for in each read request. Your server seem to return at most 34000 bytes at once. When WinSCP asked for more, it will have to then ask for the missing bytes. But as it asked for further bytes meanwhile, tt has to ask for those missing bytes out of the order. When WinSCP does that, you servers starts behaving incorrectly. If you slow the speed enough so that WinsCP never asks for more than 34000 bytes at once, the problem is mitigated.