Skip to content

Commit

Permalink
progress: Track total times following redirects
Browse files Browse the repository at this point in the history
Update the progress timers `t_nslookup`, `t_connect`, `t_appconnect`,
`t_pretransfer`, and `t_starttransfer` to track the total times for
these activities when a redirect is followed. Previously, only the times
for the most recent request would be tracked.

As a related change, rename `Curl_pgrsResetTimesSizes` to
`Curl_pgrsResetTransferSizes` now that the function only resets transfer
sizes and no longer modified any of the progress timers.

Added test case 1399.

Fixes #522 and Known Bug 1.8
Reported-by: joshhe
  • Loading branch information
rylwin committed Jun 21, 2017
1 parent 651e04c commit 6d4cac1
Show file tree
Hide file tree
Showing 8 changed files with 135 additions and 19 deletions.
7 changes: 0 additions & 7 deletions docs/KNOWN_BUGS
Expand Up @@ -18,7 +18,6 @@ problems may have been fixed or changed somewhat since this was written!
1.4 multipart formposts file name encoding
1.5 Expect-100 meets 417
1.6 Unnecessary close when 401 received waiting for 100
1.8 DNS timing is wrong for HTTP redirects
1.9 HTTP/2 frames while in the connection pool kill reuse
1.10 Strips trailing dot from host name
1.11 CURLOPT_SEEKFUNCTION not called with CURLFORM_STREAM
Expand Down Expand Up @@ -140,12 +139,6 @@ problems may have been fixed or changed somewhat since this was written!
waiting for the the 100-continue response.
https://curl.haxx.se/mail/lib-2008-08/0462.html

1.8 DNS timing is wrong for HTTP redirects

When extracting timing information after HTTP redirects, only the last
transfer's results are returned and not the totals:
https://github.com/curl/curl/issues/522

1.9 HTTP/2 frames while in the connection pool kill reuse

If the server sends HTTP/2 frames (like for example an HTTP/2 PING frame) to
Expand Down
11 changes: 3 additions & 8 deletions lib/progress.c
Expand Up @@ -149,14 +149,9 @@ int Curl_pgrsDone(struct connectdata *conn)
return 0;
}

/* reset all times except redirect, and reset the known transfer sizes */
void Curl_pgrsResetTimesSizes(struct Curl_easy *data)
/* reset the known transfer sizes */
void Curl_pgrsResetTransferSizes(struct Curl_easy *data)
{
data->progress.t_nslookup = 0;
data->progress.t_connect = 0;
data->progress.t_pretransfer = 0;
data->progress.t_starttransfer = 0;

Curl_pgrsSetDownloadSize(data, -1);
Curl_pgrsSetUploadSize(data, -1);
}
Expand Down Expand Up @@ -208,7 +203,7 @@ void Curl_pgrsTime(struct Curl_easy *data, timerid timer)
time_t us = Curl_tvdiff_us(now, data->progress.t_startsingle);
if(!us)
us++; /* make sure at least one microsecond passed */
*delta = us;
*delta += us;
}
}

Expand Down
2 changes: 1 addition & 1 deletion lib/progress.h
Expand Up @@ -47,7 +47,7 @@ void Curl_pgrsSetUploadSize(struct Curl_easy *data, curl_off_t size);
void Curl_pgrsSetDownloadCounter(struct Curl_easy *data, curl_off_t size);
void Curl_pgrsSetUploadCounter(struct Curl_easy *data, curl_off_t size);
int Curl_pgrsUpdate(struct connectdata *);
void Curl_pgrsResetTimesSizes(struct Curl_easy *data);
void Curl_pgrsResetTransferSizes(struct Curl_easy *data);
void Curl_pgrsTime(struct Curl_easy *data, timerid timer);
long Curl_pgrsLimitWaitTime(curl_off_t cursize,
curl_off_t startsize,
Expand Down
4 changes: 2 additions & 2 deletions lib/transfer.c
Expand Up @@ -1338,7 +1338,7 @@ CURLcode Curl_pretransfer(struct Curl_easy *data)
#endif

Curl_initinfo(data); /* reset session-specific information "variables" */
Curl_pgrsResetTimesSizes(data);
Curl_pgrsResetTransferSizes(data);
Curl_pgrsStartNow(data);

if(data->set.timeout)
Expand Down Expand Up @@ -1820,7 +1820,7 @@ CURLcode Curl_follow(struct Curl_easy *data,
break;
}
Curl_pgrsTime(data, TIMER_REDIRECT);
Curl_pgrsResetTimesSizes(data);
Curl_pgrsResetTransferSizes(data);

return CURLE_OK;
#endif /* CURL_DISABLE_HTTP */
Expand Down
2 changes: 1 addition & 1 deletion tests/data/Makefile.inc
Expand Up @@ -146,7 +146,7 @@ test1364 test1365 test1366 test1367 test1368 test1369 test1370 test1371 \
test1372 test1373 test1374 test1375 test1376 test1377 test1378 test1379 \
test1380 test1381 test1382 test1383 test1384 test1385 test1386 test1387 \
test1388 test1389 test1390 test1391 test1392 test1393 test1394 test1395 \
test1396 test1397 test1398 \
test1396 test1397 test1398 test1399 \
\
test1400 test1401 test1402 test1403 test1404 test1405 test1406 test1407 \
test1408 test1409 test1410 test1411 test1412 test1413 test1414 test1415 \
Expand Down
26 changes: 26 additions & 0 deletions tests/data/test1399
@@ -0,0 +1,26 @@
<testcase>
<info>
<keywords>
unittest
Curl_pgrsTime
</keywords>
</info>

#
# Client-side
<client>
<server>
none
</server>
<features>
unittest
</features>
<name>
Curl_pgrsTime unit tests
</name>
<tool>
unit1399
</tool>
</client>

</testcase>
4 changes: 4 additions & 0 deletions tests/unit/Makefile.inc
Expand Up @@ -7,6 +7,7 @@ UNITFILES = curlcheck.h \
# These are all unit test programs
UNITPROGS = unit1300 unit1301 unit1302 unit1303 unit1304 unit1305 unit1307 \
unit1308 unit1309 unit1330 unit1394 unit1395 unit1396 unit1397 unit1398 \
unit1399 \
unit1600 unit1601 unit1602 unit1603 unit1604 unit1605 unit1606

unit1300_SOURCES = unit1300.c $(UNITFILES)
Expand Down Expand Up @@ -57,6 +58,9 @@ unit1397_CPPFLAGS = $(AM_CPPFLAGS)
unit1398_SOURCES = unit1398.c $(UNITFILES)
unit1398_CPPFLAGS = $(AM_CPPFLAGS)

unit1399_SOURCES = unit1399.c $(UNITFILES)
unit1399_CPPFLAGS = $(AM_CPPFLAGS)

unit1600_SOURCES = unit1600.c $(UNITFILES)
unit1600_CPPFLAGS = $(AM_CPPFLAGS)

Expand Down
98 changes: 98 additions & 0 deletions tests/unit/unit1399.c
@@ -0,0 +1,98 @@
/***************************************************************************
* _ _ ____ _
* Project ___| | | | _ \| |
* / __| | | | |_) | |
* | (__| |_| | _ <| |___
* \___|\___/|_| \_\_____|
*
* Copyright (C) 1998 - 2017, Daniel Stenberg, <daniel@haxx.se>, et al.
*
* This software is licensed as described in the file COPYING, which
* you should have received as part of this distribution. The terms
* are also available at https://curl.haxx.se/docs/copyright.html.
*
* You may opt to use, copy, modify, merge, publish, distribute and/or sell
* copies of the Software, and permit persons to whom the Software is
* furnished to do so, under the terms of the COPYING file.
*
* This software is distributed on an "AS IS" basis, WITHOUT WARRANTY OF ANY
* KIND, either express or implied.
*
***************************************************************************/
#include "curlcheck.h"

#include "urldata.h"
#include "timeval.h"
#include "progress.h"
#include "time.h"

const int usec_magnitude = 1000000;
const int test_execution_time = 500;
int aggregate_timerids[] = {
TIMER_NAMELOOKUP,
TIMER_CONNECT,
TIMER_APPCONNECT,
TIMER_PRETRANSFER,
TIMER_STARTTRANSFER,
};

static bool unit_setup(void)
{
return false;
}

static void unit_stop(void)
{

}

static void complete_aggregate_timed_activities(struct Curl_easy *data)
{
for(unsigned int i = 0; i < sizeof(aggregate_timerids); i++) {
Curl_pgrsTime(data, aggregate_timerids[i]);
}
}

static bool within_seconds(time_t time, int seconds)
{
long diff = (long) (time - (usec_magnitude * seconds));
return labs(diff) < test_execution_time;
}

UNITTEST_START
struct Curl_easy data;
struct timeval now = Curl_tvnow();

/* set the startsingle time to a second ago. This time is used by
* Curl_pgrsTime to calculate how much time the events takes */
data.progress.t_startsingle.tv_sec = now.tv_sec - 1;
data.progress.t_startsingle.tv_usec = now.tv_usec;

/* pretend we've just completed activities */
complete_aggregate_timed_activities(&data);

fail_unless(within_seconds(data.progress.t_nslookup, 1),
"about 1 second should have passed");
fail_unless(within_seconds(data.progress.t_connect, 1),
"about 1 second should have passed");
fail_unless(within_seconds(data.progress.t_appconnect, 1),
"about 1 second should have passed");
fail_unless(within_seconds(data.progress.t_pretransfer, 1),
"about 1 second should have passed");
fail_unless(within_seconds(data.progress.t_starttransfer, 1),
"about 1 second should have passed");

/* pretend we've just completed activities again */
complete_aggregate_timed_activities(&data);

fail_unless(within_seconds(data.progress.t_nslookup, 2),
"about 2 second should have passed");
fail_unless(within_seconds(data.progress.t_connect, 2),
"about 2 second should have passed");
fail_unless(within_seconds(data.progress.t_appconnect, 2),
"about 2 second should have passed");
fail_unless(within_seconds(data.progress.t_pretransfer, 2),
"about 2 second should have passed");
fail_unless(within_seconds(data.progress.t_starttransfer, 2),
"about 2 second should have passed");
UNITTEST_STOP

0 comments on commit 6d4cac1

Please sign in to comment.