I'm using winSCP scripting (from Windows schedule task) version 4.2.7 (Build 758) on Window 2003 SP2
It is running every few hours to synchronize my directory with a remote directory using SFTP protocol.
It is usually working fine, but sometimes I see the files in my directory and the file is not copied to the remote directory.
When I then ran the schedule task manually, it did copy the file
Looking at the last day's log I see some different when the file is copied to the times it is not.
I copied below the log lines related to this issue.
The scripting file content is:
# Automatically abort script on errors
option batch abort
# Disable overwrite confirmations that conflict with the previous
option confirm off
# Connect using stored session
open CON1
# Force binary mode transfer
option transfer automatic
# Syncronize //FOLDER1 to remove with delete
synchronize remote "\\ServerNm\....\Foler1" //FOLDER1 -delete
# Syncronize //FOLDER2 to remove with delete
synchronize remote "\\ServerNm\....\Foler2" //FOLDER2 -delete
# Disconnect
close
# Exit WinSCP
exit
------------------------------------------------------------------------------------
when the file was copied:
-----------------------------------------------------------------------------------
. 2012-06-08 08:01:01.723 Changing directory to "/FOLDER1".
. 2012-06-08 08:01:01.723 Getting real path for '/FOLDER1'
> 2012-06-08 08:01:01.739 Type: SSH_FXP_REALPATH, Size: 23, Number: 16
< 2012-06-08 08:01:01.801 Type: SSH_FXP_NAME, Size: 49, Number: 16
. 2012-06-08 08:01:01.801 Real path is '/FOLDER1'
. 2012-06-08 08:01:01.817 Trying to open directory "/FOLDER1".
> 2012-06-08 08:01:01.817 Type: SSH_FXP_LSTAT, Size: 23, Number: 263
< 2012-06-08 08:01:01.880 Type: SSH_FXP_ATTRS, Size: 21, Number: 263
. 2012-06-08 08:01:01.895 Getting current directory name.
. 2012-06-08 08:01:01.895 Startup conversation with host finished.
. 2012-06-08 08:01:01.911 Collecting synchronization list for local directory '\\ServerNm\....\Foler1\' and remote directory '//FOLDER1', mode = 0, params = 3
. 2012-06-08 08:01:01.911 Listing directory "//FOLDER1".
> 2012-06-08 08:01:01.926 Type: SSH_FXP_OPENDIR, Size: 24, Number: 523
< 2012-06-08 08:01:01.989 Type: SSH_FXP_HANDLE, Size: 10, Number: 523
> 2012-06-08 08:01:01.989 Type: SSH_FXP_READDIR, Size: 10, Number: 780
< 2012-06-08 08:01:02.051 Type: SSH_FXP_STATUS, Size: 22, Number: 780
< 2012-06-08 08:01:02.067 Status code: 1
. 2012-06-08 08:01:02.067 Listing file "//FOLDER1..".
> 2012-06-08 08:01:02.067 Type: SSH_FXP_LSTAT, Size: 27, Number: 1031
< 2012-06-08 08:01:02.145 Type: SSH_FXP_ATTRS, Size: 21, Number: 1031
> 2012-06-08 08:01:02.145 Type: SSH_FXP_CLOSE, Size: 10, Number: 1284
. 2012-06-08 08:01:02.145 Synchronizing local directory '\\ServerNm\....\Foler1\\' with remote directory '//FOLDER1', params = 3
. 2012-06-08 08:01:02.161 Copying 1 files/directories to remote directory "//FOLDER1"
. 2012-06-08 08:01:02.161 PrTime: Yes; PrRO: No; Rght: rw-r--r--; PrR: No (No); FnCs: N; RIC: 01; Resume: S (102400); CalcS: No; Mask: *.*
. 2012-06-08 08:01:02.161 TM: M; ClAr: No; CPS: 0; ExclM(No):
. 2012-06-08 08:01:02.176 AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2012-06-08 08:01:02.192 File: "\\ServerNm\....\Foler1\RMSC_Request_20120608.txt"
. 2012-06-08 08:01:02.239 Copying "\\ServerNm\....\Foler1\RMSC_Request_20120608.txt" to remote directory started.
. 2012-06-08 08:01:02.239 Ascii transfer mode selected.
. 2012-06-08 08:01:02.255 Opening remote file.
> 2012-06-08 08:01:02.255 Type: SSH_FXP_OPEN, Size: 66, Number: 1539
< 2012-06-08 08:01:02.270 Type: SSH_FXP_STATUS, Size: 21, Number: 1284
. 2012-06-08 08:01:02.270 Discarding reserved response
< 2012-06-08 08:01:02.333 Type: SSH_FXP_HANDLE, Size: 10, Number: 1539
> 2012-06-08 08:01:02.348 Type: SSH_FXP_WRITE, Size: 4011, Number: 2054
. 2012-06-08 08:03:26.378 687 skipped SSH_FXP_WRITE, SSH_FXP_READ, SSH_FXP_DATA and SSH_FXP_STATUS packets.
> 2012-06-08 08:03:26.393 Type: SSH_FXP_CLOSE, Size: 10, Number: 90372
> 2012-06-08 08:03:26.409 Type: SSH_FXP_SETSTAT, Size: 62, Number: 1801
< 2012-06-08 08:03:26.675 Type: SSH_FXP_STATUS, Size: 21, Number: 89862
< 2012-06-08 08:03:27.565 Type: SSH_FXP_STATUS, Size: 21, Number: 90118
< 2012-06-08 08:03:27.565 Type: SSH_FXP_STATUS, Size: 21, Number: 90372
< 2012-06-08 08:03:27.581 Status code: 0
< 2012-06-08 08:03:27.581 Type: SSH_FXP_STATUS, Size: 21, Number: 1801
< 2012-06-08 08:03:27.596 Status code: 0
. 2012-06-08 08:03:27.612 Collecting synchronization list for local directory '\\ServerNm\....\Foler2' and remote directory '//FOLDER2', mode = 0, params = 3
. 201
------------------------------------------------------------------------------------
when new files don't exists:
------------------------------------------------------------------------------------
. 2012-06-07 10:15:02.468 We believe the server has signed timestamps bug
. 2012-06-07 10:15:02.468 We will use UTF-8 strings for status messages only
. 2012-06-07 10:15:02.484 Changing directory to "/FOLDER1".
. 2012-06-07 10:15:02.484 Getting real path for '/FOLDER1'
> 2012-06-07 10:15:02.484 Type: SSH_FXP_REALPATH, Size: 23, Number: 16
< 2012-06-07 10:15:02.578 Type: SSH_FXP_NAME, Size: 49, Number: 16
. 2012-06-07 10:15:02.578 Real path is '/FOLDER1'
. 2012-06-07 10:15:02.578 Trying to open directory "/FOLDER1".
> 2012-06-07 10:15:02.578 Type: SSH_FXP_LSTAT, Size: 23, Number: 263
< 2012-06-07 10:15:02.687 Type: SSH_FXP_ATTRS, Size: 21, Number: 263
. 2012-06-07 10:15:02.687 Getting current directory name.
. 2012-06-07 10:15:02.703 Startup conversation with host finished.
. 2012-06-07 10:15:02.703 Collecting synchronization list for local directory '\\ServerNm\....\Foler1' and remote directory '//FOLDER1', mode = 0, params = 3
. 2012-06-07 10:15:02.718 Listing directory "//FOLDER1".
> 2012-06-07 10:15:02.718 Type: SSH_FXP_OPENDIR, Size: 24, Number: 523
< 2012-06-07 10:15:02.796 Type: SSH_FXP_HANDLE, Size: 10, Number: 523
> 2012-06-07 10:15:02.796 Type: SSH_FXP_READDIR, Size: 10, Number: 780
< 2012-06-07 10:15:02.875 Type: SSH_FXP_STATUS, Size: 22, Number: 780
< 2012-06-07 10:15:02.875 Status code: 1
. 2012-06-07 10:15:02.875 Listing file "//FOLDER1/..".
------------------------------------------------------------------------------------
when new file exists and the file is not copied:
------------------------------------------------------------------------------------
. 2012-06-08 07:15:02.961 Changing directory to "/FOLDER1".
. 2012-06-08 07:15:02.977 Getting real path for '/FOLDER1'
> 2012-06-08 07:15:02.977 Type: SSH_FXP_REALPATH, Size: 23, Number: 16
< 2012-06-08 07:15:03.055 Type: SSH_FXP_NAME, Size: 49, Number: 16
. 2012-06-08 07:15:03.055 Real path is '/FOLDER1'
. 2012-06-08 07:15:03.070 Trying to open directory "/FOLDER1".
> 2012-06-08 07:15:03.070 Type: SSH_FXP_LSTAT, Size: 23, Number: 263
< 2012-06-08 07:15:03.133 Type: SSH_FXP_ATTRS, Size: 21, Number: 263
. 2012-06-08 07:15:03.148 Getting current directory name.
. 2012-06-08 07:15:03.148 Startup conversation with host finished.
. 2012-06-08 07:15:03.180 Closing connection.
. 2012-06-08 07:15:03.180 Sending special code: 12
. 2012-06-08 07:15:03.180 Sent EOF message