From e024d5665d68083dca6d3debc4b210d84978ea87 Mon Sep 17 00:00:00 2001 From: Stefan Eissing Date: Tue, 23 May 2023 12:48:58 +0200 Subject: [PATCH] lib: add CURLINFO_CONN_ID and CURLINFO_XFER_ID - add an `id` long to Curl_easy, -1 on init - once added to a multi (or its own multi), it gets a non-negative number assigned by the connection cache - `id` is unique among all transfers using the same cache until reaching LONG_MAX where it will wrap around. So, not unique eternally. - CURLINFO_CONN_ID returns the connection id attached to data or, if none present, data->state.lastconnect_id - variables and type declared in tool for write out Closes #11185 --- docs/libcurl/curl_easy_getinfo.3 | 6 +++ docs/libcurl/opts/CURLINFO_CONN_ID.3 | 69 +++++++++++++++++++++++++++ docs/libcurl/opts/CURLINFO_XFER_ID.3 | 70 ++++++++++++++++++++++++++++ docs/libcurl/symbols-in-versions | 2 + include/curl/curl.h | 4 +- lib/cfilters.c | 4 +- lib/conncache.h | 3 +- lib/connect.c | 2 +- lib/curl_log.c | 4 +- lib/curl_log.h | 19 -------- lib/easy.c | 2 + lib/getinfo.c | 7 +++ lib/http2.c | 11 ++--- lib/imap.c | 2 +- lib/multi.c | 48 +++++++++++-------- lib/sendf.c | 2 - lib/telnet.c | 5 +- lib/transfer.c | 6 +-- lib/url.c | 32 +++++++------ lib/urldata.h | 15 ++++-- lib/vquic/curl_msh3.c | 2 +- lib/vquic/curl_ngtcp2.c | 5 +- lib/vquic/curl_quiche.c | 5 +- lib/vtls/vtls.c | 6 +-- lib/ws.c | 3 +- src/tool_writeout.c | 2 + src/tool_writeout.h | 2 + tests/data/test1506 | 2 +- tests/data/test1542 | 2 +- tests/data/test970 | 2 +- tests/data/test972 | 2 +- 31 files changed, 252 insertions(+), 94 deletions(-) create mode 100644 docs/libcurl/opts/CURLINFO_CONN_ID.3 create mode 100644 docs/libcurl/opts/CURLINFO_XFER_ID.3 diff --git a/docs/libcurl/curl_easy_getinfo.3 b/docs/libcurl/curl_easy_getinfo.3 index 53a0c6fc5c..e684a859e6 100644 --- a/docs/libcurl/curl_easy_getinfo.3 +++ b/docs/libcurl/curl_easy_getinfo.3 @@ -247,6 +247,12 @@ See \fICURLINFO_PROTOCOL(3)\fP .IP CURLINFO_SCHEME The scheme used for the connection. (Added in 7.52.0) See \fICURLINFO_SCHEME(3)\fP +.IP CURLINFO_CONN_ID +The ID of the last connection used by the transfer. (Added in 8.2.0) +See \fICURLINFO_CONN_ID(3)\fP +.IP CURLINFO_XFER_ID +The ID of the transfer. (Added in 8.2.0) +See \fICURLINFO_XFER_ID(3)\fP .SH TIMES .nf An overview of the six time values available from curl_easy_getinfo() diff --git a/docs/libcurl/opts/CURLINFO_CONN_ID.3 b/docs/libcurl/opts/CURLINFO_CONN_ID.3 new file mode 100644 index 0000000000..f8e7a4651d --- /dev/null +++ b/docs/libcurl/opts/CURLINFO_CONN_ID.3 @@ -0,0 +1,69 @@ +.\" ************************************************************************** +.\" * _ _ ____ _ +.\" * Project ___| | | | _ \| | +.\" * / __| | | | |_) | | +.\" * | (__| |_| | _ <| |___ +.\" * \___|\___/|_| \_\_____| +.\" * +.\" * Copyright (C) Daniel Stenberg, , 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 +.\" * +.\" ************************************************************************** +.\" +.TH CURLINFO_CONN_ID 3 "07 June 2023" "libcurl" "libcurl" +.SH NAME +CURLINFO_CONN_ID \- get the ID of the last connection used by the handle +.SH SYNOPSIS +.nf +#include + +CURLcode curl_easy_getinfo(CURL *handle, CURLINFO_CONN_ID, + curl_off_t *conn_id); +.fi +.SH DESCRIPTION +Pass a pointer to a \fIcurl_off_t\fP to receive the connection identifier last +used by the handle. Stores -1 if there was no connection used. + +The connection id is unique among all connections using the same +connection cache. This is implicitly the case for all connections in the +same multi handle. + +.SH PROTOCOLS +All +.SH EXAMPLE +.nf +CURL *curl = curl_easy_init(); +if(curl) { + curl_easy_setopt(curl, CURLOPT_URL, "https://example.com"); + + /* Perform the request */ + res = curl_easy_perform(curl); + + if(!res) { + curl_off_t conn_id; + res = curl_easy_getinfo(curl, CURLINFO_CONN_ID, &conn_id); + if(!res) { + printf("Connection used: %" CURL_FORMAT_CURL_OFF_T "\\n", conn_id); + } + } +} +.fi +.SH AVAILABILITY +Added in 8.2.0 +.SH RETURN VALUE +Returns CURLE_OK if the option is supported, and CURLE_UNKNOWN_OPTION if not. +.SH "SEE ALSO" +.BR curl_easy_getinfo "(3), " curl_easy_setopt "(3), " +.BR CURLINFO_XFER_ID "(3), " diff --git a/docs/libcurl/opts/CURLINFO_XFER_ID.3 b/docs/libcurl/opts/CURLINFO_XFER_ID.3 new file mode 100644 index 0000000000..8040d49187 --- /dev/null +++ b/docs/libcurl/opts/CURLINFO_XFER_ID.3 @@ -0,0 +1,70 @@ +.\" ************************************************************************** +.\" * _ _ ____ _ +.\" * Project ___| | | | _ \| | +.\" * / __| | | | |_) | | +.\" * | (__| |_| | _ <| |___ +.\" * \___|\___/|_| \_\_____| +.\" * +.\" * Copyright (C) Daniel Stenberg, , 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 +.\" * +.\" ************************************************************************** +.\" +.TH CURLINFO_XFER_ID 3 "07 June 2023" "libcurl" "libcurl" +.SH NAME +CURLINFO_XFER_ID \- get the ID of a transfer +.SH SYNOPSIS +.nf +#include + +CURLcode curl_easy_getinfo(CURL *handle, CURLINFO_XFER_ID, + curl_off_t *xfer_id); +.fi +.SH DESCRIPTION +Pass a pointer to a \fIcurl_off_t\fP to receive the identifier of the +current/last transfer done with the handle. Stores -1 if no transfer +has been started yet for the handle. + +The transfer id is unique among all transfers performed using the same +connection cache. This is implicitly the case for all transfers in the +same multi handle. + +.SH PROTOCOLS +All +.SH EXAMPLE +.nf +CURL *curl = curl_easy_init(); +if(curl) { + curl_easy_setopt(curl, CURLOPT_URL, "https://example.com"); + + /* Perform the request */ + res = curl_easy_perform(curl); + + if(!res) { + curl_off_t xfer_id; + res = curl_easy_getinfo(curl, CURLINFO_XFER_ID, &xfer_id); + if(!res) { + printf("Transfer ID: %" CURL_FORMAT_CURL_OFF_T "\\n", xfer_id); + } + } +} +.fi +.SH AVAILABILITY +Added in 8.2.0 +.SH RETURN VALUE +Returns CURLE_OK if the option is supported, and CURLE_UNKNOWN_OPTION if not. +.SH "SEE ALSO" +.BR curl_easy_getinfo "(3), " curl_easy_setopt "(3), " +.BR CURLINFO_CONN_ID "(3), " diff --git a/docs/libcurl/symbols-in-versions b/docs/libcurl/symbols-in-versions index 7b08c62c0b..6f88bf5e55 100644 --- a/docs/libcurl/symbols-in-versions +++ b/docs/libcurl/symbols-in-versions @@ -421,6 +421,7 @@ CURLINFO_CAINFO 7.84.0 CURLINFO_CAPATH 7.84.0 CURLINFO_CERTINFO 7.19.1 CURLINFO_CONDITION_UNMET 7.19.4 +CURLINFO_CONN_ID 8.2.0 CURLINFO_CONNECT_TIME 7.4.1 CURLINFO_CONNECT_TIME_T 7.61.0 CURLINFO_CONTENT_LENGTH_DOWNLOAD 7.6.1 7.55.0 @@ -503,6 +504,7 @@ CURLINFO_TLS_SSL_PTR 7.48.0 CURLINFO_TOTAL_TIME 7.4.1 CURLINFO_TOTAL_TIME_T 7.61.0 CURLINFO_TYPEMASK 7.4.1 +CURLINFO_XFER_ID 8.2.0 CURLIOCMD_NOP 7.12.3 CURLIOCMD_RESTARTREAD 7.12.3 CURLIOE_FAILRESTART 7.12.3 diff --git a/include/curl/curl.h b/include/curl/curl.h index 38393b9684..0efc34e699 100644 --- a/include/curl/curl.h +++ b/include/curl/curl.h @@ -2924,7 +2924,9 @@ typedef enum { CURLINFO_REFERER = CURLINFO_STRING + 60, CURLINFO_CAINFO = CURLINFO_STRING + 61, CURLINFO_CAPATH = CURLINFO_STRING + 62, - CURLINFO_LASTONE = 62 + CURLINFO_XFER_ID = CURLINFO_OFF_T + 63, + CURLINFO_CONN_ID = CURLINFO_OFF_T + 64, + CURLINFO_LASTONE = 64 } CURLINFO; /* CURLINFO_RESPONSE_CODE is the new name for the option previously known as diff --git a/lib/cfilters.c b/lib/cfilters.c index 291c823f3d..b5621f7a3c 100644 --- a/lib/cfilters.c +++ b/lib/cfilters.c @@ -179,7 +179,7 @@ ssize_t Curl_conn_recv(struct Curl_easy *data, int num, char *buf, if(cf) { return cf->cft->do_recv(cf, data, buf, len, code); } - failf(data, CMSGI(data->conn, num, "recv: no filter connected")); + failf(data, "recv: no filter connected"); *code = CURLE_FAILED_INIT; return -1; } @@ -198,7 +198,7 @@ ssize_t Curl_conn_send(struct Curl_easy *data, int num, if(cf) { return cf->cft->do_send(cf, data, mem, len, code); } - failf(data, CMSGI(data->conn, num, "send: no filter connected")); + failf(data, "send: no filter connected"); DEBUGASSERT(0); *code = CURLE_FAILED_INIT; return -1; diff --git a/lib/conncache.h b/lib/conncache.h index 959767d596..c60f8449ee 100644 --- a/lib/conncache.h +++ b/lib/conncache.h @@ -39,7 +39,8 @@ struct connectdata; struct conncache { struct Curl_hash hash; size_t num_conn; - long next_connection_id; + curl_off_t next_connection_id; + curl_off_t next_easy_id; struct curltime last_cleanup; /* handle used for closing cached connections */ struct Curl_easy *closure_handle; diff --git a/lib/connect.c b/lib/connect.c index ed5512138e..ebb2be9f44 100644 --- a/lib/connect.c +++ b/lib/connect.c @@ -253,7 +253,7 @@ bool Curl_addr2string(struct sockaddr *sa, curl_socklen_t salen, } struct connfind { - long id_tofind; + curl_off_t id_tofind; struct connectdata *found; }; diff --git a/lib/curl_log.c b/lib/curl_log.c index c1f70a6d31..782c35a632 100644 --- a/lib/curl_log.c +++ b/lib/curl_log.c @@ -134,9 +134,7 @@ void Curl_log_cf_debug(struct Curl_easy *data, struct Curl_cfilter *cf, va_list ap; int len; char buffer[MAXINFO + 2]; - len = msnprintf(buffer, MAXINFO, "[CONN-%ld%s-%s] ", - cf->conn->connection_id, cf->sockindex? "/2" : "", - cf->cft->name); + len = msnprintf(buffer, MAXINFO, "[%s] ", cf->cft->name); va_start(ap, fmt); len += mvsnprintf(buffer + len, MAXINFO - len, fmt, ap); va_end(ap); diff --git a/lib/curl_log.h b/lib/curl_log.h index acf5630163..ebfa5a0003 100644 --- a/lib/curl_log.h +++ b/lib/curl_log.h @@ -118,23 +118,4 @@ void Curl_log_cf_debug(struct Curl_easy *data, struct Curl_cfilter *cf, #define LOG_CF_IS_DEBUG(cf, data) Curl_log_cf_is_debug(cf, data) -/* Macros intended for DEBUGF logging, use like: - * DEBUGF(infof(data, CFMSG(cf, "this filter %s rocks"), "very much")); - * and it will output: - * [CONN-1-0][CF-SSL] this filter very much rocks - * on connection #1 with sockindex 0 for filter of type "SSL". */ -#define DMSG(d,msg) \ - "[CONN-%ld] "msg, (d)->conn->connection_id -#define DMSGI(d,i,msg) \ - "[CONN-%ld-%d] "msg, (d)->conn->connection_id, (i) -#define CMSG(c,msg) \ - "[CONN-%ld] "msg, (c)->connection_id -#define CMSGI(c,i,msg) \ - "[CONN-%ld-%d] "msg, (c)->connection_id, (i) -#define CFMSG(cf,msg) \ - "[CONN-%ld-%d][CF-%s] "msg, (cf)->conn->connection_id, \ - (cf)->sockindex, (cf)->cft->name - - - #endif /* HEADER_CURL_LOG_H */ diff --git a/lib/easy.c b/lib/easy.c index 5efa088522..73a4dc3ef2 100644 --- a/lib/easy.c +++ b/lib/easy.c @@ -893,6 +893,8 @@ struct Curl_easy *curl_easy_duphandle(struct Curl_easy *data) /* the connection cache is setup on demand */ outcurl->state.conn_cache = NULL; outcurl->state.lastconnect_id = -1; + outcurl->state.recent_conn_id = -1; + outcurl->id = -1; outcurl->progress.flags = data->progress.flags; outcurl->progress.callback = data->progress.callback; diff --git a/lib/getinfo.c b/lib/getinfo.c index 826ffd0b0c..f1574e097b 100644 --- a/lib/getinfo.c +++ b/lib/getinfo.c @@ -415,6 +415,13 @@ static CURLcode getinfo_offt(struct Curl_easy *data, CURLINFO info, case CURLINFO_RETRY_AFTER: *param_offt = data->info.retry_after; break; + case CURLINFO_XFER_ID: + *param_offt = data->id; + break; + case CURLINFO_CONN_ID: + *param_offt = data->conn? + data->conn->connection_id : data->state.recent_conn_id; + break; default: return CURLE_UNKNOWN_OPTION; } diff --git a/lib/http2.c b/lib/http2.c index a81313f126..7e2b4377fb 100644 --- a/lib/http2.c +++ b/lib/http2.c @@ -1947,8 +1947,8 @@ static ssize_t h2_submit(struct stream_ctx **pstream, h2_pri_spec(data, &pri_spec); - DEBUGF(LOG_CF(data, cf, "send request allowed %d (easy handle %p)", - nghttp2_session_check_request_allowed(ctx->h2), (void *)data)); + DEBUGF(LOG_CF(data, cf, "send request allowed %d", + nghttp2_session_check_request_allowed(ctx->h2))); switch(data->state.httpreq) { case HTTPREQ_POST: @@ -1984,8 +1984,7 @@ static ssize_t h2_submit(struct stream_ctx **pstream, DEBUGF(LOG_CF(data, cf, "[h2sid=%d] cf_send(len=%zu) submit %s", stream_id, len, data->state.url)); - infof(data, "Using Stream ID: %u (easy handle %p)", - stream_id, (void *)data); + infof(data, "Using Stream ID: %u", stream_id); stream->id = stream_id; stream->local_window_size = H2_STREAM_WINDOW_SIZE; if(data->set.max_recv_speed) { @@ -2542,7 +2541,7 @@ CURLcode Curl_http2_switch(struct Curl_easy *data, CURLcode result; DEBUGASSERT(!Curl_conn_is_http2(data, conn, sockindex)); - DEBUGF(infof(data, DMSGI(data, sockindex, "switching to HTTP/2"))); + DEBUGF(infof(data, "switching to HTTP/2")); result = http2_cfilter_add(&cf, data, conn, sockindex); if(result) @@ -2601,7 +2600,7 @@ CURLcode Curl_http2_upgrade(struct Curl_easy *data, CURLcode result; DEBUGASSERT(!Curl_conn_is_http2(data, conn, sockindex)); - DEBUGF(infof(data, DMSGI(data, sockindex, "upgrading to HTTP/2"))); + DEBUGF(infof(data, "upgrading to HTTP/2")); DEBUGASSERT(data->req.upgr101 == UPGR101_RECEIVED); result = http2_cfilter_add(&cf, data, conn, sockindex); diff --git a/lib/imap.c b/lib/imap.c index f072cc5112..1a66a1a4f5 100644 --- a/lib/imap.c +++ b/lib/imap.c @@ -1777,7 +1777,7 @@ static CURLcode imap_sendf(struct Curl_easy *data, const char *fmt, ...) /* Calculate the tag based on the connection ID and command ID */ msnprintf(imapc->resptag, sizeof(imapc->resptag), "%c%03d", - 'A' + curlx_sltosi(data->conn->connection_id % 26), + 'A' + curlx_sltosi((long)(data->conn->connection_id % 26)), ++imapc->cmdid); /* start with a blank buffer */ diff --git a/lib/multi.c b/lib/multi.c index b3f35f6dea..d711a9aca4 100644 --- a/lib/multi.c +++ b/lib/multi.c @@ -194,15 +194,10 @@ static void mstate(struct Curl_easy *data, CURLMstate state #if defined(DEBUGBUILD) && !defined(CURL_DISABLE_VERBOSE_STRINGS) if(data->mstate >= MSTATE_PENDING && data->mstate < MSTATE_COMPLETED) { - long connection_id = -5000; - - if(data->conn) - connection_id = data->conn->connection_id; - infof(data, - "STATE: %s => %s handle %p; line %d (connection #%ld)", + "STATE: %s => %s handle %p; line %d", multi_statename[oldstate], multi_statename[data->mstate], - (void *)data, lineno, connection_id); + (void *)data, lineno); } #endif @@ -464,6 +459,20 @@ struct Curl_multi *curl_multi_init(void) CURL_DNS_HASH_SIZE); } +#ifdef DEBUGBUILD +static void multi_warn_debug(struct Curl_multi *multi, struct Curl_easy *data) +{ + if(!multi->warned) { + infof(data, "!!! WARNING !!!"); + infof(data, "This is a debug build of libcurl, " + "do not use in production."); + multi->warned = true; + } +} +#else +#define multi_warn_debug(x,y) Curl_nop_stmt +#endif + /* returns TRUE if the easy handle is supposed to be present in the main link list */ static bool in_main_list(struct Curl_easy *data) @@ -623,8 +632,14 @@ CURLMcode curl_multi_add_handle(struct Curl_multi *multi, data->set.server_response_timeout; data->state.conn_cache->closure_handle->set.no_signal = data->set.no_signal; + data->id = data->state.conn_cache->next_easy_id++; + if(data->state.conn_cache->next_easy_id <= 0) + data->state.conn_cache->next_easy_id = 0; CONNCACHE_UNLOCK(data); + multi_warn_debug(multi, data); + infof(data, "processing: %s", data->state.url); + return CURLM_OK; } @@ -742,6 +757,7 @@ static CURLcode multi_done(struct Curl_easy *data, but currently we have no such detail knowledge. */ + data->state.recent_conn_id = conn->connection_id; if((data->set.reuse_forbid #if defined(USE_NTLM) && !(conn->http_ntlm_state == NTLMSTATE_TYPE2 || @@ -753,7 +769,7 @@ static CURLcode multi_done(struct Curl_easy *data, #endif ) || conn->bits.close || (premature && !Curl_conn_is_multiplex(conn, FIRSTSOCKET))) { - DEBUGF(infof(data, "multi_done, not re-using connection=%ld, forbid=%d" + DEBUGF(infof(data, "multi_done, not re-using connection=%zd, forbid=%d" ", close=%d, premature=%d, conn_multiplex=%d", conn->connection_id, data->set.reuse_forbid, conn->bits.close, premature, @@ -774,15 +790,16 @@ static CURLcode multi_done(struct Curl_easy *data, conn->bits.conn_to_host ? conn->conn_to_host.dispname : conn->host.dispname; /* create string before returning the connection */ - long connection_id = conn->connection_id; + curl_off_t connection_id = conn->connection_id; msnprintf(buffer, sizeof(buffer), - "Connection #%ld to host %s left intact", + "Connection #%zd to host %s left intact", connection_id, host); /* the connection is no longer in use by this transfer */ CONNCACHE_UNLOCK(data); if(Curl_conncache_return_conn(data, conn)) { /* remember the most recently used connection */ data->state.lastconnect_id = connection_id; + data->state.recent_conn_id = connection_id; infof(data, "%s", buffer); } else @@ -1895,14 +1912,7 @@ static CURLMcode multi_runsingle(struct Curl_multi *multi, multistate(data, MSTATE_COMPLETED); } -#ifdef DEBUGBUILD - if(!multi->warned) { - infof(data, "!!! WARNING !!!"); - infof(data, "This is a debug build of libcurl, " - "do not use in production."); - multi->warned = true; - } -#endif + multi_warn_debug(multi, data); do { /* A "stream" here is a logical stream if the protocol can handle that @@ -3690,7 +3700,7 @@ void Curl_expire_clear(struct Curl_easy *data) } #ifdef DEBUGBUILD - infof(data, "Expire cleared (transfer %p)", data); + infof(data, "Expire cleared"); #endif nowp->tv_sec = 0; nowp->tv_usec = 0; diff --git a/lib/sendf.c b/lib/sendf.c index 81ee864826..437fa74b66 100644 --- a/lib/sendf.c +++ b/lib/sendf.c @@ -419,8 +419,6 @@ CURLcode Curl_read(struct Curl_easy *data, /* transfer */ *n += nread; result = CURLE_OK; out: - /* DEBUGF(infof(data, "Curl_read(handle=%p) -> %d, nread=%ld", - data, result, nread)); */ return result; } diff --git a/lib/telnet.c b/lib/telnet.c index 643e43d2b0..1d7a592e78 100644 --- a/lib/telnet.c +++ b/lib/telnet.c @@ -1534,7 +1534,7 @@ static CURLcode telnet_do(struct Curl_easy *data, bool *done) } while(keepon) { - DEBUGF(infof(data, "telnet_do(handle=%p), poll %d fds", data, poll_cnt)); + DEBUGF(infof(data, "telnet_do, poll %d fds", poll_cnt)); switch(Curl_poll(pfd, poll_cnt, interval_ms)) { case -1: /* error, stop reading */ keepon = FALSE; @@ -1558,8 +1558,7 @@ static CURLcode telnet_do(struct Curl_easy *data, bool *done) * in a clean way? Seems to be timing related, happens more * on slow debug build */ if(data->state.os_errno == ECONNRESET) { - DEBUGF(infof(data, "telnet_do(handle=%p), unexpected ECONNRESET" - " on recv", data)); + DEBUGF(infof(data, "telnet_do, unexpected ECONNRESET on recv")); } break; } diff --git a/lib/transfer.c b/lib/transfer.c index 93c4d311d8..62bccbd95c 100644 --- a/lib/transfer.c +++ b/lib/transfer.c @@ -474,7 +474,7 @@ static CURLcode readwrite_data(struct Curl_easy *data, else { /* read nothing but since we wanted nothing we consider this an OK situation to proceed from */ - DEBUGF(infof(data, DMSG(data, "readwrite_data: we're done"))); + DEBUGF(infof(data, "readwrite_data: we're done")); nread = 0; } @@ -771,7 +771,7 @@ static CURLcode readwrite_data(struct Curl_easy *data, out: if(result) - DEBUGF(infof(data, DMSG(data, "readwrite_data() -> %d"), result)); + DEBUGF(infof(data, "readwrite_data() -> %d", result)); return result; } @@ -1236,7 +1236,7 @@ CURLcode Curl_readwrite(struct connectdata *conn, *done = (0 == (k->keepon&(KEEP_RECVBITS|KEEP_SENDBITS))) ? TRUE : FALSE; out: if(result) - DEBUGF(infof(data, DMSG(data, "Curl_readwrite() -> %d"), result)); + DEBUGF(infof(data, "Curl_readwrite() -> %d", result)); return result; } diff --git a/lib/url.c b/lib/url.c index 0fb6268341..b66a7209ee 100644 --- a/lib/url.c +++ b/lib/url.c @@ -659,6 +659,9 @@ CURLcode Curl_open(struct Curl_easy **curl) /* most recent connection is not yet defined */ data->state.lastconnect_id = -1; + data->state.recent_conn_id = -1; + /* and not assigned an id yet */ + data->id = -1; data->progress.flags |= PGRS_HIDE; data->state.current_speed = -1; /* init to negative == impossible */ @@ -680,7 +683,7 @@ CURLcode Curl_open(struct Curl_easy **curl) static void conn_shutdown(struct Curl_easy *data) { DEBUGASSERT(data); - infof(data, "Closing connection %ld", data->conn->connection_id); + infof(data, "Closing connection"); /* possible left-overs from the async name resolvers */ Curl_resolver_cancel(data); @@ -763,7 +766,8 @@ void Curl_disconnect(struct Curl_easy *data, /* the transfer must be detached from the connection */ DEBUGASSERT(!data->conn); - DEBUGF(infof(data, "Curl_disconnect(conn #%ld, dead=%d)", + DEBUGF(infof(data, "Curl_disconnect(conn #%" + CURL_FORMAT_CURL_OFF_T ", dead=%d)", conn->connection_id, dead_connection)); /* * If this connection isn't marked to force-close, leave it open if there @@ -952,7 +956,8 @@ static bool extract_if_dead(struct connectdata *conn, } if(dead) { - infof(data, "Connection %ld seems to be dead", conn->connection_id); + infof(data, "Connection %" CURL_FORMAT_CURL_OFF_T " seems to be dead", + conn->connection_id); Curl_conncache_remove_conn(data, conn, FALSE); return TRUE; } @@ -1148,7 +1153,7 @@ ConnectionExists(struct Curl_easy *data, completed yet and until then we don't re-use this connection */ if(!check->primary_ip[0]) { infof(data, - "Connection #%ld is still name resolving, can't reuse", + "Connection #%zd is still name resolving, can't reuse", check->connection_id); continue; } @@ -1158,8 +1163,8 @@ ConnectionExists(struct Curl_easy *data, if(!Curl_conn_is_connected(check, FIRSTSOCKET)) { foundPendingCandidate = TRUE; /* Don't pick a connection that hasn't connected yet */ - infof(data, "Connection #%ld isn't open enough, can't reuse", - check->connection_id); + infof(data, "Connection #%" CURL_FORMAT_CURL_OFF_T + "isn't open enough, can't reuse", check->connection_id); continue; } @@ -1335,8 +1340,8 @@ ConnectionExists(struct Curl_easy *data, if(!Curl_ssl_config_matches(&needle->ssl_config, &check->ssl_config)) { DEBUGF(infof(data, - "Connection #%ld has different SSL parameters, " - "can't reuse", + "Connection #%" CURL_FORMAT_CURL_OFF_T + " has different SSL parameters, can't reuse", check->connection_id)); continue; } @@ -1477,14 +1482,14 @@ void Curl_verboseconnect(struct Curl_easy *data, struct connectdata *conn) { if(data->set.verbose) - infof(data, "Connected to %s (%s) port %u (#%ld)", + infof(data, "Connected to %s (%s) port %u", #ifndef CURL_DISABLE_PROXY conn->bits.socksproxy ? conn->socks_proxy.host.dispname : conn->bits.httpproxy ? conn->http_proxy.host.dispname : #endif conn->bits.conn_to_host ? conn->conn_to_host.dispname : conn->host.dispname, - conn->primary_ip, conn->port, conn->connection_id); + conn->primary_ip, conn->port); } #endif @@ -3678,15 +3683,14 @@ static CURLcode create_conn(struct Curl_easy *data, *in_connect = conn; #ifndef CURL_DISABLE_PROXY - infof(data, "Re-using existing connection #%ld with %s %s", - conn->connection_id, + infof(data, "Re-using existing connection with %s %s", conn->bits.proxy?"proxy":"host", conn->socks_proxy.host.name ? conn->socks_proxy.host.dispname : conn->http_proxy.host.name ? conn->http_proxy.host.dispname : conn->host.dispname); #else - infof(data, "Re-using existing connection #%ld with host %s", - conn->connection_id, conn->host.dispname); + infof(data, "Re-using existing connection with host %s", + conn->host.dispname); #endif } else { diff --git a/lib/urldata.h b/lib/urldata.h index ef81fc01b8..c45913b317 100644 --- a/lib/urldata.h +++ b/lib/urldata.h @@ -882,8 +882,8 @@ struct connectdata { #define CONN_INUSE(c) ((c)->easyq.size) /**** Fields set when inited and not modified again */ - long connection_id; /* Contains a unique number to make it easier to - track the connections in the log output */ + curl_off_t connection_id; /* Contains a unique number to make it easier to + track the connections in the log output */ /* 'dns_entry' is the particular host we use. This points to an entry in the DNS cache and it will not get pruned while locked. It gets unlocked in @@ -1294,7 +1294,9 @@ struct UrlState { /* buffers to store authentication data in, as parsed from input options */ struct curltime keeps_speed; /* for the progress meter really */ - long lastconnect_id; /* The last connection, -1 if undefined */ + curl_off_t lastconnect_id; /* The last connection, -1 if undefined */ + curl_off_t recent_conn_id; /* The most recent connection used, might no + * longer exist */ struct dynbuf headerb; /* buffer to store headers in */ char *buffer; /* download buffer */ @@ -1903,6 +1905,13 @@ struct Curl_easy { /* First a simple identifier to easier detect if a user mix up this easy handle with a multi handle. Set this to CURLEASY_MAGIC_NUMBER */ unsigned int magic; + /* once an easy handle is tied to a connection cache + a non-negative number to distinguish this transfer from + other using the same cache. For easier tracking + in log output. + This may wrap around after LONG_MAX to 0 again, so it + has no uniqueness guarantuee for very large processings. */ + curl_off_t id; /* first, two fields for the linked list of these */ struct Curl_easy *next; diff --git a/lib/vquic/curl_msh3.c b/lib/vquic/curl_msh3.c index 650156f59e..63c1ad1fb5 100644 --- a/lib/vquic/curl_msh3.c +++ b/lib/vquic/curl_msh3.c @@ -173,7 +173,7 @@ static CURLcode h3_data_setup(struct Curl_cfilter *cf, msh3_lock_initialize(&stream->recv_lock); Curl_bufq_init2(&stream->recvbuf, H3_STREAM_CHUNK_SIZE, H3_STREAM_RECV_CHUNKS, BUFQ_OPT_SOFT_LIMIT); - DEBUGF(LOG_CF(data, cf, "data setup (easy %p)", (void *)data)); + DEBUGF(LOG_CF(data, cf, "data setup")); return CURLE_OK; } diff --git a/lib/vquic/curl_ngtcp2.c b/lib/vquic/curl_ngtcp2.c index d529be1f7c..d113470dea 100644 --- a/lib/vquic/curl_ngtcp2.c +++ b/lib/vquic/curl_ngtcp2.c @@ -224,7 +224,7 @@ static CURLcode h3_data_setup(struct Curl_cfilter *cf, stream->recv_buf_nonflow = 0; H3_STREAM_LCTX(data) = stream; - DEBUGF(LOG_CF(data, cf, "data setup (easy %p)", (void *)data)); + DEBUGF(LOG_CF(data, cf, "data setup")); return CURLE_OK; } @@ -1670,8 +1670,7 @@ static ssize_t h3_stream_open(struct Curl_cfilter *cf, goto out; } - infof(data, "Using HTTP/3 Stream ID: %" PRId64 " (easy handle %p)", - stream->id, (void *)data); + infof(data, "Using HTTP/3 Stream ID: %" PRId64, stream->id); DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] opened for %s", stream->id, data->state.url)); diff --git a/lib/vquic/curl_quiche.c b/lib/vquic/curl_quiche.c index 3a4f9f9f20..baf69816e7 100644 --- a/lib/vquic/curl_quiche.c +++ b/lib/vquic/curl_quiche.c @@ -277,7 +277,7 @@ static CURLcode h3_data_setup(struct Curl_cfilter *cf, stream->id = -1; Curl_bufq_initp(&stream->recvbuf, &ctx->stream_bufcp, H3_STREAM_RECV_CHUNKS, BUFQ_OPT_SOFT_LIMIT); - DEBUGF(LOG_CF(data, cf, "data setup (easy %p)", (void *)data)); + DEBUGF(LOG_CF(data, cf, "data setup")); return CURLE_OK; } @@ -995,8 +995,7 @@ static ssize_t h3_open_stream(struct Curl_cfilter *cf, stream->closed = FALSE; stream->reset = FALSE; - infof(data, "Using HTTP/3 Stream ID: %" PRId64 " (easy handle %p)", - stream3_id, (void *)data); + infof(data, "Using HTTP/3 Stream ID: %" PRId64, stream3_id); DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] opened for %s", stream3_id, data->state.url)); diff --git a/lib/vtls/vtls.c b/lib/vtls/vtls.c index cdd3a4fdc1..bdc25919d0 100644 --- a/lib/vtls/vtls.c +++ b/lib/vtls/vtls.c @@ -453,7 +453,7 @@ bool Curl_ssl_getsessionid(struct Curl_cfilter *cf, } } - DEBUGF(infof(data, DMSG(data, "%s Session ID in cache for %s %s://%s:%d"), + DEBUGF(infof(data, "%s Session ID in cache for %s %s://%s:%d", no_match? "Didn't find": "Found", Curl_ssl_cf_is_proxy(cf) ? "proxy" : "host", cf->conn->handler->scheme, connssl->hostname, connssl->port)); @@ -601,8 +601,8 @@ CURLcode Curl_ssl_addsessionid(struct Curl_cfilter *cf, if(added) *added = TRUE; - DEBUGF(infof(data, DMSG(data, "Added Session ID to cache for %s://%s:%d" - " [%s]"), store->scheme, store->name, store->remote_port, + DEBUGF(infof(data, "Added Session ID to cache for %s://%s:%d [%s]", + store->scheme, store->name, store->remote_port, Curl_ssl_cf_is_proxy(cf) ? "PROXY" : "server")); return CURLE_OK; } diff --git a/lib/ws.c b/lib/ws.c index 8d1050f1c1..2994979bee 100644 --- a/lib/ws.c +++ b/lib/ws.c @@ -987,8 +987,7 @@ CURL_EXTERN CURLcode curl_ws_send(struct Curl_easy *data, const void *buffer, return CURLE_SEND_ERROR; } if(!data->conn->proto.ws) { - failf(data, "Not a websocket transfer on connection #%ld", - data->conn->connection_id); + failf(data, "Not a websocket transfer"); return CURLE_SEND_ERROR; } ws = data->conn->proto.ws; diff --git a/src/tool_writeout.c b/src/tool_writeout.c index ddf7deaa7e..2509d18b1a 100644 --- a/src/tool_writeout.c +++ b/src/tool_writeout.c @@ -75,6 +75,7 @@ static const struct httpmap http_version[] = { static const struct writeoutvar variables[] = { {"certs", VAR_CERT, CURLINFO_NONE, writeString}, {"content_type", VAR_CONTENT_TYPE, CURLINFO_CONTENT_TYPE, writeString}, + {"conn_id", VAR_CONN_ID, CURLINFO_CONN_ID, writeOffset}, {"errormsg", VAR_ERRORMSG, CURLINFO_NONE, writeString}, {"exitcode", VAR_EXITCODE, CURLINFO_NONE, writeLong}, {"filename_effective", VAR_EFFECTIVE_FILENAME, CURLINFO_NONE, writeString}, @@ -145,6 +146,7 @@ static const struct writeoutvar variables[] = { {"urle.zoneid", VAR_INPUT_URLEZONEID, CURLINFO_NONE, writeString}, {"url_effective", VAR_EFFECTIVE_URL, CURLINFO_EFFECTIVE_URL, writeString}, {"urlnum", VAR_URLNUM, CURLINFO_NONE, writeLong}, + {"xfer_id", VAR_EASY_ID, CURLINFO_XFER_ID, writeOffset}, {NULL, VAR_NONE, CURLINFO_NONE, NULL} }; diff --git a/src/tool_writeout.h b/src/tool_writeout.h index 25895bb440..4e690a65c9 100644 --- a/src/tool_writeout.h +++ b/src/tool_writeout.h @@ -32,6 +32,8 @@ typedef enum { VAR_CERT, VAR_CONNECT_TIME, VAR_CONTENT_TYPE, + VAR_CONN_ID, + VAR_EASY_ID, VAR_EFFECTIVE_FILENAME, VAR_EFFECTIVE_METHOD, VAR_EFFECTIVE_URL, diff --git a/tests/data/test1506 b/tests/data/test1506 index 2cad631ba5..aee53a9225 100644 --- a/tests/data/test1506 +++ b/tests/data/test1506 @@ -86,7 +86,7 @@ Accept: */* * Connection #0 to host server1.example.com left intact * Connection #1 to host server2.example.com left intact * Connection #2 to host server3.example.com left intact -* Closing connection 0 +* Closing connection * Connection #3 to host server4.example.com left intact diff --git a/tests/data/test1542 b/tests/data/test1542 index d9fece4166..51f312bf09 100644 --- a/tests/data/test1542 +++ b/tests/data/test1542 @@ -58,7 +58,7 @@ Accept: */* == Info: Connection #0 to host %HOSTIP left intact == Info: Connection #0 to host %HOSTIP left intact == Info: Connection #0 to host %HOSTIP left intact -== Info: Closing connection 0 +== Info: Closing connection == Info: Connection #1 to host %HOSTIP left intact diff --git a/tests/data/test970 b/tests/data/test970 index 3ff3a63559..88ab796122 100644 --- a/tests/data/test970 +++ b/tests/data/test970 @@ -59,7 +59,7 @@ Accept: */* -{"certs":"","content_type":"text/html","errormsg":null,"exitcode":0,"filename_effective":"%LOGDIR/out%TESTNUMBER","ftp_entry_path":null,"http_code":200,"http_connect":0,"http_version":"1.1","local_ip":"127.0.0.1","local_port":13,"method":"GET","num_certs":0,"num_connects":1,"num_headers":9,"num_redirects":0,"proxy_ssl_verify_result":0,"redirect_url":null,"referer":null,"remote_ip":"%HOSTIP","remote_port":%HTTPPORT,"response_code":200,"scheme":"HTTP","size_download":445,"size_header":4019,"size_request":4019,"size_upload":0,"speed_download":13,"speed_upload":13,"ssl_verify_result":0,"time_appconnect":0.000013,"time_connect":0.000013,"time_namelookup":0.000013,"time_pretransfer":0.000013,"time_redirect":0.000013,"time_starttransfer":0.000013,"time_total":0.000013,"url":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","url.scheme":"http","url.user":null,"url.password":null,"url.options":null,"url.host":"%HOSTIP","url.port":"%HTTPPORT","url.path":"/%TESTNUMBER","url.query":null,"url.fragment":null,"url.zoneid":null,"urle.scheme":"http","urle.user":null,"urle.password":null,"urle.options":null,"urle.host":"%HOSTIP","urle.port":"%HTTPPORT","urle.path":"/%TESTNUMBER","urle.query":null,"urle.fragment":null,"urle.zoneid":null,"url_effective":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","urlnum":0,"curl_version":"curl-unit-test-fake-version"} +{"certs":"","content_type":"text/html","conn_id":0,"errormsg":null,"exitcode":0,"filename_effective":"%LOGDIR/out%TESTNUMBER","ftp_entry_path":null,"http_code":200,"http_connect":0,"http_version":"1.1","local_ip":"127.0.0.1","local_port":13,"method":"GET","num_certs":0,"num_connects":1,"num_headers":9,"num_redirects":0,"proxy_ssl_verify_result":0,"redirect_url":null,"referer":null,"remote_ip":"%HOSTIP","remote_port":%HTTPPORT,"response_code":200,"scheme":"HTTP","size_download":445,"size_header":4019,"size_request":4019,"size_upload":0,"speed_download":13,"speed_upload":13,"ssl_verify_result":0,"time_appconnect":0.000013,"time_connect":0.000013,"time_namelookup":0.000013,"time_pretransfer":0.000013,"time_redirect":0.000013,"time_starttransfer":0.000013,"time_total":0.000013,"url":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","url.scheme":"http","url.user":null,"url.password":null,"url.options":null,"url.host":"%HOSTIP","url.port":"%HTTPPORT","url.path":"/%TESTNUMBER","url.query":null,"url.fragment":null,"url.zoneid":null,"urle.scheme":"http","urle.user":null,"urle.password":null,"urle.options":null,"urle.host":"%HOSTIP","urle.port":"%HTTPPORT","urle.path":"/%TESTNUMBER","urle.query":null,"urle.fragment":null,"urle.zoneid":null,"url_effective":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","urlnum":0,"xfer_id":0,"curl_version":"curl-unit-test-fake-version"} diff --git a/tests/data/test972 b/tests/data/test972 index fe8ee6f318..1dc2eca342 100644 --- a/tests/data/test972 +++ b/tests/data/test972 @@ -60,7 +60,7 @@ Accept: */* -{"certs":"","content_type":"text/html","errormsg":null,"exitcode":0,"filename_effective":"%LOGDIR/out972","ftp_entry_path":null,"http_code":200,"http_connect":0,"http_version":"1.1","local_ip":"%HOSTIP","local_port":13,"method":"GET","num_certs":0,"num_connects":1,"num_headers":9,"num_redirects":0,"proxy_ssl_verify_result":0,"redirect_url":null,"referer":null,"remote_ip":"%HOSTIP","remote_port":%HTTPPORT,"response_code":200,"scheme":"HTTP","size_download":445,"size_header":4019,"size_request":4019,"size_upload":0,"speed_download":13,"speed_upload":13,"ssl_verify_result":0,"time_appconnect":0.000013,"time_connect":0.000013,"time_namelookup":0.000013,"time_pretransfer":0.000013,"time_redirect":0.000013,"time_starttransfer":0.000013,"time_total":0.000013,"url":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","url.scheme":"http","url.user":null,"url.password":null,"url.options":null,"url.host":"%HOSTIP","url.port":"%HTTPPORT","url.path":"/%TESTNUMBER","url.query":null,"url.fragment":null,"url.zoneid":null,"urle.scheme":"http","urle.user":null,"urle.password":null,"urle.options":null,"urle.host":"%HOSTIP","urle.port":"%HTTPPORT","urle.path":"/%TESTNUMBER","urle.query":null,"urle.fragment":null,"urle.zoneid":null,"url_effective":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","urlnum":0,"curl_version":"curl-unit-test-fake-version"} +{"certs":"","content_type":"text/html","conn_id":0,"errormsg":null,"exitcode":0,"filename_effective":"%LOGDIR/out972","ftp_entry_path":null,"http_code":200,"http_connect":0,"http_version":"1.1","local_ip":"%HOSTIP","local_port":13,"method":"GET","num_certs":0,"num_connects":1,"num_headers":9,"num_redirects":0,"proxy_ssl_verify_result":0,"redirect_url":null,"referer":null,"remote_ip":"%HOSTIP","remote_port":%HTTPPORT,"response_code":200,"scheme":"HTTP","size_download":445,"size_header":4019,"size_request":4019,"size_upload":0,"speed_download":13,"speed_upload":13,"ssl_verify_result":0,"time_appconnect":0.000013,"time_connect":0.000013,"time_namelookup":0.000013,"time_pretransfer":0.000013,"time_redirect":0.000013,"time_starttransfer":0.000013,"time_total":0.000013,"url":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","url.scheme":"http","url.user":null,"url.password":null,"url.options":null,"url.host":"%HOSTIP","url.port":"%HTTPPORT","url.path":"/%TESTNUMBER","url.query":null,"url.fragment":null,"url.zoneid":null,"urle.scheme":"http","urle.user":null,"urle.password":null,"urle.options":null,"urle.host":"%HOSTIP","urle.port":"%HTTPPORT","urle.path":"/%TESTNUMBER","urle.query":null,"urle.fragment":null,"urle.zoneid":null,"url_effective":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","urlnum":0,"xfer_id":0,"curl_version":"curl-unit-test-fake-version"}