Bugs item #1740263, was opened at 2007-06-20 12:32
Message generated for change (Comment added) made by bagder
You can respond by visiting:
https://sourceforge.net/tracker/?func=detail&atid=100976&aid=1740263&group_id=976

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: http
Group: bad behaviour
Status: Open
Resolution: None
>Priority: 8
Private: No
Submitted By: Adam Piggott (proactivesvcs)
Assigned to: Daniel Stenberg (bagder)
Summary: Efficiency loss in 7.16.2

Initial Comment:
When using config files with lots of URLs (I tested with ~230), cURL seems to be much less efficient since 7.15.5.

Previous version that worked OK:
curl 7.15.5 (i386-pc-win32) libcurl/7.15.5 OpenSSL/0.9.7g zlib/1.2.3
Protocols: tftp ftp telnet dict ldap http file https ftps
Features: Largefile NTLM SSL libz

Current version showing signs of inefficiency:
curl 7.16.2 (i586-pc-mingw32msvc) libcurl/7.16.2 OpenSSL/0.9.7g zlib/1.2.2
Protocols: tftp ftp telnet dict ldap http file https ftps
Features: Largefile NTLM SSL SSPI libz

Config file contents:
--globoff
--url http://192.168.1.1:8080/index.htm
<repeat --url many times>

Using 7.15.5 it took 4 seconds to dispatch 235 HTTP requests to a local HTTP server, using 0.54 seconds of CPU time.

7.16.2 took 30 seconds and 18.8 seconds of CPU time with the same list of URLs.

I found this as I use cURL to dispatch large lists of URLs to a local HTTP filtering proxy, and noticed that using 7.16.2 the request speed gets progressively slower.

----------------------------------------------------------------------

>Comment By: Daniel Stenberg (bagder)
Date: 2007-06-20 23:36

Message:
Logged In: YES
user_id=1110
Originator: NO

I can confirm it and repeat it with the current CVS...

I wrote up two perl scripts for this. The first one (stamdiff.pl) is good
to show relative times in the log:

#!/usr/bin/perl

while(<STDIN>) {
    if(/^(\d\d):(\d\d):(\d\d)\.(\d\d\d\d\d\d) (.*)/) {
        my ($h, $m, $s, $ms, $rest)=($1, $2, $3, $4, $5);
        my $now = $h*3600 + $m+60 + $s + $ms/1000000;

        printf "REL: %.3f %s\n", $now-$prev, $rest;

        $prev = $now;
    }
    else {
        print $_;
    }
}

And the other for running a test with 500 URLs:

#!/usr/bin/perl

$a = sprintf "localhost " x 500;
print "$a\n";

system("curl --trace-time --trace-ascii dump $a");

Then, after having run the script we can see the increasing delta-times
with this simple grep:

./stampdiff.pl < dump | grep Re-using

Using your dumps as input also shows that a fine relative time should be
very small, 0 or 1 millisecond, while the more recent curl versions start
there and then just increase over time...

----------------------------------------------------------------------

Comment By: Adam Piggott (proactivesvcs)
Date: 2007-06-20 18:25

Message:
Logged In: YES
user_id=1611181
Originator: YES

File Added: tracelogs.zip

----------------------------------------------------------------------

Comment By: Adam Piggott (proactivesvcs)
Date: 2007-06-20 18:25

Message:
Logged In: YES
user_id=1611181
Originator: YES

Taking times from each quarter-way though the log files it's evident the
newer version is taking cumulatively longer as time goes on. I've done
these tests on my laptop which is a different OS (Windows XP Pro vs 2000)
and machine, so it seems to rule out the set-up of my desktop machine.
File Added: cURL fetch stats2.txt

----------------------------------------------------------------------

Comment By: Daniel Stenberg (bagder)
Date: 2007-06-20 13:59

Message:
Logged In: YES
user_id=1110
Originator: NO

30 seconds sounds excessive indeed. Did you try -v or --trace-ascii
togetether with --trace-time to see if you can detect what might differ?

I've not seen anyone else report this and I don't know of anything in
particular that would explain this.

----------------------------------------------------------------------

You can respond by visiting:
https://sourceforge.net/tracker/?func=detail&atid=100976&aid=1740263&group_id=976
Received on 2007-06-20