Scripted Download fails

Advertisement

gcaporale
Joined:
Posts:
2

Scripted Download fails

I have created a simple script to download a file from a sFTP server. When I test the stored session and connectivity in the GUI it works fine. But when I use the script it fails with a permissions error.

The script is:
option batch abort
option confirm off
option transfer ascii
open CITI_Ucits_Download
get navsummary.csv
exit


Here is the log file from the attempted transfer. The odd part is that even though I am getting a permission denied error the script actually creates an empty folder with the filename instead of the actual file.

. 2013-01-14 13:58:41.611 --------------------------------------------------------------------------
. 2013-01-14 13:58:41.611 WinSCP Version 5.1.3 (Build 2881) (OS 5.2.3790 Service Pack 2)
. 2013-01-14 13:58:41.611 Configuration: HKEY_CURRENT_USER\Software\Martin Prikryl\WinSCP 2\
. 2013-01-14 13:58:41.611 Local account: DOMAIN\administrator
. 2013-01-14 13:58:41.611 Working directory: C:\Documents and Settings\Administrator.DOMAIN
. 2013-01-14 13:58:41.611 Command-line: "C:\Program Files\WinSCP\WinSCP.exe" /console=513 /consoleinstance=_4312_928 "/passive=on" "/log=d:\log.txt" "/script=c:\greg\downloaducits.txt"
. 2013-01-14 13:58:41.611 Time zone: Current: GMT-5, Standard: GMT-5, DST: GMT-4, DST Start: 3/10/2013, DST End: 11/3/2013
. 2013-01-14 13:58:41.611 Login time: Monday, January 14, 2013 1:58:41 PM
. 2013-01-14 13:58:41.611 --------------------------------------------------------------------------
. 2013-01-14 13:58:41.611 Session name: CITI_Ucits_Download (Stored session)
. 2013-01-14 13:58:41.611 Host name: psftp-citi.ms.gxs.com (Port: 22)
. 2013-01-14 13:58:41.611 User name: ACM (Password: No, Key file: Yes)
. 2013-01-14 13:58:41.611 Tunnel: No
. 2013-01-14 13:58:41.611 Transfer Protocol: SFTP (SCP)
. 2013-01-14 13:58:41.611 Ping type: -, Ping interval: 30 sec; Timeout: 15 sec
. 2013-01-14 13:58:41.611 Proxy: none
. 2013-01-14 13:58:41.611 SSH protocol version: 2; Compression: No
. 2013-01-14 13:58:41.611 Bypass authentication: No
. 2013-01-14 13:58:41.611 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2013-01-14 13:58:41.611 Ciphers: aes,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2013-01-14 13:58:41.611 SSH Bugs: A,A,A,A,A,A,A,A,A,A
. 2013-01-14 13:58:41.611 SFTP Bugs: A,A
. 2013-01-14 13:58:41.611 Return code variable: Autodetect; Lookup user groups: A
. 2013-01-14 13:58:41.611 Shell: default
. 2013-01-14 13:58:41.611 EOL: 0, UTF: 2
. 2013-01-14 13:58:41.611 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes
. 2013-01-14 13:58:41.611 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2013-01-14 13:58:41.611 Local directory: D:\, Remote directory: /ACM, Update: Yes, Cache: Yes
. 2013-01-14 13:58:41.611 Cache directory changes: Yes, Permanent: Yes
. 2013-01-14 13:58:41.611 DST mode: 1
. 2013-01-14 13:58:41.611 --------------------------------------------------------------------------
. 2013-01-14 13:58:41.611 Looking up host "psftp-citi.ms.gxs.com"
. 2013-01-14 13:58:41.626 Connecting to 150.105.184.15 port 22
. 2013-01-14 13:58:41.673 Server version: SSH-2.0-GXSSSHD_Comments
. 2013-01-14 13:58:41.673 Using SSH protocol version 2
. 2013-01-14 13:58:41.673 We claim version: SSH-2.0-WinSCP_release_5.1.3
. 2013-01-14 13:58:41.704 Using Diffie-Hellman with standard group "group14"
. 2013-01-14 13:58:41.704 Doing Diffie-Hellman key exchange with hash SHA-1
. 2013-01-14 13:58:42.048 Verifying host key rsa2 0x10001,0x98cb2766676cbec7ae98a273cf4722cb3a34a4b4d677ad2acbba8a8c6...
. 2013-01-14 13:58:42.048 Host key matches cached key
. 2013-01-14 13:58:42.048 Host key fingerprint is:
. 2013-01-14 13:58:42.048 ssh-rsa 1024 c5:3e:81:51:44:17:05:d0:73:55:a5:aa:e7:5c:9b:02
. 2013-01-14 13:58:42.048 Initialised AES-256 CBC client->server encryption
. 2013-01-14 13:58:42.048 Initialised HMAC-SHA1 client->server MAC algorithm
. 2013-01-14 13:58:42.079 Initialised AES-256 CBC server->client encryption
. 2013-01-14 13:58:42.079 Initialised HMAC-SHA1 server->client MAC algorithm
. 2013-01-14 13:58:42.173 Reading private key file "N:\Utils\WinSCP\citi\CitiPrivateKey.ppk"
! 2013-01-14 13:58:42.189 Using username "ACM".
. 2013-01-14 13:58:42.423 Offered public key
. 2013-01-14 13:58:42.486 Offer of public key accepted
! 2013-01-14 13:58:42.486 Authenticating with public key "rsa-key-20121218"
. 2013-01-14 13:58:42.533 Sent public key signature
. 2013-01-14 13:58:42.564 Access granted
. 2013-01-14 13:58:42.595 Opened channel for session
. 2013-01-14 13:58:42.798 Started a shell/command
. 2013-01-14 13:58:42.798 --------------------------------------------------------------------------
. 2013-01-14 13:58:42.798 Using SFTP protocol.
. 2013-01-14 13:58:42.798 Doing startup conversation with host.
> 2013-01-14 13:58:42.798 Type: SSH_FXP_INIT, Size: 5, Number: -1
< 2013-01-14 13:58:42.954 Type: SSH_FXP_VERSION, Size: 5, Number: -1
. 2013-01-14 13:58:42.954 SFTP version 3 negotiated.
. 2013-01-14 13:58:42.954 We believe the server has signed timestamps bug
. 2013-01-14 13:58:42.954 We will use UTF-8 strings for status messages only
. 2013-01-14 13:58:42.954 Changing directory to "/ACM".
. 2013-01-14 13:58:42.954 Getting real path for '/ACM'
> 2013-01-14 13:58:42.954 Type: SSH_FXP_REALPATH, Size: 13, Number: 16
< 2013-01-14 13:58:42.986 Type: SSH_FXP_NAME, Size: 41, Number: 16
. 2013-01-14 13:58:42.986 Real path is '/ACM'
. 2013-01-14 13:58:42.986 Trying to open directory "/ACM".
> 2013-01-14 13:58:42.986 Type: SSH_FXP_LSTAT, Size: 13, Number: 263
< 2013-01-14 13:58:43.017 Type: SSH_FXP_ATTRS, Size: 21, Number: 263
. 2013-01-14 13:58:43.017 Getting current directory name.
. 2013-01-14 13:58:43.017 Startup conversation with host finished.
< 2013-01-14 13:58:43.017 Script: Active session: [1] CITI_Ucits_Download
> 2013-01-14 13:58:43.017 Script: get navsummary.csv
. 2013-01-14 13:58:43.017 Listing file "navsummary.csv".
> 2013-01-14 13:58:43.017 Type: SSH_FXP_LSTAT, Size: 28, Number: 519
< 2013-01-14 13:58:43.048 Type: SSH_FXP_ATTRS, Size: 21, Number: 519
. 2013-01-14 13:58:43.048 File: "/ACM/navsummary.csv"
. 2013-01-14 13:58:43.048 Listing directory "/ACM/navsummary.csv".
> 2013-01-14 13:58:43.048 Type: SSH_FXP_OPENDIR, Size: 28, Number: 779
< 2013-01-14 13:58:43.079 Type: SSH_FXP_STATUS, Size: 29, Number: 779
< 2013-01-14 13:58:43.079 Status code: 3, Message: 779, Server: Invalid user, Language:
. 2013-01-14 13:58:43.079 Asking user:
. 2013-01-14 13:58:43.079 Error listing directory '/ACM/navsummary.csv'. ("Permission denied.
. 2013-01-14 13:58:43.079 Error code: 3
. 2013-01-14 13:58:43.079 Error message from server: Invalid user
. 2013-01-14 13:58:43.079 Request code: 11")
< 2013-01-14 13:58:43.079 Script: Error listing directory '/ACM/navsummary.csv'.
< 2013-01-14 13:58:43.095 Script: Permission denied.
< 2013-01-14 13:58:43.095 Error code: 3
< 2013-01-14 13:58:43.095 Error message from server: Invalid user
< 2013-01-14 13:58:43.095 Request code: 11
. 2013-01-14 13:58:43.111 Script: Failed
. 2013-01-14 13:58:43.111 Script: Exit code: 1
. 2013-01-14 13:58:43.111 Closing connection.
. 2013-01-14 13:58:43.111 Sending special code: 12
. 2013-01-14 13:58:43.111 Sent EOF message

Reply with quote

Advertisement

gcaporale
Joined:
Posts:
2

Re: Scripted Download fails

[quote="prikryl"]Please attach Debug 2-level session log file.[/quote]
Thanks Martin, I am attaching two files. The first is the log from the script. The second is the log from the GUI which successfully downloaded the file.

I have a simple batch file which calls the script.
Batch File:
winscp.com /script=c:\greg\downloaducits.txt /log=d:\scriptlog.log

Script:
option batch abort
option confirm off
option transfer ascii
open CITI_Ucits_Download
get navsummary.csv d:\navsummary.csv
exit
Description: Log from GUI
Description: Log from script.

Reply with quote

martin
Site Admin
martin avatar
Joined:
Posts:
41,468
Location:
Prague, Czechia

Re: Scripted Download fails

Your server returns mode 40600 (octal) = 0x4180 for the navsummary.csv, what according to POSIX standards means the file is directory (40000 = 0x4000 = S_IFDIR).
< 2013-01-23 09:07:21.633 Type: SSH_FXP_ATTRS, Size: 21, Number: 519
< 2013-01-23 09:07:21.633 69,00,00,02,07,00,00,00,0C,00,00,41,80,50,FF,EE,9A,50,FF,EE,9A,
That makes WinSCP to try to recurse into the directory. That obviously fails as I presume it is actually a file.

So it looks like a server-side bug. Please report it to the software vendor.

GUI uses different way to retrieve file properties, that does not trigger the server's bug.

I believe you can workaround the bug (emulate the GUI approach) by using:
get -filemask="navsummary.csv" * d:\

Reply with quote

Advertisement

You can post new topics in this forum