luo980/curl
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

quic: improve connect error message, debugging info, fix false connect report

Browse Source 
- ECONNECTREFUSED has not its own fail message in quic filters
- Debug logging in connect eyballing improved
- Fix bug in ngtcp2/quiche that could lead to false success reporting.

Reported-by: Divy Le Ray

Fixes #10245
Closes #10248
This commit is contained in:
Stefan Eissing 2023-01-06 12:33:34 +01:00 committed by Daniel Stenberg
parent 0ef2926881
commit 1c5d8acf79
No known key found for this signature in database
GPG Key ID: 5CC908FDB71E12C2
5 changed files with 64 additions and 38 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
lib/cf-socket.c
View File

@ -1555,9 +1555,13 @@ CURLcode Curl_cf_socket_peek(struct Curl_cfilter *cf,
if(Curl_cf_is_socket(cf) && cf->ctx) { if(Curl_cf_is_socket(cf) && cf->ctx) {
struct cf_socket_ctx *ctx = cf->ctx; struct cf_socket_ctx *ctx = cf->ctx;
if(psock)
*psock = ctx->sock; *psock = ctx->sock;
if(paddr)
*paddr = &ctx->addr; *paddr = &ctx->addr;
if(premote_ip_str)
*premote_ip_str = ctx->r_ip; *premote_ip_str = ctx->r_ip;
if(premote_port)
*premote_port = ctx->r_port; *premote_port = ctx->r_port;
return CURLE_OK; return CURLE_OK;
} }

4
lib/cf-socket.h
View File

@ -166,6 +166,10 @@ bool Curl_cf_is_socket(struct Curl_cfilter *cf);
/** /**
* Peek at the socket and remote ip/port the socket filter is using. * Peek at the socket and remote ip/port the socket filter is using.
* The filter owns all returned values. * The filter owns all returned values.
* @param psock pointer to hold socket descriptor or NULL
* @param paddr pointer to hold addr reference or NULL
* @param premote_ip_str pointer to hold remote addr as string or NULL
* @param premote_port pointer to hold remote port number or NULL
* Returns error if the filter is of invalid type. * Returns error if the filter is of invalid type.
*/ */
CURLcode Curl_cf_socket_peek(struct Curl_cfilter *cf, CURLcode Curl_cf_socket_peek(struct Curl_cfilter *cf,

50
lib/connect.c
View File

@ -352,6 +352,7 @@ void Curl_conncontrol(struct connectdata *conn,
* provided method `cf_create` and running setup/connect on it. * provided method `cf_create` and running setup/connect on it.
*/ */
struct eyeballer { struct eyeballer {
const char *name;
const struct Curl_addrinfo *addr; /* List of addresses to try, not owned */ const struct Curl_addrinfo *addr; /* List of addresses to try, not owned */
int ai_family; /* matching address family only */ int ai_family; /* matching address family only */
cf_ip_connect_create *cf_create; /* for creating cf */ cf_ip_connect_create *cf_create; /* for creating cf */
@ -379,7 +380,7 @@ struct cf_he_ctx {
cf_ip_connect_create *cf_create; cf_ip_connect_create *cf_create;
const struct Curl_dns_entry *remotehost; const struct Curl_dns_entry *remotehost;
cf_connect_state state; cf_connect_state state;
struct eyeballer *baller[5]; struct eyeballer *baller[2];
struct eyeballer *winner; struct eyeballer *winner;
struct curltime started; struct curltime started;
}; };
@ -400,6 +401,8 @@ static CURLcode eyeballer_new(struct eyeballer **pballer,
if(!baller) if(!baller)
return CURLE_OUT_OF_MEMORY; return CURLE_OUT_OF_MEMORY;
baller->name = ((ai_family == AF_INET)? "ipv4" : (
(ai_family == AF_INET6)? "ipv6" : "ip"));
baller->cf_create = cf_create; baller->cf_create = cf_create;
baller->addr = addr; baller->addr = addr;
baller->ai_family = ai_family; baller->ai_family = ai_family;
@ -458,8 +461,6 @@ static void baller_initiate(struct Curl_cfilter *cf,
if(result) if(result)
goto out; goto out;
CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer created %s"),
baller->cf->cft->name));
/* the new filter might have sub-filters */ /* the new filter might have sub-filters */
for(wcf = baller->cf; wcf; wcf = wcf->next) { for(wcf = baller->cf; wcf; wcf = wcf->next) {
wcf->conn = cf->conn; wcf->conn = cf->conn;
@ -472,7 +473,7 @@ static void baller_initiate(struct Curl_cfilter *cf,
out: out:
if(result) { if(result) {
CF_DEBUGF(infof(data, "eyeballer failed")); CF_DEBUGF(infof(data, "eyeballer[%s] failed", baller->name));
baller_close(baller, data); baller_close(baller, data);
} }
if(cf_prev) if(cf_prev)
@ -546,8 +547,8 @@ static CURLcode baller_connect(struct Curl_cfilter *cf,
baller->is_done = TRUE; baller->is_done = TRUE;
} }
else if(Curl_timediff(*now, ctx->started) >= baller->timeoutms) { else if(Curl_timediff(*now, ctx->started) >= baller->timeoutms) {
infof(data, "After %" CURL_FORMAT_TIMEDIFF_T infof(data, "%s connect timeout after %" CURL_FORMAT_TIMEDIFF_T
"ms connect time, move on!", baller->timeoutms); "ms, move on!", baller->name, baller->timeoutms);
#if defined(ETIMEDOUT) #if defined(ETIMEDOUT)
baller->error = ETIMEDOUT; baller->error = ETIMEDOUT;
#endif #endif
@ -592,13 +593,12 @@ evaluate:
continue; continue;
if(!baller->has_started) { if(!baller->has_started) {
CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%d] not started yet"), i));
++not_started; ++not_started;
continue; continue;
} }
baller->result = baller_connect(cf, data, baller, &now, connected); baller->result = baller_connect(cf, data, baller, &now, connected);
CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%d] connect -> %d, " CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%s] connect -> %d, "
"connected=%d"), i, baller->result, *connected)); "connected=%d"), baller->name, baller->result, *connected));
if(!baller->result) { if(!baller->result) {
if(*connected) { if(*connected) {
@ -619,11 +619,14 @@ evaluate:
} }
allow = Curl_timeleft(data, &now, TRUE); allow = Curl_timeleft(data, &now, TRUE);
baller->timeoutms = baller->addr->ai_next == NULL ? allow : allow / 2; baller->timeoutms = baller->addr->ai_next == NULL ? allow : allow / 2;
CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%d] starting"), i));
baller_start_next(cf, data, baller); baller_start_next(cf, data, baller);
if(!baller->is_done) { if(baller->is_done) {
CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%s] done"), baller->name));
}
else {
/* next attempt was started */ /* next attempt was started */
CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%d] started"), i)); CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%s] trying next"),
baller->name));
++ongoing; ++ongoing;
} }
} }
@ -655,10 +658,14 @@ evaluate:
* its start delay_ms have expired */ * its start delay_ms have expired */
if((baller->primary && baller->primary->is_done) || if((baller->primary && baller->primary->is_done) ||
Curl_timediff(now, ctx->started) >= baller->delay_ms) { Curl_timediff(now, ctx->started) >= baller->delay_ms) {
CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%d] starting"), i));
baller_start(cf, data, baller); baller_start(cf, data, baller);
if(!baller->is_done) { if(baller->is_done) {
CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%d] has started"), i)); CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%s] done"),
baller->name));
}
else {
CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%s] starting"),
baller->name));
++ongoing; ++ongoing;
++added; ++added;
} }
@ -679,8 +686,9 @@ evaluate:
result = CURLE_COULDNT_CONNECT; result = CURLE_COULDNT_CONNECT;
for(i = 0; i < sizeof(ctx->baller)/sizeof(ctx->baller[0]); i++) { for(i = 0; i < sizeof(ctx->baller)/sizeof(ctx->baller[0]); i++) {
struct eyeballer *baller = ctx->baller[i]; struct eyeballer *baller = ctx->baller[i];
CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%d] assess started=%d, " CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%s] assess started=%d, "
"result=%d"), i, baller->has_started, baller->result)); "result=%d"),
baller->name, baller->has_started, baller->result));
if(baller && baller->has_started && baller->result) { if(baller && baller->has_started && baller->result) {
result = baller->result; result = baller->result;
break; break;
@ -887,6 +895,7 @@ static CURLcode cf_he_connect(struct Curl_cfilter *cf,
if(!result && *done) { if(!result && *done) {
DEBUGASSERT(ctx->winner); DEBUGASSERT(ctx->winner);
DEBUGASSERT(ctx->winner->cf); DEBUGASSERT(ctx->winner->cf);
DEBUGASSERT(ctx->winner->cf->connected);
/* we have a winner. Install and activate it. /* we have a winner. Install and activate it.
* close/free all others. */ * close/free all others. */
ctx->state = SCFST_DONE; ctx->state = SCFST_DONE;
@ -953,7 +962,7 @@ static void cf_he_destroy(struct Curl_cfilter *cf, struct Curl_easy *data)
CF_DEBUGF(infof(data, CFMSG(cf, "destroy"))); CF_DEBUGF(infof(data, CFMSG(cf, "destroy")));
if(ctx) { if(ctx) {
cf_he_close(cf, data); cf_he_ctx_clear(cf, data);
} }
/* release any resources held in state */ /* release any resources held in state */
Curl_safefree(ctx); Curl_safefree(ctx);
@ -1189,11 +1198,8 @@ static void cf_setup_destroy(struct Curl_cfilter *cf, struct Curl_easy *data)
{ {
struct cf_setup_ctx *ctx = cf->ctx; struct cf_setup_ctx *ctx = cf->ctx;
(void)data;
CF_DEBUGF(infof(data, CFMSG(cf, "destroy"))); CF_DEBUGF(infof(data, CFMSG(cf, "destroy")));
if(ctx) {
cf_setup_close(cf, data);
}
/* release any resources held in state */
Curl_safefree(ctx); Curl_safefree(ctx);
} }

28
lib/vquic/curl_ngtcp2.c
View File

@ -1169,6 +1169,10 @@ static ssize_t cf_ngtcp2_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
struct cf_ngtcp2_ctx *ctx = cf->ctx; struct cf_ngtcp2_ctx *ctx = cf->ctx;
struct HTTP *stream = data->req.p.http; struct HTTP *stream = data->req.p.http;
DEBUGASSERT(cf->connected);
DEBUGASSERT(ctx);
DEBUGASSERT(ctx->qconn);
DEBUGASSERT(ctx->h3conn);
*err = CURLE_OK; *err = CURLE_OK;
if(!stream->memlen) { if(!stream->memlen) {
@ -1442,6 +1446,10 @@ static ssize_t cf_ngtcp2_send(struct Curl_cfilter *cf, struct Curl_easy *data,
ssize_t sent = 0; ssize_t sent = 0;
struct HTTP *stream = data->req.p.http; struct HTTP *stream = data->req.p.http;
DEBUGASSERT(cf->connected);
DEBUGASSERT(ctx);
DEBUGASSERT(ctx->qconn);
DEBUGASSERT(ctx->h3conn);
*err = CURLE_OK; *err = CURLE_OK;
if(stream->closed) { if(stream->closed) {
@ -1576,8 +1584,16 @@ static CURLcode cf_process_ingress(struct Curl_cfilter *cf,
if(recvd == -1) { if(recvd == -1) {
if(SOCKERRNO == EAGAIN || SOCKERRNO == EWOULDBLOCK) if(SOCKERRNO == EAGAIN || SOCKERRNO == EWOULDBLOCK)
break; break;
if(SOCKERRNO == ECONNREFUSED) {
failf(data, "ngtcp2: recvfrom() unexpectedly returned %zd", recvd); const char *r_ip;
int r_port;
Curl_cf_socket_peek(cf->next, NULL, NULL, &r_ip, &r_port);
failf(data, "ngtcp2: connection to %s port %u refused",
r_ip, r_port);
return CURLE_COULDNT_CONNECT;
}
failf(data, "ngtcp2: recvfrom() unexpectedly returned %zd (errno=%d)",
recvd, SOCKERRNO);
return CURLE_RECV_ERROR; return CURLE_RECV_ERROR;
} }
@ -2273,13 +2289,13 @@ static CURLcode cf_ngtcp2_connect(struct Curl_cfilter *cf,
return result; return result;
} }
*done = FALSE;
if(!ctx->qconn) { if(!ctx->qconn) {
result = cf_connect_start(cf, data); result = cf_connect_start(cf, data);
if(result) if(result)
goto out; goto out;
} }
*done = FALSE;
result = cf_process_ingress(cf, data); result = cf_process_ingress(cf, data);
if(result) if(result)
goto out; goto out;
@ -2301,12 +2317,10 @@ static CURLcode cf_ngtcp2_connect(struct Curl_cfilter *cf,
out: out:
#ifndef CURL_DISABLE_VERBOSE_STRINGS #ifndef CURL_DISABLE_VERBOSE_STRINGS
if(result && result != CURLE_AGAIN) { if(result && result != CURLE_AGAIN) {
const struct Curl_sockaddr_ex *sockaddr;
const char *r_ip; const char *r_ip;
int r_port; int r_port;
result = Curl_cf_socket_peek(cf->next, &ctx->sockfd, Curl_cf_socket_peek(cf->next, NULL, NULL, &r_ip, &r_port);
&sockaddr, &r_ip, &r_port);
infof(data, "connect to %s port %u failed: %s", infof(data, "connect to %s port %u failed: %s",
r_ip, r_port, curl_easy_strerror(result)); r_ip, r_port, curl_easy_strerror(result));
} }
@ -2364,7 +2378,7 @@ CURLcode Curl_cf_ngtcp2_create(struct Curl_cfilter **pcf,
const struct Curl_addrinfo *ai) const struct Curl_addrinfo *ai)
{ {
struct cf_ngtcp2_ctx *ctx = NULL; struct cf_ngtcp2_ctx *ctx = NULL;
struct Curl_cfilter *cf = NULL, *udp_cf; struct Curl_cfilter *cf = NULL, *udp_cf = NULL;
CURLcode result; CURLcode result;
(void)data; (void)data;

8
lib/vquic/curl_quiche.c
View File

@ -961,13 +961,13 @@ static CURLcode cf_quiche_connect(struct Curl_cfilter *cf,
return result; return result;
} }
*done = FALSE;
if(!ctx->qconn) { if(!ctx->qconn) {
result = cf_connect_start(cf, data); result = cf_connect_start(cf, data);
if(result) if(result)
goto out; goto out;
} }
*done = FALSE;
result = cf_process_ingress(cf, data); result = cf_process_ingress(cf, data);
if(result) if(result)
goto out; goto out;
@ -990,12 +990,10 @@ static CURLcode cf_quiche_connect(struct Curl_cfilter *cf,
out: out:
#ifndef CURL_DISABLE_VERBOSE_STRINGS #ifndef CURL_DISABLE_VERBOSE_STRINGS
if(result && result != CURLE_AGAIN) { if(result && result != CURLE_AGAIN) {
const struct Curl_sockaddr_ex *sockaddr;
const char *r_ip; const char *r_ip;
int r_port; int r_port;
result = Curl_cf_socket_peek(cf->next, &ctx->sockfd, Curl_cf_socket_peek(cf->next, NULL, NULL, &r_ip, &r_port);
&sockaddr, &r_ip, &r_port);
infof(data, "connect to %s port %u failed: %s", infof(data, "connect to %s port %u failed: %s",
r_ip, r_port, curl_easy_strerror(result)); r_ip, r_port, curl_easy_strerror(result));
} }
@ -1094,7 +1092,7 @@ CURLcode Curl_cf_quiche_create(struct Curl_cfilter **pcf,
const struct Curl_addrinfo *ai) const struct Curl_addrinfo *ai)
{ {
struct cf_quiche_ctx *ctx = NULL; struct cf_quiche_ctx *ctx = NULL;
struct Curl_cfilter *cf = NULL, *udp_cf; struct Curl_cfilter *cf = NULL, *udp_cf = NULL;
CURLcode result; CURLcode result;
(void)data; (void)data;