Topic "Lots of timeouts while uploading multiple files"

Author Message
andresp
[View user's profile]

Joined: 2014-11-08
Posts: 4
I've created a script to automate the process of updating my Drupal installation. This update process includes the upload of several Drupal files. Till now I've done this manually with FileZilla without any problem, but in order to automate the process I've mode on to WinSCP.

The problem that I'm facing now is that I'm getting lots of connection timeouts. I'm only able to upload something like 10 consecutive files without getting a connection timeout.

I've already tried to increase the timeout and force the passive mode, but the problem is still there.

Example:

Code:
C:\...\includes\cache.inc |            0 B |    6.1 KiB/s | binary |   0%
Lost connection.
Timeout detected.
Copying files to remote side failed.
(A)bort, (R)econnect (0 s): Reconnect
Connecting to ftp.sobreira.net ...
Connected with ftp.sobreira.net. Waiting for welcome message...
Connected
Starting the session...
Reading remote directory...
Session started.
C:\...\includes\cache.inc |         19 KiB |   16.9 KiB/s | binary | 100%



This happens continuously...

Here is the relevant log part:

Quote:
. 2014-11-08 15:35:35.555 File: 'C:\site\drupal_updater\new_drupal\includes\cache.inc' [2014-11-07T15:25:27.000Z] [20429]
. 2014-11-08 15:35:35.555 Copying "C:\site\drupal_updater\new_drupal\includes\cache.inc" to remote directory started.
. 2014-11-08 15:35:35.555 Binary transfer mode selected.
. 2014-11-08 15:35:35.555 Starting upload of C:\site\drupal_updater\new_drupal\includes\cache.inc
> 2014-11-08 15:35:35.555 TYPE I
< 2014-11-08 15:35:35.571 200 TYPE is now 8-bit binary
> 2014-11-08 15:35:35.571 PASV
< 2014-11-08 15:35:35.587 227 Entering Passive Mode (185,32,189,200,225,25)
> 2014-11-08 15:35:35.587 STOR cache.inc
. 2014-11-08 15:36:05.975 Timeout detected.
. 2014-11-08 15:36:05.975 Copying files to remote side failed.
. 2014-11-08 15:36:05.975 Connection was lost, asking what to do.
. 2014-11-08 15:36:05.975 Asking user:
. 2014-11-08 15:36:05.975 Lost connection. ("Timeout detected.","Copying files to remote side failed.")
< 2014-11-08 15:36:05.975 Script: Lost connection.
< 2014-11-08 15:36:05.975 Script: Timeout detected.

< 2014-11-08 15:36:05.975 Copying files to remote side failed.
< 2014-11-08 15:36:12.215 Script: Connecting to ftp.sobreira.net ...
. 2014-11-08 15:36:12.215 Connecting to ftp.sobreira.net ...
< 2014-11-08 15:36:12.247 Script: Connected with ftp.sobreira.net. Waiting for welcome message...
. 2014-11-08 15:36:12.247 Connected with ftp.sobreira.net. Waiting for welcome message...
< 2014-11-08 15:36:12.262 220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------
< 2014-11-08 15:36:12.262 220-You are user number 1 of 50 allowed.
< 2014-11-08 15:36:12.262 220-Local time is now 16:36. Server port: 21.
< 2014-11-08 15:36:12.262 220-This is a private system - No anonymous login
< 2014-11-08 15:36:12.262 220-IPv6 connections are also welcome on this server.
< 2014-11-08 15:36:12.262 220 You will be disconnected after 15 minutes of inactivity.
> 2014-11-08 15:36:12.262 USER sobreira
< 2014-11-08 15:36:12.278 331 User sobreira OK. Password required
> 2014-11-08 15:36:12.278 PASS **********
< 2014-11-08 15:36:12.340 230 OK. Current restricted directory is /
> 2014-11-08 15:36:12.340 SYST
< 2014-11-08 15:36:12.340 215 UNIX Type: L8
> 2014-11-08 15:36:12.356 FEAT
< 2014-11-08 15:36:12.356 211-Extensions supported:
< 2014-11-08 15:36:12.356 EPRT
< 2014-11-08 15:36:12.356 IDLE
< 2014-11-08 15:36:12.371 MDTM
< 2014-11-08 15:36:12.371 SIZE
< 2014-11-08 15:36:12.371 MFMT
< 2014-11-08 15:36:12.371 REST STREAM
< 2014-11-08 15:36:12.371 MLST type*;size*;sizd*;modify*;UNIX.mode*;UNIX.uid*;UNIX.gid*;unique*;
< 2014-11-08 15:36:12.371 MLSD
< 2014-11-08 15:36:12.371 AUTH TLS
< 2014-11-08 15:36:12.371 PBSZ
< 2014-11-08 15:36:12.371 PROT
< 2014-11-08 15:36:12.371 TVFS
< 2014-11-08 15:36:12.371 ESTA
< 2014-11-08 15:36:12.371 PASV
< 2014-11-08 15:36:12.371 EPSV
< 2014-11-08 15:36:12.371 SPSV
< 2014-11-08 15:36:12.371 ESTP
< 2014-11-08 15:36:12.371 211 End.
< 2014-11-08 15:36:12.371 Script: Connected
. 2014-11-08 15:36:12.371 Connected
. 2014-11-08 15:36:12.371 Doing startup conversation with host.
< 2014-11-08 15:36:12.371 Script: Starting the session...
> 2014-11-08 15:36:12.371 PWD
< 2014-11-08 15:36:12.387 257 "/" is your current location
< 2014-11-08 15:36:12.387 Script: Reading remote directory...
. 2014-11-08 15:36:12.387 Changing directory to "/public_html".
> 2014-11-08 15:36:12.387 CWD /public_html
< 2014-11-08 15:36:12.403 250 OK. Current directory is /public_html
. 2014-11-08 15:36:12.403 Getting current directory name.
> 2014-11-08 15:36:12.403 PWD
< 2014-11-08 15:36:12.418 257 "/public_html" is your current location
. 2014-11-08 15:36:12.418 Startup conversation with host finished.
< 2014-11-08 15:36:12.418 Script: Session started.
. 2014-11-08 15:36:12.418 File: 'C:\site\drupal_updater\new_drupal\includes\cache.inc' [2014-11-07T15:25:27.000Z] [20429]
. 2014-11-08 15:36:12.418 Copying "C:\site\drupal_updater\new_drupal\includes\cache.inc" to remote directory started.
. 2014-11-08 15:36:12.418 Binary transfer mode selected.
. 2014-11-08 15:36:12.418 Starting upload of C:\site\drupal_updater\new_drupal\includes\cache.inc
> 2014-11-08 15:36:12.418 CWD /public_html/includes/
< 2014-11-08 15:36:12.449 250 OK. Current directory is /public_html/includes
> 2014-11-08 15:36:12.449 PWD
< 2014-11-08 15:36:12.449 257 "/public_html/includes" is your current location
> 2014-11-08 15:36:12.449 TYPE A
< 2014-11-08 15:36:12.481 200 TYPE is now ASCII
> 2014-11-08 15:36:12.481 PASV
< 2014-11-08 15:36:12.481 227 Entering Passive Mode (185,32,189,200,76,125)
> 2014-11-08 15:36:12.496 MLSD
< 2014-11-08 15:36:12.527 150 Accepted data connection
< 2014-11-08 15:36:12.527 226-Options: -a -l
< 2014-11-08 15:36:12.527 226 11 matches total
. 2014-11-08 15:36:12.527 type=cdir;sizd=4096;modify=20141108153534;UNIX.mode=0755;UNIX.uid=1184;UNIX.gid=1185;unique=805g2781d32; .
. 2014-11-08 15:36:12.527 type=pdir;sizd=4096;modify=20141108153530;UNIX.mode=0750;UNIX.uid=1184;UNIX.gid=99;unique=805g15c79b4; ..
. 2014-11-08 15:36:12.527 type=file;size=13816;modify=20141107152527;UNIX.mode=0644;UNIX.uid=1184;UNIX.gid=1185;unique=805g2781d3a; actions.inc
. 2014-11-08 15:36:12.527 type=file;size=49242;modify=20141107152527;UNIX.mode=0644;UNIX.uid=1184;UNIX.gid=1185;unique=805g27834c4; ajax.inc
. 2014-11-08 15:36:12.527 type=file;size=1701;modify=20141107152527;UNIX.mode=0644;UNIX.uid=1184;UNIX.gid=1185;unique=805g2784b35; archiver.inc
. 2014-11-08 15:36:12.527 type=file;size=13664;modify=20141107152527;UNIX.mode=0644;UNIX.uid=1184;UNIX.gid=1185;unique=805g2784b36; authorize.inc
. 2014-11-08 15:36:12.527 type=file;size=17497;modify=20141107152527;UNIX.mode=0644;UNIX.uid=1184;UNIX.gid=1185;unique=805g2784b37; batch.inc
. 2014-11-08 15:36:12.527 type=file;size=2310;modify=20141107152527;UNIX.mode=0644;UNIX.uid=1184;UNIX.gid=1185;unique=805g2784b38; batch.queue.inc
. 2014-11-08 15:36:12.527 type=file;size=120417;modify=20141107152527;UNIX.mode=0644;UNIX.uid=1184;UNIX.gid=1185;unique=805g2784b3a; bootstrap.inc
. 2014-11-08 15:36:12.527 type=file;size=2487;modify=20141107152527;UNIX.mode=0644;UNIX.uid=1184;UNIX.gid=1185;unique=805g2784b3c; cache-install.inc
. 2014-11-08 15:36:12.527 type=file;size=0;modify=20141108153534;UNIX.mode=0644;UNIX.uid=1184;UNIX.gid=1185;unique=805g2784b3d; cache.inc
> 2014-11-08 15:36:12.527 TYPE I
< 2014-11-08 15:36:12.559 200 TYPE is now 8-bit binary
> 2014-11-08 15:36:12.559 PASV
< 2014-11-08 15:36:12.574 227 Entering Passive Mode (185,32,189,200,150,30)
> 2014-11-08 15:36:12.574 STOR cache.inc
< 2014-11-08 15:36:12.605 150 Accepted data connection
< 2014-11-08 15:36:12.824 226-File successfully transferred
< 2014-11-08 15:36:12.824 226 0.211 seconds (measured here), 94.50 Kbytes per second
> 2014-11-08 15:36:12.824 MFMT 20141107152527 cache.inc
< 2014-11-08 15:36:12.839 213 UTIME OK
. 2014-11-08 15:36:12.839 Upload successful


Any idea of what can I do to fix this problem?
Advertisements
martin
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 24530
Location: Prague, Czechia
Can you attach a complete log file from WinSCP and FileZilla?
_________________
Martin Prikryl
andresp
[View user's profile]

Joined: 2014-11-08
Posts: 4
There you go. I didn't let them run till the end of the Drupal upload but there was enough time for WinSCP to start timing out.
WinSCP.log (329.23 KB) Private file

Description: WinSCP log

filezilla.log (76.27 KB) Private file

Description: Filezilla log

martin
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 24530
Location: Prague, Czechia
Thanks.
I have sent you an email with a debug version of WinSCP to address you have used to register on this forum.
_________________
Martin Prikryl
andresp
[View user's profile]

Joined: 2014-11-08
Posts: 4
Hi Martin,

were you able to find anything useful from the logs I've sent you?

André
martin
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 24530
Location: Prague, Czechia
I have responded you via email meanwhile.
_________________
Martin Prikryl
Advertisements

You can post new topics in this forum






Search Site

What is WinSCP?

It is award-winning SFTP client, SCP client, FTPS client and FTP client integrated into one software program for file transfer to FTP server or secure SFTP server. [More]

And it's free!

Donate

About donations

$9   $19   $49   $99

About donations

Recommend

WinSCP Privacy Policy

WinSCP License