Transfer in GUI but not with Script

Below is the log output when transferring files through GUI:
. 2017-12-28 21:27:07.778 Copying 2 files/directories to remote directory "/" - total size: 527,708
. 2017-12-28 21:27:07.778 PrTime: Yes; PrRO: No; Rght: rwxrwxrwx; PrR: Yes (Yes); FnCs: N; RIC: 0100; Resume: N (102400); CalcS: Yes; Mask: *.*
. 2017-12-28 21:27:07.778 TM: B; ClAr: No; RemEOF: No; RemBOM: No; CPS: 0; NewerOnly: No; InclM: *; ResumeL: 0
. 2017-12-28 21:27:07.778 AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; *.js; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2017-12-28 21:27:07.809 File: 'Z:\VIP2\S99997572.SLS' [2017-12-28T15:59:54.000Z] [52876]
. 2017-12-28 21:27:07.809 Copying "Z:\VIP2\S99997572.SLS" to remote directory started.
. 2017-12-28 21:27:07.809 Binary transfer mode selected.
. 2017-12-28 21:27:07.809 Opening remote file.
> 2017-12-28 21:27:07.809 Type: SSH_FXP_OPEN, Size: 36, Number: 49923
< 2017-12-28 21:27:07.809 Type: SSH_FXP_STATUS, Size: 31, Number: 49420
. 2017-12-28 21:27:07.809 Discarding reserved response
< 2017-12-28 21:27:07.809 Type: SSH_FXP_STATUS, Size: 27, Number: 49668
. 2017-12-28 21:27:07.809 Discarding reserved response
< 2017-12-28 21:27:07.887 Type: SSH_FXP_HANDLE, Size: 17, Number: 49923
> 2017-12-28 21:27:07.934 Type: SSH_FXP_WRITE, Size: 32764, Number: 50438
. 2017-12-28 21:27:07.981 1 skipped SSH_FXP_WRITE, SSH_FXP_READ, SSH_FXP_DATA and SSH_FXP_STATUS packets.
> 2017-12-28 21:27:07.981 Type: SSH_FXP_CLOSE, Size: 17, Number: 50948
> 2017-12-28 21:27:07.981 Type: SSH_FXP_SETSTAT, Size: 40, Number: 50185
< 2017-12-28 21:27:08.184 Type: SSH_FXP_STATUS, Size: 27, Number: 50438
< 2017-12-28 21:27:08.184 Status code: 0
< 2017-12-28 21:27:08.496 Type: SSH_FXP_STATUS, Size: 27, Number: 50694
< 2017-12-28 21:27:08.496 Status code: 0
< 2017-12-28 21:27:08.496 Type: SSH_FXP_STATUS, Size: 27, Number: 50948
< 2017-12-28 21:27:08.496 Status code: 0
. 2017-12-28 21:27:08.496 Preserving timestamp [2017-12-28T15:59:54.000Z]
< 2017-12-28 21:27:08.496 Type: SSH_FXP_STATUS, Size: 27, Number: 50185
< 2017-12-28 21:27:08.496 Status code: 0

Below is the output when running through a script w/ Task Scheduler:
. 2017-12-28 21:19:35.887 Searching directory "/" (real path "/")
. 2017-12-28 21:19:35.887 Listing directory "/".
> 2017-12-28 21:19:35.887 Type: SSH_FXP_OPENDIR, Size: 10, Number: 47115
< 2017-12-28 21:19:35.887 Type: SSH_FXP_STATUS, Size: 31, Number: 46604
. 2017-12-28 21:19:35.887 Discarding reserved response
< 2017-12-28 21:19:35.887 Type: SSH_FXP_STATUS, Size: 27, Number: 46852
. 2017-12-28 21:19:35.887 Discarding reserved response
< 2017-12-28 21:19:35.965 Type: SSH_FXP_HANDLE, Size: 13, Number: 47115
> 2017-12-28 21:19:35.965 Type: SSH_FXP_READDIR, Size: 13, Number: 47372
< 2017-12-28 21:19:36.074 Type: SSH_FXP_NAME, Size: 30731, Number: 47372
> 2017-12-28 21:19:36.074 Type: SSH_FXP_READDIR, Size: 13, Number: 47628
< 2017-12-28 21:19:36.184 Type: SSH_FXP_NAME, Size: 30786, Number: 47628
> 2017-12-28 21:19:36.184 Type: SSH_FXP_READDIR, Size: 13, Number: 47884
< 2017-12-28 21:19:36.277 Type: SSH_FXP_NAME, Size: 29790, Number: 47884
> 2017-12-28 21:19:36.277 Type: SSH_FXP_READDIR, Size: 13, Number: 48140
> 2017-12-28 21:19:36.277 Type: SSH_FXP_CLOSE, Size: 13, Number: 48388

I have the below setup for the text file:
open sftp://username:password@ftpsite/ -hostkey="ssh-dss 1024 "key from WinSCP when you copy the script" -rawsettings Proxyport=0
lcd
cd
put -permissions=0777 -filemask="*" -resumesupport=off *
exit

This runs through Task Scheduler with the below arguement:
/ini=nul /script=FTPScript.txt

Thoughts?

Thanks.

Please attach complete log files.

Attached is the log requested. I replaced some sensitive info such as Username-FTP Site-IP Address with generic info. Thanks for taking the time to look into this.

I need a full log file on the script with the get command.
The section "Shown below is the output when script is run:" does not show a script log file. It's GUI log file of "Find Files" command.

I used a "put" command to transfer all files in the designated folder. The log does not even show a attempt when I run the script. It just lists the files and shows what I posted above and then lists the files again. The commands I use are at the bottom of my original post, none of them seem to be triggered. Could it be because I have the WinSCP program open; it conflicts? Or a Transfer setting needs to be adjusted?

Thanks.

Did you add /log switch to WinSCP command-line in Task Scheduler?
https://winscp.net/eng/docs/commandline#logging

No, I have the logging set through the Preferences (Normal). Would the logging output be the same with the command line /log as opposed to the Preference-->Logging option?

If I did add it through the argument on Task Scheduler; how would I amend it onto this?

/ini=nul /script=FTPScript.txt

Thanks.

I have been experiencing the exact same problem recently. We use WinSCP on numerous sites/servers to script file transfers and have never had a problem. After installing the latest version (5.11.3) our scripts that always worked, with the same destination server, started giving us this behavior. We were able to get them to work in the GUI by disabling the resume/multipart options of the settings but were not able to disable it with the script. However, the exact same script worked with no problems when using 5.11.1. Unfortunately, we were forced to downgrade to that version in order to see results.

I know this may not be the soltion you're looking for but it's worked for us after troubleshooting both versions endlessly in many different scenarios and seeing the same, consistent, results.

Thank you for the suggestion of downgrading from 5.11.3 to 5.11.1. It did not solve the problem but felt brought me closer to a solution based on the below output from the logs:

Below is the output when running through a script w/ Task Scheduler (Running on WinSCP version 5.11.3)
. 2017-12-28 21:19:35.887 Searching directory "/" (real path "/")
. 2017-12-28 21:19:35.887 Listing directory "/".
> 2017-12-28 21:19:35.887 Type: SSH_FXP_OPENDIR, Size: 10, Number: 47115
< 2017-12-28 21:19:35.887 Type: SSH_FXP_STATUS, Size: 31, Number: 46604
. 2017-12-28 21:19:35.887 Discarding reserved response
< 2017-12-28 21:19:35.887 Type: SSH_FXP_STATUS, Size: 27, Number: 46852
. 2017-12-28 21:19:35.887 Discarding reserved response
< 2017-12-28 21:19:35.965 Type: SSH_FXP_HANDLE, Size: 13, Number: 47115
> 2017-12-28 21:19:35.965 Type: SSH_FXP_READDIR, Size: 13, Number: 47372
< 2017-12-28 21:19:36.074 Type: SSH_FXP_NAME, Size: 30731, Number: 47372
> 2017-12-28 21:19:36.074 Type: SSH_FXP_READDIR, Size: 13, Number: 47628
< 2017-12-28 21:19:36.184 Type: SSH_FXP_NAME, Size: 30786, Number: 47628
> 2017-12-28 21:19:36.184 Type: SSH_FXP_READDIR, Size: 13, Number: 47884
< 2017-12-28 21:19:36.277 Type: SSH_FXP_NAME, Size: 29790, Number: 47884
> 2017-12-28 21:19:36.277 Type: SSH_FXP_READDIR, Size: 13, Number: 48140
> 2017-12-28 21:19:36.277 Type: SSH_FXP_CLOSE, Size: 13, Number: 48388

Below is the output when running through a script w/ Task Scheduler (Running on WinSCP version 5.11.1)
. 2018-01-10 17:38:03.979 Server unexpectedly closed network connection
* 2018-01-10 17:38:03.979 (ESshFatal) Server unexpectedly closed network connection.
. 2018-01-10 17:38:13.230 Looking up host "sftp site" for SSH connection
. 2018-01-10 17:38:13.370 Connecting to "IP Address" port 22
. 2018-01-10 17:38:13.433 We claim version: SSH-2.0-WinSCP_release_5.11.1
. 2018-01-10 17:38:13.511 Server version: SSH-2.0-2.0
. 2018-01-10 17:38:13.511 Using SSH protocol version 2
. 2018-01-10 17:38:13.511 Have a known host key of type dss
. 2018-01-10 17:38:13.620 Using Diffie-Hellman with standard group "group14"
. 2018-01-10 17:38:13.620 Doing Diffie-Hellman key exchange with hash SHA-1
. 2018-01-10 17:38:14.821 Host key fingerprint is:
. 2018-01-10 17:38:14.821 ssh-dss 1024 ff:ae:49:25:8e:cc:d1:3b:55:32:6e:a6:80:8c:c2:b9
. 2018-01-10 17:38:14.821 Verifying host key dss "key would be here"
. 2018-01-10 17:38:14.883 Host key matches cached key
. 2018-01-10 17:38:14.883 Initialised AES-256 SDCTR client->server encryption
. 2018-01-10 17:38:14.883 Initialised HMAC-SHA-256 client->server MAC algorithm
. 2018-01-10 17:38:14.883 Initialised AES-256 SDCTR server->client encryption
. 2018-01-10 17:38:14.883 Initialised HMAC-SHA-256 server->client MAC algorithm
! 2018-01-10 17:38:15.086 Using username "username".
. 2018-01-10 17:38:16.131 Server offered these authentication methods: password
. 2018-01-10 17:38:16.131 Prompt (password, "SSH password", <no instructions>, "&Password: ")
. 2018-01-10 17:38:16.131 Using stored password.
. 2018-01-10 17:38:16.194 Sent password
. 2018-01-10 17:38:16.319 Access granted
. 2018-01-10 17:38:16.319 Opening session as main channel
. 2018-01-10 17:38:16.397 Opened main channel
. 2018-01-10 17:38:16.584 Started a shell/command
. 2018-01-10 17:38:16.662 Doing startup conversation with host.
> 2018-01-10 17:38:16.677 Type: SSH_FXP_INIT, Size: 5, Number: -1
< 2018-01-10 17:38:16.771 Type: SSH_FXP_VERSION, Size: 72, Number: -1
. 2018-01-10 17:38:16.771 SFTP version 6 negotiated.
. 2018-01-10 17:38:16.771 Server requests EOL sequence "\r\n".
. 2018-01-10 17:38:16.771 Server support information (supported2):
. 2018-01-10 17:38:16.771 Attribute mask: 33D, Attribute bits: 17, Open flags: 7
. 2018-01-10 17:38:16.771 Access mask: 3, Open block vector: 0, Block vector: 0, Max read size: 1048576
. 2018-01-10 17:38:16.771 Attribute extensions (0)
. 2018-01-10 17:38:16.771 Extensions (0)
. 2018-01-10 17:38:16.771 We will use UTF-8 strings as it is mandatory with SFTP version 4 and newer
. 2018-01-10 17:38:16.771 Changing directory to "/".
. 2018-01-10 17:38:16.771 Getting real path for '/'
> 2018-01-10 17:38:16.771 Type: SSH_FXP_REALPATH, Size: 11, Number: 45584
< 2018-01-10 17:38:16.849 Type: SSH_FXP_NAME, Size: 92, Number: 45584
. 2018-01-10 17:38:16.849 Real path is '/'
. 2018-01-10 17:38:16.849 Trying to open directory "/".
> 2018-01-10 17:38:16.849 Type: SSH_FXP_LSTAT, Size: 14, Number: 45831
< 2018-01-10 17:38:16.943 Type: SSH_FXP_ATTRS, Size: 55, Number: 45831
. 2018-01-10 17:38:16.943 Getting current directory name.
. 2018-01-10 17:38:17.130 Directory content loaded from cache.
. 2018-01-10 17:38:17.145 Cached directory not reloaded.
. 2018-01-10 17:38:17.145 Listing directory "/".
> 2018-01-10 17:38:17.145 Type: SSH_FXP_OPENDIR, Size: 10, Number: 46091
< 2018-01-10 17:38:17.223 Type: SSH_FXP_HANDLE, Size: 13, Number: 46091
> 2018-01-10 17:38:17.223 Type: SSH_FXP_READDIR, Size: 13, Number: 46348
< 2018-01-10 17:38:17.504 Type: SSH_FXP_NAME, Size: 14646, Number: 46348
> 2018-01-10 17:38:17.504 Type: SSH_FXP_READDIR, Size: 13, Number: 46604
> 2018-01-10 17:38:17.551 Type: SSH_FXP_CLOSE, Size: 13, Number: 46852
. 2018-01-10 17:38:17.551 10 Users.csv;-;816;2017-06-23T17:30:17.000Z;3;"user" [0];"group" [0];rw-rw-rw-;1
. 2018-01-10 17:38:17.551 20170314diageo_north_america_balance_report.csv;-;82481;2017-03-16T14:15:56.000Z;3;"user" [0];"group" [0];rw-rw-rw-;1
. 2018-01-10 17:38:17.551 7B296FB0-376B-497e-B012-9C450E1B7327-5P-0.C7483456-A289-439d-8115-601632D005A0;-;21504;2017-05-19T15:38:34.000Z;3;"user" [0];"group" [0];rw-rw-rw-;1
. 2018-01-10 17:38:17.551 7B296FB0-376B-497e-B012-9C450E1B7327-5P-1.C7483456-A289-439d-8115-601632D005A0;-;21504;2017-05-19T15:38:35.000Z;3;"user" [0];"group" [0];rw-rw-rw-;1


Thoughts?

Thanks.

I apologize for the suggestion. It turns out that did not ultimately fix my problem either. I have tried every variation of ResumeSupport=off and ResumeSupport=2 as well as the -resumesupport flag in the put command. Nothing is working at all, but only from within my script. I am able to transfer the file using the GUI once I disable the resume support. This has been taking up the majority of 2 days and I have made very little progress. I desperately need to find a solution to this problem. I've looked at he logs from my SFTP server and it shows the connection is being terminated by the software. Everything points to this being a problem with WinSCP but I am having trouble finding a solution that works.

Can anyone else help us out?

I would also like to add that I am positive this issue is related to the resume setting. When I use my script to transfer any files under 100 KB then it works just fine. It's only when I upload files over 100 KB that it doesn't finish the transfer and just hangs.
As stated, disabling the feature in the GUI has worked and allows me to upload the file. But when doing it via script, nothing works. I have tried using -resumesupport=off in the put command as well as putting -resumesupport=999999 or any other value of the file size I am trying to send it has the same unsuccessful results. I've also tried using /rawconfig ResumeSupport=off and ResumeSupport=2 when launching WinSCP.com, prior to calling my script. None of that works, either.
When the script runs, prior to the upload, it says "Using configured transfer settings different from factory defaults." which leads me to believe it detects the parameters I'm using, it just doesn't. Unless I am going about it the wrong way but between the documentation and other forums posts, that's what I found.

cfanta12 wrote:

No, I have the logging set through the Preferences (Normal). Would the logging output be the same with the command line /log as opposed to the Preference-->Logging option?

No, as the /ini=nul switch isolates the script from the global configuration.

If I did add it through the argument on Task Scheduler; how would I amend it onto this?

/ini=nul /script=FTPScript.txt

/ini=nul /script=FTPScript.txt /log=c:\path\to\winscp.log

Please post a complete log file!

Thank you for the response; I amended the /log onto the Task Scheduler argument. I will send the log after I have a chance to run the Task. Attached I have the a word doc showing the current Preference settings. Also shown below is the FTP commands I have:

I have the below setup for the text file:
open sftp://username:password@ftpsite/ -hostkey="ssh-dss 1024 "key from WinSCP when you copy the script" -rawsettings Proxyport=0
lcd
cd
put -permissions=0777 -filemask="*" -resumesupport=off *
exit

If the /ini=nul isolates the script from the GUI Preferences; what other method can I use and how to run the program automated?

Thanks.

I added the /log to the argument but it did not create a log. Could you tell me what I am doing wrong?

I disabled Logging under Preferences (also removed the prior log files from the folder to another location) and then amended the argument a few ways as shown below:

Program/script:
"C:\Program Files (x86)\WinSCP\WinSCP.exe"

Add arguments:
/ini=nul /script=FTPScript.txt /log="C:\Program Files (x86)\WinSCP\winscp.log"
/ini=nul /script=FTPScript.txt /log="C:\Program Files (x86)\WinSCP\winscp.log" /loglevel=0
/ini=nul /script=FTPScript.txt /log=C:\Program Files (x86)\WinSCP\winscp.log
/ini=nul /script=FTPScript.txt /log=C:\Program Files (x86)\WinSCP\winscp.log /loglevel=0

Start in:
C:\Program Files (x86)\WinSCP\

Thanks.

cfanta12 wrote:

Program/script:
"C:\Program Files (x86)\WinSCP\WinSCP.exe"

Add arguments:
/ini=nul /script=FTPScript.txt /log="C:\Program Files (x86)\WinSCP\winscp.log"
/ini=nul /script=FTPScript.txt /log="C:\Program Files (x86)\WinSCP\winscp.log" /loglevel=0
/ini=nul /script=FTPScript.txt /log=C:\Program Files (x86)\WinSCP\winscp.log
/ini=nul /script=FTPScript.txt /log=C:\Program Files (x86)\WinSCP\winscp.log /loglevel=0

Start in:
C:\Program Files (x86)\WinSCP\

The local account that runs the task most likely does not have write permissions to the C:\Program Files (x86) folder. Pick another folder, where you know to have write permissions. And try to run the command manually first, it will show you error messages if there's any problem.

I uninstalled WinSCP and reinstalled it under a folder with full permissions under the C drive as shown by the below path:
C:\WinSCP\WinSCP\

I ran the below command from CMD PRMPT while under the above path where the WinSCP.exe file is:
ini=nul /script=FTPVIP.txt /log="C:\WinSCP\WinSCP\winscp.log" /loglevel=0

I had the below output:
"ini" is not recognized as an internal or external command, operable program or batch file.

During the uninstall could files under the Registry have been effected now allowing the commands to function?

Thanks.

cfanta12 wrote:

I ran the below command from CMD PRMPT while under the above path where the WinSCP.exe file is:
ini=nul /script=FTPVIP.txt /log="C:\WinSCP\WinSCP\winscp.log" /loglevel=0

You have to specify that you are running WinSCP (the same way you do in Windows Scheduler).
Plus for testing, you better use winscp.com:
"C:\Program Files (x86)\WinSCP\WinSCP.com" /ini=nul /script=FTPVIP.txt /log="C:\WinSCP\WinSCP\winscp.log" /loglevel=0

(Note that I did not ask you to reinstall WinSCP, I've just asked you to point /log to another folder, but OK)

I reinstalled it under C:\ to see if the permissions were also interfering with running the program. I ran the suggested command through command line and it worked. Then ran it through Task Scheduler which also worked. The changes I needed to make were to change the directory the program was installed in and use WinSCP.com as opposed to WinSCP.exe. Thank you for your help in resolving this matter.