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.

Username

Subject

Message body

Font colour:

Font size:

[quote="Anonymous"]Hi,
I'm scripting download of a bunch of files from an SFTP site. When the script runs, it downloads most of the files, but not all - the reason being that PASV is returning the IP of the client that winscp (5.13.2) is being run on, and not the IP of the server.
Here's the script:
option batch on
option confirm off
open ftpes://SITE_AND_PASSWORD_HERE:2010/
cd csavp/outtrans
lcd C:\Users\USER1\AppData\Local\Temp\getfiles
get A037PRD4.ZIP
get A037PED4.ZIP
get A037SRD4.ZIP
get A037SED4.ZIP
get Z_AN2236_181003.CAB
get Z_AN2237_181003.CAB
get Z_AN2238_181003.CAB
get Z_AN2239_181003.CAB
get Z_AN2240_181003.CAB
get Z_AN2241_181003.CAB
get Z_AN2262_181003.CAB
exit
This is the command line used to execute the script:
c:/winscp/winscp.com /script=sftp.txt /log=sftp.log
This is being run on Windows 7.

Here's a snippet of the log file showing that all the files exist (I'll attach the entire log):
[size=9]
. 2018-10-04 08:30:12.850 size=95584;type=file;create=20061011204105;modify=20181003213909; A037PED4.ZIP
. 2018-10-04 08:30:12.850 size=105247;type=file;create=20061011204108;modify=20181003213916; A037PRD4.ZIP
. 2018-10-04 08:30:12.851 size=8097;type=file;create=20061011204110;modify=20181003213920; A037SED4.ZIP
. 2018-10-04 08:30:12.851 size=42836;type=file;create=20061011204112;modify=20181003213924; A037SRD4.ZIP
. 2018-10-04 08:30:12.851 size=4010;type=file;create=20181003011735;modify=20181003000102; Z_AN2236_181003.CAB
. 2018-10-04 08:30:12.852 size=3385;type=file;create=20181003011733;modify=20181003000102; Z_AN2237_181003.CAB
. 2018-10-04 08:30:12.852 size=5912;type=file;create=20181003011755;modify=20181003000103; Z_AN2238_181003.CAB
. 2018-10-04 08:30:12.852 size=2317;type=file;create=20181003011756;modify=20181003000101; Z_AN2239_181003.CAB
. 2018-10-04 08:30:12.852 size=4026;type=file;create=20181003011752;modify=20181003000102; Z_AN2240_181003.CAB
. 2018-10-04 08:30:12.853 size=7922;type=file;create=20181003011706;modify=20181003000108; Z_AN2241_181003.CAB
. 2018-10-04 08:30:12.853 size=3893;type=file;create=20181003011722;modify=20181003000111; Z_AN2262_181003.CAB
[/size]
Here's a snip of the log showing one successful download of A037PED4.ZIP (note I changed the server's IP to 5.5.5.5) and a failed download of A037SRD4.ZIP ( the workstation's IP is 192.168.10.96):
[size=9]
> 2018-10-04 08:30:13.072 Script: get A037PED4.ZIP
. 2018-10-04 08:30:13.072 Listing file "A037PED4.ZIP".
. 2018-10-04 08:30:13.072 Retrieving file information...
> 2018-10-04 08:30:13.072 MLST /csavp/outtrans/A037PED4.ZIP
< 2018-10-04 08:30:13.130 250-MLST listing for /csavp/outtrans/A037PED4.ZIP
< 2018-10-04 08:30:13.130     size=95584;type=file;create=20061011204105;modify=20181003213909; A037PED4.ZIP
< 2018-10-04 08:30:13.130 250 MLST end
. 2018-10-04 08:30:13.130 size=95584;type=file;create=20061011204105;modify=20181003213909; A037PED4.ZIP
. 2018-10-04 08:30:13.130 Retrieving file information successful
. 2018-10-04 08:30:13.131 A037PED4.ZIP;-;95584;2018-10-03T21:39:09.000Z;3;"" [0];"" [0];---------;0
. 2018-10-04 08:30:13.131 Copying 1 files/directories to local directory "C:\Users\USER1\AppData\Local\Temp\getfiles" - total size: 95,584
. 2018-10-04 08:30:13.131   PrTime: Yes; PrRO: No; Rght: rw-r--r--; PrR: No (No); FnCs: N; RIC: 0100; Resume: S (102400); CalcS: No; Mask: 
. 2018-10-04 08:30:13.131   TM: B; ClAr: No; RemEOF: No; RemBOM: No; CPS: 0; NewerOnly: No; InclM: ; ResumeL: 0
. 2018-10-04 08:30:13.131   AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; *.js; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2018-10-04 08:30:13.131 File: '/csavp/outtrans/A037PED4.ZIP' [2018-10-03T21:39:09.000Z] [95584]
. 2018-10-04 08:30:13.131 Copying "/csavp/outtrans/A037PED4.ZIP" to local directory started.
. 2018-10-04 08:30:13.131 Binary transfer mode selected.
. 2018-10-04 08:30:13.132 Starting download of /csavp/outtrans/A037PED4.ZIP
> 2018-10-04 08:30:13.132 CWD /csavp/outtrans
< 2018-10-04 08:30:13.169 250 Command CWD succeed
> 2018-10-04 08:30:13.169 PWD
< 2018-10-04 08:30:13.188 257 "/CSAVP/outtrans" is current directory
> 2018-10-04 08:30:13.188 TYPE A
< 2018-10-04 08:30:13.208 200 Transfer mode set to ASCII
> 2018-10-04 08:30:13.208 PASV
< 2018-10-04 08:30:13.228 227 Entering Passive Mode (5,5,5,5,7,219).
> 2018-10-04 08:30:13.228 MLSD
. 2018-10-04 08:30:13.228 Connecting to 5.5.5.5:2011 ...
< 2018-10-04 08:30:13.268 150 Transferring directory
. 2018-10-04 08:30:13.270 Session ID reused
. 2018-10-04 08:30:13.270 Using TLSv1.2, cipher TLSv1/SSLv3: AES256-GCM-SHA384, 2048 bit RSA, AES256-GCM-SHA384       TLSv1.2 Kx=RSA      Au=RSA  Enc=AESGCM(256) Mac=AEAD
. 2018-10-04 08:30:13.270 TLS connection established
< 2018-10-04 08:30:13.340 226 Transfer completed
. 2018-10-04 08:30:13.356 Data connection closed

FILES ARE LISTED AGAIN HERE...

> 2018-10-04 08:30:13.583 Script: get A037SRD4.ZIP
. 2018-10-04 08:30:13.583 Listing file "A037SRD4.ZIP".
. 2018-10-04 08:30:13.583 Retrieving file information...
> 2018-10-04 08:30:13.583 MLST /csavp/outtrans/A037SRD4.ZIP
< 2018-10-04 08:30:13.672 250-MLST listing for /csavp/outtrans/A037SRD4.ZIP
< 2018-10-04 08:30:13.672     size=42836;type=file;create=20061011204112;modify=20181003213924; A037SRD4.ZIP
< 2018-10-04 08:30:13.672 250 MLST end
. 2018-10-04 08:30:13.672 size=42836;type=file;create=20061011204112;modify=20181003213924; A037SRD4.ZIP
. 2018-10-04 08:30:13.672 Retrieving file information successful
. 2018-10-04 08:30:13.672 A037SRD4.ZIP;-;42836;2018-10-03T21:39:24.000Z;3;"" [0];"" [0];---------;0
. 2018-10-04 08:30:13.673 Copying 1 files/directories to local directory "C:\Users\USER1\AppData\Local\Temp\getfiles" - total size: 42,836
. 2018-10-04 08:30:13.673   PrTime: Yes; PrRO: No; Rght: rw-r--r--; PrR: No (No); FnCs: N; RIC: 0100; Resume: S (102400); CalcS: No; Mask: 
. 2018-10-04 08:30:13.673   TM: B; ClAr: No; RemEOF: No; RemBOM: No; CPS: 0; NewerOnly: No; InclM: ; ResumeL: 0
. 2018-10-04 08:30:13.673   AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; *.js; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2018-10-04 08:30:13.673 File: '/csavp/outtrans/A037SRD4.ZIP' [2018-10-03T21:39:24.000Z] [42836]
. 2018-10-04 08:30:13.673 Copying "/csavp/outtrans/A037SRD4.ZIP" to local directory started.
. 2018-10-04 08:30:13.673 Binary transfer mode selected.
. 2018-10-04 08:30:13.674 Starting download of /csavp/outtrans/A037SRD4.ZIP
> 2018-10-04 08:30:13.674 CWD /csavp/outtrans
< 2018-10-04 08:30:13.723 250 Command CWD succeed
> 2018-10-04 08:30:13.723 PWD
< 2018-10-04 08:30:13.743 257 "/CSAVP/outtrans" is current directory
> 2018-10-04 08:30:13.743 TYPE A
< 2018-10-04 08:30:13.762 200 Transfer mode set to ASCII
> 2018-10-04 08:30:13.762 PASV
[/size]
[b]< 2018-10-04 08:30:13.783 550 Command PASV failed
> 2018-10-04 08:30:13.783 PORT 192,168,10,96,223,144[/b] 
[size=9]
< 2018-10-04 08:30:13.803 550 Command PORT failed
. 2018-10-04 08:30:13.803 Copying files from remote side failed.
* 2018-10-04 08:30:13.803 (ExtException) **Copying files from remote side failed.**
* 2018-10-04 08:30:13.803 Command PORT failed
. 2018-10-04 08:30:13.803 Asking user:
. 2018-10-04 08:30:13.803 Error transferring file '/csavp/outtrans/A037SRD4.ZIP'. ("Copying files from remote side failed.","Command PORT failed")
< 2018-10-04 08:30:13.803 Script: Error transferring file '/csavp/outtrans/A037SRD4.ZIP'.
< 2018-10-04 08:30:13.804 Script: Copying files from remote side failed.

< 2018-10-04 08:30:13.804 Command PORT failed
* 2018-10-04 08:30:13.805 (ESkipFile) Error transferring file '/csavp/outtrans/A037SRD4.ZIP'.
* 2018-10-04 08:30:13.805 Copying files from remote side failed.
* 2018-10-04 08:30:13.805 Command PORT failed
. 2018-10-04 08:30:13.805 Copying finished: Transferred: 0, Elapsed: 0:00:00, CPS: 0/s
. 2018-10-04 08:30:13.805 Script: Failed
[/size]

The next file was OK, then another failure, then OK....  please refer to the log.

So far, on different days, we've had different files fail to download. When I launch winscp.com from a command prompt and download them manually, everything is fine.

Thanks for your help...[/quote]

Options

Disable BBCode in this post

Notify me when a reply is posted (registered users only)

Add an Attachment

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

Filename

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

File Comment

Options

Private file (available to author and site moderators only)

Topic review

rsford31

Re: RE: PASV command sometimes returns IP of client, not server

2019-08-30 15:08

Ahhh...that's what I thought! Thanks Martin!

martin

Re: RE: PASV command sometimes returns IP of client, not server

2019-08-30

rsford31 wrote:

I'm seeing the same thing too in our logs, which I'm trying to understand. So why does PORT send send the client IP address back when PASV fails? The server we're trying to connect to has WS_FTP installed. The explanation from their site on PORT is:

PORT - In PORT mode, the FTP client gives WS_FTP Server an IP address and a TCP port to which WS_FTP Server should connect.
If we're connecting to a WS_FTP server to upload files then why would the WS_FTP server need to connect to us when PASV fails? Or am I confusing the term PORT between what I'm seeing in the logs to the info on WS_FTP? Again, I'm just trying to understand what I'm seeing in the logs. Thank you for your time!

If the passive mode connection (PASV) fails, WinSCP tries the active mode (PORT) - and vice versa.
In the active mode, the server connects to the client.
See https://winscp.net/eng/docs/ftp_modes

rsford31

RE: PASV command sometimes returns IP of client, not server

2019-08-29 19:06

I'm seeing the same thing too in our logs, which I'm trying to understand. So why does PORT send send the client IP address back when PASV fails? The server we're trying to connect to has WS_FTP installed. The explanation from their site on PORT is:

PORT - In PORT mode, the FTP client gives WS_FTP Server an IP address and a TCP port to which WS_FTP Server should connect.

If we're connecting to a WS_FTP server to upload files then why would the WS_FTP server need to connect to us when PASV fails? Or am I confusing the term PORT between what I'm seeing in the logs to the info on WS_FTP? Again, I'm just trying to understand what I'm seeing in the logs. Thank you for your time!

martin

Re: PASV command sometimes returns IP of client, not server

2018-10-05

I do not see PASV returning a wrong IP address anywhere. It's that WinSCP falls back to PORT, as PASV fails. And PORT sends (correctly) client IP address.

The root problem is the failing of PASV. That's a server-side problem. A common cause of this problem is that the server runs out of free passive ports, due to a large number of file transfers. Check FTP server configuration and increase a passive port range, if possible. If that's not possible, you can try decreasing transfer speed on WinSCP side.

Guest

PASV command sometimes returns IP of client, not server

2018-10-04 19:46

Hi,
I'm scripting download of a bunch of files from an SFTP site. When the script runs, it downloads most of the files, but not all - the reason being that PASV is returning the IP of the client that winscp (5.13.2) is being run on, and not the IP of the server.
Here's the script:
option batch on
option confirm off
open ftpes://SITE_AND_PASSWORD_HERE:2010/
cd csavp/outtrans
lcd C:\Users\USER1\AppData\Local\Temp\getfiles
get A037PRD4.ZIP
get A037PED4.ZIP
get A037SRD4.ZIP
get A037SED4.ZIP
get Z_AN2236_181003.CAB
get Z_AN2237_181003.CAB
get Z_AN2238_181003.CAB
get Z_AN2239_181003.CAB
get Z_AN2240_181003.CAB
get Z_AN2241_181003.CAB
get Z_AN2262_181003.CAB
exit
This is the command line used to execute the script:
c:/winscp/winscp.com /script=sftp.txt /log=sftp.log
This is being run on Windows 7.

Here's a snippet of the log file showing that all the files exist (I'll attach the entire log):

. 2018-10-04 08:30:12.850 size=95584;type=file;create=20061011204105;modify=20181003213909; A037PED4.ZIP
. 2018-10-04 08:30:12.850 size=105247;type=file;create=20061011204108;modify=20181003213916; A037PRD4.ZIP
. 2018-10-04 08:30:12.851 size=8097;type=file;create=20061011204110;modify=20181003213920; A037SED4.ZIP
. 2018-10-04 08:30:12.851 size=42836;type=file;create=20061011204112;modify=20181003213924; A037SRD4.ZIP
. 2018-10-04 08:30:12.851 size=4010;type=file;create=20181003011735;modify=20181003000102; Z_AN2236_181003.CAB
. 2018-10-04 08:30:12.852 size=3385;type=file;create=20181003011733;modify=20181003000102; Z_AN2237_181003.CAB
. 2018-10-04 08:30:12.852 size=5912;type=file;create=20181003011755;modify=20181003000103; Z_AN2238_181003.CAB
. 2018-10-04 08:30:12.852 size=2317;type=file;create=20181003011756;modify=20181003000101; Z_AN2239_181003.CAB
. 2018-10-04 08:30:12.852 size=4026;type=file;create=20181003011752;modify=20181003000102; Z_AN2240_181003.CAB
. 2018-10-04 08:30:12.853 size=7922;type=file;create=20181003011706;modify=20181003000108; Z_AN2241_181003.CAB
. 2018-10-04 08:30:12.853 size=3893;type=file;create=20181003011722;modify=20181003000111; Z_AN2262_181003.CAB

Here's a snip of the log showing one successful download of A037PED4.ZIP (note I changed the server's IP to 5.5.5.5) and a failed download of A037SRD4.ZIP ( the workstation's IP is 192.168.10.96):

> 2018-10-04 08:30:13.072 Script: get A037PED4.ZIP
. 2018-10-04 08:30:13.072 Listing file "A037PED4.ZIP".
. 2018-10-04 08:30:13.072 Retrieving file information...
> 2018-10-04 08:30:13.072 MLST /csavp/outtrans/A037PED4.ZIP
< 2018-10-04 08:30:13.130 250-MLST listing for /csavp/outtrans/A037PED4.ZIP
< 2018-10-04 08:30:13.130 size=95584;type=file;create=20061011204105;modify=20181003213909; A037PED4.ZIP
< 2018-10-04 08:30:13.130 250 MLST end
. 2018-10-04 08:30:13.130 size=95584;type=file;create=20061011204105;modify=20181003213909; A037PED4.ZIP
. 2018-10-04 08:30:13.130 Retrieving file information successful
. 2018-10-04 08:30:13.131 A037PED4.ZIP;-;95584;2018-10-03T21:39:09.000Z;3;"" [0];"" [0];---------;0
. 2018-10-04 08:30:13.131 Copying 1 files/directories to local directory "C:\Users\USER1\AppData\Local\Temp\getfiles" - total size: 95,584
. 2018-10-04 08:30:13.131 PrTime: Yes; PrRO: No; Rght: rw-r--r--; PrR: No (No); FnCs: N; RIC: 0100; Resume: S (102400); CalcS: No; Mask:
. 2018-10-04 08:30:13.131 TM: B; ClAr: No; RemEOF: No; RemBOM: No; CPS: 0; NewerOnly: No; InclM: ; ResumeL: 0
. 2018-10-04 08:30:13.131 AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; *.js; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2018-10-04 08:30:13.131 File: '/csavp/outtrans/A037PED4.ZIP' [2018-10-03T21:39:09.000Z] [95584]
. 2018-10-04 08:30:13.131 Copying "/csavp/outtrans/A037PED4.ZIP" to local directory started.
. 2018-10-04 08:30:13.131 Binary transfer mode selected.
. 2018-10-04 08:30:13.132 Starting download of /csavp/outtrans/A037PED4.ZIP
> 2018-10-04 08:30:13.132 CWD /csavp/outtrans
< 2018-10-04 08:30:13.169 250 Command CWD succeed
> 2018-10-04 08:30:13.169 PWD
< 2018-10-04 08:30:13.188 257 "/CSAVP/outtrans" is current directory
> 2018-10-04 08:30:13.188 TYPE A
< 2018-10-04 08:30:13.208 200 Transfer mode set to ASCII
> 2018-10-04 08:30:13.208 PASV
< 2018-10-04 08:30:13.228 227 Entering Passive Mode (5,5,5,5,7,219).
> 2018-10-04 08:30:13.228 MLSD
. 2018-10-04 08:30:13.228 Connecting to 5.5.5.5:2011 ...
< 2018-10-04 08:30:13.268 150 Transferring directory
. 2018-10-04 08:30:13.270 Session ID reused
. 2018-10-04 08:30:13.270 Using TLSv1.2, cipher TLSv1/SSLv3: AES256-GCM-SHA384, 2048 bit RSA, AES256-GCM-SHA384 TLSv1.2 Kx=RSA Au=RSA Enc=AESGCM(256) Mac=AEAD
. 2018-10-04 08:30:13.270 TLS connection established
< 2018-10-04 08:30:13.340 226 Transfer completed
. 2018-10-04 08:30:13.356 Data connection closed

FILES ARE LISTED AGAIN HERE...

> 2018-10-04 08:30:13.583 Script: get A037SRD4.ZIP
. 2018-10-04 08:30:13.583 Listing file "A037SRD4.ZIP".
. 2018-10-04 08:30:13.583 Retrieving file information...
> 2018-10-04 08:30:13.583 MLST /csavp/outtrans/A037SRD4.ZIP
< 2018-10-04 08:30:13.672 250-MLST listing for /csavp/outtrans/A037SRD4.ZIP
< 2018-10-04 08:30:13.672 size=42836;type=file;create=20061011204112;modify=20181003213924; A037SRD4.ZIP
< 2018-10-04 08:30:13.672 250 MLST end
. 2018-10-04 08:30:13.672 size=42836;type=file;create=20061011204112;modify=20181003213924; A037SRD4.ZIP
. 2018-10-04 08:30:13.672 Retrieving file information successful
. 2018-10-04 08:30:13.672 A037SRD4.ZIP;-;42836;2018-10-03T21:39:24.000Z;3;"" [0];"" [0];---------;0
. 2018-10-04 08:30:13.673 Copying 1 files/directories to local directory "C:\Users\USER1\AppData\Local\Temp\getfiles" - total size: 42,836
. 2018-10-04 08:30:13.673 PrTime: Yes; PrRO: No; Rght: rw-r--r--; PrR: No (No); FnCs: N; RIC: 0100; Resume: S (102400); CalcS: No; Mask:
. 2018-10-04 08:30:13.673 TM: B; ClAr: No; RemEOF: No; RemBOM: No; CPS: 0; NewerOnly: No; InclM: ; ResumeL: 0
. 2018-10-04 08:30:13.673 AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; *.js; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2018-10-04 08:30:13.673 File: '/csavp/outtrans/A037SRD4.ZIP' [2018-10-03T21:39:24.000Z] [42836]
. 2018-10-04 08:30:13.673 Copying "/csavp/outtrans/A037SRD4.ZIP" to local directory started.
. 2018-10-04 08:30:13.673 Binary transfer mode selected.
. 2018-10-04 08:30:13.674 Starting download of /csavp/outtrans/A037SRD4.ZIP
> 2018-10-04 08:30:13.674 CWD /csavp/outtrans
< 2018-10-04 08:30:13.723 250 Command CWD succeed
> 2018-10-04 08:30:13.723 PWD
< 2018-10-04 08:30:13.743 257 "/CSAVP/outtrans" is current directory
> 2018-10-04 08:30:13.743 TYPE A
< 2018-10-04 08:30:13.762 200 Transfer mode set to ASCII
> 2018-10-04 08:30:13.762 PASV

< 2018-10-04 08:30:13.783 550 Command PASV failed
> 2018-10-04 08:30:13.783 PORT 192,168,10,96,223,144

< 2018-10-04 08:30:13.803 550 Command PORT failed
. 2018-10-04 08:30:13.803 Copying files from remote side failed.
* 2018-10-04 08:30:13.803 (ExtException) **Copying files from remote side failed.**
* 2018-10-04 08:30:13.803 Command PORT failed
. 2018-10-04 08:30:13.803 Asking user:
. 2018-10-04 08:30:13.803 Error transferring file '/csavp/outtrans/A037SRD4.ZIP'. ("Copying files from remote side failed.","Command PORT failed")
< 2018-10-04 08:30:13.803 Script: Error transferring file '/csavp/outtrans/A037SRD4.ZIP'.
< 2018-10-04 08:30:13.804 Script: Copying files from remote side failed.

< 2018-10-04 08:30:13.804 Command PORT failed
* 2018-10-04 08:30:13.805 (ESkipFile) Error transferring file '/csavp/outtrans/A037SRD4.ZIP'.
* 2018-10-04 08:30:13.805 Copying files from remote side failed.
* 2018-10-04 08:30:13.805 Command PORT failed
. 2018-10-04 08:30:13.805 Copying finished: Transferred: 0, Elapsed: 0:00:00, CPS: 0/s
. 2018-10-04 08:30:13.805 Script: Failed

The next file was OK, then another failure, then OK.... please refer to the log.

So far, on different days, we've had different files fail to download. When I launch winscp.com from a command prompt and download them manually, everything is fine.

Thanks for your help...

Post a reply

Topic review

Re: RE: PASV command sometimes returns IP of client, not server

Re: RE: PASV command sometimes returns IP of client, not server

RE: PASV command sometimes returns IP of client, not server

Re: PASV command sometimes returns IP of client, not server

PASV command sometimes returns IP of client, not server

Documentation

Support

Associations

Follow Us