Post a reply

Before posting, please read how to report bug or request support effectively.

Bug reports without an attached log file are usually useless.

Options
Add an Attachment

If you do not want to add an Attachment to your Post, please leave the Fields blank.

(maximum 10 MB; please compress large files; only common media, archive, text and programming file formats are allowed)

Options

Topic review

Jvkpi

martin wrote:

Thanks. Though I have asked for a log with option batch on, not continue.
Also, why do you set option reconnecttime 5? Can you try to remove that?


You'll always see... no problems since 2020-03-24. I am quite sure they will come back and will report asap to provide you with the necessary information.
martin

Thanks. Though I have asked for a log with option batch on, not continue.
Also, why do you set option reconnecttime 5? Can you try to remove that?
Jvkpi

martin wrote:

We need a full log file.
If you post the log as an attachment, you can mark it as private.


Thanks for your help, I really appreciate it. Attached you find an as full as possible logfile.
martin

We need a full log file.
If you post the log as an attachment, you can mark it as private.
Jvkpi

Oh, my bad. When using original option batch on in the script it looks of course:

> 2020-03-18 14:41:29.708 Script: option batch on

< 2020-03-18 14:41:29.708 Script: batch           on       
> 2020-03-18 14:41:29.708 Script: option confirm off
< 2020-03-18 14:41:29.708 Script: confirm         off       
> 2020-03-18 14:41:29.708 Script: option reconnecttime 5
< 2020-03-18 14:41:29.708 Script: reconnecttime   5   


An error runs into:

. 2020-03-18 14:41:32.964 Transfer done: '/aaa/filename.CDX' => 'C:\xxx\aaa\filename.CDX' [279552]

. 2020-03-18 14:41:32.964 File: '/aaa/filename.dbf' [2019-12-11T21:05:16.000Z] [2164328]
. 2020-03-18 14:41:32.964 Copying "/aaa/filename.dbf" to local directory started.
. 2020-03-18 14:41:32.964 Binary transfer mode selected.
. 2020-03-18 14:41:32.964 Starting download of /aaa/filename.dbf
> 2020-03-18 14:41:32.964 TYPE I
< 2020-03-18 14:41:32.980 200 Type set to I
> 2020-03-18 14:41:32.980 PASV
< 2020-03-18 14:41:32.995 421 Could not create socket.
> 2020-03-18 14:41:32.995 PORT xxx
< 2020-03-18 14:41:32.995 200 Port command successful
> 2020-03-18 14:41:32.995 RETR filename.dbf
< 2020-03-18 14:41:33.020 150 Opening data channel for file download from server of "/aaa/filename.dbf"
< 2020-03-18 14:41:43.455 425 Can't open data connection for transfer of "/aaa/filename.dbf"
. 2020-03-18 14:41:43.455 Copying files from remote side failed.
* 2020-03-18 14:41:43.455 (ExtException) **Copying files from remote side failed.**
* 2020-03-18 14:41:43.455 Can't open data connection for transfer of "/aaa/filename.dbf"
. 2020-03-18 14:41:43.455 Asking user:
. 2020-03-18 14:41:43.455 Error transferring file '/aaa/filename.dbf'. ("Copying files from remote side failed.","Can't open data connection for transfer of ""/aaa/filename.dbf""")
< 2020-03-18 14:41:43.455 Script: Error transferring file '/aaa/filename.dbf'.
< 2020-03-18 14:41:43.455 Script: Copying files from remote side failed.

< 2020-03-18 14:41:43.455 Can't open data connection for transfer of "/aaa/filename.dbf"
* 2020-03-18 14:41:43.455 (ESkipFile) Error transferring file '/aaa/filename.dbf'.
* 2020-03-18 14:41:43.455 Copying files from remote side failed.
* 2020-03-18 14:41:43.455 Can't open data connection for transfer of "/aaa/filename.dbf"
. 2020-03-18 14:41:43.455 Script: Failed
> 2020-03-18 14:41:43.455 Script: get COMPLETELYNEWDIRECTORY
Jvkpi

martin wrote:

What version of WinSCP are you using?
Please post a full log file using original option batch on.


Version is 5.15.9 Build 10071

I hope this code is what you were looking for. I cannot send the whole log as it is not anonyimised. Is this the right info?

. 2020-03-18 00:00:04.020 --------------------------------------------------------------------------

. 2020-03-18 00:00:04.020 WinSCP Version 5.15.9 (Build 10071) (OS 10.0.14393 - Windows Server 2016 Datacenter)
. 2020-03-18 00:00:04.020 Configuration: nul
. 2020-03-18 00:00:04.020 Log level: Normal
. 2020-03-18 00:00:04.020 Local account: xxx
. 2020-03-18 00:00:04.020 Working directory: C:\Windows\system32
. 2020-03-18 00:00:04.020 Process ID: 8288
. 2020-03-18 00:00:04.020 Command-line: "C:\Program Files (x86)\WinSCP\WinSCP.exe"  /ini=nul /log="C:\jobs\log\prod-xxx-2020-03.log" /script="C:\jobs\sql\xxx.txt"
. 2020-03-18 00:00:04.020 Time zone: Current: GMT+1, Standard: GMT+1 (W. Europe Standard Time), DST: GMT+2 (W. Europe Daylight Time), DST Start: 3/29/2020, DST End: 10/25/2020
. 2020-03-18 00:00:04.020 Login time: Wednesday, March 18, 2020 12:00:04 AM
. 2020-03-18 00:00:04.020 --------------------------------------------------------------------------
. 2020-03-18 00:00:04.020 Script: Retrospectively logging previous script records:
> 2020-03-18 00:00:04.020 Script: open ftp://xxx/
. 2020-03-18 00:00:04.020 --------------------------------------------------------------------------
. 2020-03-18 00:00:04.020 Session name: xxx@xxx (Ad-Hoc site)
. 2020-03-18 00:00:04.020 Host name: xxx (Port: xxx)
. 2020-03-18 00:00:04.020 User name: xxx(Password: Yes, Key file: No, Passphrase: No)
. 2020-03-18 00:00:04.020 Transfer Protocol: FTP
. 2020-03-18 00:00:04.020 Ping type: Dummy, Ping interval: 30 sec; Timeout: 15 sec
. 2020-03-18 00:00:04.020 Disable Nagle: No
. 2020-03-18 00:00:04.020 Proxy: None
. 2020-03-18 00:00:04.020 Send buffer: 262144
. 2020-03-18 00:00:04.020 UTF: Auto
. 2020-03-18 00:00:04.020 FTPS: None [Client certificate: No]
. 2020-03-18 00:00:04.020 FTP: Passive: Yes [Force IP: Auto]; MLSD: Auto [List all: Auto]; HOST: Auto
. 2020-03-18 00:00:04.020 Local directory: default, Remote directory: home, Update: Yes, Cache: Yes
. 2020-03-18 00:00:04.020 Cache directory changes: Yes, Permanent: Yes
. 2020-03-18 00:00:04.020 Recycle bin: Delete to: No, Overwritten to: No, Bin path:
. 2020-03-18 00:00:04.020 Timezone offset: 0h 0m
. 2020-03-18 00:00:04.020 --------------------------------------------------------------------------
. 2020-03-18 00:00:04.020 Connecting to xxx:xxx ...
. 2020-03-18 00:00:04.035 Connected with xxx:xxx. Waiting for welcome message...
< 2020-03-18 00:00:04.035 220-FileZilla Server 0.9.60 beta
< 2020-03-18 00:00:04.035 220-written by Tim Kosse (tim.kosse@filezilla-project.org)
< 2020-03-18 00:00:04.035 220 Please visit https://filezilla-project.org/
> 2020-03-18 00:00:04.035 USER xxx
< 2020-03-18 00:00:04.051 331 Password required for xxx
> 2020-03-18 00:00:04.051 PASS *********
< 2020-03-18 00:00:04.067 230 Logged on
> 2020-03-18 00:00:04.067 SYST
< 2020-03-18 00:00:04.082 215 UNIX emulated by FileZilla
> 2020-03-18 00:00:04.082 FEAT
< 2020-03-18 00:00:04.098 211-Features:
< 2020-03-18 00:00:04.098  MDTM
< 2020-03-18 00:00:04.098  REST STREAM
< 2020-03-18 00:00:04.098  SIZE
< 2020-03-18 00:00:04.098  MLST type*;size*;modify*;
< 2020-03-18 00:00:04.098  MLSD
< 2020-03-18 00:00:04.098  UTF8
< 2020-03-18 00:00:04.098  CLNT
< 2020-03-18 00:00:04.098  MFMT
< 2020-03-18 00:00:04.098  EPSV
< 2020-03-18 00:00:04.098  EPRT
< 2020-03-18 00:00:04.098 211 End
> 2020-03-18 00:00:04.098 CLNT WinSCP-release-5.15.9
< 2020-03-18 00:00:04.113 200 Don't care
> 2020-03-18 00:00:04.113 OPTS UTF8 ON
< 2020-03-18 00:00:04.113 202 UTF8 mode is always enabled. No need to send this command.
. 2020-03-18 00:00:04.113 Connected
. 2020-03-18 00:00:04.113 --------------------------------------------------------------------------
. 2020-03-18 00:00:04.113 Using FTP protocol.
. 2020-03-18 00:00:04.113 Doing startup conversation with host.
> 2020-03-18 00:00:04.113 PWD
< 2020-03-18 00:00:04.129 257 "/" is current directory.
. 2020-03-18 00:00:04.129 Getting current directory name.
. 2020-03-18 00:00:04.129 Startup conversation with host finished.
< 2020-03-18 00:00:04.129 Script: Active session: [1] xxx@xxx
> 2020-03-18 00:00:04.129 Script: cd /
. 2020-03-18 00:00:04.129 Changing directory to "/".
> 2020-03-18 00:00:04.129 CWD /
< 2020-03-18 00:00:04.145 250 CWD successful. "/" is current directory.
. 2020-03-18 00:00:04.145 Getting current directory name.
> 2020-03-18 00:00:04.145 PWD
< 2020-03-18 00:00:04.160 257 "/" is current directory.
< 2020-03-18 00:00:04.160 Script: /
> 2020-03-18 00:00:04.160 Script: lcd "C:\xxx"
< 2020-03-18 00:00:04.160 Script: C:\xxx
> 2020-03-18 00:00:04.160 Script: option batch continue
< 2020-03-18 00:00:04.160 Script: batch           continue 
> 2020-03-18 00:00:04.160 Script: option confirm off
< 2020-03-18 00:00:04.160 Script: confirm         off       
> 2020-03-18 00:00:04.160 Script: option reconnecttime 5
< 2020-03-18 00:00:04.160 Script: reconnecttime   5         
> 2020-03-18 00:00:04.160 Script: get yyy
. 2020-03-18 00:00:04.160 Listing file "yyy".
. 2020-03-18 00:00:04.160 Retrieving file information...
> 2020-03-18 00:00:04.160 MLST /yyy
< 2020-03-18 00:00:04.176 250-Listing /yyy
< 2020-03-18 00:00:04.176  type=dir;modify=20191016203833; /yyy
< 2020-03-18 00:00:04.176 250 End
. 2020-03-18 00:00:04.176 type=dir;modify=20191016203833; /yyy
. 2020-03-18 00:00:04.176 Retrieving file information successful
. 2020-03-18 00:00:04.176 yyy;D;0;2019-10-16T20:38:33.000Z;3;"" [0];"" [0];---------;0
. 2020-03-18 00:00:04.176 Copying 1 files/directories to local directory "C:\xxx"
. 2020-03-18 00:00:04.176   PrTime: Yes; PrRO: No; Rght: rw-r--r--; PrR: No (No); FnCs: N; RIC: 0100; Resume: S (102400); CalcS: No; Mask:
. 2020-03-18 00:00:04.176   TM: B; ClAr: No; RemEOF: No; RemBOM: No; CPS: 0; NewerOnly: No; EncryptNewFiles: Yes; ExcludeHiddenFiles: No; ExcludeEmptyDirectories: No; InclM: ; ResumeL: 0
. 2020-03-18 00:00:04.176   AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; *.js; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2020-03-18 00:00:04.176 File: '/yyy' [2019-10-16T20:38:33.000Z] [0]
. 2020-03-18 00:00:04.176 Retrieving directory listing...
> 2020-03-18 00:00:04.176 CWD /yyy
< 2020-03-18 00:00:04.176 250 CWD successful. "/yyy" is current directory.
> 2020-03-18 00:00:04.176 PWD
< 2020-03-18 00:00:04.192 257 "/yyy" is current directory.
> 2020-03-18 00:00:04.192 TYPE A
< 2020-03-18 00:00:04.207 200 Type set to A
> 2020-03-18 00:00:04.207 PASV
< 2020-03-18 00:00:04.223 227 Entering Passive Mode (31,160,49,17,238,117)
> 2020-03-18 00:00:04.223 MLSD
. 2020-03-18 00:00:04.223 Connecting to xxx ...
< 2020-03-18 00:00:04.254 150 Opening data channel for directory listing of "/yyy"
. 2020-03-18 00:00:04.254 Data connection closed
< 2020-03-18 00:00:04.254 226 Successfully transferred "/yyy"
. 2020-03-18 00:00:04.254 type=file;modify=20200227161452;size=12180881; zzz.dbf
(...)
. 2020-03-18 00:00:04.254 Directory listing successful
. 2020-03-18 00:00:04.254 ..;D;0;1899-12-30T01:00:00.000Z;0;"" [0];"" [0];---------;0
. 2020-03-18 00:00:04.254 zzz.dbf;-;12180881;2020-02-27T16:14:52.000Z;3;"" [0];"" [0];---------;0
(...)
. 2020-03-18 00:00:04.254 File: '/yyy/zzz.dbf' [2020-02-27T16:14:52.000Z] [12180881]
. 2020-03-18 00:00:04.254 Copying "/yyy/zzz.dbf" to local directory started.
. 2020-03-18 00:00:04.254 Binary transfer mode selected.
. 2020-03-18 00:00:04.254 Starting download of /yyy/zzz.dbf
> 2020-03-18 00:00:04.254 TYPE I
< 2020-03-18 00:00:04.254 200 Type set to I
> 2020-03-18 00:00:04.254 PASV
< 2020-03-18 00:00:04.270 227 Entering Passive Mode (31,160,49,17,248,92)
> 2020-03-18 00:00:04.270 RETR zzz.dbf
. 2020-03-18 00:00:04.270 Connecting to xxx ...
< 2020-03-18 00:00:04.301 150 Opening data channel for file download from server of "/yyy/zzz.dbf"
. 2020-03-18 00:00:05.009 Data connection closed
< 2020-03-18 00:00:05.009 226 Successfully transferred "/yyy/zzz.dbf"
. 2020-03-18 00:00:05.009 Preserving timestamp [2020-02-27T16:14:52.000Z]
. 2020-03-18 00:00:05.009 Download successful
. 2020-03-18 00:00:05.009 Transfer done: '/yyy/zzz.dbf' => 'C:\xxx\yyy\zzz.dbf' [12180881]
. 2020-03-18 00:00:05.009 File: '/yyy/zzz.FPT' [2020-02-27T16:14:56.000Z] [848256]
. 2020-03-18 00:00:05.009 Copying "/yyy/zzz.FPT" to local directory started.
. 2020-03-18 00:00:05.009 Binary transfer mode selected.
martin

What version of WinSCP are you using?
Please post a full log file using original option batch on.
Jvkpi

I just saw I wasn't logged in, but the last message was by me. A soluiton for RETRY would be highly appreciated.
Guest

Thanks for your answer.

In the documentation, it says:

When set to continue any choice prompt is automatically replied with “Skip”, “Ignore” or similar answer.


And when I test it, it does indeed choose SKIP instead of RETRY.

< 2020-03-16 10:26:34.409 Can't open data connection for transfer of "/Y2015/xxx.CDX"

* 2020-03-16 10:26:34.409 (ESkipFile) Error transferring file '/Y2015/xxx.CDX'.
* 2020-03-16 10:26:34.409 Copying files from remote side failed.
* 2020-03-16 10:26:34.409 Can't open data connection for transfer of "/Y2015/xxx.CDX"
. 2020-03-16 10:26:34.409 File: '/Y2015/xxx.DBF' [2019-05-09T10:25:08.000Z] [712]
. 2020-03-16 10:26:34.409 Copying "/Y2015/xxx.DBF" to local directory started.
. 2020-03-16 10:26:34.409 Binary transfer mode selected.
. 2020-03-16 10:26:34.409 Starting download of /Y2015/xxx.DBF


This means it does continue within the same directory, but the file itself is still missing.
martin

Re: Retry on Error - in script

Try:

option batch continue
Jvkpi

Retry on Error - in script

I have this winscp script:

open ftp://someplace/
 
cd /
lcd "C:\somefolder\"
 
option batch on
option confirm off
option reconnecttime 5
 
get Y2019
get Y2020
 
exit


It gets multiple folders. However, when one file transfer in a certain folder fails for some connection reason, it stops the whole folder and continues to the next.

. 2020-03-10 00:10:20.752 File: '/Y2019/xxx.FPT' [2020-02-21T15:53:13.000Z] [0000000]

. 2020-03-10 00:10:20.752 Copying "/Y2019/xxx.FPT" to local directory started.
. 2020-03-10 00:10:20.752 Binary transfer mode selected.
. 2020-03-10 00:10:20.752 Starting download of /Y2019/xxx.FPT
> 2020-03-10 00:10:20.752 TYPE I
< 2020-03-10 00:10:20.768 200 Type set to I
> 2020-03-10 00:10:20.768 PASV
< 2020-03-10 00:10:20.783 421 Could not create socket.
> 2020-03-10 00:10:20.783 PORT xxx
< 2020-03-10 00:10:20.799 200 Port command successful
> 2020-03-10 00:10:20.799 RETR xxx.FPT
< 2020-03-10 00:10:20.815 150 Opening data channel for file download from server of "/Y2019/xxx.FPT"
< 2020-03-10 00:10:31.407 425 Can't open data connection for transfer of "/Y2019/xxx.FPT"
. 2020-03-10 00:10:31.407 Copying files from remote side failed.
* 2020-03-10 00:10:31.407 (ExtException) **Copying files from remote side failed.**
* 2020-03-10 00:10:31.407 Can't open data connection for transfer of "/Y2019/xxx.FPT"
. 2020-03-10 00:10:31.407 Asking user:
. 2020-03-10 00:10:31.407 Error transferring file '/Y2019/xxx.FPT'. ("Copying files from remote side failed.","Can't open data connection for transfer of ""/Y2019/xxx.FPT""")
< 2020-03-10 00:10:31.407 Script: Error transferring file '/Y2019/xxx.FPT'.
< 2020-03-10 00:10:31.407 Script: Copying files from remote side failed.

< 2020-03-10 00:10:31.407 Can't open data connection for transfer of "/Y2019/xxx.FPT"
* 2020-03-10 00:10:31.407 (ESkipFile) Error transferring file '/Y2019/xxx.FPT'.
* 2020-03-10 00:10:31.407 Copying files from remote side failed.
* 2020-03-10 00:10:31.407 Can't open data connection for transfer of "/Y2019/xxx.FPT"
. 2020-03-10 00:10:31.407 Script: Failed
> 2020-03-10 00:10:31.407 Script: get Y2020
. 2020-03-10 00:10:31.407 Listing file "Y2020".
. 2020-03-10 00:10:31.407 Retrieving file information...
> 2020-03-10 00:10:31.407 MLST /Y2020
< 2020-03-10 00:10:31.423 250-Listing /Y2020
< 2020-03-10 00:10:31.423  type=dir;modify=20200114213117; /Y2020
< 2020-03-10 00:10:31.423 250 End
. 2020-03-10 00:10:31.423 type=dir;modify=20200114213117; /Y2020
. 2020-03-10 00:10:31.423 Retrieving file information successful


Is there any way to retry a certain file and continue in the same folder? Like clicking RETRY on the error in de GUI? There's no persistent connection problem and the transfer always works on 2nd try. Thanks in advance.