WinSCP returning error status 1 even though it succeeds :: Support Forum

CartoonHead
Joined:: 2010-07-21
Posts:: 6
Location:: Georgia, USA

WinSCP returning error status 1 even though it succeeds

2010-07-21 13:50

I am trying to run a WinSCP batch from within a SQL server job, using the CmdExec option, to upload 3 files to an FTP site.

CMD /C ""C:\Program Files (x86)\WinSCP\WinSCP.exe" /console /script="D:\ExportFiles\WinSCP_Batch""

When I check the WinSCP log, it indicates success (and the files were successfully uploaded):

< 2010-07-21 08:27:27.753 226 Transfer complete.
. 2010-07-21 08:27:27.753 Upload successful
> 2010-07-21 08:27:27.768 Script: close
. 2010-07-21 08:27:27.768 Disconnected from server

However, SQL gets a returned error flag of 1, and it interprets that as a failure:

The step did not generate any output.  Process Exit Code 1.  The step failed.

If I run the same command using xp_cmdshell, it works fine, and I don't get any errors.
I am using INI-based storage for WinSCP.

How can I get WinSCP to return a 0 code, to indicate success?
Or is there something missing from the end of my batch:

    :
    :
# Change remote directory
cd ..\..
cd \SQLOutputFile
# Force binary mode transfer and upload file
option transfer binary
put D:\ExportFiles\DataExtract.txt
# Disconnect
close
# Exit WinSCP
exit

Suggestions are appreciated.

Reply with quote

CartoonHead
Joined:: 2010-07-21
Posts:: 6
Location:: Georgia, USA

One Correction - Batch File

2010-07-21 13:52

The batch file has a .txt at the end:

CMD /C ""C:\Program Files (x86)\WinSCP\WinSCP.exe" /console /script="D:\ExportFiles\WinSCP_Batch.txt""

Reply with quote

CartoonHead
Joined:: 2010-07-21
Posts:: 6
Location:: Georgia, USA

Figured out a workaround... works, but it's wrong

2010-07-21 14:14

In the SQL [Operating System (CmdExec)], I set:
Process exit code of a successful command: = 1

That takes the 1 it's getting from WinSCP and treats it as success.

While that solves the issue, it's really still treating the mysterious "failure" as a success, so it's really not a preferred solution. But at least there's a workaround.

I'd still like to get that batch corrected, if there's something I'm missing that is causing it to return a 1 versus a 0. (So that a 1 truly indicates an error occurred.)

Reply with quote

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

Re: WinSCP returning error status 1 even though it succeeds

2010-07-23

Can you post an output of the script?
Anyway, if you indeed have two lines with colon at the beginning of the file, then it is the cause of the error code.

Reply with quote

CartoonHead
Joined:: 2010-07-21
Posts:: 6
Location:: Georgia, USA

Full Script and Log File

2010-07-27 17:07

Thank you.

I didn't want to include the entire script/log in the interest of brevity and security, so that's why I used the double-colons.

But here is the "complete" version of both, although I did search/replace to change names to make them anonymous.

Script:

# BATCH FOR XEI PROCESSING OF VENDOR FILES
# Automatically answer all prompts negatively not to stall
# the script on errors
option batch on
# Disable overwrite confirmations that conflict with the previous
option confirm off
open ourusername@sftp.educationalvendor.com
# Change remote directory
cd \Vendor\Accounts
# Force binary mode transfer and upload file
option transfer binary
put D:\ExportFiles\Accounts.csv
# Change remote directory
cd ..\..
cd \Vendor\Courses
# Force binary mode transfer and upload file
option transfer binary
put D:\ExportFiles\Courses.csv
# Change remote directory
cd ..\..
cd \Vendor\Rosters
# Force binary mode transfer and upload file
option transfer binary
put D:\ExportFiles\Rosters.csv
# Disconnect
close
# Exit WinSCP
exit

Log results:

. 2010-07-27 11:15:43.797 --------------------------------------------------------------------------
. 2010-07-27 11:15:43.797 WinSCP Version 4.2.8 (Build 818) (OS 5.2.3790 Service Pack 2)
. 2010-07-27 11:15:43.797 Login time: Tuesday, July 27, 2010 11:15:43 AM
. 2010-07-27 11:15:43.797 --------------------------------------------------------------------------
. 2010-07-27 11:15:43.797 Session name: ourusername@sftp.educationalvendor.com
. 2010-07-27 11:15:43.797 Host name: sftp.educationalvendor.com (Port: 22)
. 2010-07-27 11:15:43.797 User name: ourusername (Password: Yes, Key file: No)
. 2010-07-27 11:15:43.797 Tunnel: No
. 2010-07-27 11:15:43.797 Transfer Protocol: SFTP (SCP)
. 2010-07-27 11:15:43.797 Ping type: -, Ping interval: 30 sec; Timeout: 15 sec
. 2010-07-27 11:15:43.797 Proxy: none
. 2010-07-27 11:15:43.797 SSH protocol version: 2; Compression: No
. 2010-07-27 11:15:43.797 Bypass authentication: No
. 2010-07-27 11:15:43.797 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2010-07-27 11:15:43.797 Ciphers: aes,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2010-07-27 11:15:43.797 SSH Bugs: -,-,-,-,-,-,-,-,-
. 2010-07-27 11:15:43.797 SFTP Bugs: -,-
. 2010-07-27 11:15:43.797 Return code variable: Autodetect; Lookup user groups: Yes
. 2010-07-27 11:15:43.797 Shell: default
. 2010-07-27 11:15:43.797 EOL: 0, UTF: 2
. 2010-07-27 11:15:43.797 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes
. 2010-07-27 11:15:43.797 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2010-07-27 11:15:43.797 Local directory: default, Remote directory: home, Update: No, Cache: Yes
. 2010-07-27 11:15:43.797 Cache directory changes: Yes, Permanent: Yes
. 2010-07-27 11:15:43.797 DST mode: 1
. 2010-07-27 11:15:43.797 --------------------------------------------------------------------------
. 2010-07-27 11:15:43.813 Looking up host "sftp.educationalvendor.com"
. 2010-07-27 11:15:43.860 Connecting to 208.40.252.85 port 22
. 2010-07-27 11:15:43.938 Server version: SSH-2.0-1.36_sshlib GlobalSCAPE
. 2010-07-27 11:15:43.938 We believe remote version ignores SSH-2 maximum packet size
. 2010-07-27 11:15:43.938 We believe remote version has SSH-2 ignore bug
. 2010-07-27 11:15:43.938 Using SSH protocol version 2
. 2010-07-27 11:15:43.938 We claim version: SSH-2.0-WinSCP_release_4.2.8
. 2010-07-27 11:15:44.032 Doing Diffie-Hellman group exchange
. 2010-07-27 11:15:44.235 Doing Diffie-Hellman key exchange with hash SHA-1
. 2010-07-27 11:15:44.500 Host key fingerprint is:
. 2010-07-27 11:15:44.500 ssh-dss 1024 3c:5b:93:d0:be:16:2d:ad:50:0f:90:2b:c3:8f:57:87
. 2010-07-27 11:15:44.500 Initialised AES-256 CBC client->server encryption
. 2010-07-27 11:15:44.500 Initialised HMAC-SHA1 client->server MAC algorithm
. 2010-07-27 11:15:44.500 Initialised AES-256 CBC server->client encryption
. 2010-07-27 11:15:44.500 Initialised HMAC-SHA1 server->client MAC algorithm
! 2010-07-27 11:15:44.688 Using username "ourusername".
! 2010-07-27 11:15:44.735 Further authentication required
. 2010-07-27 11:15:44.735 Further authentication required
. 2010-07-27 11:15:44.735 Prompt (6, SSH password, , &Password: )
. 2010-07-27 11:15:44.735 Using stored password.
. 2010-07-27 11:15:44.735 Sent password
. 2010-07-27 11:15:44.782 Access granted
. 2010-07-27 11:15:44.828 Opened channel for session
. 2010-07-27 11:15:45.032 Started a shell/command
. 2010-07-27 11:15:45.032 --------------------------------------------------------------------------
. 2010-07-27 11:15:45.032 Using SFTP protocol.
. 2010-07-27 11:15:45.032 Doing startup conversation with host.
> 2010-07-27 11:15:45.032 Type: SSH_FXP_INIT, Size: 5, Number: -1
< 2010-07-27 11:15:45.078 Type: SSH_FXP_VERSION, Size: 5, Number: -1
. 2010-07-27 11:15:45.078 SFTP version 3 negotiated.
. 2010-07-27 11:15:45.078 We believe the server has signed timestamps bug
. 2010-07-27 11:15:45.078 We will use UTF-8 strings for status messages only
. 2010-07-27 11:15:45.078 Getting current directory name.
. 2010-07-27 11:15:45.078 Getting real path for '.'
> 2010-07-27 11:15:45.078 Type: SSH_FXP_REALPATH, Size: 10, Number: 16
< 2010-07-27 11:15:45.125 Type: SSH_FXP_NAME, Size: 23, Number: 16
. 2010-07-27 11:15:45.125 Real path is '/'
. 2010-07-27 11:15:45.125 Listing directory "/".
> 2010-07-27 11:15:45.125 Type: SSH_FXP_OPENDIR, Size: 10, Number: 267
< 2010-07-27 11:15:45.203 Type: SSH_FXP_HANDLE, Size: 10, Number: 267
> 2010-07-27 11:15:45.203 Type: SSH_FXP_READDIR, Size: 10, Number: 524
< 2010-07-27 11:15:45.250 Type: SSH_FXP_NAME, Size: 94, Number: 524
> 2010-07-27 11:15:45.250 Type: SSH_FXP_READDIR, Size: 10, Number: 780
< 2010-07-27 11:15:45.297 Type: SSH_FXP_STATUS, Size: 22, Number: 780
< 2010-07-27 11:15:45.297 Status code: 1
> 2010-07-27 11:15:45.297 Type: SSH_FXP_CLOSE, Size: 10, Number: 1028
. 2010-07-27 11:15:45.297 Startup conversation with host finished.
. 2010-07-27 11:15:46.688 Cached directory change via "XEI" to "/Vendor".
. 2010-07-27 11:15:46.688 Getting current directory name.
. 2010-07-27 11:15:46.688 Listing directory "/Vendor".
> 2010-07-27 11:15:46.688 Type: SSH_FXP_OPENDIR, Size: 13, Number: 1291
< 2010-07-27 11:15:46.688 Type: SSH_FXP_STATUS, Size: 21, Number: 1028
. 2010-07-27 11:15:46.688 Discarding reserved response
< 2010-07-27 11:15:46.750 Type: SSH_FXP_HANDLE, Size: 10, Number: 1291
> 2010-07-27 11:15:46.750 Type: SSH_FXP_READDIR, Size: 10, Number: 1548
< 2010-07-27 11:15:46.797 Type: SSH_FXP_NAME, Size: 290, Number: 1548
> 2010-07-27 11:15:46.797 Type: SSH_FXP_READDIR, Size: 10, Number: 1804
< 2010-07-27 11:15:46.844 Type: SSH_FXP_STATUS, Size: 22, Number: 1804
< 2010-07-27 11:15:46.844 Status code: 1
> 2010-07-27 11:15:46.844 Type: SSH_FXP_CLOSE, Size: 10, Number: 2052
. 2010-07-27 11:15:47.735 Cached directory change via "Accounts" to "/Vendor/Accounts".
. 2010-07-27 11:15:47.735 Getting current directory name.
. 2010-07-27 11:15:47.735 Listing directory "/Vendor/Accounts".
> 2010-07-27 11:15:47.735 Type: SSH_FXP_OPENDIR, Size: 22, Number: 2315
< 2010-07-27 11:15:47.735 Type: SSH_FXP_STATUS, Size: 21, Number: 2052
. 2010-07-27 11:15:47.735 Discarding reserved response
< 2010-07-27 11:15:47.813 Type: SSH_FXP_HANDLE, Size: 10, Number: 2315
> 2010-07-27 11:15:47.813 Type: SSH_FXP_READDIR, Size: 10, Number: 2572
< 2010-07-27 11:15:47.860 Type: SSH_FXP_NAME, Size: 215, Number: 2572
> 2010-07-27 11:15:47.860 Type: SSH_FXP_READDIR, Size: 10, Number: 2828
< 2010-07-27 11:15:47.907 Type: SSH_FXP_STATUS, Size: 22, Number: 2828
< 2010-07-27 11:15:47.907 Status code: 1
> 2010-07-27 11:15:47.907 Type: SSH_FXP_CLOSE, Size: 10, Number: 3076
. 2010-07-27 11:15:50.907 Cached directory change via ".." to "/Vendor".
. 2010-07-27 11:15:50.907 Getting current directory name.
. 2010-07-27 11:15:50.922 Directory content loaded from cache.
. 2010-07-27 11:15:51.797 Cached directory change via "Courses" to "/Vendor/Courses".
. 2010-07-27 11:15:51.797 Getting current directory name.
. 2010-07-27 11:15:51.797 Listing directory "/Vendor/Courses".
> 2010-07-27 11:15:51.797 Type: SSH_FXP_OPENDIR, Size: 21, Number: 3339
< 2010-07-27 11:15:51.797 Type: SSH_FXP_STATUS, Size: 21, Number: 3076
. 2010-07-27 11:15:51.797 Discarding reserved response
< 2010-07-27 11:15:51.875 Type: SSH_FXP_HANDLE, Size: 10, Number: 3339
> 2010-07-27 11:15:51.875 Type: SSH_FXP_READDIR, Size: 10, Number: 3596
< 2010-07-27 11:15:51.922 Type: SSH_FXP_NAME, Size: 213, Number: 3596
> 2010-07-27 11:15:51.922 Type: SSH_FXP_READDIR, Size: 10, Number: 3852
< 2010-07-27 11:15:51.969 Type: SSH_FXP_STATUS, Size: 22, Number: 3852
< 2010-07-27 11:15:51.969 Status code: 1
> 2010-07-27 11:15:51.969 Type: SSH_FXP_CLOSE, Size: 10, Number: 4100
. 2010-07-27 11:15:53.391 Cached directory change via ".." to "/Vendor".
. 2010-07-27 11:15:53.391 Getting current directory name.
. 2010-07-27 11:15:53.391 Directory content loaded from cache.
. 2010-07-27 11:15:54.251 Cached directory change via "Rosters" to "/Vendor/Rosters".
. 2010-07-27 11:15:54.251 Getting current directory name.
. 2010-07-27 11:15:54.251 Listing directory "/Vendor/Rosters".
> 2010-07-27 11:15:54.251 Type: SSH_FXP_OPENDIR, Size: 21, Number: 4363
< 2010-07-27 11:15:54.251 Type: SSH_FXP_STATUS, Size: 21, Number: 4100
. 2010-07-27 11:15:54.251 Discarding reserved response
< 2010-07-27 11:15:55.891 Type: SSH_FXP_HANDLE, Size: 10, Number: 4363
> 2010-07-27 11:15:55.891 Type: SSH_FXP_READDIR, Size: 10, Number: 4620
< 2010-07-27 11:15:55.938 Type: SSH_FXP_NAME, Size: 213, Number: 4620
> 2010-07-27 11:15:55.938 Type: SSH_FXP_READDIR, Size: 10, Number: 4876
< 2010-07-27 11:15:55.985 Type: SSH_FXP_STATUS, Size: 22, Number: 4876
< 2010-07-27 11:15:55.985 Status code: 1
> 2010-07-27 11:15:55.985 Type: SSH_FXP_CLOSE, Size: 10, Number: 5124
. 2010-07-27 11:16:03.407 Cached directory change via ".." to "/Vendor".
. 2010-07-27 11:16:03.407 Getting current directory name.
. 2010-07-27 11:16:03.407 Directory content loaded from cache.
. 2010-07-27 11:16:05.423 Cached directory change via "Courses" to "/Vendor/Courses".
. 2010-07-27 11:16:05.423 Getting current directory name.
. 2010-07-27 11:16:05.438 Directory content loaded from cache.
. 2010-07-27 11:16:07.782 Cached directory change via ".." to "/Vendor".
. 2010-07-27 11:16:07.782 Getting current directory name.
. 2010-07-27 11:16:07.782 Directory content loaded from cache.
. 2010-07-27 11:16:09.142 Cached directory change via "Accounts" to "/Vendor/Accounts".
. 2010-07-27 11:16:09.142 Getting current directory name.
. 2010-07-27 11:16:09.142 Directory content loaded from cache.
. 2010-07-27 11:16:11.360 Cached directory change via ".." to "/Vendor".
. 2010-07-27 11:16:11.360 Getting current directory name.
. 2010-07-27 11:16:11.360 Directory content loaded from cache.
. 2010-07-27 11:16:13.095 Closing connection.
. 2010-07-27 11:16:13.095 Sending special code: 12
. 2010-07-27 11:16:13.095 Sent EOF message

Reply with quote

martin◆ Site Admin

Re: Full Script and Log File

2010-07-30

WinSCP 4.2.8 logs a message "Failed" when error happens that makes it return error exit code (1). I do not see the message in the log. So I do not know what to suggest you.

Reply with quote

CartoonHead
Joined:: 2010-07-21
Posts:: 6
Location:: Georgia, USA

K-I-S-S

2010-07-30 15:05

I tried a super-simplified script:

Test.txt

option batch on
option confirm off
open anonymous@ourserver
close
exit

I also created a small batch file to test this:

BatchTest.cmd

"C:\Program Files (x86)\WinSCP\WinSCP.exe" /console /script="D:\ExportFiles\WinSCP_Batch\Test.txt"
ECHO.%ERRORLEVEL%
pause

It returns an error code of 1 and the following log gets generated.

. 2010-07-30 09:48:51.991 --------------------------------------------------------------------------
. 2010-07-30 09:48:51.991 WinSCP Version 4.2.8 (Build 818) (OS 5.2.3790 Service Pack 2)
. 2010-07-30 09:48:51.991 Login time: Friday, July 30, 2010 9:48:51 AM
. 2010-07-30 09:48:51.991 --------------------------------------------------------------------------
. 2010-07-30 09:48:51.991 Session name: anonymous@ourserver
. 2010-07-30 09:48:51.991 Host name: 10.1.11.170 (Port: 21)
. 2010-07-30 09:48:51.991 User name: anonymous (Password: Yes, Key file: No)
. 2010-07-30 09:48:51.991 Tunnel: No
. 2010-07-30 09:48:51.991 Transfer Protocol: FTP
. 2010-07-30 09:48:51.991 Ping type: C, Ping interval: 30 sec; Timeout: 15 sec
. 2010-07-30 09:48:51.991 Proxy: none
. 2010-07-30 09:48:51.991 FTP: FTPS: None; Passive: No [Force IP: No]
. 2010-07-30 09:48:51.991 Local directory: default, Remote directory: home, Update: No, Cache: Yes
. 2010-07-30 09:48:51.991 Cache directory changes: Yes, Permanent: Yes
. 2010-07-30 09:48:51.991 DST mode: 1
. 2010-07-30 09:48:51.991 --------------------------------------------------------------------------
. 2010-07-30 09:48:51.991 Connecting to 10.1.11.170 ...
. 2010-07-30 09:48:51.991 Connected with 10.1.11.170. Waiting for welcome message...
< 2010-07-30 09:48:51.991 220 Microsoft FTP Service
> 2010-07-30 09:48:51.991 USER anonymous
< 2010-07-30 09:48:51.991 331 Anonymous access allowed, send identity (e-mail name) as password.
> 2010-07-30 09:48:51.991 PASS *****************************
< 2010-07-30 09:48:51.991 230 Anonymous user logged in.
> 2010-07-30 09:48:51.991 SYST
< 2010-07-30 09:48:52.006 215 Windows_NT
> 2010-07-30 09:48:52.006 FEAT
< 2010-07-30 09:48:52.006 211-FEAT
< 2010-07-30 09:48:52.162     SIZE
< 2010-07-30 09:48:52.162     MDTM
< 2010-07-30 09:48:52.162 211 END
. 2010-07-30 09:48:52.162 Connected
. 2010-07-30 09:48:52.162 --------------------------------------------------------------------------
. 2010-07-30 09:48:52.162 Using FTP protocol.
. 2010-07-30 09:48:52.162 Doing startup conversation with host.
> 2010-07-30 09:48:52.162 PWD
< 2010-07-30 09:48:52.162 257 "/" is current directory.
. 2010-07-30 09:48:52.162 Getting current directory name.
. 2010-07-30 09:48:52.162 Startup conversation with host finished.
< 2010-07-30 09:48:52.162 Script: Active session: [1] anonymous@ourserver
> 2010-07-30 09:48:52.162 Script: close
. 2010-07-30 09:48:52.162 Disconnected from server

I do not see any error either, which is my original observation.

So there's no way for me to determine whether the batch was an actual success or a failure.

Reply with quote

martin◆ Site Admin

Re: K-I-S-S

2010-08-02

You need to run winscp.com. The winscp.exe is run asynchronously, being GUI application, so the "echo" command is run before winscp.exe exits.

Reply with quote

CartoonHead
Joined:: 2010-07-21
Posts:: 6
Location:: Georgia, USA

Using WinSCP.com did the trick - thank you

2010-08-02 14:01

Thank you sir, that fixed the problem!

I removed the close command from the end of the script, and then changed my reference within the SQL command to use WinSCP.com instead of WinSCP.exe, and indicated that a 0 return value means success.

It works now. Thank you.

Reply with quote

takku Guest

Allways error 1

2012-12-02 17:17

Hi!

So the bat file is
"c:\Program Files\WinSCP2\WinSCP.com" /script=c:\winscpscript\testscript.txt /log=c:\winscpscript\log.txt
ECHO.%ERRORLEVEL%

and testscript.txt is
c:\Program Files\WinSCP1\winscp.exe/script=this_filename /log=logfile.txt
open **** -hostkey="ssh-rsa 1024 *************'*'"
option confirm off
option batch abort
cd /home/takku/siirto/
put C:\temp\lahtitulo.JPG
exit

it just stopped working and attachment

log.txt (8.97 KB)

Reply with quote

IndyMike Guest

Returning condition from WinSCP batch file

2014-09-17 22:35

Old thread is old, but it is also a top hit when searching for WinSCP used in Sql Server Agent Jobs.

Using WinSCP.com and ECHO.%ERRORLEVEL% worked well for me on one system, but on another it would always return as a success. What eventually worked for me is to replace the ECHO command with:

EXIT /B %ERRORLEVEL%

immediately after the call to WinSCP.com. I don't know if the /B switch is necessary for an agent job, but it was vital when testing in a Command Shell, and leaving it in did no harm.

Reply with quote

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

Re: Returning condition from WinSCP batch file

2014-09-18

IndyMike wrote:

Old thread is old, but it is also a top hit when searching for WinSCP used in Sql Server Agent Jobs.

Using WinSCP.com and ECHO.%ERRORLEVEL% worked well for me on one system, but on another it would always return as a success. What eventually worked for me is to replace the ECHO command with:

EXIT /B %ERRORLEVEL%

immediately after the call to WinSCP.com. I don't know if the /B switch is necessary for an agent job, but it was vital when testing in a Command Shell, and leaving it in did no harm.

This is bit confusing. The echo %ERRORLEVEL% and EXIT /B %ERRORLEVEL% are two completely different commands. I assume that you want to propagate WinSCP exit code from the batch file to the SQL Server. By default the batch file exits with an exit code of the last command (not including commands such as echo). So if winscp.com is the last command (except for maybe echo %ERRORLEVEL%), the batch file returns WinSCP exit code. If you have other commands after the winscp.exe, you may need to preserve WinSCP exit code in an environment variable (e.g. RESULT) and do call exit %RESULT% at the end of the batch file. Using exit %ERRORLEVEL% is IMHO noop call. And the /b switch does not make any sense at the end of the batch file.

Reply with quote