mirror/curl
2
0
Fork 0
mirror of https://github.com/curl/curl.git synced 2025-02-17 14:59:45 +08:00
Code Issues Packages Projects Releases Wiki Activity

connect: fix strategy testing for attempts, timeouts and happy-eyeball

Browse Source 
- add test2600 as a unit test that triggers various connect conditions
  and monitors behaviour, available in a debug build only.

- this exposed edge cases in connect.c that have been fixed

Closes #10312
This commit is contained in:
Stefan Eissing 2023-01-17 15:58:49 +01:00 committed by Daniel Stenberg
parent 5651a36d1a
commit d55de24dce
No known key found for this signature in database
GPG Key ID: 5CC908FDB71E12C2
7 changed files with 452 additions and 32 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

90
lib/connect.c
View File

@ -352,7 +352,8 @@ struct eyeballer {
struct Curl_cfilter *cf; /* current sub-cfilter connecting */
struct eyeballer *primary; /* eyeballer this one is backup for */
timediff_t delay_ms; /* delay until start */
timediff_t timeoutms; /* timeout for all tries */
struct curltime started; /* start of current attempt */
timediff_t timeoutms; /* timeout for current attempt */
expire_id timeout_id; /* ID for Curl_expire() */
CURLcode result;
int error;
@ -463,7 +464,7 @@ static void baller_initiate(struct Curl_cfilter *cf,
wcf->sockindex = cf->sockindex;
}
if(cf->conn->num_addr > 1) {
if(baller->addr && baller->addr->ai_next) {
Curl_expire(data, baller->timeoutms, baller->timeout_id);
}
@ -485,13 +486,17 @@ out:
*/
static CURLcode baller_start(struct Curl_cfilter *cf,
struct Curl_easy *data,
struct eyeballer *baller)
struct eyeballer *baller,
timediff_t timeoutms)
{
baller->error = 0;
baller->connected = FALSE;
baller->has_started = TRUE;
while(baller->addr) {
baller->started = Curl_now();
baller->timeoutms = (baller->addr->ai_next == NULL) ?
timeoutms : timeoutms / 2;
baller_initiate(cf, data, baller);
if(!baller->result)
break;
@ -508,11 +513,12 @@ static CURLcode baller_start(struct Curl_cfilter *cf,
more address exists or error */
static CURLcode baller_start_next(struct Curl_cfilter *cf,
struct Curl_easy *data,
struct eyeballer *baller)
struct eyeballer *baller,
timediff_t timeoutms)
{
if(cf->sockindex == FIRSTSOCKET) {
baller_next_addr(baller);
baller_start(cf, data, baller);
baller_start(cf, data, baller, timeoutms);
}
else {
baller->error = 0;
@ -530,8 +536,7 @@ static CURLcode baller_connect(struct Curl_cfilter *cf,
struct curltime *now,
bool *connected)
{
struct cf_he_ctx *ctx = cf->ctx;
(void)cf;
*connected = baller->connected;
if(!baller->result && !*connected) {
/* evaluate again */
@ -542,14 +547,13 @@ static CURLcode baller_connect(struct Curl_cfilter *cf,
baller->connected = TRUE;
baller->is_done = TRUE;
}
else if(Curl_timediff(*now, ctx->started) >= baller->timeoutms) {
else if(Curl_timediff(*now, baller->started) >= baller->timeoutms) {
infof(data, "%s connect timeout after %" CURL_FORMAT_TIMEDIFF_T
"ms, move on!", baller->name, baller->timeoutms);
#if defined(ETIMEDOUT)
baller->error = ETIMEDOUT;
#endif
baller->result = CURLE_OPERATION_TIMEDOUT;
baller->is_done = TRUE;
}
}
}
@ -566,7 +570,6 @@ static CURLcode is_connected(struct Curl_cfilter *cf,
struct cf_he_ctx *ctx = cf->ctx;
struct connectdata *conn = cf->conn;
CURLcode result;
timediff_t allow;
struct curltime now;
size_t i;
int ongoing, not_started;
@ -613,9 +616,7 @@ evaluate:
data->state.os_errno = baller->error;
SET_SOCKERRNO(baller->error);
}
allow = Curl_timeleft(data, &now, TRUE);
baller->timeoutms = baller->addr->ai_next == NULL ? allow : allow / 2;
baller_start_next(cf, data, baller);
baller_start_next(cf, data, baller, Curl_timeleft(data, &now, TRUE));
if(baller->is_done) {
DEBUGF(LOG_CF(data, cf, "%s done", baller->name));
}
@ -632,9 +633,9 @@ evaluate:
return CURLE_OK;
}
/* Nothing connected, have we timed out completely yet? */
allow = Curl_timeleft(data, &now, TRUE);
if(allow < 0) {
/* Nothing connected, check the time before we might
* start new ballers or return ok. */
if((ongoing || not_started) && Curl_timeleft(data, &now, TRUE) < 0) {
failf(data, "Connection timeout after %ld ms",
Curl_timediff(now, data->progress.t_startsingle));
return CURLE_OPERATION_TIMEDOUT;
@ -653,7 +654,7 @@ evaluate:
* its start delay_ms have expired */
if((baller->primary && baller->primary->is_done) ||
Curl_timediff(now, ctx->started) >= baller->delay_ms) {
baller_start(cf, data, baller);
baller_start(cf, data, baller, Curl_timeleft(data, &now, TRUE));
if(baller->is_done) {
DEBUGF(LOG_CF(data, cf, "%s done", baller->name));
}
@ -740,7 +741,6 @@ static CURLcode start_connect(struct Curl_cfilter *cf,
}
ctx->started = Curl_now();
conn->num_addr = Curl_num_addresses(remotehost->addr);
/* remotehost->addr is the list of addresses from the resolver, each
* with an address family. The list has at least one entry, possibly
@ -1010,23 +1010,51 @@ out:
return result;
}
struct transport_provider {
int transport;
cf_ip_connect_create *cf_create;
};
static
#ifndef DEBUGBUILD
const
#endif
struct transport_provider transport_providers[] = {
{ TRNSPRT_TCP, Curl_cf_tcp_create },
#ifdef ENABLE_QUIC
{ TRNSPRT_QUIC, Curl_cf_quic_create },
#endif
{ TRNSPRT_UDP, Curl_cf_udp_create },
{ TRNSPRT_UNIX, Curl_cf_unix_create },
};
#ifndef ARRAYSIZE
#define ARRAYSIZE(A) (sizeof(A)/sizeof((A)[0]))
#endif
static cf_ip_connect_create *get_cf_create(int transport)
{
switch(transport) {
case TRNSPRT_TCP:
return Curl_cf_tcp_create;
case TRNSPRT_UDP:
return Curl_cf_udp_create;
case TRNSPRT_UNIX:
return Curl_cf_unix_create;
#ifdef ENABLE_QUIC
case TRNSPRT_QUIC:
return Curl_cf_quic_create;
#endif
default:
return NULL;
size_t i;
for(i = 0; i < ARRAYSIZE(transport_providers); ++i) {
if(transport == transport_providers[i].transport)
return transport_providers[i].cf_create;
}
return NULL;
}
#ifdef DEBUGBUILD
void Curl_debug_set_transport_provider(int transport,
cf_ip_connect_create *cf_create)
{
size_t i;
for(i = 0; i < ARRAYSIZE(transport_providers); ++i) {
if(transport == transport_providers[i].transport) {
transport_providers[i].cf_create = cf_create;
return;
}
}
}
#endif /* DEBUGBUILD */
static CURLcode cf_he_insert_after(struct Curl_cfilter *cf_at,
struct Curl_easy *data,

5
lib/connect.h
View File

@ -135,4 +135,9 @@ CURLcode Curl_conn_setup(struct Curl_easy *data,
extern struct Curl_cftype Curl_cft_happy_eyeballs;
extern struct Curl_cftype Curl_cft_setup;
#ifdef DEBUGBUILD
void Curl_debug_set_transport_provider(int transport,
cf_ip_connect_create *cf_create);
#endif
#endif /* HEADER_CURL_CONNECT_H */

1
lib/urldata.h
View File

@ -1038,7 +1038,6 @@ struct connectdata {
int socks5_gssapi_enctype;
#endif
/* The field below gets set in connect.c:connecthost() */
int num_addr; /* number of addresses to try to connect to */
int port; /* which port to use locally - to connect to */
int remote_port; /* the remote port, not the proxy port! */
int conn_to_port; /* the remote port to connect to. valid only if

2
tests/data/Makefile.inc
View File

@ -248,6 +248,8 @@ test2400 test2401 test2402 \
\
test2500 test2501 test2502 \
\
test2600 \
\
test3000 test3001 test3002 test3003 test3004 test3005 test3006 test3007 \
test3008 test3009 test3010 test3011 test3012 test3013 test3014 test3015 \
test3016 test3017 test3018 test3019 test3020 test3021 test3022 test3023 \

24
tests/data/test2600 Normal file
View File

@ -0,0 +1,24 @@
<testcase>
<info>
<keywords>
unittest
llist
</keywords>
</info>
#
# Client-side
<client>
<server>
none
</server>
<features>
unittest
debug
http
</features>
<name>
llist unit tests
</name>
</client>
</testcase>

4
tests/unit/Makefile.inc
View File

@ -38,6 +38,7 @@ UNITPROGS = unit1300 unit1302 unit1303 unit1304 unit1305 unit1307 \
unit1620 unit1621 \
unit1650 unit1651 unit1652 unit1653 unit1654 unit1655 \
unit1660 unit1661 \
unit2600 \
unit3200
unit1300_SOURCES = unit1300.c $(UNITFILES)
@ -164,5 +165,8 @@ unit1660_CPPFLAGS = $(AM_CPPFLAGS)
unit1661_SOURCES = unit1661.c $(UNITFILES)
unit1661_CPPFLAGS = $(AM_CPPFLAGS)
unit2600_SOURCES = unit2600.c $(UNITFILES)
unit2600_CPPFLAGS = $(AM_CPPFLAGS)
unit3200_SOURCES = unit3200.c $(UNITFILES)
unit3200_CPPFLAGS = $(AM_CPPFLAGS)

358
tests/unit/unit2600.c Normal file
View File

@ -0,0 +1,358 @@
/***************************************************************************
* _ _ ____ _
* Project ___| | | | _ \| |
* / __| | | | |_) | |
* | (__| |_| | _ <| |___
* \___|\___/|_| \_\_____|
*
* Copyright (C) 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.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.
*
* SPDX-License-Identifier: curl
*
***************************************************************************/
#include "curlcheck.h"
#include "urldata.h"
#include "connect.h"
#include "cfilters.h"
#include "curl_log.h"
static CURL *easy;
static CURLcode unit_setup(void)
{
CURLcode res = CURLE_OK;
global_init(CURL_GLOBAL_ALL);
easy = curl_easy_init();
if(!easy) {
curl_global_cleanup();
return CURLE_OUT_OF_MEMORY;
}
curl_easy_setopt(easy, CURLOPT_VERBOSE, 1L);
return res;
}
static void unit_stop(void)
{
curl_easy_cleanup(easy);
curl_global_cleanup();
}
#ifdef DEBUGBUILD
struct test_case {
int id;
const char *url;
const char *resolve_info;
timediff_t connect_timeout_ms;
timediff_t he_timeout_ms;
timediff_t cf4_fail_delay_ms;
timediff_t cf6_fail_delay_ms;
int exp_cf4_creations;
int exp_cf6_creations;
timediff_t min_duration_ms;
timediff_t max_duration_ms;
CURLcode exp_result;
const char *pref_family;
};
struct ai_family_stats {
const char *family;
int creations;
timediff_t first_created;
timediff_t last_created;
};
struct test_result {
CURLcode result;
struct curltime started;
struct curltime ended;
struct ai_family_stats cf4;
struct ai_family_stats cf6;
};
static struct test_case *current_tc;
static struct test_result *current_tr;
struct cf_test_ctx {
int ai_family;
char id[16];
struct curltime started;
timediff_t fail_delay_ms;
struct ai_family_stats *stats;
};
static void cf_test_destroy(struct Curl_cfilter *cf, struct Curl_easy *data)
{
struct cf_test_ctx *ctx = cf->ctx;
infof(data, "%04dms: cf[%s] destroyed",
(int)Curl_timediff(Curl_now(), current_tr->started), ctx->id);
free(ctx);
cf->ctx = NULL;
}
static CURLcode cf_test_connect(struct Curl_cfilter *cf,
struct Curl_easy *data,
bool blocking, bool *done)
{
struct cf_test_ctx *ctx = cf->ctx;
struct curltime now;
(void)data;
(void)blocking;
*done = FALSE;
now = Curl_now();
if(Curl_timediff(now, ctx->started) >= ctx->fail_delay_ms) {
infof(data, "%04dms: cf[%s] fail delay reached",
(int)Curl_timediff(Curl_now(), current_tr->started), ctx->id);
return CURLE_COULDNT_CONNECT;
}
infof(data, "%04dms: cf[%s] continuing",
(int)Curl_timediff(Curl_now(), current_tr->started), ctx->id);
return CURLE_OK;
}
static struct Curl_cftype cft_test = {
"TEST",
CF_TYPE_IP_CONNECT,
CURL_LOG_DEFAULT,
cf_test_destroy,
cf_test_connect,
Curl_cf_def_close,
Curl_cf_def_get_host,
Curl_cf_def_get_select_socks,
Curl_cf_def_data_pending,
Curl_cf_def_send,
Curl_cf_def_recv,
Curl_cf_def_cntrl,
Curl_cf_def_conn_is_alive,
Curl_cf_def_conn_keep_alive,
Curl_cf_def_query,
};
static CURLcode cf_test_create(struct Curl_cfilter **pcf,
struct Curl_easy *data,
struct connectdata *conn,
const struct Curl_addrinfo *ai)
{
struct cf_test_ctx *ctx = NULL;
struct Curl_cfilter *cf = NULL;
timediff_t created_at;
CURLcode result;
(void)data;
(void)conn;
ctx = calloc(sizeof(*ctx), 1);
if(!ctx) {
result = CURLE_OUT_OF_MEMORY;
goto out;
}
ctx->ai_family = ai->ai_family;
ctx->started = Curl_now();
#ifdef ENABLE_IPV6
if(ctx->ai_family == AF_INET6) {
ctx->stats = &current_tr->cf6;
ctx->fail_delay_ms = current_tc->cf6_fail_delay_ms;
curl_msprintf(ctx->id, "v6-%d", ctx->stats->creations);
ctx->stats->creations++;
}
else
#endif
{
ctx->stats = &current_tr->cf4;
ctx->fail_delay_ms = current_tc->cf4_fail_delay_ms;
curl_msprintf(ctx->id, "v4-%d", ctx->stats->creations);
ctx->stats->creations++;
}
created_at = Curl_timediff(ctx->started, current_tr->started);
if(ctx->stats->creations == 1)
ctx->stats->first_created = created_at;
ctx->stats->last_created = created_at;
infof(data, "%04dms: cf[%s] created", (int)created_at, ctx->id);
result = Curl_cf_create(&cf, &cft_test, ctx);
out:
*pcf = (!result)? cf : NULL;
if(result) {
free(cf);
free(ctx);
}
return result;
}
static void check_result(struct test_case *tc,
struct test_result *tr)
{
char msg[256];
timediff_t duration_ms;
if(tr->result != tc->exp_result
&& CURLE_OPERATION_TIMEDOUT != tr->result) {
/* on CI we encounter the TIMEOUT result, since images get less CPU
* and events are not as sharply timed. */
curl_msprintf(msg, "%d: expected result %d but got %d",
tc->id, CURLE_COULDNT_CONNECT, tr->result);
fail(msg);
}
if(tr->cf4.creations != tc->exp_cf4_creations) {
curl_msprintf(msg, "%d: expected %d ipv4 creations, but got %d",
tc->id, tc->exp_cf4_creations, tr->cf4.creations);
fail(msg);
}
if(tr->cf6.creations != tc->exp_cf6_creations) {
curl_msprintf(msg, "%d: expected %d ipv6 creations, but got %d",
tc->id, tc->exp_cf6_creations, tr->cf6.creations);
fail(msg);
}
duration_ms = Curl_timediff(tr->ended, tr->started);
if(duration_ms < tc->min_duration_ms) {
curl_msprintf(msg, "%d: expected min duration of %dms, but took %dms",
tc->id, (int)tc->min_duration_ms, (int)duration_ms);
fail(msg);
}
if(duration_ms > tc->max_duration_ms) {
curl_msprintf(msg, "%d: expected max duration of %dms, but took %dms",
tc->id, (int)tc->max_duration_ms, (int)duration_ms);
fail(msg);
}
if(tr->cf6.creations && tr->cf4.creations && tc->pref_family) {
/* did ipv4 and ipv6 both, expect the preferred family to start right arway
* with the other being delayed by the happy_eyeball_timeout */
struct ai_family_stats *stats1 = !strcmp(tc->pref_family, "v6")?
&tr->cf6 : &tr->cf4;
struct ai_family_stats *stats2 = !strcmp(tc->pref_family, "v6")?
&tr->cf4 : &tr->cf6;
if(stats1->first_created > 100) {
curl_msprintf(msg, "%d: expected ip%s to start right away, instead "
"first attempt made after %dms",
tc->id, stats1->family, (int)stats1->first_created);
fail(msg);
}
if(stats2->first_created < tc->he_timeout_ms) {
curl_msprintf(msg, "%d: expected ip%s to start delayed after %dms, "
"instead first attempt made after %dms",
tc->id, stats2->family, (int)tc->he_timeout_ms,
(int)stats2->first_created);
fail(msg);
}
}
}
static void test_connect(struct test_case *tc)
{
struct test_result tr;
struct curl_slist *list = NULL;
Curl_debug_set_transport_provider(TRNSPRT_TCP, cf_test_create);
current_tc = tc;
current_tr = &tr;
list = curl_slist_append(NULL, tc->resolve_info);
fail_unless(list, "error allocating resolve list entry");
curl_easy_setopt(easy, CURLOPT_RESOLVE, list);
curl_easy_setopt(easy, CURLOPT_CONNECTTIMEOUT_MS, tc->connect_timeout_ms);
curl_easy_setopt(easy, CURLOPT_HAPPY_EYEBALLS_TIMEOUT_MS, tc->he_timeout_ms);
curl_easy_setopt(easy, CURLOPT_URL, tc->url);
memset(&tr, 0, sizeof(tr));
tr.cf6.family = "v6";
tr.cf4.family = "v4";
tr.started = Curl_now();
tr.result = curl_easy_perform(easy);
tr.ended = Curl_now();
curl_easy_setopt(easy, CURLOPT_RESOLVE, NULL);
curl_slist_free_all(list);
list = NULL;
current_tc = NULL;
current_tr = NULL;
check_result(tc, &tr);
}
#endif /* DEBUGBUILD */
/*
* How these test cases work:
* - replace the creation of the TCP socket filter with out test filter
* - test filter does nothing and reports failure after configured delay
* - we feed addresses into the resolve cache to simulate different cases
* - we monitor how many instances of ipv4/v6 attempts are made and when
* - for mixed families, we expect HAPPY_EYEBALLS_TIMEOUT to trigger
*
* Max Duration checks needs to be conservative since CI jobs are not
* as sharp.
*/
#define TURL "http://test.com:123"
#define R_FAIL CURLE_COULDNT_CONNECT
#define R_TIME CURLE_OPERATION_TIMEDOUT
static struct test_case TEST_CASES[] = {
/* TIMEOUT_MS, FAIL_MS CREATED DURATION Result, HE_PREF */
/* CNCT HE v4 v6 v4 v6 MIN MAX */
{ 1, TURL, "test.com:123:192.0.2.1",
250, 150, 200, 200, 1, 0, 200, 500, R_FAIL, NULL },
/* 1 ipv4, fails after ~200ms, reports COULDNT_CONNECT */
{ 2, TURL, "test.com:123:192.0.2.1,192.0.2.2",
500, 150, 200, 200, 2, 0, 400, 800, R_FAIL, NULL },
/* 2 ipv4, fails after ~400ms, reports COULDNT_CONNECT */
#ifdef ENABLE_IPV6
{ 3, TURL, "test.com:123:::1",
250, 150, 200, 200, 0, 1, 200, 500, R_FAIL, NULL },
/* 1 ipv6, fails after ~200ms, reports COULDNT_CONNECT */
{ 4, TURL, "test.com:123:::1,::2",
500, 150, 200, 200, 0, 2, 400, 800, R_FAIL, NULL },
/* 2 ipv6, fails after ~400ms, reports COULDNT_CONNECT */
{ 5, TURL, "test.com:123:192.0.2.1,::1",
500, 150, 200, 200, 1, 1, 350, 800, R_FAIL, "v4" },
/* mixed ip4+6, v4 starts, v6 kicks in on HE, fails after ~350ms */
{ 6, TURL, "test.com:123:::1,192.0.2.1",
500, 150, 200, 200, 1, 1, 350, 800, R_FAIL, "v6" },
/* mixed ip6+4, v6 starts, v4 kicks in on HE, fails after ~350ms */
{ 7, TURL, "test.com:123:::1,192.0.2.1,::2,::3",
500, 600, 200, 200, 0, 3, 350, 800, R_TIME, "v6" },
/* mixed ip6+4, v6 starts, v4 never starts due to high HE, TIMEOUT */
#endif
};
/* copied from hostip.c to switch using SIGALARM for timeouts.
* SIGALARM has only seconds resolution, so our tests will not work
* here. */
#if defined(CURLRES_SYNCH) && \
defined(HAVE_ALARM) && defined(SIGALRM) && defined(HAVE_SIGSETJMP)
#define USE_ALARM_TIMEOUT
#endif
UNITTEST_START
#if defined(DEBUGBUILD) && !defined(USE_ALARM_TIMEOUT)
size_t i;
for(i = 0; i < sizeof(TEST_CASES)/sizeof(TEST_CASES[0]); ++i) {
test_connect(&TEST_CASES[i]);
}
#endif
UNITTEST_STOP