diff options
author | Stefan Eissing <stefan@eissing.org> | 2023-01-17 15:58:49 +0100 |
---|---|---|
committer | Daniel Stenberg <daniel@haxx.se> | 2023-01-31 11:28:14 +0100 |
commit | d55de24dce9d51eac913e20c17022c732124b83f (patch) | |
tree | 01db7bd74c68a18115cf1d7ed5b2c7d9b706c558 | |
parent | 5651a36d1ae46db61a31771a8d4d6dcf2a510856 (diff) | |
download | curl-d55de24dce9d51eac913e20c17022c732124b83f.tar.gz |
connect: fix strategy testing for attempts, timeouts and happy-eyeball
- 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
-rw-r--r-- | lib/connect.c | 90 | ||||
-rw-r--r-- | lib/connect.h | 5 | ||||
-rw-r--r-- | lib/urldata.h | 1 | ||||
-rw-r--r-- | tests/data/Makefile.inc | 2 | ||||
-rw-r--r-- | tests/data/test2600 | 24 | ||||
-rw-r--r-- | tests/unit/Makefile.inc | 4 | ||||
-rw-r--r-- | tests/unit/unit2600.c | 358 |
7 files changed, 452 insertions, 32 deletions
diff --git a/lib/connect.c b/lib/connect.c index 6bdb9e3ca..64165542f 100644 --- a/lib/connect.c +++ b/lib/connect.c @@ -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; } -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; +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 - case TRNSPRT_QUIC: - return Curl_cf_quic_create; + { 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 - default: - return NULL; + +static cf_ip_connect_create *get_cf_create(int transport) +{ + 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, diff --git a/lib/connect.h b/lib/connect.h index f4db38e40..1650c4921 100644 --- a/lib/connect.h +++ b/lib/connect.h @@ -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 */ diff --git a/lib/urldata.h b/lib/urldata.h index ce0d73118..5aca0c931 100644 --- a/lib/urldata.h +++ b/lib/urldata.h @@ -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 diff --git a/tests/data/Makefile.inc b/tests/data/Makefile.inc index 042ea3e13..ffcd93620 100644 --- a/tests/data/Makefile.inc +++ b/tests/data/Makefile.inc @@ -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 \ diff --git a/tests/data/test2600 b/tests/data/test2600 new file mode 100644 index 000000000..dba42249b --- /dev/null +++ b/tests/data/test2600 @@ -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> diff --git a/tests/unit/Makefile.inc b/tests/unit/Makefile.inc index ab4d63187..7a7895446 100644 --- a/tests/unit/Makefile.inc +++ b/tests/unit/Makefile.inc @@ -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) diff --git a/tests/unit/unit2600.c b/tests/unit/unit2600.c new file mode 100644 index 000000000..72b8eb0c6 --- /dev/null +++ b/tests/unit/unit2600.c @@ -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 = ¤t_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 = ¤t_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 |