Topic "Timeout error when running winscp by script as part of SSIS package"

Author Message
Ghenk

Guest


I was previously using an older version of WinSCP but upgraded to version 5.9.4 during the troubleshooting process today. However, it didn't resolve my issue and the logging I'm seeing is pretty confusing since it just stops without any timeout error or information. Visual studio provides this informative error:

SSIS package ... starting.
Error: 0xC002914C at Upload via Winscp, Execute Process Task: The process timed out.
Task failed: Upload via Winscp
SSIS package ... finished: Success.
The program '[772] DtsDebugHost.exe: DTS' has exited with code 0 (0x0).

A bit about my setup: Currently I'm triggering the individual winscp step from the visual studio window, but it also fails when run as a scheduled job on SQL server at the same step. I've stripped out some identifying information, but otherwise this accurately represents my setup.

- I'm running winscp from a centrally hosted fileshare (\\SSS-DD3\reports\WinSCP\WinSCP.exe)
- Script argument: -script="\\SSS-DD3\Reports\SQL\FTPscriptwParameters.txt" -parameter "\\SSS-DD3\reports\Accounts\Name\" "/FOLDERS/HOME/Reports/Name/" -log="\\SSS-DD3\reports\Accounts\Name\log.txt"

Log posted below from 3 separate attempts triggered as a scripted step in the SSIS package. (identifying info removed). In each case, the logging just seems to truncate and I can't figure out what's going on.

. 2017-04-18 08:51:09.384 --------------------------------------------------------------------------
. 2017-04-18 08:51:09.477 WinSCP Version 5.9.4 (Build 7333) (OS 6.3.9600 - Windows Server 2012 R2 Datacenter)
. 2017-04-18 08:51:09.649 Configuration: \\SSS-DD3\reports\WinSCP\WinSCP.ini
. 2017-04-18 08:51:09.649 Log level: Normal
. 2017-04-18 08:51:09.665 Local account: HPL\p-serveruser
. 2017-04-18 08:51:09.665 Working directory: C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE
. 2017-04-18 08:51:09.665 Process ID: 1124
. 2017-04-18 08:51:09.665 Command-line: "\\SSS-DD3\reports\WinSCP\WinSCP.exe" -script="\\SSS-DD3\Reports\SQL\FTPscriptwParameters.txt" -parameter "\\SSS-DD3\reports\Accounts\Name\" "/FOLDERS/HOME/Company/Reports/Name/" -log="\\SSS-DD3\reports\Accounts\Name\log.txt"
. 2017-04-18 08:51:09.665 Time zone: Current: GMT-5, Standard: GMT-6 (Central Standard Time), DST: GMT-5 (Central Daylight Time), DST Start: 3/12/2017, DST End: 11/5/2017
. 2017-04-18 08:51:09.665 Login time: Tuesday, April 18, 2017 8:51:09 AM
. 2017-04-18 08:51:09.665 --------------------------------------------------------------------------
. 2017-04-18 08:51:09.665 Script: Retrospectively logging previous script records:
> 2017-04-18 08:51:09.681 Script: option batch continue
< 2017-04-18 08:51:09.681 Script: batch continue
< 2017-04-18 08:51:09.681 Script: reconnecttime 120
> 2017-04-18 08:51:09.681 Script: option confirm off
< 2017-04-18 08:51:09.681 Script: confirm off
> 2017-04-18 08:51:09.681 Script: open sftp://company.serverinc.net\username:***@SJC-FTP.serverinc.net -passive -hostkey="ssh-rsa 2048 2e:4b:b7:ab:ee:6d:ea:c5:60:e8:a5:4e:50:23:09:70"
. 2017-04-18 08:51:09.681 --------------------------------------------------------------------------
. 2017-04-18 08:51:09.681 Session name: company.serverinc.net\username@SJC-FTP.serverinc.net (Ad-Hoc site)
. 2017-04-18 08:51:09.681 Host name: SJC-FTP.serverinc.net (Port: 22)
. 2017-04-18 08:51:09.681 User name: company.serverinc.net\username (Password: Yes, Key file: No, Passphrase: No)
. 2017-04-18 08:51:09.681 Tunnel: No
. 2017-04-18 08:51:09.681 Transfer Protocol: SFTP
. 2017-04-18 08:51:09.696 Ping type: Off, Ping interval: 30 sec; Timeout: 15 sec
. 2017-04-18 08:51:09.696 Disable Nagle: No
. 2017-04-18 08:51:09.696 Proxy: None
. 2017-04-18 08:51:09.696 Send buffer: 262144
. 2017-04-18 08:51:09.696 SSH protocol version: 2; Compression: No
. 2017-04-18 08:51:09.696 Bypass authentication: No
. 2017-04-18 08:51:09.696 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2017-04-18 08:51:09.696 Ciphers: aes,chacha20,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2017-04-18 08:51:09.712 KEX: ecdh,dh-gex-sha1,dh-group14-sha1,rsa,WARN,dh-group1-sha1
. 2017-04-18 08:51:09.712 SSH Bugs: Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto
. 2017-04-18 08:51:09.712 Simple channel: Yes
. 2017-04-18 08:51:09.712 Return code variable: Autodetect; Lookup user groups: Auto
. 2017-04-18 08:51:09.712 Shell: default
. 2017-04-18 08:51:09.712 EOL: LF, UTF: Auto
. 2017-04-18 08:51:09.712 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes; Follow directory symlinks: No
. 2017-04-18 08:51:09.727 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2017-04-18 08:51:09.727 SFTP Bugs: Auto,Auto
. 2017-04-18 08:51:09.727 SFTP Server: default
. 2017-04-18 08:51:09.727 Local directory: default, Remote directory: home, Update: Yes, Cache: Yes
. 2017-04-18 08:51:09.727 Cache directory changes: Yes, Permanent: Yes
. 2017-04-18 08:51:09.727 Recycle bin: Delete to: No, Overwritten to: No, Bin path:
. 2017-04-18 08:51:09.727 DST mode: Unix
. 2017-04-18 08:51:09.727 --------------------------------------------------------------------------
. 2017-04-18 08:51:09.727 Looking up host "SJC-FTP.serverinc.net" for SSH connection
. 2017-04-18 08:51:09.743 Connecting to 50.56.9.35 port 22
. 2017-04-18 08:51:09.790 We claim version: SSH-2.0-WinSCP_release_5.9.4
. 2017-04-18 08:51:09.837 Server version: SSH-2.0-server SFTP Service 2.5.0
. 2017-04-18 08:51:09.837 We believe remote version has SSH-2 channel request bug
. 2017-04-18 08:51:09.837 Using SSH protocol version 2
. 2017-04-18 08:51:14.352 Have a known host key of type rsa2
. 2017-04-18 08:51:16.353 Doing Diffie-Hellman group exchange
. 2017-04-18 08:51:17.259 Doing Diffie-Hellman key exchange with hash SHA-256
. 2017-04-18 08:51:19.743 Host key fingerprint is:
. 2017-04-18 08:51:21.884 ssh-rsa 2048 2e:4b:b7:ab:ee:6d:ea:c5:60:e8:a5:4e:50:23:09:70
. 2017-04-18 08:51:22.915 Verifying host key rsa2 0x10001,0xcec8a3458cd5c815 353245f571c11c53 bf7a7c4b186b020d 226c46634e22576c accb81166a77327a deea177922c9e873 f851a7d91c834f97 b1b2bd413d4dd78f f9231179aa027c8a 275c59804c23de4f 469900d6fa948e79 06f7416b50a96b91 3055e5589062a823 9c499dc13366597a eefa115acaa2fe13 fb86393294dece2d 823b4f95ee16e048 de5c74f3f2d25024 ff755d4468d3c423 f99292125c4a675c a2918f9794e7a371 3efbebe20d3656c9 8641e3e312ee45f2 fc1da66eaef17932 ee40d9913de41f66 c14c6a716b224c5e 3bddea1e237ce8bb 119288c8a10c1ef1 c7490891e90dd78e a8fcb5ce0567464e 692d7e5ee2cecb15 07b2fb58cd7eb2e5 with fingerprint ssh-rsa 2048 2e:4b:b7:ab:ee:6d:ea:c5:60:e8:a5:4e:50:23:09:70
. 2017-04-18 08:51:26.533 Host key matches configured key
. 2017-04-18 08:51:30.773 Initialised AES-256 SDCTR client->server encryption
. 2017-04-18 08:51:30.913 Initialised HMAC-SHA-256 client->server MAC algorithm
. 2017-04-18 08:51:31.087 Initialised AES-256 SDCTR server->client encryption
. 2017-04-18 08:51:31.287 Initialised HMAC-SHA-256 server->client MAC algorithm
! 2017-04-18 08:51:32.155 Using username "company.serverinc.net\username".
. 2017-04-18 08:51:33.075 Server offered these authentication methods: password,publickey
. 2017-04-18 09:24:05.524 --------------------------------------------------------------------------
. 2017-04-18 09:24:05.696 WinSCP Version 5.9.4 (Build 7333) (OS 6.3.9600 - Windows Server 2012 R2 Datacenter)
. 2017-04-18 09:24:11.649 Configuration: \\SSS-DD3\reports\WinSCP\WinSCP.ini
. 2017-04-18 09:24:11.978 Log level: Normal
. 2017-04-18 09:24:12.259 Local account: HPL\p-serveruser
. 2017-04-18 09:24:12.415 Working directory: C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE
. 2017-04-18 09:24:12.524 Process ID: 1772
. 2017-04-18 09:24:12.681 Command-line: "\\SSS-DD3\reports\WinSCP\WinSCP.exe" -script="\\SSS-DD3\Reports\SQL\FTPscriptwParameters.txt" -parameter "\\SSS-DD3\reports\Accounts\Name\" "/FOLDERS/HOME/Company/Reports/Name/" -log="\\SSS-DD3\reports\Accounts\Name\log.txt"
. 2017-04-18 09:24:12.915 Time zone: Current: GMT-5, Standard: GMT-6 (Central Standard Time), DST: GMT-5 (Central Daylight Time), DST Start: 3/12/2017, DST End: 11/5/2017
. 2017-04-18 09:24:12.946 Login time: Tuesday, April 18, 2017 9:24:12 AM
. 2017-04-18 09:24:12.946 --------------------------------------------------------------------------
. 2017-04-18 09:24:12.962 Script: Retrospectively logging previous script records:
> 2017-04-18 09:24:12.978 Script: option batch continue
< 2017-04-18 09:24:12.978 Script: batch continue
< 2017-04-18 09:24:12.978 Script: reconnecttime 120
> 2017-04-18 09:24:12.978 Script: option confirm off
< 2017-04-18 09:24:12.978 Script: confirm off
> 2017-04-18 09:24:12.993 Script: open sftp://company.servername.net\username:***@SJC-FTP.servername.net -passive -hostkey="ssh-rsa 2048 2e:4b:b7:ab:ee:6d:ea:c5:60:e8:a5:4e:50:23:09:70"
. 2017-04-18 09:24:12.993 --------------------------------------------------------------------------
. 2017-04-18 09:24:12.993 Session name: company.servername.net\username@SJC-FTP.servername.net (Ad-Hoc site)
. 2017-04-18 09:24:12.993 Host name: SJC-FTP.servername.net (Port: 22)
. 2017-04-18 09:24:13.009 User name: company.servername.net\username (Password: Yes, Key file: No, Passphrase: No)
. 2017-04-18 09:24:13.024 Tunnel: No
. 2017-04-18 09:24:13.274 Transfer Protocol: SFTP
. 2017-04-18 09:24:13.915 Ping type: Off, Ping interval: 30 sec; Timeout: 15 sec
. 2017-04-18 09:24:14.556 Disable Nagle: No
. 2017-04-18 09:24:15.868 Proxy: None
. 2017-04-18 09:24:16.618 Send buffer: 262144
. 2017-04-18 09:24:17.337 SSH protocol version: 2; Compression: No
. 2017-04-18 09:24:17.743 Bypass authentication: No
. 2017-04-18 09:24:18.290 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2017-04-18 09:24:19.337 Ciphers: aes,chacha20,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2017-04-18 09:24:19.837 KEX: ecdh,dh-gex-sha1,dh-group14-sha1,rsa,WARN,dh-group1-sha1
. 2017-04-18 09:24:20.290 SSH Bugs: Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto
. 2017-04-18 09:24:21.353 Simple channel: Yes
. 2017-04-18 09:24:23.665 Return code variable: Autodetect; Lookup user groups: Auto
. 2017-04-18 09:24:24.978 Shell: default
. 2017-04-18 09:24:26.681 EOL: LF, UTF: Auto
. 2017-04-18 09:24:26.978 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes; Follow directory symlinks: No
. 2017-04-18 09:24:27.743 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2017-04-18 09:24:27.993 SFTP Bugs: Auto,Auto
. 2017-04-18 09:24:28.353 SFTP Server: default
. 2017-04-18 09:24:28.587 Local directory: default, Remote directory: home, Update: Yes, Cache: Yes
. 2017-04-18 09:24:29.431 Cache directory changes: Yes, Permanent: Yes
. 2017-04-18 09:24:29.915 Recycle bin: Delete to: No, Overwritten to: No, Bin path:
. 2017-04-18 09:24:30.165 DST mode: Unix
. 2017-04-18 09:24:30.353 --------------------------------------------------------------------------
. 2017-04-18 09:39:52.723 --------------------------------------------------------------------------
. 2017-04-18 09:39:53.567 WinSCP Version 5.9.4 (Build 7333) (OS 6.3.9600 - Windows Server 2012 R2 Datacenter)
Advertisements
Ghenk

Guest


When opening winscp on the same server to perform the uploads manually, it takes 1-2 minutes to open. I have tested whether this might be an issue with the network connecting the fileshare to the server, but that connection is extremely fast, typically taking <1 second to transfer 10 mb files. I'm also investigating the possibility that there are some performance issues with our server.
Ghenk

Guest


This is from today where the first instance failed, and the second attempt worked. Is there a possibility that there's an issue with the host FTP server?

. 2017-04-19 06:26:25.725 --------------------------------------------------------------------------
. 2017-04-19 06:26:25.951 WinSCP Version 5.9.4 (Build 7333) (OS 6.3.9600 - Windows Server 2012 R2 Datacenter)
. 2017-04-19 06:26:26.924 Configuration: \\SSS-DD3\reports\WinSCP\WinSCP.ini
. 2017-04-19 06:26:27.224 Log level: Normal
. 2017-04-19 06:26:27.349 Local account: HPL\SSSreport2_Agent_sa
. 2017-04-19 06:26:27.412 Working directory: C:\Windows\system32
. 2017-04-19 06:26:27.521 Process ID: 7156
. 2017-04-19 06:26:27.633 Command-line: "\\SSS-DD3\reports\WinSCP\WinSCP.exe" -script="\\SSS-DD3\Reports\SQL\FTPscriptwParameters.txt" -parameter "\\SSS-DD3\reports\Accounts\name\" "/FOLDERS/HOME/company/Reports/name/" -log="\\SSS-DD3\reports\Accounts\name\log.txt"
. 2017-04-19 06:26:27.727 Time zone: Current: GMT-5, Standard: GMT-6 (Central Standard Time), DST: GMT-5 (Central Daylight Time), DST Start: 3/12/2017, DST End: 11/5/2017
. 2017-04-19 06:26:27.758 Login time: Wednesday, April 19, 2017 6:26:27 AM
. 2017-04-19 06:26:27.789 --------------------------------------------------------------------------
. 2017-04-19 06:26:27.947 Script: Retrospectively logging previous script records:
> 2017-04-19 06:26:28.063 Script: option batch continue
< 2017-04-19 06:26:28.189 Script: batch continue
< 2017-04-19 06:26:28.204 Script: reconnecttime 120
> 2017-04-19 06:26:28.251 Script: option confirm off
< 2017-04-19 06:26:28.331 Script: confirm off
> 2017-04-19 06:26:28.425 Script: open sftp://company.servername.net\username:***@SJC-FTP.servername.net -passive -hostkey="ssh-rsa 2048 2e:4b:b7:ab:ee:6d:ea:c5:60:e8:a5:4e:50:23:09:70"
. 2017-04-19 06:26:28.582 --------------------------------------------------------------------------
. 2017-04-19 06:26:28.677 Session name: company.servername.net\username@SJC-FTP.servername.net (Ad-Hoc site)
. 2017-04-19 06:26:28.833 Host name: SJC-FTP.servername.net (Port: 22)
. 2017-04-19 06:26:28.911 User name: company.servername.net\username (Password: Yes, Key file: No, Passphrase: No)
. 2017-04-19 06:26:29.036 Tunnel: No
. 2017-04-19 06:26:29.159 Transfer Protocol: SFTP
. 2017-04-19 06:26:29.238 Ping type: Off, Ping interval: 30 sec; Timeout: 15 sec
. 2017-04-19 06:26:29.301 Disable Nagle: No
. 2017-04-19 06:26:29.410 Proxy: None
. 2017-04-19 06:26:29.520 Send buffer: 262144
. 2017-04-19 06:26:29.664 SSH protocol version: 2; Compression: No
. 2017-04-19 06:26:29.773 Bypass authentication: No
. 2017-04-19 06:26:29.867 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2017-04-19 06:26:29.945 Ciphers: aes,chacha20,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2017-04-19 06:26:29.960 KEX: ecdh,dh-gex-sha1,dh-group14-sha1,rsa,WARN,dh-group1-sha1
. 2017-04-19 06:26:30.024 SSH Bugs: Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto
. 2017-04-19 06:26:30.040 Simple channel: Yes
. 2017-04-19 06:26:30.071 Return code variable: Autodetect; Lookup user groups: Auto
. 2017-04-19 06:26:30.135 Shell: default
. 2017-04-19 06:26:30.228 EOL: LF, UTF: Auto
. 2017-04-19 06:26:30.244 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes; Follow directory symlinks: No
. 2017-04-19 06:26:30.281 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2017-04-19 06:26:30.344 SFTP Bugs: Auto,Auto
. 2017-04-19 06:26:30.359 SFTP Server: default
. 2017-04-19 06:26:30.375 Local directory: default, Remote directory: home, Update: Yes, Cache: Yes
. 2017-04-19 06:26:30.570 Cache directory changes: Yes, Permanent: Yes
. 2017-04-19 06:26:30.711 Recycle bin: Delete to: No, Overwritten to: No, Bin path:
. 2017-04-19 06:26:30.789 DST mode: Unix
. 2017-04-19 06:26:30.836 --------------------------------------------------------------------------
. 2017-04-19 06:26:31.167 Looking up host "SJC-FTP.servername.net" for SSH connection


. 2017-04-19 08:28:18.595 --------------------------------------------------------------------------
. 2017-04-19 08:28:18.782 WinSCP Version 5.9.4 (Build 7333) (OS 6.3.9600 - Windows Server 2012 R2 Datacenter)
. 2017-04-19 08:28:19.017 Configuration: \\SSS-DD3\reports\WinSCP\WinSCP.ini
. 2017-04-19 08:28:19.063 Log level: Normal
. 2017-04-19 08:28:19.188 Local account: HPL\p-jj.chritton
. 2017-04-19 08:28:19.470 Working directory: C:\Program Files (x86)\Microsoft Visual Studio 10.0\Common7\IDE
. 2017-04-19 08:28:19.579 Process ID: 4052
. 2017-04-19 08:28:19.642 Command-line: "\\SSS-DD3\reports\WinSCP\WinSCP.exe" -script="\\SSS-DD3\Reports\SQL\FTPscriptwParameters.txt" -parameter "\\SSS-DD3\reports\Accounts\name\" "/FOLDERS/HOME/company/Reports/name/" -log="\\SSS-DD3\reports\Accounts\name\log.txt"
. 2017-04-19 08:28:19.657 Time zone: Current: GMT-5, Standard: GMT-6 (Central Standard Time), DST: GMT-5 (Central Daylight Time), DST Start: 3/12/2017, DST End: 11/5/2017
. 2017-04-19 08:28:19.782 Login time: Wednesday, April 19, 2017 8:28:19 AM
. 2017-04-19 08:28:19.860 --------------------------------------------------------------------------
. 2017-04-19 08:28:19.970 Script: Retrospectively logging previous script records:
> 2017-04-19 08:28:20.048 Script: option batch continue
< 2017-04-19 08:28:20.079 Script: batch continue
< 2017-04-19 08:28:20.110 Script: reconnecttime 120
> 2017-04-19 08:28:20.142 Script: option confirm off
< 2017-04-19 08:28:20.157 Script: confirm off
> 2017-04-19 08:28:20.173 Script: open sftp://company.servername.net\username:***@SJC-FTP.servername.net -passive -hostkey="ssh-rsa 2048 2e:4b:b7:ab:ee:6d:ea:c5:60:e8:a5:4e:50:23:09:70"
. 2017-04-19 08:28:20.173 --------------------------------------------------------------------------
. 2017-04-19 08:28:20.189 Session name: company.servername.net\username@SJC-FTP.servername.net (Ad-Hoc site)
. 2017-04-19 08:28:20.189 Host name: SJC-FTP.servername.net (Port: 22)
. 2017-04-19 08:28:20.189 User name: company.servername.net\username (Password: Yes, Key file: No, Passphrase: No)
. 2017-04-19 08:28:20.204 Tunnel: No
. 2017-04-19 08:28:20.251 Transfer Protocol: SFTP
. 2017-04-19 08:28:20.267 Ping type: Off, Ping interval: 30 sec; Timeout: 15 sec
. 2017-04-19 08:28:20.282 Disable Nagle: No
. 2017-04-19 08:28:20.407 Proxy: None
. 2017-04-19 08:28:20.501 Send buffer: 262144
. 2017-04-19 08:28:20.642 SSH protocol version: 2; Compression: No
. 2017-04-19 08:28:20.689 Bypass authentication: No
. 2017-04-19 08:28:20.704 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2017-04-19 08:28:20.735 Ciphers: aes,chacha20,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2017-04-19 08:28:20.751 KEX: ecdh,dh-gex-sha1,dh-group14-sha1,rsa,WARN,dh-group1-sha1
. 2017-04-19 08:28:20.782 SSH Bugs: Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto,Auto
. 2017-04-19 08:28:20.798 Simple channel: Yes
. 2017-04-19 08:28:20.845 Return code variable: Autodetect; Lookup user groups: Auto
. 2017-04-19 08:28:20.923 Shell: default
. 2017-04-19 08:28:20.985 EOL: LF, UTF: Auto
. 2017-04-19 08:28:21.001 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes; Follow directory symlinks: No
. 2017-04-19 08:28:21.095 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2017-04-19 08:28:21.220 SFTP Bugs: Auto,Auto
. 2017-04-19 08:28:21.329 SFTP Server: default
. 2017-04-19 08:28:21.532 Local directory: default, Remote directory: home, Update: Yes, Cache: Yes
. 2017-04-19 08:28:21.767 Cache directory changes: Yes, Permanent: Yes
. 2017-04-19 08:28:21.970 Recycle bin: Delete to: No, Overwritten to: No, Bin path:
. 2017-04-19 08:28:22.251 DST mode: Unix
. 2017-04-19 08:28:22.423 --------------------------------------------------------------------------
. 2017-04-19 08:28:22.564 Looking up host "SJC-FTP.servername.net" for SSH connection
. 2017-04-19 08:28:22.751 Connecting to 50.56.9.35 port 22
. 2017-04-19 08:28:22.814 We claim version: SSH-2.0-WinSCP_release_5.9.4
. 2017-04-19 08:28:22.939 Server version: SSH-2.0-Thru SFTP Service 2.5.0
. 2017-04-19 08:28:23.095 We believe remote version has SSH-2 channel request bug
. 2017-04-19 08:28:23.142 Using SSH protocol version 2
. 2017-04-19 08:28:24.689 Have a known host key of type rsa2
. 2017-04-19 08:28:25.204 Doing Diffie-Hellman group exchange
. 2017-04-19 08:28:25.720 Doing Diffie-Hellman key exchange with hash SHA-256
. 2017-04-19 08:28:27.314 Host key fingerprint is:
. 2017-04-19 08:28:27.533 ssh-rsa 2048 2e:4b:b7:ab:ee:6d:ea:c5:60:e8:a5:4e:50:23:09:70
. 2017-04-19 08:28:27.579 Verifying host key rsa2 0x10001,0xcec8a3458cd5c815 353245f571c11c53 bf7a7c4b186b020d 226c46634e22576c accb81166a77327a deea177922c9e873 f851a7d91c834f97 b1b2bd413d4dd78f f9231179aa027c8a 275c59804c23de4f 469900d6fa948e79 06f7416b50a96b91 3055e5589062a823 9c499dc13366597a eefa115acaa2fe13 fb86393294dece2d 823b4f95ee16e048 de5c74f3f2d25024 ff755d4468d3c423 f99292125c4a675c a2918f9794e7a371 3efbebe20d3656c9 8641e3e312ee45f2 fc1da66eaef17932 ee40d9913de41f66 c14c6a716b224c5e 3bddea1e237ce8bb 119288c8a10c1ef1 c7490891e90dd78e a8fcb5ce0567464e 692d7e5ee2cecb15 07b2fb58cd7eb2e5 with fingerprint ssh-rsa 2048 2e:4b:b7:ab:ee:6d:ea:c5:60:e8:a5:4e:50:23:09:70
. 2017-04-19 08:28:28.064 Host key matches configured key
. 2017-04-19 08:28:28.486 Initialised AES-256 SDCTR client->server encryption
. 2017-04-19 08:28:28.595 Initialised HMAC-SHA-256 client->server MAC algorithm
. 2017-04-19 08:28:28.658 Initialised AES-256 SDCTR server->client encryption
. 2017-04-19 08:28:28.736 Initialised HMAC-SHA-256 server->client MAC algorithm
! 2017-04-19 08:28:28.986 Using username "company.servername.net\username".
. 2017-04-19 08:28:29.048 Server offered these authentication methods: password,publickey
. 2017-04-19 08:28:29.079 Prompt (password, "SSH password", <no instructions>, "&Password: ")
. 2017-04-19 08:28:29.142 Using stored password.
. 2017-04-19 08:28:29.158 Sent password
. 2017-04-19 08:28:29.236 Access granted
. 2017-04-19 08:28:29.376 Opening session as main channel
. 2017-04-19 08:28:29.408 Opened main channel
. 2017-04-19 08:28:29.658 Started a shell/command
. 2017-04-19 08:28:29.892 --------------------------------------------------------------------------
. 2017-04-19 08:28:30.345 Using SFTP protocol.
. 2017-04-19 08:28:30.767 Doing startup conversation with host.
> 2017-04-19 08:28:30.908 Type: SSH_FXP_INIT, Size: 5, Number: -1
< 2017-04-19 08:28:31.017 Type: SSH_FXP_VERSION, Size: 5, Number: -1
. 2017-04-19 08:28:31.080 SFTP version 3 negotiated.
. 2017-04-19 08:28:31.189 We believe the server has signed timestamps bug
. 2017-04-19 08:28:31.189 We will use UTF-8 strings until server sends an invalid UTF-8 string as with SFTP version 3 and older UTF-8 strings are not mandatory
. 2017-04-19 08:28:31.267 Getting current directory name.
. 2017-04-19 08:28:31.298 Getting real path for '.'
> 2017-04-19 08:28:31.376 Type: SSH_FXP_REALPATH, Size: 10, Number: 16
< 2017-04-19 08:28:31.439 Type: SSH_FXP_NAME, Size: 83, Number: 16
. 2017-04-19 08:28:31.501 Real path is '/'
. 2017-04-19 08:28:31.533 Startup conversation with host finished.
< 2017-04-19 08:28:31.642 Script: Active session: [1] company.servername.net\username@SJC-FTP.servername.net
> 2017-04-19 08:28:31.689 Script: lcd "\\SSS-DD3\reports\Accounts\name\"
< 2017-04-19 08:28:31.830 Script: \\SSS-DD3\reports\Accounts\name
> 2017-04-19 08:28:31.861 Script: put *.xls* "/FOLDERS/HOME/company/Reports/name/" -resumesupport=off
< 2017-04-19 08:28:31.908 Script: Using configured transfer settings different from factory defaults.
. 2017-04-19 08:28:33.283 Copying 2 files/directories to remote directory "/FOLDERS/HOME/company/Reports/name/"
. 2017-04-19 08:28:33.330 PrTime: Yes; PrRO: No; Rght: rw-r--r--; PrR: No (No); FnCs: N; RIC: 0100; Resume: N (102400); CalcS: No; Mask:
. 2017-04-19 08:28:33.470 TM: B; ClAr: No; RemEOF: No; RemBOM: No; CPS: 0; NewerOnly: No; InclM: ; ResumeL: 0
. 2017-04-19 08:28:33.564 AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; *.js; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2017-04-19 08:28:34.611 File: 'Report 20170419.xlsx' [2017-04-19T11:08:53.204Z] [31826]
. 2017-04-19 08:28:35.033 Copying "Report 20170419.xlsx" to remote directory started.
. 2017-04-19 08:28:35.095 Binary transfer mode selected.
. 2017-04-19 08:28:35.158 Opening remote file.
> 2017-04-19 08:28:35.330 Type: SSH_FXP_OPEN, Size: 113, Number: 259
< 2017-04-19 08:28:35.564 Type: SSH_FXP_HANDLE, Size: 10, Number: 259
> 2017-04-19 08:28:36.517 Type: SSH_FXP_WRITE, Size: 16380, Number: 774
. 2017-04-19 08:28:36.564 1 skipped SSH_FXP_WRITE, SSH_FXP_READ, SSH_FXP_DATA and SSH_FXP_STATUS packets.
> 2017-04-19 08:28:36.595 Type: SSH_FXP_CLOSE, Size: 10, Number: 1284
< 2017-04-19 08:28:36.627 Type: SSH_FXP_STATUS, Size: 19, Number: 774
< 2017-04-19 08:28:36.658 Status code: 0
> 2017-04-19 08:28:36.689 Type: SSH_FXP_SETSTAT, Size: 109, Number: 521
< 2017-04-19 08:28:36.752 Type: SSH_FXP_STATUS, Size: 19, Number: 1030
< 2017-04-19 08:28:36.861 Status code: 0
< 2017-04-19 08:28:36.877 Type: SSH_FXP_STATUS, Size: 19, Number: 1284
< 2017-04-19 08:28:36.939 Status code: 0
. 2017-04-19 08:28:37.017 Preserving timestamp [2017-04-19T11:08:53.000Z]
< 2017-04-19 08:28:37.048 Type: SSH_FXP_STATUS, Size: 19, Number: 521
< 2017-04-19 08:28:37.173 Status code: 0
. 2017-04-19 08:28:37.236 Transfer done: 'Report 20170419.xlsx' [31826]
. 2017-04-19 08:28:40.205 File: 'NewReport 20170419.xlsx' [2017-04-19T11:25:25.424Z] [27024]
. 2017-04-19 08:28:42.283 Copying "NewReport 20170419.xlsx" to remote directory started.
. 2017-04-19 08:28:42.361 Binary transfer mode selected.
. 2017-04-19 08:28:42.517 Opening remote file.
> 2017-04-19 08:28:42.611 Type: SSH_FXP_OPEN, Size: 118, Number: 1539
< 2017-04-19 08:28:42.846 Type: SSH_FXP_HANDLE, Size: 10, Number: 1539
> 2017-04-19 08:28:43.283 Type: SSH_FXP_WRITE, Size: 16380, Number: 2054
. 2017-04-19 08:28:43.611 2 skipped SSH_FXP_WRITE, SSH_FXP_READ, SSH_FXP_DATA and SSH_FXP_STATUS packets.
> 2017-04-19 08:28:43.627 Type: SSH_FXP_CLOSE, Size: 10, Number: 2564
< 2017-04-19 08:28:43.642 Type: SSH_FXP_STATUS, Size: 19, Number: 2310
< 2017-04-19 08:28:43.767 Status code: 0
> 2017-04-19 08:28:43.861 Type: SSH_FXP_SETSTAT, Size: 114, Number: 1801
< 2017-04-19 08:28:43.924 Type: SSH_FXP_STATUS, Size: 19, Number: 2564
< 2017-04-19 08:28:44.080 Status code: 0
. 2017-04-19 08:28:44.111 Preserving timestamp [2017-04-19T11:25:25.000Z]
< 2017-04-19 08:28:44.127 Type: SSH_FXP_STATUS, Size: 19, Number: 1801
< 2017-04-19 08:28:44.158 Status code: 0
. 2017-04-19 08:28:44.283 Transfer done: 'NewReport 20170419.xlsx' [27024]
> 2017-04-19 08:28:45.752 Script: exit
. 2017-04-19 08:28:46.611 Script: Exit code: 0
. 2017-04-19 08:28:46.736 Closing connection.
. 2017-04-19 08:28:46.799 Sending special code: 12
. 2017-04-19 08:28:46.893 Sent EOF message
martin◆
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 26889
Location: Prague, Czechia
It does not look like a problem with the server.

It rather looks like the local machine is under a heavy load.
Ghenk

Guest


martin wrote:
It does not look like a problem with the server.

It rather looks like the local machine is under a heavy load.


Thanks. I will try rescheduling the upload to a different time to see if I'm running into some kind of conflict with another process at the current scheduled time.
Ghenk

Guest


I rescheduled job an hour later, but realized in the process of some of my testing that the step in the SSIS package that I was using to trigger the upload had a 60 second timeout setup. It probably only became an issue when the target FTP server or the SQL server became bogged down during the upload process.

so lesson learned, check to make sure the process that's triggering WinSCP is not shutting it down uncerimoniously.
Advertisements

You can post new topics in this forum

Search

What is WinSCP?

It is award-winning SFTP client, SCP client, FTPS client and FTP client integrated into one software program for file transfer to FTP server or secure SFTP server. [More]

And it's free!

Donate

About donations

$9   $19   $49   $99

About donations

Recommend

WinSCP Privacy Policy

WinSCP License