Topic "WinSCP returning error status 1 even though it succeeds"

Author Message
CartoonHead
[View user's profile]

Joined: 2010-07-21
Posts: 6
Location: Georgia, USA
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.
Code:
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):
Code:
< 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:
Code:
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:
Code:
    :
    :
# 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.
Advertisements
CartoonHead
[View user's profile]

Joined: 2010-07-21
Posts: 6
Location: Georgia, USA
The batch file has a .txt at the end:
Code:
CMD /C ""C:\Program Files (x86)\WinSCP\WinSCP.exe" /console /script="D:\ExportFiles\WinSCP_Batch.txt""
CartoonHead
[View user's profile]

Joined: 2010-07-21
Posts: 6
Location: Georgia, USA
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.)
martin
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 25034
Location: Prague, Czechia
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.
_________________
Martin Prikryl
CartoonHead
[View user's profile]

Joined: 2010-07-21
Posts: 6
Location: Georgia, USA
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:
Code:

# 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:
Code:

. 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
martin
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 25034
Location: Prague, Czechia
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.
_________________
Martin Prikryl
CartoonHead
[View user's profile]

Joined: 2010-07-21
Posts: 6
Location: Georgia, USA
I tried a super-simplified script:

Test.txt
Code:

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


I also created a small batch file to test this:

BatchTest.cmd
Code:

"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.
Code:

. 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.
martin
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 25034
Location: Prague, Czechia
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.
_________________
Martin Prikryl
CartoonHead
[View user's profile]

Joined: 2010-07-21
Posts: 6
Location: Georgia, USA
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.
takku

Guest


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) [Download]

Description: (none)

IndyMike

Guest


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.
martin
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 25034
Location: Prague, Czechia
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.
_________________
Martin Prikryl
Advertisements

You can post new topics in this forum






Search Site

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