I've stumbled upon a rather annoying and completely baffling issue. I have an Execute Process in SSIS (see attached screenshot) which successfully runs a script file (contents below). The log file confirms that the script is being executed, but is returning a Status Code: 1 and Sending special code: 12 (because there are no files to collect) but the SSIS Execute Process is not returning a failure - it is simply continuing on to the next step (which it shouldn't).
option confirm off
open sftp://username:password@serveraddress.com/ -hostkey="ssh-rsa 2048 XXXXXXXXXXXX"
option transfer binary
get "Test_315599340_C*" "g:\ftproot\Test\Customer.txt"
get "Test*_V_*" "g:\ftproot\Test\Transaction.txt"
close
exit
. 2015-09-28 14:30:19.552 --------------------------------------------------------------------------
. 2015-09-28 14:30:19.552 WinSCP Version 5.7.5 (Build 5665) (OS 6.3.9600 - Windows Server 2012 R2 Standard)
. 2015-09-28 14:30:19.552 Configuration: HKCU\Software\Martin Prikryl\WinSCP 2\
. 2015-09-28 14:30:19.552 Log level: Debug 1
. 2015-09-28 14:30:19.552 Local account: PRODNET\NREES
. 2015-09-28 14:30:19.552 Working directory: G:\ftproot\Test
. 2015-09-28 14:30:19.552 Process ID: 2284
. 2015-09-28 14:30:19.552 Command-line: "C:\Program Files (x86)\WinSCP\WinSCP.exe" /script="G:\ftproot\Test\FTP\FTP_IN.txt" /log="G:\ftproot\Test\WinSCP_In_Log.txt"
. 2015-09-28 14:30:19.552 Switch: /script=G:\ftproot\Test\FTP\FTP_IN.txt
. 2015-09-28 14:30:19.552 Switch: /log=G:\ftproot\Test\WinSCP_In_Log.txt
. 2015-09-28 14:30:19.552 Time zone: Current: GMT+1, Standard: GMT+0 (GMT Standard Time), DST: GMT+1 (GMT Daylight Time), DST Start: 29/03/2015, DST End: 25/10/2015
. 2015-09-28 14:30:19.552 Login time: 28 September 2015 14:30:19
. 2015-09-28 14:30:19.552 --------------------------------------------------------------------------
. 2015-09-28 14:30:19.552 Script: Retrospectively logging previous script records:
> 2015-09-28 14:30:19.552 Script: option confirm off
> 2015-09-28 14:30:19.552 Script: Parameter: confirm
> 2015-09-28 14:30:19.552 Script: Parameter: off
< 2015-09-28 14:30:19.552 Script: confirm off
> 2015-09-28 14:30:19.552 Script: open sftp://username:***@serveraddress.com/ -hostkey="ssh-rsa 2048 4e:21:c5:7f:3c:69:32:0f:d6:aa:fd:be:1a:6d:b7:6e"
> 2015-09-28 14:30:19.552 Script: Parameter: sftp://username:***@serveraddress.com/
> 2015-09-28 14:30:19.552 Script: Switch: -hostkey=ssh-rsa 2048 4e:21:c5:7f:3c:69:32:0f:d6:aa:fd:be:1a:6d:b7:6e
. 2015-09-28 14:30:19.552 --------------------------------------------------------------------------
. 2015-09-28 14:30:19.552 Session name: username@serveraddress.com (Ad-Hoc site)
. 2015-09-28 14:30:19.552 Host name: serveraddress.com (Port: 22)
. 2015-09-28 14:30:19.552 User name: username (Password: Yes, Key file: No)
. 2015-09-28 14:30:19.552 Tunnel: No
. 2015-09-28 14:30:19.552 Transfer Protocol: SFTP
. 2015-09-28 14:30:19.552 Ping type: -, Ping interval: 30 sec; Timeout: 15 sec
. 2015-09-28 14:30:19.552 Disable Nagle: No
. 2015-09-28 14:30:19.552 Proxy: none
. 2015-09-28 14:30:19.552 Send buffer: 262144
. 2015-09-28 14:30:19.552 SSH protocol version: 2; Compression: No
. 2015-09-28 14:30:19.552 Bypass authentication: No
. 2015-09-28 14:30:19.552 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2015-09-28 14:30:19.552 Ciphers: aes,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2015-09-28 14:30:19.552 KEX: dh-gex-sha1,dh-group14-sha1,dh-group1-sha1,rsa,WARN
. 2015-09-28 14:30:19.552 SSH Bugs: A,A,A,A,A,A,A,A,A,A,A,A
. 2015-09-28 14:30:19.552 Simple channel: Yes
. 2015-09-28 14:30:19.552 Return code variable: Autodetect; Lookup user groups: A
. 2015-09-28 14:30:19.552 Shell: default
. 2015-09-28 14:30:19.552 EOL: 0, UTF: 2
. 2015-09-28 14:30:19.552 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes
. 2015-09-28 14:30:19.552 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2015-09-28 14:30:19.552 SFTP Bugs: A,A
. 2015-09-28 14:30:19.552 SFTP Server: default
. 2015-09-28 14:30:19.552 Local directory: default, Remote directory: home, Update: Yes, Cache: Yes
. 2015-09-28 14:30:19.552 Cache directory changes: Yes, Permanent: Yes
. 2015-09-28 14:30:19.552 DST mode: 1
. 2015-09-28 14:30:19.552 --------------------------------------------------------------------------
. 2015-09-28 14:30:19.552 Looking up host "serveraddress.com"
. 2015-09-28 14:30:19.552 Connecting to 192.168.252.90 port 22
. 2015-09-28 14:30:19.552 Waiting for the server to continue with the initialization
. 2015-09-28 14:30:19.552 Detected network event
. 2015-09-28 14:30:19.614 Detected network event
. 2015-09-28 14:30:19.614 Server version: SSH-2.0-OpenSSH_6.6.1
. 2015-09-28 14:30:19.614 Using SSH protocol version 2
. 2015-09-28 14:30:19.614 We claim version: SSH-2.0-WinSCP_release_5.7.5
. 2015-09-28 14:30:19.614 Waiting for the server to continue with the initialization
. 2015-09-28 14:30:19.646 Detected network event
. 2015-09-28 14:30:19.646 Doing Diffie-Hellman group exchange
. 2015-09-28 14:30:19.646 Waiting for the server to continue with the initialization
. 2015-09-28 14:30:19.852 Detected network event
. 2015-09-28 14:30:19.852 Doing Diffie-Hellman key exchange with hash SHA-256
. 2015-09-28 14:30:20.196 Waiting for the server to continue with the initialization
. 2015-09-28 14:30:20.243 Detected network event
. 2015-09-28 14:30:20.618 Verifying host key rsa2 0x10001,0xaaf2e6320399cdef 40d37e0dad873610 37ef3373c78de866 96ae9ff8da264b16 242f3ccb43ae706d 113bc3ed9992bf8a eaa7cd41f7ddd0fd e5b51af8737b4269 0ccd8d7b3e90dcb9 6e00606e01389491 bca210c041bc41fe b817a2e63adc2508 31de9ac448a8c08a 70393a22a846530a 5d385ad7463e9b63 1d21521e8fb33ef3 e48aa269acba102a 4d3d3f70ab427bb3 3ef94f3570232709 f226a5afd6ba6887 fb49d15a753ee7ed da503492f7c5dd18 186c58f655a3689c 78f426af9540aa84 4837db0b11550e78 e985ae8457cb8eb7 239c152928a20ea7 17acaf26fc372587 f914712d77ec75ef 9bad7b77fa13b79e 0dba380cfb80eca3 782890482aee6d69 with fingerprint ssh-rsa 2048 4e:21:c5:7f:3c:69:32:0f:d6:aa:fd:be:1a:6d:b7:6e
. 2015-09-28 14:30:20.618 Host key matches cached key
. 2015-09-28 14:30:20.618 Host key fingerprint is:
. 2015-09-28 14:30:20.618 ssh-rsa 2048 4e:21:c5:7f:3c:69:32:0f:d6:aa:fd:be:1a:6d:b7:6e
. 2015-09-28 14:30:20.618 Initialised AES-256 SDCTR client->server encryption
. 2015-09-28 14:30:20.618 Initialised HMAC-SHA-256 client->server MAC algorithm
. 2015-09-28 14:30:20.618 Initialised AES-256 SDCTR server->client encryption
. 2015-09-28 14:30:20.618 Initialised HMAC-SHA-256 server->client MAC algorithm
. 2015-09-28 14:30:20.618 Waiting for the server to continue with the initialization
. 2015-09-28 14:30:20.821 Detected network event
! 2015-09-28 14:30:20.821 Using username "username".
. 2015-09-28 14:30:20.821 Waiting for the server to continue with the initialization
. 2015-09-28 14:30:20.837 Detected network event
. 2015-09-28 14:30:20.837 Attempting keyboard-interactive authentication
. 2015-09-28 14:30:20.837 Waiting for the server to continue with the initialization
. 2015-09-28 14:30:20.837 Detected network event
. 2015-09-28 14:30:20.837 Server refused keyboard-interactive authentication
. 2015-09-28 14:30:20.837 Prompt (password, "SSH password", <no instructions>, "&Password: ")
. 2015-09-28 14:30:20.837 Using stored password.
. 2015-09-28 14:30:20.837 Sent password
. 2015-09-28 14:30:20.837 Waiting for the server to continue with the initialization
. 2015-09-28 14:30:20.837 Detected network event
. 2015-09-28 14:30:20.837 Access granted
. 2015-09-28 14:30:20.837 Opening session as main channel
. 2015-09-28 14:30:20.837 Waiting for the server to continue with the initialization
. 2015-09-28 14:30:20.852 Detected network event
. 2015-09-28 14:30:20.852 Opened main channel
. 2015-09-28 14:30:20.852 Waiting for the server to continue with the initialization
. 2015-09-28 14:30:21.055 Detected network event
. 2015-09-28 14:30:21.055 Started a shell/command
. 2015-09-28 14:30:21.055 --------------------------------------------------------------------------
. 2015-09-28 14:30:21.055 Using SFTP protocol.
. 2015-09-28 14:30:21.055 Doing startup conversation with host.
> 2015-09-28 14:30:21.055 Type: SSH_FXP_INIT, Size: 5, Number: -1
. 2015-09-28 14:30:21.055 Sent 9 bytes
. 2015-09-28 14:30:21.055 There are 0 bytes remaining in the send buffer
. 2015-09-28 14:30:21.055 Waiting for another 4 bytes
. 2015-09-28 14:30:21.118 Detected network event
. 2015-09-28 14:30:21.118 Received 154 bytes (0)
. 2015-09-28 14:30:21.118 Read 4 bytes (150 pending)
. 2015-09-28 14:30:21.118 Read 150 bytes (0 pending)
< 2015-09-28 14:30:21.118 Type: SSH_FXP_VERSION, Size: 150, Number: -1
. 2015-09-28 14:30:21.118 SFTP version 3 negotiated.
. 2015-09-28 14:30:21.118 Unknown server extension posix-rename@openssh.com="1"
. 2015-09-28 14:30:21.118 Supports statvfs@openssh.com extension version "2"
. 2015-09-28 14:30:21.118 Unknown server extension fstatvfs@openssh.com="2"
. 2015-09-28 14:30:21.118 Supports hardlink@openssh.com extension version "1"
. 2015-09-28 14:30:21.118 Unknown server extension fsync@openssh.com="1"
. 2015-09-28 14:30:21.118 We believe the server has signed timestamps bug
. 2015-09-28 14:30:21.118 We will use UTF-8 strings until server sends an invalid UTF-8 string as with SFTP version 3 and older UTF-8 string are not mandatory
. 2015-09-28 14:30:21.118 Limiting packet size to OpenSSH sftp-server limit of 262148 bytes
. 2015-09-28 14:30:21.118 Getting current directory name.
. 2015-09-28 14:30:21.118 Getting real path for '.'
> 2015-09-28 14:30:21.118 Type: SSH_FXP_REALPATH, Size: 10, Number: 16
. 2015-09-28 14:30:21.118 Sent 14 bytes
. 2015-09-28 14:30:21.118 There are 0 bytes remaining in the send buffer
. 2015-09-28 14:30:21.118 Waiting for another 4 bytes
. 2015-09-28 14:30:21.118 Detected network event
. 2015-09-28 14:30:21.118 Received 89 bytes (0)
. 2015-09-28 14:30:21.118 Read 4 bytes (85 pending)
. 2015-09-28 14:30:21.118 Read 85 bytes (0 pending)
< 2015-09-28 14:30:21.118 Type: SSH_FXP_NAME, Size: 85, Number: 16
. 2015-09-28 14:30:21.118 Real path is '/cygdrive/E/SFTP_Data/username'
. 2015-09-28 14:30:21.118 Startup conversation with host finished.
< 2015-09-28 14:30:21.118 Script: Active session: [1] username@serveraddress.com
. 2015-09-28 14:30:21.118 Session upkeep
> 2015-09-28 14:30:21.118 Script: option transfer binary
> 2015-09-28 14:30:21.118 Script: Parameter: transfer
> 2015-09-28 14:30:21.118 Script: Parameter: binary
< 2015-09-28 14:30:21.118 Script: transfer binary
. 2015-09-28 14:30:21.118 Session upkeep
> 2015-09-28 14:30:21.118 Script: get "Test_315599340_C*" "g:\ftproot\Test\Customer.txt"
> 2015-09-28 14:30:21.118 Script: Parameter: Test_315599340_C*
> 2015-09-28 14:30:21.118 Script: Parameter: g:\ftproot\Test\Customer.txt
. 2015-09-28 14:30:21.118 Listing directory "/cygdrive/E/SFTP_Data/username".
> 2015-09-28 14:30:21.118 Type: SSH_FXP_OPENDIR, Size: 41, Number: 267
. 2015-09-28 14:30:21.118 Sent 45 bytes
. 2015-09-28 14:30:21.118 There are 0 bytes remaining in the send buffer
. 2015-09-28 14:30:21.118 Waiting for another 4 bytes
. 2015-09-28 14:30:21.118 Detected network event
. 2015-09-28 14:30:21.118 Received 17 bytes (0)
. 2015-09-28 14:30:21.118 Read 4 bytes (13 pending)
. 2015-09-28 14:30:21.118 Read 13 bytes (0 pending)
< 2015-09-28 14:30:21.118 Type: SSH_FXP_HANDLE, Size: 13, Number: 267
> 2015-09-28 14:30:21.118 Type: SSH_FXP_READDIR, Size: 13, Number: 524
. 2015-09-28 14:30:21.118 Sent 17 bytes
. 2015-09-28 14:30:21.118 There are 0 bytes remaining in the send buffer
. 2015-09-28 14:30:21.118 Waiting for another 4 bytes
. 2015-09-28 14:30:21.118 Detected network event
. 2015-09-28 14:30:21.118 Received 221 bytes (0)
. 2015-09-28 14:30:21.118 Read 4 bytes (217 pending)
. 2015-09-28 14:30:21.118 Read 217 bytes (0 pending)
< 2015-09-28 14:30:21.118 Type: SSH_FXP_NAME, Size: 217, Number: 524
> 2015-09-28 14:30:21.118 Type: SSH_FXP_READDIR, Size: 13, Number: 780
. 2015-09-28 14:30:21.118 Sent 17 bytes
. 2015-09-28 14:30:21.118 There are 0 bytes remaining in the send buffer
. 2015-09-28 14:30:21.118 Read file '.' from listing
. 2015-09-28 14:30:21.118 Read file '..' from listing
. 2015-09-28 14:30:21.118 Waiting for another 4 bytes
. 2015-09-28 14:30:21.133 Detected network event
. 2015-09-28 14:30:21.133 Received 32 bytes (0)
. 2015-09-28 14:30:21.133 Read 4 bytes (28 pending)
. 2015-09-28 14:30:21.133 Read 28 bytes (0 pending)
< 2015-09-28 14:30:21.133 Type: SSH_FXP_STATUS, Size: 28, Number: 780
< 2015-09-28 14:30:21.133 Status code: 1
> 2015-09-28 14:30:21.133 Type: SSH_FXP_CLOSE, Size: 13, Number: 1028
. 2015-09-28 14:30:21.133 Sent 17 bytes
. 2015-09-28 14:30:21.133 There are 0 bytes remaining in the send buffer
. 2015-09-28 14:30:21.133 .;d;0;2015-09-28T12:58:06.000Z;"Administrators" [544];"Domain Users" [10513];rwx------;2
. 2015-09-28 14:30:21.133 ..;d;0;2015-09-25T08:16:52.000Z;"????????" [-1];"????????" [-1];rwxr-x---;0
< 2015-09-28 14:30:21.133 Script: No file matching 'Test_315599340_C*' found.
. 2015-09-28 14:30:21.133 Copying 0 files/directories to local directory "g:\ftproot\Test\"
. 2015-09-28 14:30:21.133 PrTime: Yes; PrRO: No; Rght: rw-r--r--; PrR: No (No); FnCs: N; RIC: 0100; Resume: S (102400); CalcS: No; Mask: Customer.txt
. 2015-09-28 14:30:21.133 TM: B; ClAr: No; RemEOF: No; RemBOM: No; CPS: 0; NewerOnly: No; InclM: ; ResumeL: 0
. 2015-09-28 14:30:21.133 AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; *.js; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2015-09-28 14:30:21.133 Session upkeep
> 2015-09-28 14:30:21.133 Script: get "Test*_V_*" "g:\ftproot\Test\Transaction.txt"
> 2015-09-28 14:30:21.133 Script: Parameter: Test*_V_*
> 2015-09-28 14:30:21.133 Script: Parameter: g:\ftproot\Test\Transaction.txt
. 2015-09-28 14:30:21.133 Listing directory "/cygdrive/E/SFTP_Data/username".
> 2015-09-28 14:30:21.133 Type: SSH_FXP_OPENDIR, Size: 41, Number: 1291
. 2015-09-28 14:30:21.133 Sent 45 bytes
. 2015-09-28 14:30:21.133 There are 0 bytes remaining in the send buffer
. 2015-09-28 14:30:21.133 Waiting for another 4 bytes
. 2015-09-28 14:30:21.133 Detected network event
. 2015-09-28 14:30:21.133 Received 28 bytes (0)
. 2015-09-28 14:30:21.133 Read 4 bytes (24 pending)
. 2015-09-28 14:30:21.133 Read 24 bytes (0 pending)
< 2015-09-28 14:30:21.133 Type: SSH_FXP_STATUS, Size: 24, Number: 1028
. 2015-09-28 14:30:21.133 Discarding reserved response
. 2015-09-28 14:30:21.133 Waiting for another 4 bytes
. 2015-09-28 14:30:21.133 Detected network event
. 2015-09-28 14:30:21.133 Received 17 bytes (0)
. 2015-09-28 14:30:21.133 Read 4 bytes (13 pending)
. 2015-09-28 14:30:21.133 Read 13 bytes (0 pending)
< 2015-09-28 14:30:21.133 Type: SSH_FXP_HANDLE, Size: 13, Number: 1291
> 2015-09-28 14:30:21.133 Type: SSH_FXP_READDIR, Size: 13, Number: 1548
. 2015-09-28 14:30:21.133 Sent 17 bytes
. 2015-09-28 14:30:21.133 There are 0 bytes remaining in the send buffer
. 2015-09-28 14:30:21.133 Waiting for another 4 bytes
. 2015-09-28 14:30:21.133 Detected network event
. 2015-09-28 14:30:21.133 Received 221 bytes (0)
. 2015-09-28 14:30:21.133 Read 4 bytes (217 pending)
. 2015-09-28 14:30:21.133 Read 217 bytes (0 pending)
< 2015-09-28 14:30:21.133 Type: SSH_FXP_NAME, Size: 217, Number: 1548
> 2015-09-28 14:30:21.133 Type: SSH_FXP_READDIR, Size: 13, Number: 1804
. 2015-09-28 14:30:21.133 Sent 17 bytes
. 2015-09-28 14:30:21.133 There are 0 bytes remaining in the send buffer
. 2015-09-28 14:30:21.133 Read file '.' from listing
. 2015-09-28 14:30:21.133 Read file '..' from listing
. 2015-09-28 14:30:21.133 Waiting for another 4 bytes
. 2015-09-28 14:30:21.133 Detected network event
. 2015-09-28 14:30:21.133 Received 32 bytes (0)
. 2015-09-28 14:30:21.133 Read 4 bytes (28 pending)
. 2015-09-28 14:30:21.133 Read 28 bytes (0 pending)
< 2015-09-28 14:30:21.133 Type: SSH_FXP_STATUS, Size: 28, Number: 1804
< 2015-09-28 14:30:21.133 Status code: 1
> 2015-09-28 14:30:21.133 Type: SSH_FXP_CLOSE, Size: 13, Number: 2052
. 2015-09-28 14:30:21.133 Sent 17 bytes
. 2015-09-28 14:30:21.133 There are 0 bytes remaining in the send buffer
. 2015-09-28 14:30:21.133 .;d;0;2015-09-28T12:58:06.000Z;"Administrators" [544];"Domain Users" [10513];rwx------;2
. 2015-09-28 14:30:21.133 ..;d;0;2015-09-25T08:16:52.000Z;"????????" [-1];"????????" [-1];rwxr-x---;0
< 2015-09-28 14:30:21.133 Script: No file matching 'Test*_V_*' found.
. 2015-09-28 14:30:21.133 Copying 0 files/directories to local directory "g:\ftproot\Test\"
. 2015-09-28 14:30:21.133 PrTime: Yes; PrRO: No; Rght: rw-r--r--; PrR: No (No); FnCs: N; RIC: 0100; Resume: S (102400); CalcS: No; Mask: Transaction.txt
. 2015-09-28 14:30:21.133 TM: B; ClAr: No; RemEOF: No; RemBOM: No; CPS: 0; NewerOnly: No; InclM: ; ResumeL: 0
. 2015-09-28 14:30:21.133 AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; *.js; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2015-09-28 14:30:21.133 Session upkeep
> 2015-09-28 14:30:21.133 Script: close
. 2015-09-28 14:30:21.133 Closing connection.
. 2015-09-28 14:30:21.133 Sending special code: 12
. 2015-09-28 14:30:21.133 Sent EOF message