Trouble "put"ting files on remote server via WinSCP script.
I have a simple script for uploading files to our linux server. When I use the script to transfer a file, I often (not always) get the following error: "Copying files to remote side failed. Invalid argument to time encode." Sometimes, the transfer will be successful. It seems more likely to fail with larger files, although I haven't been transfering extremely large files - these are on the order of 50MB. If I attempt to transfer the same file 10 times in a row, it might be successful 2 or 3 times out of 10.
One more thing. If I open the WinSCP GUI (commander mode) and transfer the file, it works every time without fail, even for very large files.
On the local side, I'm running the script via a dos batch file under windows XP X64 SP2. I have WinSCP 4.2.7 (Build 758) installed. The remote system is a 64bit Linux server.
Here is the dos script:
@echo on
@echo off
rem
rem set server user name and password
rem
set USER=username
set PASS=passwd
rem
rem ***************************************************************
rem BEGIN: Generate temporary winscp script to upload and run files
rem ***************************************************************
rem
echo option batch on > runscript.tmp
echo option confirm off >> runscript.tmp
echo option reconnecttime 1000 >> runscript.tmp
echo option transfer automatic >> runscript.tmp
echo open %USER%:%PASS%@atc-pbs00 -timeout=100000 >> runscript.tmp
echo cd /stage/jobs/rmorris/QTEST >> runscript.tmp
echo put -resume -nopreservetime -nopermissions upload.zip >> runscript.tmp
rem echo close >> runscript.tmp
rem echo exit >> runscript.tmp
rem
rem ********************************************************
rem END: Generate temporary script to upload and run files
rem ********************************************************
rem
winscp.exe /console /log=winscplog.txt /script=runscript.tmp
rem
@echo off
Next is the winscp script used to pass the file:
option batch on
option confirm off
option reconnecttime 1000
option transfer automatic
open rmorris:Jason1@atc-pbs00 -timeout=100000
cd /stage/jobs/rmorris/QTEST
put -resume -nopreservetime -nopermissions upload.zip
I have tried it with and without the -nopreservetime/-preservetime and -nopermissions switches.
Finally, below is the log file contents:
. 2010-06-23 13:51:55.928 --------------------------------------------------------------------------
. 2010-06-23 13:51:55.928 WinSCP Version 4.2.7 (Build 758) (OS 5.2.3790 Service Pack 2)
. 2010-06-23 13:51:55.928 Login time: Wednesday, June 23, 2010 1:51:55 PM
. 2010-06-23 13:51:55.928 --------------------------------------------------------------------------
. 2010-06-23 13:51:55.928 Session name: username@atc-pbs00
. 2010-06-23 13:51:55.928 Host name: atc-pbs00 (Port: 22)
. 2010-06-23 13:51:55.928 User name: username (Password: Yes, Key file: No)
. 2010-06-23 13:51:55.928 Tunnel: No
. 2010-06-23 13:51:55.928 Transfer Protocol: SFTP (SCP)
. 2010-06-23 13:51:55.928 Ping type: -, Ping interval: 30 sec; Timeout: 100000 sec
. 2010-06-23 13:51:55.928 Proxy: none
. 2010-06-23 13:51:55.928 SSH protocol version: 2; Compression: No
. 2010-06-23 13:51:55.928 Bypass authentication: No
. 2010-06-23 13:51:55.928 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2010-06-23 13:51:55.928 Ciphers: aes,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2010-06-23 13:51:55.928 SSH Bugs: -,-,-,-,-,-,-,-,-
. 2010-06-23 13:51:55.928 SFTP Bugs: -,-
. 2010-06-23 13:51:55.928 Return code variable: Autodetect; Lookup user groups: Yes
. 2010-06-23 13:51:55.928 Shell: default, EOL: 0
. 2010-06-23 13:51:55.928 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes
. 2010-06-23 13:51:55.928 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2010-06-23 13:51:55.928 Local directory: default, Remote directory: home, Update: No, Cache: Yes
. 2010-06-23 13:51:55.928 Cache directory changes: Yes, Permanent: Yes
. 2010-06-23 13:51:55.928 DST mode: 1
. 2010-06-23 13:51:55.928 --------------------------------------------------------------------------
. 2010-06-23 13:51:55.928 Looking up host "atc-pbs00"
. 2010-06-23 13:51:55.990 Connecting to *.*.*.* port 22
. 2010-06-23 13:51:55.990 Server version: SSH-1.99-OpenSSH_3.9p1
. 2010-06-23 13:51:55.990 Using SSH protocol version 2
. 2010-06-23 13:51:55.990 We claim version: SSH-2.0-WinSCP_release_4.2.7
. 2010-06-23 13:51:55.990 Doing Diffie-Hellman group exchange
. 2010-06-23 13:51:55.990 Doing Diffie-Hellman key exchange with hash SHA-1
. 2010-06-23 13:51:56.131 Host key fingerprint is:
. 2010-06-23 13:51:56.131 ssh-rsa 1024 *:*:*:*:*:*:*:*:*:*:*:*:*:*:*:*
. 2010-06-23 13:51:56.131 Initialised AES-256 SDCTR client->server encryption
. 2010-06-23 13:51:56.131 Initialised HMAC-SHA1 client->server MAC algorithm
. 2010-06-23 13:51:56.131 Initialised AES-256 SDCTR server->client encryption
. 2010-06-23 13:51:56.131 Initialised HMAC-SHA1 server->client MAC algorithm
! 2010-06-23 13:51:56.178 Using username "username".
. 2010-06-23 13:51:56.178 Prompt (6, SSH password, , &Password: )
. 2010-06-23 13:51:56.178 Using stored password.
. 2010-06-23 13:51:56.178 Sent password
. 2010-06-23 13:51:56.178 Access granted
. 2010-06-23 13:51:56.178 Opened channel for session
. 2010-06-23 13:51:56.225 Started a shell/command
. 2010-06-23 13:51:56.225 --------------------------------------------------------------------------
. 2010-06-23 13:51:56.225 Using SFTP protocol.
. 2010-06-23 13:51:56.225 Doing startup conversation with host.
> 2010-06-23 13:51:56.225 Type: SSH_FXP_INIT, Size: 5, Number: -1
< 2010-06-23 13:51:56.240 Type: SSH_FXP_VERSION, Size: 5, Number: -1
. 2010-06-23 13:51:56.240 SFTP version 3 negotiated.
. 2010-06-23 13:51:56.240 We believe the server has signed timestamps bug
. 2010-06-23 13:51:56.240 We will use UTF-8 strings for status messages only
. 2010-06-23 13:51:56.240 Limiting packet size to OpenSSH sftp-server limit of 262148 bytes
. 2010-06-23 13:51:56.240 Getting current directory name.
. 2010-06-23 13:51:56.240 Getting real path for '.'
> 2010-06-23 13:51:56.240 Type: SSH_FXP_REALPATH, Size: 10, Number: 16
< 2010-06-23 13:51:56.240 Type: SSH_FXP_NAME, Size: 47, Number: 16
. 2010-06-23 13:51:56.240 Real path is '/home/username'
. 2010-06-23 13:51:56.240 Startup conversation with host finished.
. 2010-06-23 13:51:56.240 Cached directory change via "/stage/jobs/username/QTEST" to "/stage/jobs/username/QTEST".
. 2010-06-23 13:51:56.240 Getting current directory name.
. 2010-06-23 13:51:56.240 Copying 1 files/directories to remote directory "/stage/jobs/username/QTEST"
. 2010-06-23 13:51:56.240 PrTime: No; PrRO: Yes; Rght: rw-r--r--; PrR: No (No); FnCs: N; RIC: 01; Resume: S (102400); CalcS: No; Mask:
. 2010-06-23 13:51:56.240 TM: M; ClAr: No; CPS: 0; ExclM(No):
. 2010-06-23 13:51:56.240 AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2010-06-23 13:51:56.240 File: "upload.zip"
. 2010-06-23 13:51:56.240 Copying "upload.zip" to remote directory started.
. 2010-06-23 13:51:56.240 Binary transfer mode selected.
. 2010-06-23 13:51:56.240 Checking existence of file.
> 2010-06-23 13:51:56.240 Type: SSH_FXP_LSTAT, Size: 45, Number: 263
< 2010-06-23 13:51:56.240 Type: SSH_FXP_ATTRS, Size: 37, Number: 263
. 2010-06-23 13:51:56.240 Checking existence of partially transfered file.
> 2010-06-23 13:51:56.240 Type: SSH_FXP_LSTAT, Size: 54, Number: 519
< 2010-06-23 13:51:56.240 Type: SSH_FXP_ATTRS, Size: 37, Number: 519
. 2010-06-23 13:51:56.240 Resuming file transfer.
. 2010-06-23 13:51:56.240 Opening remote file.
> 2010-06-23 13:51:56.240 Type: SSH_FXP_OPEN, Size: 62, Number: 771
< 2010-06-23 13:51:56.240 Type: SSH_FXP_HANDLE, Size: 13, Number: 771
> 2010-06-23 13:51:56.240 Type: SSH_FXP_WRITE, Size: 4121, Number: 1286
. 2010-06-23 13:51:57.147 403 skipped SSH_FXP_WRITE, SSH_FXP_READ, SSH_FXP_DATA and SSH_FXP_STATUS packets.
> 2010-06-23 13:51:57.147 Type: SSH_FXP_CLOSE, Size: 13, Number: 52996
< 2010-06-23 13:51:57.162 Type: SSH_FXP_STATUS, Size: 24, Number: 52996
< 2010-06-23 13:51:57.162 Status code: 0
* 2010-06-23 13:51:57.162 (ECommand) Copying files to remote side failed.
* 2010-06-23 13:51:57.162 Invalid argument to time encode
One more thing. If I open the WinSCP GUI (commander mode) and transfer the file, it works every time without fail, even for very large files.
On the local side, I'm running the script via a dos batch file under windows XP X64 SP2. I have WinSCP 4.2.7 (Build 758) installed. The remote system is a 64bit Linux server.
Here is the dos script:
@echo on
@echo off
rem
rem set server user name and password
rem
set USER=username
set PASS=passwd
rem
rem ***************************************************************
rem BEGIN: Generate temporary winscp script to upload and run files
rem ***************************************************************
rem
echo option batch on > runscript.tmp
echo option confirm off >> runscript.tmp
echo option reconnecttime 1000 >> runscript.tmp
echo option transfer automatic >> runscript.tmp
echo open %USER%:%PASS%@atc-pbs00 -timeout=100000 >> runscript.tmp
echo cd /stage/jobs/rmorris/QTEST >> runscript.tmp
echo put -resume -nopreservetime -nopermissions upload.zip >> runscript.tmp
rem echo close >> runscript.tmp
rem echo exit >> runscript.tmp
rem
rem ********************************************************
rem END: Generate temporary script to upload and run files
rem ********************************************************
rem
winscp.exe /console /log=winscplog.txt /script=runscript.tmp
rem
@echo off
Next is the winscp script used to pass the file:
option batch on
option confirm off
option reconnecttime 1000
option transfer automatic
open rmorris:Jason1@atc-pbs00 -timeout=100000
cd /stage/jobs/rmorris/QTEST
put -resume -nopreservetime -nopermissions upload.zip
I have tried it with and without the -nopreservetime/-preservetime and -nopermissions switches.
Finally, below is the log file contents:
. 2010-06-23 13:51:55.928 --------------------------------------------------------------------------
. 2010-06-23 13:51:55.928 WinSCP Version 4.2.7 (Build 758) (OS 5.2.3790 Service Pack 2)
. 2010-06-23 13:51:55.928 Login time: Wednesday, June 23, 2010 1:51:55 PM
. 2010-06-23 13:51:55.928 --------------------------------------------------------------------------
. 2010-06-23 13:51:55.928 Session name: username@atc-pbs00
. 2010-06-23 13:51:55.928 Host name: atc-pbs00 (Port: 22)
. 2010-06-23 13:51:55.928 User name: username (Password: Yes, Key file: No)
. 2010-06-23 13:51:55.928 Tunnel: No
. 2010-06-23 13:51:55.928 Transfer Protocol: SFTP (SCP)
. 2010-06-23 13:51:55.928 Ping type: -, Ping interval: 30 sec; Timeout: 100000 sec
. 2010-06-23 13:51:55.928 Proxy: none
. 2010-06-23 13:51:55.928 SSH protocol version: 2; Compression: No
. 2010-06-23 13:51:55.928 Bypass authentication: No
. 2010-06-23 13:51:55.928 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2010-06-23 13:51:55.928 Ciphers: aes,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2010-06-23 13:51:55.928 SSH Bugs: -,-,-,-,-,-,-,-,-
. 2010-06-23 13:51:55.928 SFTP Bugs: -,-
. 2010-06-23 13:51:55.928 Return code variable: Autodetect; Lookup user groups: Yes
. 2010-06-23 13:51:55.928 Shell: default, EOL: 0
. 2010-06-23 13:51:55.928 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes
. 2010-06-23 13:51:55.928 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2010-06-23 13:51:55.928 Local directory: default, Remote directory: home, Update: No, Cache: Yes
. 2010-06-23 13:51:55.928 Cache directory changes: Yes, Permanent: Yes
. 2010-06-23 13:51:55.928 DST mode: 1
. 2010-06-23 13:51:55.928 --------------------------------------------------------------------------
. 2010-06-23 13:51:55.928 Looking up host "atc-pbs00"
. 2010-06-23 13:51:55.990 Connecting to *.*.*.* port 22
. 2010-06-23 13:51:55.990 Server version: SSH-1.99-OpenSSH_3.9p1
. 2010-06-23 13:51:55.990 Using SSH protocol version 2
. 2010-06-23 13:51:55.990 We claim version: SSH-2.0-WinSCP_release_4.2.7
. 2010-06-23 13:51:55.990 Doing Diffie-Hellman group exchange
. 2010-06-23 13:51:55.990 Doing Diffie-Hellman key exchange with hash SHA-1
. 2010-06-23 13:51:56.131 Host key fingerprint is:
. 2010-06-23 13:51:56.131 ssh-rsa 1024 *:*:*:*:*:*:*:*:*:*:*:*:*:*:*:*
. 2010-06-23 13:51:56.131 Initialised AES-256 SDCTR client->server encryption
. 2010-06-23 13:51:56.131 Initialised HMAC-SHA1 client->server MAC algorithm
. 2010-06-23 13:51:56.131 Initialised AES-256 SDCTR server->client encryption
. 2010-06-23 13:51:56.131 Initialised HMAC-SHA1 server->client MAC algorithm
! 2010-06-23 13:51:56.178 Using username "username".
. 2010-06-23 13:51:56.178 Prompt (6, SSH password, , &Password: )
. 2010-06-23 13:51:56.178 Using stored password.
. 2010-06-23 13:51:56.178 Sent password
. 2010-06-23 13:51:56.178 Access granted
. 2010-06-23 13:51:56.178 Opened channel for session
. 2010-06-23 13:51:56.225 Started a shell/command
. 2010-06-23 13:51:56.225 --------------------------------------------------------------------------
. 2010-06-23 13:51:56.225 Using SFTP protocol.
. 2010-06-23 13:51:56.225 Doing startup conversation with host.
> 2010-06-23 13:51:56.225 Type: SSH_FXP_INIT, Size: 5, Number: -1
< 2010-06-23 13:51:56.240 Type: SSH_FXP_VERSION, Size: 5, Number: -1
. 2010-06-23 13:51:56.240 SFTP version 3 negotiated.
. 2010-06-23 13:51:56.240 We believe the server has signed timestamps bug
. 2010-06-23 13:51:56.240 We will use UTF-8 strings for status messages only
. 2010-06-23 13:51:56.240 Limiting packet size to OpenSSH sftp-server limit of 262148 bytes
. 2010-06-23 13:51:56.240 Getting current directory name.
. 2010-06-23 13:51:56.240 Getting real path for '.'
> 2010-06-23 13:51:56.240 Type: SSH_FXP_REALPATH, Size: 10, Number: 16
< 2010-06-23 13:51:56.240 Type: SSH_FXP_NAME, Size: 47, Number: 16
. 2010-06-23 13:51:56.240 Real path is '/home/username'
. 2010-06-23 13:51:56.240 Startup conversation with host finished.
. 2010-06-23 13:51:56.240 Cached directory change via "/stage/jobs/username/QTEST" to "/stage/jobs/username/QTEST".
. 2010-06-23 13:51:56.240 Getting current directory name.
. 2010-06-23 13:51:56.240 Copying 1 files/directories to remote directory "/stage/jobs/username/QTEST"
. 2010-06-23 13:51:56.240 PrTime: No; PrRO: Yes; Rght: rw-r--r--; PrR: No (No); FnCs: N; RIC: 01; Resume: S (102400); CalcS: No; Mask:
. 2010-06-23 13:51:56.240 TM: M; ClAr: No; CPS: 0; ExclM(No):
. 2010-06-23 13:51:56.240 AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2010-06-23 13:51:56.240 File: "upload.zip"
. 2010-06-23 13:51:56.240 Copying "upload.zip" to remote directory started.
. 2010-06-23 13:51:56.240 Binary transfer mode selected.
. 2010-06-23 13:51:56.240 Checking existence of file.
> 2010-06-23 13:51:56.240 Type: SSH_FXP_LSTAT, Size: 45, Number: 263
< 2010-06-23 13:51:56.240 Type: SSH_FXP_ATTRS, Size: 37, Number: 263
. 2010-06-23 13:51:56.240 Checking existence of partially transfered file.
> 2010-06-23 13:51:56.240 Type: SSH_FXP_LSTAT, Size: 54, Number: 519
< 2010-06-23 13:51:56.240 Type: SSH_FXP_ATTRS, Size: 37, Number: 519
. 2010-06-23 13:51:56.240 Resuming file transfer.
. 2010-06-23 13:51:56.240 Opening remote file.
> 2010-06-23 13:51:56.240 Type: SSH_FXP_OPEN, Size: 62, Number: 771
< 2010-06-23 13:51:56.240 Type: SSH_FXP_HANDLE, Size: 13, Number: 771
> 2010-06-23 13:51:56.240 Type: SSH_FXP_WRITE, Size: 4121, Number: 1286
. 2010-06-23 13:51:57.147 403 skipped SSH_FXP_WRITE, SSH_FXP_READ, SSH_FXP_DATA and SSH_FXP_STATUS packets.
> 2010-06-23 13:51:57.147 Type: SSH_FXP_CLOSE, Size: 13, Number: 52996
< 2010-06-23 13:51:57.162 Type: SSH_FXP_STATUS, Size: 24, Number: 52996
< 2010-06-23 13:51:57.162 Status code: 0
* 2010-06-23 13:51:57.162 (ECommand) Copying files to remote side failed.
* 2010-06-23 13:51:57.162 Invalid argument to time encode
