From db91dbbf2c0a853670ce0246d6d6579e6b0f6c0c Mon Sep 17 00:00:00 2001 From: Stefan Eissing Date: Wed, 11 Jan 2023 10:30:42 +0100 Subject: curl_log: for failf/infof and debug logging implementations - new functions and macros for cfilter debugging - set CURL_DEBUG with names of cfilters where debug logging should be enabled - use GNUC __attribute__ to enable printf format checks during compile Closes #10271 --- lib/Makefile.inc | 2 + lib/cf-socket.c | 67 +++++++-------- lib/cf-socket.h | 5 ++ lib/cfilters.c | 33 +------- lib/cfilters.h | 3 +- lib/connect.c | 52 +++++------- lib/connect.h | 2 + lib/curl_log.c | 219 ++++++++++++++++++++++++++++++++++++++++++++++++ lib/curl_log.h | 137 ++++++++++++++++++++++++++++++ lib/easy.c | 5 ++ lib/http2.c | 53 ++++++------ lib/http2.h | 2 + lib/http_proxy.c | 79 ++++++++--------- lib/http_proxy.h | 5 ++ lib/sendf.c | 71 ---------------- lib/sendf.h | 25 +----- lib/socks.c | 7 +- lib/socks.h | 2 + lib/urldata.h | 17 ---- lib/vquic/curl_msh3.c | 71 ++++++++-------- lib/vquic/curl_ngtcp2.c | 72 +++++++--------- lib/vquic/curl_quiche.c | 79 ++++++++--------- lib/vquic/vquic.h | 2 + lib/vtls/mbedtls.c | 8 +- lib/vtls/openssl.c | 17 ++-- lib/vtls/rustls.c | 18 ++-- lib/vtls/sectransp.c | 47 +++++------ lib/vtls/vtls.c | 19 +++-- lib/vtls/vtls.h | 3 + 29 files changed, 656 insertions(+), 466 deletions(-) create mode 100644 lib/curl_log.c create mode 100644 lib/curl_log.h (limited to 'lib') diff --git a/lib/Makefile.inc b/lib/Makefile.inc index c9fc37a58..73472fc96 100644 --- a/lib/Makefile.inc +++ b/lib/Makefile.inc @@ -120,6 +120,7 @@ LIB_CFILES = \ curl_get_line.c \ curl_gethostname.c \ curl_gssapi.c \ + curl_log.c \ curl_memrchr.c \ curl_multibyte.c \ curl_ntlm_core.c \ @@ -249,6 +250,7 @@ LIB_HFILES = \ curl_hmac.h \ curl_krb5.h \ curl_ldap.h \ + curl_log.h \ curl_md4.h \ curl_md5.h \ curl_memory.h \ diff --git a/lib/cf-socket.c b/lib/cf-socket.c index b052781ff..72fc804dd 100644 --- a/lib/cf-socket.c +++ b/lib/cf-socket.c @@ -79,14 +79,6 @@ #include "memdebug.h" -#define DEBUG_CF 1 - -#if DEBUG_CF -#define CF_DEBUGF(x) x -#else -#define CF_DEBUGF(x) do { } while(0) -#endif - static void tcpnodelay(struct Curl_easy *data, curl_socket_t sockfd) { #if defined(TCP_NODELAY) @@ -305,7 +297,6 @@ static int socket_close(struct Curl_easy *data, struct connectdata *conn, { if(use_callback && conn && conn->fclosesocket) { int rc; - CF_DEBUGF(infof(data, "socket_close(%d) via callback", (int)sock)); Curl_multi_closed(data, sock); Curl_set_in_callback(data, true); rc = conn->fclosesocket(conn->closesocket_client, sock); @@ -313,7 +304,6 @@ static int socket_close(struct Curl_easy *data, struct connectdata *conn, return rc; } - CF_DEBUGF(infof(data, "socket_close(%d)", (int)sock)); if(conn) /* tell the multi-socket code about this */ Curl_multi_closed(data, sock); @@ -777,22 +767,20 @@ static void cf_socket_close(struct Curl_cfilter *cf, struct Curl_easy *data) * closed it) and we just forget about it. */ if(ctx->sock == cf->conn->sock[cf->sockindex]) { - CF_DEBUGF(infof(data, CFMSG(cf, "cf_socket_close(%d) active"), - (int)ctx->sock)); + DEBUGF(LOG_CF(data, cf, "cf_socket_close(%d) active", (int)ctx->sock)); socket_close(data, cf->conn, !ctx->accepted, ctx->sock); cf->conn->sock[cf->sockindex] = CURL_SOCKET_BAD; } else { - CF_DEBUGF(infof(data, CFMSG(cf, "cf_socket_close(%d) no longer at " - "conn->sock[%d], discarding"), (int)ctx->sock)); + DEBUGF(LOG_CF(data, cf, "cf_socket_close(%d) no longer at " + "conn->sock[], discarding", (int)ctx->sock)); } if(cf->sockindex == FIRSTSOCKET) cf->conn->remote_addr = NULL; } else { /* this is our local socket, we did never publish it */ - CF_DEBUGF(infof(data, CFMSG(cf, "cf_socket_close(%d) local"), - (int)ctx->sock)); + DEBUGF(LOG_CF(data, cf, "cf_socket_close(%d) local", (int)ctx->sock)); sclose(ctx->sock); } ctx->sock = CURL_SOCKET_BAD; @@ -807,6 +795,7 @@ static void cf_socket_destroy(struct Curl_cfilter *cf, struct Curl_easy *data) struct cf_socket_ctx *ctx = cf->ctx; cf_socket_close(cf, data); + DEBUGF(LOG_CF(data, cf, "destroy")); free(ctx); cf->ctx = NULL; } @@ -1018,7 +1007,7 @@ static CURLcode cf_tcp_connect(struct Curl_cfilter *cf, CURLcode result = CURLE_COULDNT_CONNECT; int rc = 0; - CF_DEBUGF(infof(data, CFMSG(cf, "connect"))); + DEBUGF(LOG_CF(data, cf, "connect")); (void)data; if(cf->connected) { *done = TRUE; @@ -1036,7 +1025,7 @@ static CURLcode cf_tcp_connect(struct Curl_cfilter *cf, if(result) goto out; - CF_DEBUGF(infof(data, CFMSG(cf, "connect opened(%d)"), (int)ctx->sock)); + DEBUGF(LOG_CF(data, cf, "connect opened(%d)", (int)ctx->sock)); /* Connect TCP socket */ rc = do_connect(cf, data); if(-1 == rc) { @@ -1141,8 +1130,8 @@ static ssize_t cf_socket_send(struct Curl_cfilter *cf, struct Curl_easy *data, DEBUGASSERT(data->conn == cf->conn); nwritten = Curl_send_plain(data, cf->sockindex, buf, len, err); - CF_DEBUGF(infof(data, CFMSG(cf, "send(len=%zu) -> %d, err=%d"), - len, (int)nwritten, *err)); + DEBUGF(LOG_CF(data, cf, "send(len=%zu) -> %d, err=%d", + len, (int)nwritten, *err)); return nwritten; } @@ -1153,8 +1142,8 @@ static ssize_t cf_socket_recv(struct Curl_cfilter *cf, struct Curl_easy *data, DEBUGASSERT(data->conn == cf->conn); nread = Curl_recv_plain(data, cf->sockindex, buf, len, err); - CF_DEBUGF(infof(data, CFMSG(cf, "recv(len=%zu) -> %d, err=%d"), - len, (int)nread, *err)); + DEBUGF(LOG_CF(data, cf, "recv(len=%zu) -> %d, err=%d", len, (int)nread, + *err)); return nread; } @@ -1263,9 +1252,10 @@ static bool cf_socket_conn_is_alive(struct Curl_cfilter *cf, return TRUE; } -static const struct Curl_cftype cft_tcp = { +struct Curl_cftype Curl_cft_tcp = { "TCP", CF_TYPE_IP_CONNECT, + CURL_LOG_DEFAULT, cf_socket_destroy, cf_tcp_connect, cf_socket_close, @@ -1300,7 +1290,7 @@ CURLcode Curl_cf_tcp_create(struct Curl_cfilter **pcf, Curl_sock_assign_addr(&ctx->addr, ai, ctx->transport); ctx->sock = CURL_SOCKET_BAD; - result = Curl_cf_create(&cf, &cft_tcp, ctx); + result = Curl_cf_create(&cf, &Curl_cft_tcp, ctx); out: *pcf = (!result)? cf : NULL; @@ -1342,9 +1332,10 @@ static CURLcode cf_udp_connect(struct Curl_cfilter *cf, return result; } -static const struct Curl_cftype cft_udp = { +struct Curl_cftype Curl_cft_udp = { "UDP", CF_TYPE_IP_CONNECT, + CURL_LOG_DEFAULT, cf_socket_destroy, cf_udp_connect, cf_socket_close, @@ -1379,7 +1370,7 @@ CURLcode Curl_cf_udp_create(struct Curl_cfilter **pcf, Curl_sock_assign_addr(&ctx->addr, ai, ctx->transport); ctx->sock = CURL_SOCKET_BAD; - result = Curl_cf_create(&cf, &cft_udp, ctx); + result = Curl_cf_create(&cf, &Curl_cft_udp, ctx); out: *pcf = (!result)? cf : NULL; @@ -1392,9 +1383,10 @@ out: } /* this is the TCP filter which can also handle this case */ -static const struct Curl_cftype cft_unix = { +struct Curl_cftype Curl_cft_unix = { "UNIX", CF_TYPE_IP_CONNECT, + CURL_LOG_DEFAULT, cf_socket_destroy, cf_tcp_connect, cf_socket_close, @@ -1429,7 +1421,7 @@ CURLcode Curl_cf_unix_create(struct Curl_cfilter **pcf, Curl_sock_assign_addr(&ctx->addr, ai, ctx->transport); ctx->sock = CURL_SOCKET_BAD; - result = Curl_cf_create(&cf, &cft_unix, ctx); + result = Curl_cf_create(&cf, &Curl_cft_unix, ctx); out: *pcf = (!result)? cf : NULL; @@ -1455,9 +1447,10 @@ static CURLcode cf_tcp_accept_connect(struct Curl_cfilter *cf, return CURLE_FAILED_INIT; } -static const struct Curl_cftype cft_tcp_accept = { +struct Curl_cftype Curl_cft_tcp_accept = { "TCP-ACCEPT", CF_TYPE_IP_CONNECT, + CURL_LOG_DEFAULT, cf_socket_destroy, cf_tcp_accept_connect, cf_socket_close, @@ -1492,7 +1485,7 @@ CURLcode Curl_conn_tcp_listen_set(struct Curl_easy *data, ctx->transport = conn->transport; ctx->sock = *s; ctx->accepted = FALSE; - result = Curl_cf_create(&cf, &cft_tcp_accept, ctx); + result = Curl_cf_create(&cf, &Curl_cft_tcp_accept, ctx); if(result) goto out; Curl_conn_cf_add(data, conn, sockindex, cf); @@ -1502,8 +1495,7 @@ CURLcode Curl_conn_tcp_listen_set(struct Curl_easy *data, set_local_ip(cf, data); ctx->active = TRUE; cf->connected = TRUE; - CF_DEBUGF(infof(data, CFMSG(cf, "Curl_conn_tcp_listen_set(%d)"), - (int)ctx->sock)); + DEBUGF(LOG_CF(data, cf, "Curl_conn_tcp_listen_set(%d)", (int)ctx->sock)); out: if(result) { @@ -1521,7 +1513,7 @@ CURLcode Curl_conn_tcp_accepted_set(struct Curl_easy *data, struct cf_socket_ctx *ctx = NULL; cf = conn->cfilter[sockindex]; - if(!cf || cf->cft != &cft_tcp_accept) + if(!cf || cf->cft != &Curl_cft_tcp_accept) return CURLE_FAILED_INIT; ctx = cf->ctx; @@ -1534,16 +1526,17 @@ CURLcode Curl_conn_tcp_accepted_set(struct Curl_easy *data, ctx->active = TRUE; ctx->accepted = TRUE; cf->connected = TRUE; - CF_DEBUGF(infof(data, CFMSG(cf, "Curl_conn_tcp_accepted_set(%d)"), - (int)ctx->sock)); + DEBUGF(LOG_CF(data, cf, "Curl_conn_tcp_accepted_set(%d)", (int)ctx->sock)); return CURLE_OK; } bool Curl_cf_is_socket(struct Curl_cfilter *cf) { - return cf && (cf->cft == &cft_tcp || cf->cft == &cft_udp || - cf->cft == &cft_unix || cf->cft == &cft_tcp_accept); + return cf && (cf->cft == &Curl_cft_tcp || + cf->cft == &Curl_cft_udp || + cf->cft == &Curl_cft_unix || + cf->cft == &Curl_cft_tcp_accept); } CURLcode Curl_cf_socket_peek(struct Curl_cfilter *cf, diff --git a/lib/cf-socket.h b/lib/cf-socket.h index 9f1b01d4b..af2b3e30e 100644 --- a/lib/cf-socket.h +++ b/lib/cf-socket.h @@ -178,4 +178,9 @@ CURLcode Curl_cf_socket_peek(struct Curl_cfilter *cf, const char **premote_ip_str, int *premote_port); +extern struct Curl_cftype Curl_cft_tcp; +extern struct Curl_cftype Curl_cft_udp; +extern struct Curl_cftype Curl_cft_unix; +extern struct Curl_cftype Curl_cft_tcp_accept; + #endif /* HEADER_CURL_CF_SOCKET_H */ diff --git a/lib/cfilters.c b/lib/cfilters.c index 7f524cdb8..9582a951a 100644 --- a/lib/cfilters.c +++ b/lib/cfilters.c @@ -44,13 +44,6 @@ #define ARRAYSIZE(A) (sizeof(A)/sizeof((A)[0])) #endif -#define DEBUG_CF 0 - -#if DEBUG_CF -#define CF_DEBUGF(x) x -#else -#define CF_DEBUGF(x) do { } while(0) -#endif void Curl_cf_def_destroy_this(struct Curl_cfilter *cf, struct Curl_easy *data) { @@ -197,7 +190,6 @@ ssize_t Curl_conn_recv(struct Curl_easy *data, int num, char *buf, size_t len, CURLcode *code) { struct Curl_cfilter *cf; - ssize_t nread; DEBUGASSERT(data); DEBUGASSERT(data->conn); @@ -206,10 +198,7 @@ ssize_t Curl_conn_recv(struct Curl_easy *data, int num, char *buf, cf = cf->next; } if(cf) { - nread = cf->cft->do_recv(cf, data, buf, len, code); - CF_DEBUGF(infof(data, "Curl_conn_recv(handle=%p, index=%d)" - "-> %ld, err=%d", data, num, nread, *code)); - return nread; + return cf->cft->do_recv(cf, data, buf, len, code); } failf(data, CMSGI(data->conn, num, "recv: no filter connected")); *code = CURLE_FAILED_INIT; @@ -220,7 +209,6 @@ ssize_t Curl_conn_send(struct Curl_easy *data, int num, const void *mem, size_t len, CURLcode *code) { struct Curl_cfilter *cf; - ssize_t nwritten; DEBUGASSERT(data); DEBUGASSERT(data->conn); @@ -229,10 +217,7 @@ ssize_t Curl_conn_send(struct Curl_easy *data, int num, cf = cf->next; } if(cf) { - nwritten = cf->cft->do_send(cf, data, mem, len, code); - CF_DEBUGF(infof(data, "Curl_conn_send(handle=%p, index=%d, len=%ld)" - " -> %ld, err=%d", data, num, len, nwritten, *code)); - return nwritten; + return cf->cft->do_send(cf, data, mem, len, code); } failf(data, CMSGI(data->conn, num, "send: no filter connected")); DEBUGASSERT(0); @@ -274,7 +259,7 @@ void Curl_conn_cf_add(struct Curl_easy *data, cf->conn = conn; cf->sockindex = index; conn->cfilter[index] = cf; - CF_DEBUGF(infof(data, CFMSG(cf, "added"))); + DEBUGF(LOG_CF(data, cf, "added")); } void Curl_conn_cf_insert_after(struct Curl_cfilter *cf_at, @@ -381,18 +366,6 @@ CURLcode Curl_conn_connect(struct Curl_easy *data, } } -#ifdef DEBUGBUILD - if(result) { - CF_DEBUGF(infof(data, DMSGI(data, sockindex, "connect()-> %d, done=%d"), - result, *done)); - } - else if(!*done) { - while(cf->next && !cf->next->connected) - cf = cf->next; - CF_DEBUGF(infof(data, DMSGI(data, sockindex, "connect()-> waiting for %s"), - cf->cft->name)); - } -#endif return result; } diff --git a/lib/cfilters.h b/lib/cfilters.h index 4f10847f5..e101cd37e 100644 --- a/lib/cfilters.h +++ b/lib/cfilters.h @@ -153,7 +153,8 @@ typedef CURLcode Curl_cft_query(struct Curl_cfilter *cf, /* A connection filter type, e.g. specific implementation. */ struct Curl_cftype { const char *name; /* name of the filter type */ - long flags; /* flags of filter type */ + int flags; /* flags of filter type */ + int log_level; /* log level for such filters */ Curl_cft_destroy_this *destroy; /* destroy resources of this cf */ Curl_cft_connect *connect; /* establish connection */ Curl_cft_close *close; /* close conn */ diff --git a/lib/connect.c b/lib/connect.c index dfcf51401..663cf3aff 100644 --- a/lib/connect.c +++ b/lib/connect.c @@ -82,13 +82,6 @@ #include "curl_memory.h" #include "memdebug.h" -#define DEBUG_CF 0 - -#if DEBUG_CF -#define CF_DEBUGF(x) x -#else -#define CF_DEBUGF(x) do { } while(0) -#endif /* * Curl_timeleft() returns the amount of milliseconds left allowed for the @@ -473,7 +466,7 @@ static void baller_initiate(struct Curl_cfilter *cf, out: if(result) { - CF_DEBUGF(infof(data, "eyeballer[%s] failed", baller->name)); + DEBUGF(LOG_CF(data, cf, "%s failed", baller->name)); baller_close(baller, data); } if(cf_prev) @@ -597,8 +590,8 @@ evaluate: continue; } baller->result = baller_connect(cf, data, baller, &now, connected); - CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%s] connect -> %d, " - "connected=%d"), baller->name, baller->result, *connected)); + DEBUGF(LOG_CF(data, cf, "%s connect -> %d, connected=%d", + baller->name, baller->result, *connected)); if(!baller->result) { if(*connected) { @@ -621,12 +614,11 @@ evaluate: baller->timeoutms = baller->addr->ai_next == NULL ? allow : allow / 2; baller_start_next(cf, data, baller); if(baller->is_done) { - CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%s] done"), baller->name)); + DEBUGF(LOG_CF(data, cf, "%s done", baller->name)); } else { /* next attempt was started */ - CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%s] trying next"), - baller->name)); + DEBUGF(LOG_CF(data, cf, "%s trying next", baller->name)); ++ongoing; } } @@ -660,12 +652,10 @@ evaluate: Curl_timediff(now, ctx->started) >= baller->delay_ms) { baller_start(cf, data, baller); if(baller->is_done) { - CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%s] done"), - baller->name)); + DEBUGF(LOG_CF(data, cf, "%s done", baller->name)); } else { - CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%s] starting"), - baller->name)); + DEBUGF(LOG_CF(data, cf, "%s starting", baller->name)); ++ongoing; ++added; } @@ -682,13 +672,12 @@ evaluate: } /* all ballers have failed to connect. */ - CF_DEBUGF(infof(data, CFMSG(cf, "all eyeballers failed"))); + DEBUGF(LOG_CF(data, cf, "all eyeballers failed")); result = CURLE_COULDNT_CONNECT; for(i = 0; i < sizeof(ctx->baller)/sizeof(ctx->baller[0]); i++) { struct eyeballer *baller = ctx->baller[i]; - CF_DEBUGF(infof(data, CFMSG(cf, "eyeballer[%s] assess started=%d, " - "result=%d"), - baller->name, baller->has_started, baller->result)); + DEBUGF(LOG_CF(data, cf, "%s assess started=%d, result=%d", + baller->name, baller->has_started, baller->result)); if(baller && baller->has_started && baller->result) { result = baller->result; break; @@ -926,7 +915,7 @@ static void cf_he_close(struct Curl_cfilter *cf, { struct cf_he_ctx *ctx = cf->ctx; - CF_DEBUGF(infof(data, CFMSG(cf, "close"))); + DEBUGF(LOG_CF(data, cf, "close")); cf_he_ctx_clear(cf, data); cf->connected = FALSE; ctx->state = SCFST_INIT; @@ -960,7 +949,7 @@ static void cf_he_destroy(struct Curl_cfilter *cf, struct Curl_easy *data) { struct cf_he_ctx *ctx = cf->ctx; - CF_DEBUGF(infof(data, CFMSG(cf, "destroy"))); + DEBUGF(LOG_CF(data, cf, "destroy")); if(ctx) { cf_he_ctx_clear(cf, data); } @@ -968,9 +957,10 @@ static void cf_he_destroy(struct Curl_cfilter *cf, struct Curl_easy *data) Curl_safefree(ctx); } -static const struct Curl_cftype cft_happy_eyeballs = { +struct Curl_cftype Curl_cft_happy_eyeballs = { "HAPPY-EYEBALLS", 0, + CURL_LOG_DEFAULT, cf_he_destroy, cf_he_connect, cf_he_close, @@ -1005,7 +995,7 @@ CURLcode Curl_cf_happy_eyeballs_create(struct Curl_cfilter **pcf, ctx->cf_create = cf_create; ctx->remotehost = remotehost; - result = Curl_cf_create(pcf, &cft_happy_eyeballs, ctx); + result = Curl_cf_create(pcf, &Curl_cft_happy_eyeballs, ctx); out: if(result) { @@ -1046,8 +1036,7 @@ static CURLcode cf_he_insert_after(struct Curl_cfilter *cf_at, DEBUGASSERT(cf_at); cf_create = get_cf_create(transport); if(!cf_create) { - CF_DEBUGF(infof(data, DMSG(data, "unsupported transport type %d"), - transport)); + DEBUGF(LOG_CF(data, cf_at, "unsupported transport type %d", transport)); return CURLE_UNSUPPORTED_PROTOCOL; } result = Curl_cf_happy_eyeballs_create(&cf, data, cf_at->conn, @@ -1184,7 +1173,7 @@ static void cf_setup_close(struct Curl_cfilter *cf, { struct cf_setup_ctx *ctx = cf->ctx; - CF_DEBUGF(infof(data, CFMSG(cf, "close"))); + DEBUGF(LOG_CF(data, cf, "close")); cf->connected = FALSE; ctx->state = CF_SETUP_INIT; @@ -1199,14 +1188,15 @@ static void cf_setup_destroy(struct Curl_cfilter *cf, struct Curl_easy *data) struct cf_setup_ctx *ctx = cf->ctx; (void)data; - CF_DEBUGF(infof(data, CFMSG(cf, "destroy"))); + DEBUGF(LOG_CF(data, cf, "destroy")); Curl_safefree(ctx); } -static const struct Curl_cftype cft_setup = { +struct Curl_cftype Curl_cft_setup = { "SETUP", 0, + CURL_LOG_DEFAULT, cf_setup_destroy, cf_setup_connect, cf_setup_close, @@ -1245,7 +1235,7 @@ CURLcode Curl_conn_setup(struct Curl_easy *data, ctx->remotehost = remotehost; ctx->ssl_mode = ssl_mode; - result = Curl_cf_create(&cf, &cft_setup, ctx); + result = Curl_cf_create(&cf, &Curl_cft_setup, ctx); if(result) goto out; ctx = NULL; diff --git a/lib/connect.h b/lib/connect.h index 24c21310a..0372d387a 100644 --- a/lib/connect.h +++ b/lib/connect.h @@ -132,5 +132,7 @@ CURLcode Curl_conn_setup(struct Curl_easy *data, const struct Curl_dns_entry *remotehost, int ssl_mode); +extern struct Curl_cftype Curl_cft_happy_eyeballs; +extern struct Curl_cftype Curl_cft_setup; #endif /* HEADER_CURL_CONNECT_H */ diff --git a/lib/curl_log.c b/lib/curl_log.c new file mode 100644 index 000000000..0a792a7e7 --- /dev/null +++ b/lib/curl_log.c @@ -0,0 +1,219 @@ +/*************************************************************************** + * _ _ ____ _ + * 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 + * + ***************************************************************************/ + +#include "curl_setup.h" + +#include + +#include "curl_log.h" +#include "urldata.h" +#include "easyif.h" +#include "cfilters.h" +#include "timeval.h" +#include "multiif.h" +#include "strcase.h" + +#include "cf-socket.h" +#include "connect.h" +#include "http2.h" +#include "http_proxy.h" +#include "socks.h" +#include "strtok.h" +#include "vtls/vtls.h" +#include "vquic/vquic.h" + +/* The last 3 #include files should be in this order */ +#include "curl_printf.h" +#include "curl_memory.h" +#include "memdebug.h" + + +void Curl_debug(struct Curl_easy *data, curl_infotype type, + char *ptr, size_t size) +{ + if(data->set.verbose) { + static const char s_infotype[CURLINFO_END][3] = { + "* ", "< ", "> ", "{ ", "} ", "{ ", "} " }; + if(data->set.fdebug) { + bool inCallback = Curl_is_in_callback(data); + Curl_set_in_callback(data, true); + (void)(*data->set.fdebug)(data, type, ptr, size, data->set.debugdata); + Curl_set_in_callback(data, inCallback); + } + else { + switch(type) { + case CURLINFO_TEXT: + case CURLINFO_HEADER_OUT: + case CURLINFO_HEADER_IN: + fwrite(s_infotype[type], 2, 1, data->set.err); + fwrite(ptr, size, 1, data->set.err); + break; + default: /* nada */ + break; + } + } + } +} + + +/* Curl_failf() is for messages stating why we failed. + * The message SHALL NOT include any LF or CR. + */ +void Curl_failf(struct Curl_easy *data, const char *fmt, ...) +{ + DEBUGASSERT(!strchr(fmt, '\n')); + if(data->set.verbose || data->set.errorbuffer) { + va_list ap; + int len; + char error[CURL_ERROR_SIZE + 2]; + va_start(ap, fmt); + len = mvsnprintf(error, CURL_ERROR_SIZE, fmt, ap); + + if(data->set.errorbuffer && !data->state.errorbuf) { + strcpy(data->set.errorbuffer, error); + data->state.errorbuf = TRUE; /* wrote error string */ + } + error[len++] = '\n'; + error[len] = '\0'; + Curl_debug(data, CURLINFO_TEXT, error, len); + va_end(ap); + } +} + +/* Curl_infof() is for info message along the way */ +#define MAXINFO 2048 + +void Curl_infof(struct Curl_easy *data, const char *fmt, ...) +{ + DEBUGASSERT(!strchr(fmt, '\n')); + if(data && data->set.verbose) { + va_list ap; + int len; + char buffer[MAXINFO + 2]; + va_start(ap, fmt); + len = mvsnprintf(buffer, MAXINFO, fmt, ap); + va_end(ap); + buffer[len++] = '\n'; + buffer[len] = '\0'; + Curl_debug(data, CURLINFO_TEXT, buffer, len); + } +} + +#ifdef DEBUGBUILD + +void Curl_log_cf_debug(struct Curl_easy *data, struct Curl_cfilter *cf, + const char *fmt, ...) +{ + DEBUGASSERT(cf); + if(data && Curl_log_cf_is_debug(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); + va_start(ap, fmt); + len += mvsnprintf(buffer + len, MAXINFO - len, fmt, ap); + va_end(ap); + buffer[len++] = '\n'; + buffer[len] = '\0'; + Curl_debug(data, CURLINFO_TEXT, buffer, len); + } +} + + +static struct Curl_cftype *cf_types[] = { + &Curl_cft_tcp, + &Curl_cft_udp, + &Curl_cft_unix, + &Curl_cft_tcp_accept, + &Curl_cft_happy_eyeballs, + &Curl_cft_setup, +#ifdef USE_NGHTTP2 + &Curl_cft_nghttp2, +#endif +#ifdef USE_SSL + &Curl_cft_ssl, + &Curl_cft_ssl_proxy, +#endif +#if !defined(CURL_DISABLE_PROXY) +#if !defined(CURL_DISABLE_HTTP) + &Curl_cft_http_proxy, +#endif /* !CURL_DISABLE_HTTP */ + &Curl_cft_haproxy, + &Curl_cft_socks_proxy, +#endif /* !CURL_DISABLE_PROXY */ +#ifdef ENABLE_QUIC + &Curl_cft_http3, +#endif + NULL, +}; + +#ifndef ARRAYSIZE +#define ARRAYSIZE(A) (sizeof(A)/sizeof((A)[0])) +#endif + +CURLcode Curl_log_init(void) +{ + const char *setting = getenv("CURL_DEBUG"); + if(setting) { + char *token, *tok_buf, *tmp; + size_t i; + + tmp = strdup(setting); + if(!tmp) + return CURLE_OUT_OF_MEMORY; + + token = strtok_r(tmp, ", ", &tok_buf); + while(token) { + for(i = 0; cf_types[i]; ++i) { + if(strcasecompare(token, cf_types[i]->name)) { + cf_types[i]->log_level = CURL_LOG_DEBUG; + break; + } + } + token = strtok_r(NULL, ", ", &tok_buf); + } + free(tmp); + } + return CURLE_OK; +} +#else /* DEBUGBUILD */ + +CURLcode Curl_log_init(void) +{ + return CURLE_OK; +} + +#if !defined(__STDC_VERSION__) || (__STDC_VERSION__ < 199901L) +void Curl_log_cf_debug(struct Curl_easy *data, struct Curl_cfilter *cf, + const char *fmt, ...) +{ + (void)data; + (void)cf; + (void)fmt; +} +#endif + +#endif /* !DEBUGBUILD */ diff --git a/lib/curl_log.h b/lib/curl_log.h new file mode 100644 index 000000000..9ce1e9133 --- /dev/null +++ b/lib/curl_log.h @@ -0,0 +1,137 @@ +#ifndef HEADER_CURL_LOG_H +#define HEADER_CURL_LOG_H +/*************************************************************************** + * _ _ ____ _ + * 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 + * + ***************************************************************************/ + +struct Curl_easy; +struct Curl_cfilter; + +/** + * Init logging, return != 0 on failure. + */ +CURLcode Curl_log_init(void); + + +void Curl_infof(struct Curl_easy *, const char *fmt, ...); +void Curl_failf(struct Curl_easy *, const char *fmt, ...); + +#if defined(CURL_DISABLE_VERBOSE_STRINGS) + +#if defined(HAVE_VARIADIC_MACROS_C99) +#define infof(...) Curl_nop_stmt +#elif defined(HAVE_VARIADIC_MACROS_GCC) +#define infof(x...) Curl_nop_stmt +#else +#error "missing VARIADIC macro define, fix and rebuild!" +#endif + +#else /* CURL_DISABLE_VERBOSE_STRINGS */ + +#define infof Curl_infof + +#endif /* CURL_DISABLE_VERBOSE_STRINGS */ + +#define failf Curl_failf + + +#define CURL_LOG_DEFAULT 0 +#define CURL_LOG_DEBUG 1 +#define CURL_LOG_TRACE 2 + + +/* the function used to output verbose information */ +void Curl_debug(struct Curl_easy *data, curl_infotype type, + char *ptr, size_t size); + +#ifdef DEBUGBUILD + +/* explainer: we have some mix configuration and werror settings + * that define HAVE_VARIADIC_MACROS_C99 even though C89 is enforced + * on gnuc and some other compiler. Need to treat carefully. + */ +#if defined(HAVE_VARIADIC_MACROS_C99) && \ + defined(__STDC_VERSION__) && (__STDC_VERSION__ >= 199901L) + +#define LOG_CF(data, cf, ...) \ + do { if(Curl_log_cf_is_debug(cf)) \ + Curl_log_cf_debug(data, cf, __VA_ARGS__); } while(0) +#else +#define LOG_CF Curl_log_cf_debug +#endif + +void Curl_log_cf_debug(struct Curl_easy *data, struct Curl_cfilter *cf, +#if defined(__GNUC__) && !defined(printf) && \ + defined(__STDC_VERSION__) && (__STDC_VERSION__ >= 199901L) + const char *fmt, ...) + __attribute__((format(printf, 3, 4))); +#else + const char *fmt, ...); +#endif + +#define Curl_log_cf_is_debug(cf) \ + ((cf) && (cf)->cft->log_level >= CURL_LOG_DEBUG) + +#else /* !DEBUGBUILD */ + +#if defined(HAVE_VARIADIC_MACROS_C99) && \ + defined(__STDC_VERSION__) && (__STDC_VERSION__ >= 199901L) +#define LOG_CF(...) Curl_nop_stmt +#define Curl_log_cf_debug(...) Curl_nop_stmt +#elif defined(HAVE_VARIADIC_MACROS_GCC) && \ + defined(__STDC_VERSION__) && (__STDC_VERSION__ >= 199901L) +#define LOG_CF(x...) Curl_nop_stmt +#define Curl_log_cf_debug(x...) Curl_nop_stmt +#else +#define LOG_CF Curl_log_cf_debug +/* without c99, we seem unable to completely define away this function. */ +void Curl_log_cf_debug(struct Curl_easy *data, struct Curl_cfilter *cf, + const char *fmt, ...); +#endif + +#define Curl_log_cf_is_debug(x) ((void)(x), FALSE) + +#endif /* !DEBUGBUILD */ + +#define LOG_CF_IS_DEBUG(x) Curl_log_cf_is_debug(x) + +/* 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 f5ccaae6e..2cd1ada4e 100644 --- a/lib/easy.c +++ b/lib/easy.c @@ -165,6 +165,11 @@ static CURLcode global_init(long flags, bool memoryfuncs) #endif } + if(Curl_log_init()) { + DEBUGF(fprintf(stderr, "Error: Curl_log_init failed\n")); + goto fail; + } + if(!Curl_ssl_init()) { DEBUGF(fprintf(stderr, "Error: Curl_ssl_init failed\n")); goto fail; diff --git a/lib/http2.c b/lib/http2.c index 88064aa1a..a1628ef44 100644 --- a/lib/http2.c +++ b/lib/http2.c @@ -64,6 +64,7 @@ #define HTTP2_HUGE_WINDOW_SIZE (32 * 1024 * 1024) /* 32 MB */ + #define DEBUG_HTTP2 #ifdef DEBUG_HTTP2 #define H2BUGF(x) x @@ -776,19 +777,19 @@ static int on_frame_recv(nghttp2_session *session, const nghttp2_frame *frame, switch(frame->hd.type) { case NGHTTP2_SETTINGS: { uint32_t max_conn = ctx->max_concurrent_streams; - H2BUGF(infof(data, CFMSG(cf, "recv frame SETTINGS"))); + DEBUGF(LOG_CF(data, cf, "recv frame SETTINGS")); ctx->max_concurrent_streams = nghttp2_session_get_remote_settings( session, NGHTTP2_SETTINGS_MAX_CONCURRENT_STREAMS); ctx->enable_push = nghttp2_session_get_remote_settings( session, NGHTTP2_SETTINGS_ENABLE_PUSH); - H2BUGF(infof(data, CFMSG(cf, "MAX_CONCURRENT_STREAMS == %d"), - ctx->max_concurrent_streams)); - H2BUGF(infof(data, CFMSG(cf, "ENABLE_PUSH == %s"), - ctx->enable_push?"TRUE":"false")); + DEBUGF(LOG_CF(data, cf, "MAX_CONCURRENT_STREAMS == %d", + ctx->max_concurrent_streams)); + DEBUGF(LOG_CF(data, cf, "ENABLE_PUSH == %s", + ctx->enable_push ? "TRUE" : "false")); if(data && max_conn != ctx->max_concurrent_streams) { /* only signal change if the value actually changed */ - infof(data, CFMSG(cf, "MAX_CONCURRENT_STREAMS now %u"), - ctx->max_concurrent_streams); + DEBUGF(LOG_CF(data, cf, "MAX_CONCURRENT_STREAMS now %u", + ctx->max_concurrent_streams)); multi_connchanged(data->multi); } break; @@ -801,31 +802,30 @@ static int on_frame_recv(nghttp2_session *session, const nghttp2_frame *frame, } break; case NGHTTP2_WINDOW_UPDATE: - H2BUGF(infof(data, CFMSG(cf, "recv frame WINDOW_UPDATE"))); + DEBUGF(LOG_CF(data, cf, "recv frame WINDOW_UPDATE")); break; default: - H2BUGF(infof(data, CFMSG(cf, "recv frame %x on 0"), frame->hd.type)); + DEBUGF(LOG_CF(data, cf, "recv frame %x on 0", frame->hd.type)); } return 0; } data_s = nghttp2_session_get_stream_user_data(session, stream_id); if(!data_s) { - H2BUGF(infof(data, CFMSG(cf, "No Curl_easy associated with stream: %u"), - stream_id)); + DEBUGF(LOG_CF(data, cf, "No Curl_easy associated with stream: %u", + stream_id)); return 0; } stream = data_s->req.p.http; if(!stream) { - H2BUGF(infof(data_s, CFMSG(cf, "No proto pointer for stream: %u"), - stream_id)); + DEBUGF(LOG_CF(data_s, cf, "No proto pointer for stream: %u", stream_id)); return NGHTTP2_ERR_CALLBACK_FAILURE; } switch(frame->hd.type) { case NGHTTP2_DATA: /* If body started on this stream, then receiving DATA is illegal. */ - H2BUGF(infof(data_s, CFMSG(cf, "recv frame DATA stream %u"), stream_id)); + DEBUGF(LOG_CF(data_s, cf, "recv frame DATA stream %u", stream_id)); if(!stream->bodystarted) { rv = nghttp2_submit_rst_stream(session, NGHTTP2_FLAG_NONE, stream_id, NGHTTP2_PROTOCOL_ERROR); @@ -836,8 +836,7 @@ static int on_frame_recv(nghttp2_session *session, const nghttp2_frame *frame, } break; case NGHTTP2_HEADERS: - H2BUGF(infof(data_s, CFMSG(cf, "recv frame HEADERS stream %u"), - stream_id)); + DEBUGF(LOG_CF(data_s, cf, "recv frame HEADERS stream %u", stream_id)); if(stream->bodystarted) { /* Only valid HEADERS after body started is trailer HEADERS. We buffer them in on_header callback. */ @@ -871,8 +870,8 @@ static int on_frame_recv(nghttp2_session *session, const nghttp2_frame *frame, stream->nread_header_recvbuf += ncopy; DEBUGASSERT(stream->mem); - H2BUGF(infof(data_s, CFMSG(cf, "%zu header bytes, stream %u at %p"), - ncopy, stream_id, stream->mem)); + DEBUGF(LOG_CF(data_s, cf, "%zu header bytes, stream %u at %p", + ncopy, stream_id, (void *)stream->mem)); stream->len -= ncopy; stream->memlen += ncopy; @@ -883,8 +882,7 @@ static int on_frame_recv(nghttp2_session *session, const nghttp2_frame *frame, Curl_expire(data_s, 0, EXPIRE_RUN_NOW); break; case NGHTTP2_PUSH_PROMISE: - H2BUGF(infof(data_s, CFMSG(cf, "recv frame PUSH_PROMISE stream %u"), - stream_id)); + DEBUGF(LOG_CF(data_s, cf, "recv frame PUSH_PROMISE stream %u", stream_id)); rv = push_promise(cf, data_s, &frame->push_promise); if(rv) { /* deny! */ int h2; @@ -895,14 +893,14 @@ static int on_frame_recv(nghttp2_session *session, const nghttp2_frame *frame, if(nghttp2_is_fatal(h2)) return NGHTTP2_ERR_CALLBACK_FAILURE; else if(rv == CURL_PUSH_ERROROUT) { - DEBUGF(infof(data_s, CFMSG(cf, "Fail the parent stream (too)"))); + DEBUGF(LOG_CF(data_s, cf, "Fail the parent stream (too)")); return NGHTTP2_ERR_CALLBACK_FAILURE; } } break; default: - H2BUGF(infof(data_s, CFMSG(cf, "recv frame %x for stream %u"), - frame->hd.type, stream_id)); + DEBUGF(LOG_CF(data_s, cf, "recv frame %x for stream %u", + frame->hd.type, stream_id)); break; } return 0; @@ -2248,9 +2246,10 @@ static CURLcode h2_cf_query(struct Curl_cfilter *cf, CURLE_UNKNOWN_OPTION; } -static const struct Curl_cftype cft_nghttp2 = { +struct Curl_cftype Curl_cft_nghttp2 = { "NGHTTP2", CF_TYPE_MULTIPLEX, + CURL_LOG_DEFAULT, h2_cf_destroy, h2_cf_connect, h2_cf_close, @@ -2279,7 +2278,7 @@ static CURLcode http2_cfilter_add(struct Curl_cfilter **pcf, if(!ctx) goto out; - result = Curl_cf_create(&cf, &cft_nghttp2, ctx); + result = Curl_cf_create(&cf, &Curl_cft_nghttp2, ctx); if(result) goto out; @@ -2301,7 +2300,7 @@ bool Curl_conn_is_http2(const struct Curl_easy *data, (void)data; for(; cf; cf = cf->next) { - if(cf->cft == &cft_nghttp2) + if(cf->cft == &Curl_cft_nghttp2) return TRUE; if(cf->cft->flags & CF_TYPE_IP_CONNECT) return FALSE; @@ -2343,7 +2342,7 @@ CURLcode Curl_http2_switch(struct Curl_easy *data, if(result) return result; - DEBUGASSERT(cf->cft == &cft_nghttp2); + DEBUGASSERT(cf->cft == &Curl_cft_nghttp2); ctx = cf->ctx; result = h2_cf_ctx_init(cf, data, (data->req.upgr101 == UPGR101_RECEIVED)); diff --git a/lib/http2.h b/lib/http2.h index 863f592c6..5d8f35e62 100644 --- a/lib/http2.h +++ b/lib/http2.h @@ -58,6 +58,8 @@ CURLcode Curl_http2_switch(struct Curl_easy *data, struct connectdata *conn, int sockindex, const char *ptr, size_t nread); +extern struct Curl_cftype Curl_cft_nghttp2; + #else /* USE_NGHTTP2 */ #define Curl_conn_is_http2(a,b,c) FALSE diff --git a/lib/http_proxy.c b/lib/http_proxy.c index 1afea5491..f8c832f34 100644 --- a/lib/http_proxy.c +++ b/lib/http_proxy.c @@ -50,14 +50,6 @@ #include "memdebug.h" -#define DEBUG_CF 0 - -#if DEBUG_CF -#define CF_DEBUGF(x) x -#else -#define CF_DEBUGF(x) do { } while(0) -#endif - #if !defined(CURL_DISABLE_HTTP) typedef enum { @@ -182,35 +174,35 @@ static void tunnel_go_state(struct Curl_cfilter *cf, /* entering this one */ switch(new_state) { case TUNNEL_INIT: - CF_DEBUGF(infof(data, CFMSG(cf, "new tunnel state 'init'"))); + DEBUGF(LOG_CF(data, cf, "new tunnel state 'init'")); tunnel_reinit(ts, cf->conn, data); break; case TUNNEL_CONNECT: - CF_DEBUGF(infof(data, CFMSG(cf, "new tunnel state 'connect'"))); + DEBUGF(LOG_CF(data, cf, "new tunnel state 'connect'")); ts->tunnel_state = TUNNEL_CONNECT; ts->keepon = KEEPON_CONNECT; Curl_dyn_reset(&ts->rcvbuf); break; case TUNNEL_RECEIVE: - CF_DEBUGF(infof(data, CFMSG(cf, "new tunnel state 'receive'"))); + DEBUGF(LOG_CF(data, cf, "new tunnel state 'receive'")); ts->tunnel_state = TUNNEL_RECEIVE; break; case TUNNEL_RESPONSE: - CF_DEBUGF(infof(data, CFMSG(cf, "new tunnel state 'response'"))); + DEBUGF(LOG_CF(data, cf, "new tunnel state 'response'")); ts->tunnel_state = TUNNEL_RESPONSE; break; case TUNNEL_ESTABLISHED: - CF_DEBUGF(infof(data, CFMSG(cf, "new tunnel state 'established'"))); + DEBUGF(LOG_CF(data, cf, "new tunnel state 'established'")); infof(data, "CONNECT phase completed"); data->state.authproxy.done = TRUE; data->state.authproxy.multipass = FALSE; /* FALLTHROUGH */ case TUNNEL_FAILED: - CF_DEBUGF(infof(data, CFMSG(cf, "new tunnel state 'failed'"))); + DEBUGF(LOG_CF(data, cf, "new tunnel state 'failed'")); ts->tunnel_state = new_state; Curl_dyn_reset(&ts->rcvbuf); Curl_dyn_reset(&ts->req); @@ -403,13 +395,15 @@ out: return result; } -static CURLcode on_resp_header(struct Curl_easy *data, +static CURLcode on_resp_header(struct Curl_cfilter *cf, + struct Curl_easy *data, struct tunnel_state *ts, const char *header) { CURLcode result = CURLE_OK; struct SingleRequest *k = &data->req; int subversion = 0; + (void)cf; if((checkprefix("WWW-Authenticate:", header) && (401 == k->httpcode)) || @@ -421,8 +415,7 @@ static CURLcode on_resp_header(struct Curl_easy *data, if(!auth) return CURLE_OUT_OF_MEMORY; - CF_DEBUGF(infof(data, "CONNECT: fwd auth header '%s'", - header)); + DEBUGF(LOG_CF(data, cf, "CONNECT: fwd auth header '%s'", header)); result = Curl_http_input_auth(data, proxy, auth); free(auth); @@ -476,14 +469,14 @@ static CURLcode on_resp_header(struct Curl_easy *data, return result; } -static CURLcode recv_CONNECT_resp(struct Curl_easy *data, - struct connectdata *conn, +static CURLcode recv_CONNECT_resp(struct Curl_cfilter *cf, + struct Curl_easy *data, struct tunnel_state *ts, bool *done) { CURLcode result = CURLE_OK; struct SingleRequest *k = &data->req; - curl_socket_t tunnelsocket = conn->sock[ts->sockindex]; + curl_socket_t tunnelsocket = cf->conn->sock[ts->sockindex]; char *linep; size_t perline; int error; @@ -639,7 +632,7 @@ static CURLcode recv_CONNECT_resp(struct Curl_easy *data, /* without content-length or chunked encoding, we can't keep the connection alive since the close is the end signal so we bail out at once instead */ - CF_DEBUGF(infof(data, "CONNECT: no content-length or chunked")); + DEBUGF(LOG_CF(data, cf, "CONNECT: no content-length or chunked")); ts->keepon = KEEPON_DONE; } } @@ -652,7 +645,7 @@ static CURLcode recv_CONNECT_resp(struct Curl_easy *data, continue; } - result = on_resp_header(data, ts, linep); + result = on_resp_header(cf, data, ts, linep); if(result) return result; @@ -919,8 +912,8 @@ error: return result; } -static CURLcode recv_CONNECT_resp(struct Curl_easy *data, - struct connectdata *conn, +static CURLcode recv_CONNECT_resp(struct Curl_cfilter *cf, + struct Curl_easy *data, struct tunnel_state *ts, bool *done) { @@ -930,7 +923,7 @@ static CURLcode recv_CONNECT_resp(struct Curl_easy *data, (void)ts; *done = FALSE; - result = Curl_hyper_stream(data, conn, &didwhat, done, + result = Curl_hyper_stream(data, cf->conn, &didwhat, done, CURL_CSELECT_IN | CURL_CSELECT_OUT); if(result || !*done) return result; @@ -977,7 +970,7 @@ static CURLcode CONNECT(struct Curl_cfilter *cf, switch(ts->tunnel_state) { case TUNNEL_INIT: /* Prepare the CONNECT request and make a first attempt to send. */ - CF_DEBUGF(infof(data, CFMSG(cf, "CONNECT start"))); + DEBUGF(LOG_CF(data, cf, "CONNECT start")); result = start_CONNECT(data, cf->conn, ts); if(result) goto out; @@ -986,7 +979,7 @@ static CURLcode CONNECT(struct Curl_cfilter *cf, case TUNNEL_CONNECT: /* see that the request is completely sent */ - CF_DEBUGF(infof(data, CFMSG(cf, "CONNECT send"))); + DEBUGF(LOG_CF(data, cf, "CONNECT send")); result = send_CONNECT(data, cf->conn, ts, &done); if(result || !done) goto out; @@ -995,8 +988,8 @@ static CURLcode CONNECT(struct Curl_cfilter *cf, case TUNNEL_RECEIVE: /* read what is there */ - CF_DEBUGF(infof(data, CFMSG(cf, "CONNECT receive"))); - result = recv_CONNECT_resp(data, cf->conn, ts, &done); + DEBUGF(LOG_CF(data, cf, "CONNECT receive")); + result = recv_CONNECT_resp(cf, data, ts, &done); if(Curl_pgrsUpdate(data)) { result = CURLE_ABORTED_BY_CALLBACK; goto out; @@ -1009,7 +1002,7 @@ static CURLcode CONNECT(struct Curl_cfilter *cf, /* FALLTHROUGH */ case TUNNEL_RESPONSE: - CF_DEBUGF(infof(data, CFMSG(cf, "CONNECT response"))); + DEBUGF(LOG_CF(data, cf, "CONNECT response")); if(data->req.newurl) { /* not the "final" response, we need to do a follow up request. * If the other side indicated a connection close, or if someone @@ -1021,7 +1014,7 @@ static CURLcode CONNECT(struct Curl_cfilter *cf, * reset our tunnel state. To avoid recursion, we return * and expect to be called again. */ - CF_DEBUGF(infof(data, CFMSG(cf, "CONNECT need to close+open"))); + DEBUGF(LOG_CF(data, cf, "CONNECT need to close+open")); infof(data, "Connect me again please"); Curl_conn_cf_close(cf, data); connkeep(conn, "HTTP proxy CONNECT"); @@ -1076,12 +1069,12 @@ static CURLcode http_proxy_cf_connect(struct Curl_cfilter *cf, return CURLE_OK; } - CF_DEBUGF(infof(data, CFMSG(cf, "connect"))); + DEBUGF(LOG_CF(data, cf, "connect")); result = cf->next->cft->connect(cf->next, data, blocking, done); if(result || !*done) return result; - CF_DEBUGF(infof(data, CFMSG(cf, "subchain is connected"))); + DEBUGF(LOG_CF(data, cf, "subchain is connected")); /* TODO: can we do blocking? */ /* We want "seamless" operations through HTTP proxy tunnel */ @@ -1159,7 +1152,7 @@ static int http_proxy_cf_get_select_socks(struct Curl_cfilter *cf, static void http_proxy_cf_destroy(struct Curl_cfilter *cf, struct Curl_easy *data) { - CF_DEBUGF(infof(data, CFMSG(cf, "destroy"))); + DEBUGF(LOG_CF(data, cf, "destroy")); tunnel_free(cf, data); } @@ -1167,7 +1160,7 @@ static void http_proxy_cf_close(struct Curl_cfilter *cf, struct Curl_easy *data) { DEBUGASSERT(cf->next); - CF_DEBUGF(infof(data, CFMSG(cf, "close"))); + DEBUGF(LOG_CF(data, cf, "close")); cf->connected = FALSE; cf->next->cft->close(cf->next, data); if(cf->ctx) { @@ -1176,9 +1169,10 @@ static void http_proxy_cf_close(struct Curl_cfilter *cf, } -static const struct Curl_cftype cft_http_proxy = { +struct Curl_cftype Curl_cft_http_proxy = { "HTTP-PROXY", CF_TYPE_IP_CONNECT, + 0, http_proxy_cf_destroy, http_proxy_cf_connect, http_proxy_cf_close, @@ -1200,7 +1194,7 @@ CURLcode Curl_conn_http_proxy_add(struct Curl_easy *data, struct Curl_cfilter *cf; CURLcode result; - result = Curl_cf_create(&cf, &cft_http_proxy, NULL); + result = Curl_cf_create(&cf, &Curl_cft_http_proxy, NULL); if(!result) Curl_conn_cf_add(data, conn, sockindex, cf); return result; @@ -1213,7 +1207,7 @@ CURLcode Curl_cf_http_proxy_insert_after(struct Curl_cfilter *cf_at, CURLcode result; (void)data; - result = Curl_cf_create(&cf, &cft_http_proxy, NULL); + result = Curl_cf_create(&cf, &Curl_cft_http_proxy, NULL); if(!result) Curl_conn_cf_insert_after(cf_at, cf); return result; @@ -1335,14 +1329,14 @@ static void cf_haproxy_destroy(struct Curl_cfilter *cf, struct Curl_easy *data) { (void)data; - CF_DEBUGF(infof(data, CFMSG(cf, "destroy"))); + DEBUGF(LOG_CF(data, cf, "destroy")); cf_haproxy_ctx_free(cf->ctx); } static void cf_haproxy_close(struct Curl_cfilter *cf, struct Curl_easy *data) { - CF_DEBUGF(infof(data, CFMSG(cf, "close"))); + DEBUGF(LOG_CF(data, cf, "close")); cf->connected = FALSE; cf_haproxy_ctx_reset(cf->ctx); if(cf->next) @@ -1368,9 +1362,10 @@ static int cf_haproxy_get_select_socks(struct Curl_cfilter *cf, } -static const struct Curl_cftype cft_haproxy = { +struct Curl_cftype Curl_cft_haproxy = { "HAPROXY", 0, + 0, cf_haproxy_destroy, cf_haproxy_connect, cf_haproxy_close, @@ -1401,7 +1396,7 @@ static CURLcode cf_haproxy_create(struct Curl_cfilter **pcf, ctx->state = HAPROXY_INIT; Curl_dyn_init(&ctx->data_out, DYN_HAXPROXY); - result = Curl_cf_create(&cf, &cft_haproxy, ctx); + result = Curl_cf_create(&cf, &Curl_cft_haproxy, ctx); if(result) goto out; ctx = NULL; diff --git a/lib/http_proxy.h b/lib/http_proxy.h index 2bf80db4b..f573da273 100644 --- a/lib/http_proxy.h +++ b/lib/http_proxy.h @@ -40,6 +40,8 @@ CURLcode Curl_conn_http_proxy_add(struct Curl_easy *data, CURLcode Curl_cf_http_proxy_insert_after(struct Curl_cfilter *cf_at, struct Curl_easy *data); +extern struct Curl_cftype Curl_cft_http_proxy; + #endif /* !CURL_DISABLE_HTTP */ CURLcode Curl_conn_haproxy_add(struct Curl_easy *data, @@ -48,6 +50,9 @@ CURLcode Curl_conn_haproxy_add(struct Curl_easy *data, CURLcode Curl_cf_haproxy_insert_after(struct Curl_cfilter *cf_at, struct Curl_easy *data); + +extern struct Curl_cftype Curl_cft_haproxy; + #endif /* !CURL_DISABLE_PROXY */ #endif /* HEADER_CURL_HTTP_PROXY_H */ diff --git a/lib/sendf.c b/lib/sendf.c index a0fe27e1e..2d976f3c4 100644 --- a/lib/sendf.c +++ b/lib/sendf.c @@ -237,50 +237,6 @@ bool Curl_recv_has_postponed_data(struct connectdata *conn, int sockindex) #define get_pre_recved(c,n,b,l) 0 #endif /* ! USE_RECV_BEFORE_SEND_WORKAROUND */ -/* Curl_infof() is for info message along the way */ -#define MAXINFO 2048 - -void Curl_infof(struct Curl_easy *data, const char *fmt, ...) -{ - DEBUGASSERT(!strchr(fmt, '\n')); - if(data && data->set.verbose) { - va_list ap; - int len; - char buffer[MAXINFO + 2]; - va_start(ap, fmt); - len = mvsnprintf(buffer, MAXINFO, fmt, ap); - va_end(ap); - buffer[len++] = '\n'; - buffer[len] = '\0'; - Curl_debug(data, CURLINFO_TEXT, buffer, len); - } -} - -/* Curl_failf() is for messages stating why we failed. - * The message SHALL NOT include any LF or CR. - */ - -void Curl_failf(struct Curl_easy *data, const char *fmt, ...) -{ - DEBUGASSERT(!strchr(fmt, '\n')); - if(data->set.verbose || data->set.errorbuffer) { - va_list ap; - int len; - char error[CURL_ERROR_SIZE + 2]; - va_start(ap, fmt); - len = mvsnprintf(error, CURL_ERROR_SIZE, fmt, ap); - - if(data->set.errorbuffer && !data->state.errorbuf) { - strcpy(data->set.errorbuffer, error); - data->state.errorbuf = TRUE; /* wrote error string */ - } - error[len++] = '\n'; - error[len] = '\0'; - Curl_debug(data, CURLINFO_TEXT, error, len); - va_end(ap); - } -} - /* * Curl_write() is an internal write function that sends data to the * server. Works with plain sockets, SCP, SSL or kerberos. @@ -752,30 +708,3 @@ out: return result; } -/* return 0 on success */ -void Curl_debug(struct Curl_easy *data, curl_infotype type, - char *ptr, size_t size) -{ - if(data->set.verbose) { - static const char s_infotype[CURLINFO_END][3] = { - "* ", "< ", "> ", "{ ", "} ", "{ ", "} " }; - if(data->set.fdebug) { - bool inCallback = Curl_is_in_callback(data); - Curl_set_in_callback(data, true); - (void)(*data->set.fdebug)(data, type, ptr, size, data->set.debugdata); - Curl_set_in_callback(data, inCallback); - } - else { - switch(type) { - case CURLINFO_TEXT: - case CURLINFO_HEADER_OUT: - case CURLINFO_HEADER_IN: - fwrite(s_infotype[type], 2, 1, data->set.err); - fwrite(ptr, size, 1, data->set.err); - break; - default: /* nada */ - break; - } - } - } -} diff --git a/lib/sendf.h b/lib/sendf.h index eb66acc3a..409618f7e 100644 --- a/lib/sendf.h +++ b/lib/sendf.h @@ -26,26 +26,8 @@ #include "curl_setup.h" -void Curl_infof(struct Curl_easy *, const char *fmt, ...); -void Curl_failf(struct Curl_easy *, const char *fmt, ...); +#include "curl_log.h" -#if defined(CURL_DISABLE_VERBOSE_STRINGS) - -#if defined(HAVE_VARIADIC_MACROS_C99) -#define infof(...) Curl_nop_stmt -#elif defined(HAVE_VARIADIC_MACROS_GCC) -#define infof(x...) Curl_nop_stmt -#else -#error "missing VARIADIC macro define, fix and rebuild!" -#endif - -#else /* CURL_DISABLE_VERBOSE_STRINGS */ - -#define infof Curl_infof - -#endif /* CURL_DISABLE_VERBOSE_STRINGS */ - -#define failf Curl_failf #define CLIENTWRITE_BODY (1<<0) #define CLIENTWRITE_HEADER (1<<1) @@ -89,9 +71,4 @@ CURLcode Curl_write_plain(struct Curl_easy *data, const void *mem, size_t len, ssize_t *written); -/* the function used to output verbose information */ -void Curl_debug(struct Curl_easy *data, curl_infotype type, - char *ptr, size_t size); - - #endif /* HEADER_CURL_SENDF_H */ diff --git a/lib/socks.c b/lib/socks.c index 129c5f036..b8b4f8cb8 100644 --- a/lib/socks.c +++ b/lib/socks.c @@ -1221,9 +1221,10 @@ static void socks_cf_get_host(struct Curl_cfilter *cf, } } -static const struct Curl_cftype cft_socks_proxy = { +struct Curl_cftype Curl_cft_socks_proxy = { "SOCKS-PROXYY", CF_TYPE_IP_CONNECT, + 0, socks_proxy_cf_destroy, socks_proxy_cf_connect, socks_proxy_cf_close, @@ -1245,7 +1246,7 @@ CURLcode Curl_conn_socks_proxy_add(struct Curl_easy *data, struct Curl_cfilter *cf; CURLcode result; - result = Curl_cf_create(&cf, &cft_socks_proxy, NULL); + result = Curl_cf_create(&cf, &Curl_cft_socks_proxy, NULL); if(!result) Curl_conn_cf_add(data, conn, sockindex, cf); return result; @@ -1258,7 +1259,7 @@ CURLcode Curl_cf_socks_proxy_insert_after(struct Curl_cfilter *cf_at, CURLcode result; (void)data; - result = Curl_cf_create(&cf, &cft_socks_proxy, NULL); + result = Curl_cf_create(&cf, &Curl_cft_socks_proxy, NULL); if(!result) Curl_conn_cf_insert_after(cf_at, cf); return result; diff --git a/lib/socks.h b/lib/socks.h index 1b55b4c8c..b6ce4534b 100644 --- a/lib/socks.h +++ b/lib/socks.h @@ -58,6 +58,8 @@ CURLcode Curl_conn_socks_proxy_add(struct Curl_easy *data, CURLcode Curl_cf_socks_proxy_insert_after(struct Curl_cfilter *cf_at, struct Curl_easy *data); +extern struct Curl_cftype Curl_cft_socks_proxy; + #endif /* CURL_DISABLE_PROXY */ #endif /* HEADER_CURL_SOCKS_H */ diff --git a/lib/urldata.h b/lib/urldata.h index 87e4b052a..2dfe19669 100644 --- a/lib/urldata.h +++ b/lib/urldata.h @@ -113,23 +113,6 @@ typedef unsigned int curl_prot_t; input easier and better. */ #define CURL_MAX_INPUT_LENGTH 8000000 -/* 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 - #include "cookie.h" #include "psl.h" diff --git a/lib/vquic/curl_msh3.c b/lib/vquic/curl_msh3.c index 6f7497e9d..e0027fbbb 100644 --- a/lib/vquic/curl_msh3.c +++ b/lib/vquic/curl_msh3.c @@ -30,12 +30,14 @@ #include "timeval.h" #include "multiif.h" #include "sendf.h" +#include "curl_log.h" #include "cfilters.h" #include "cf-socket.h" #include "connect.h" #include "h2h3.h" #include "curl_msh3.h" #include "socketpair.h" +#include "vquic/vquic.h" /* The last 3 #include files should be in this order */ #include "curl_printf.h" @@ -44,7 +46,7 @@ #define DEBUG_CF 1 -#if DEBUG_CF +#if DEBUG_CF && defined(DEBUGBUILD) #define CF_DEBUGF(x) x #else #define CF_DEBUGF(x) do { } while(0) @@ -176,7 +178,7 @@ static CURLcode msh3_data_setup(struct Curl_cfilter *cf, DEBUGASSERT(stream); if(!stream->recv_buf) { - CF_DEBUGF(infof(data, CFMSG(cf, "req: setup"))); + DEBUGF(LOG_CF(data, cf, "req: setup")); stream->recv_buf = malloc(MSH3_REQ_INIT_BUF_LEN); if(!stream->recv_buf) { return CURLE_OUT_OF_MEMORY; @@ -364,8 +366,7 @@ static ssize_t cf_msh3_recv(struct Curl_cfilter *cf, struct Curl_easy *data, size_t outsize = 0; (void)cf; - CF_DEBUGF(infof(data, CFMSG(cf, "req: recv with %zu byte buffer"), - len)); + DEBUGF(LOG_CF(data, cf, "req: recv with %zu byte buffer", len)); if(stream->recv_error) { failf(data, "request aborted"); @@ -388,8 +389,7 @@ static ssize_t cf_msh3_recv(struct Curl_cfilter *cf, struct Curl_easy *data, stream->recv_header_len + stream->recv_data_len - outsize); } stream->recv_header_len -= outsize; - CF_DEBUGF(infof(data, CFMSG(cf, "req: returned %zu bytes of header"), - outsize)); + DEBUGF(LOG_CF(data, cf, "req: returned %zu bytes of header", outsize)); } else if(stream->recv_data_len) { outsize = len; @@ -402,17 +402,16 @@ static ssize_t cf_msh3_recv(struct Curl_cfilter *cf, struct Curl_easy *data, stream->recv_data_len - outsize); } stream->recv_data_len -= outsize; - CF_DEBUGF(infof(data, CFMSG(cf, "req: returned %zu bytes of data"), - outsize)); + DEBUGF(LOG_CF(data, cf, "req: returned %zu bytes of data", outsize)); if(stream->recv_data_len == 0 && stream->recv_data_complete) data->state.drain = 1; } else if(stream->recv_data_complete) { - CF_DEBUGF(infof(data, CFMSG(cf, "req: receive complete"))); + DEBUGF(LOG_CF(data, cf, "req: receive complete")); data->state.drain = 0; } else { - CF_DEBUGF(infof(data, CFMSG(cf, "req: nothing here, call again"))); + DEBUGF(LOG_CF(data, cf, "req: nothing here, call again")); *err = CURLE_AGAIN; outsize = -1; } @@ -433,7 +432,7 @@ static ssize_t cf_msh3_send(struct Curl_cfilter *cf, struct Curl_easy *data, /* Sizes must match for cast below to work" */ DEBUGASSERT(sizeof(MSH3_HEADER) == sizeof(struct h2h3pseudo)); - CF_DEBUGF(infof(data, CFMSG(cf, "req: send %zu bytes"), len)); + DEBUGF(LOG_CF(data, cf, "req: send %zu bytes", len)); if(!stream->req) { /* The first send on the request contains the headers and possibly some @@ -452,8 +451,7 @@ static ssize_t cf_msh3_send(struct Curl_cfilter *cf, struct Curl_easy *data, return -1; } - CF_DEBUGF(infof(data, CFMSG(cf, "req: send %zu headers"), - hreq->entries)); + DEBUGF(LOG_CF(data, cf, "req: send %zu headers", hreq->entries)); stream->req = MsH3RequestOpen(ctx->qconn, &msh3_request_if, data, (MSH3_HEADER*)hreq->header, hreq->entries, hdrlen == len ? MSH3_REQUEST_FLAG_FIN : @@ -468,7 +466,7 @@ static ssize_t cf_msh3_send(struct Curl_cfilter *cf, struct Curl_easy *data, return len; } - CF_DEBUGF(infof(data, CFMSG(cf, "req: send %zd body bytes"), len)); + DEBUGF(LOG_CF(data, cf, "req: send %zd body bytes", len)); if(len > 0xFFFFFFFF) { /* msh3 doesn't support size_t sends currently. */ *err = CURLE_SEND_ERROR; @@ -508,8 +506,8 @@ static int cf_msh3_get_select_socks(struct Curl_cfilter *cf, data->state.drain = 1; } } - CF_DEBUGF(infof(data, CFMSG(cf, "select_sock %u -> %d"), - (uint32_t)data->state.drain, bitmap)); + DEBUGF(LOG_CF(data, cf, "select_sock %u -> %d", + (uint32_t)data->state.drain, bitmap)); return bitmap; } @@ -520,8 +518,8 @@ static bool cf_msh3_data_pending(struct Curl_cfilter *cf, struct HTTP *stream = data->req.p.http; (void)cf; - CF_DEBUGF(infof((struct Curl_easy *)data, CFMSG(cf, "data pending = %hhu"), - (bool)(stream->recv_header_len || stream->recv_data_len))); + DEBUGF(LOG_CF((struct Curl_easy *)data, cf, "data pending = %hhu", + (bool)(stream->recv_header_len || stream->recv_data_len))); return stream->recv_header_len || stream->recv_data_len; } @@ -557,7 +555,7 @@ static CURLcode cf_msh3_data_event(struct Curl_cfilter *cf, break; case CF_CTRL_DATA_DONE: - CF_DEBUGF(infof(data, CFMSG(cf, "req: done"))); + DEBUGF(LOG_CF(data, cf, "req: done")); if(stream) { if(stream->recv_buf) { Curl_safefree(stream->recv_buf); @@ -571,12 +569,12 @@ static CURLcode cf_msh3_data_event(struct Curl_cfilter *cf, break; case CF_CTRL_DATA_DONE_SEND: - CF_DEBUGF(infof(data, CFMSG(cf, "req: send done"))); + DEBUGF(LOG_CF(data, cf, "req: send done")); stream->upload_done = TRUE; break; case CF_CTRL_CONN_INFO_UPDATE: - CF_DEBUGF(infof(data, CFMSG(cf, "req: update"))); + DEBUGF(LOG_CF(data, cf, "req: update")); cf_msh3_active(cf, data); break; @@ -600,17 +598,17 @@ static CURLcode cf_connect_start(struct Curl_cfilter *cf, /* TODO: need a way to provide trust anchors to MSH3 */ #ifdef DEBUGBUILD /* we need this for our test cases to run */ - CF_DEBUGF(infof(data, CFMSG(cf, "non-standard CA not supported, " - "switching off verifypeer in DEBUG mode"))); + DEBUGF(LOG_CF(data, cf, "non-standard CA not supported, " + "switching off verifypeer in DEBUG mode")); verify = 0; #else - CF_DEBUGF(infof(data, CFMSG(cf, "non-standard CA not supported, " - "attempting with built-in verification"))); + DEBUGF(LOG_CF(data, cf, "non-standard CA not supported, " + "attempting with built-in verification")); #endif } - CF_DEBUGF(infof(data, CFMSG(cf, "connecting to %s:%d (verify=%d)"), - cf->conn->host.name, (int)cf->conn->remote_port, verify)); + DEBUGF(LOG_CF(data, cf, "connecting to %s:%d (verify=%d)", + cf->conn->host.name, (int)cf->conn->remote_port, verify)); ctx->api = MsH3ApiOpen(); if(!ctx->api) { @@ -690,7 +688,7 @@ static void cf_msh3_close(struct Curl_cfilter *cf, struct Curl_easy *data) (void)data; if(ctx) { - CF_DEBUGF(infof(data, CFMSG(cf, "destroying"))); + DEBUGF(LOG_CF(data, cf, "destroying")); if(ctx->qconn) MsH3ConnectionClose(ctx->qconn); if(ctx->api) @@ -702,13 +700,13 @@ static void cf_msh3_close(struct Curl_cfilter *cf, struct Curl_easy *data) * closed it) and we just forget about it. */ if(ctx->sock[SP_LOCAL] == cf->conn->sock[cf->sockindex]) { - CF_DEBUGF(infof(data, CFMSG(cf, "cf_msh3_close(%d) active"), - (int)ctx->sock[SP_LOCAL])); + DEBUGF(LOG_CF(data, cf, "cf_msh3_close(%d) active", + (int)ctx->sock[SP_LOCAL])); cf->conn->sock[cf->sockindex] = CURL_SOCKET_BAD; } else { - CF_DEBUGF(infof(data, CFMSG(cf, "cf_socket_close(%d) no longer at " - "conn->sock[%d], discarding"), (int)ctx->sock[SP_LOCAL])); + DEBUGF(LOG_CF(data, cf, "cf_socket_close(%d) no longer at " + "conn->sock[], discarding", (int)ctx->sock[SP_LOCAL])); ctx->sock[SP_LOCAL] = CURL_SOCKET_BAD; } if(cf->sockindex == FIRSTSOCKET) @@ -764,9 +762,10 @@ static bool cf_msh3_conn_is_alive(struct Curl_cfilter *cf, ctx->connected; } -static const struct Curl_cftype cft_msh3 = { - "HTTP/3-MSH3", +struct Curl_cftype Curl_cft_http3 = { + "HTTP/3", CF_TYPE_IP_CONNECT | CF_TYPE_SSL | CF_TYPE_MULTIPLEX, + 0, cf_msh3_destroy, cf_msh3_connect, cf_msh3_close, @@ -802,7 +801,7 @@ CURLcode Curl_cf_msh3_create(struct Curl_cfilter **pcf, ctx->sock[SP_LOCAL] = CURL_SOCKET_BAD; ctx->sock[SP_REMOTE] = CURL_SOCKET_BAD; - result = Curl_cf_create(&cf, &cft_msh3, ctx); + result = Curl_cf_create(&cf, &Curl_cft_http3, ctx); out: *pcf = (!result)? cf : NULL; @@ -822,7 +821,7 @@ bool Curl_conn_is_msh3(const struct Curl_easy *data, (void)data; for(; cf; cf = cf->next) { - if(cf->cft == &cft_msh3) + if(cf->cft == &Curl_cft_http3) return TRUE; if(cf->cft->flags & CF_TYPE_IP_CONNECT) return FALSE; diff --git a/lib/vquic/curl_ngtcp2.c b/lib/vquic/curl_ngtcp2.c index 4f6fe5593..dd694805f 100644 --- a/lib/vquic/curl_ngtcp2.c +++ b/lib/vquic/curl_ngtcp2.c @@ -66,24 +66,6 @@ #include "curl_memory.h" #include "memdebug.h" -/* #define DEBUG_NGTCP2 */ -#define DEBUG_CF 0 - -#if DEBUG_CF -#define CF_DEBUGF(x) x -#define H3STRM(cf,sid,msg) \ - "[CONN-%ld-%d][CF-%s][h3sid=%" PRIx64 "] "msg, (cf)->conn->connection_id, \ - (cf)->sockindex, (cf)->cft->name, sid -#define QSTRM(cf,sid,msg) \ - "[CONN-%ld-%d][CF-%s][qsid=%" PRIx64 "] "msg, (cf)->conn->connection_id, \ - (cf)->sockindex, (cf)->cft->name, sid - -#else -#define H3STRM(cf,sid,msg) -#define QSTRM(cf,sid,msg) -#define CF_DEBUGF(x) do { } while(0) -#endif - #define H3_ALPN_H3_29 "\x5h3-29" #define H3_ALPN_H3 "\x2h3" @@ -450,15 +432,15 @@ static CURLcode quic_init_ssl(struct Curl_cfilter *cf, gnutls_session_set_ptr(ctx->gtls->session, &ctx->conn_ref); if(ngtcp2_crypto_gnutls_configure_client_session(ctx->gtls->session) != 0) { - CF_DEBUGF(fprintf(stderr, - "ngtcp2_crypto_gnutls_configure_client_session failed\n")); + DEBUGF(LOG_CF(data, cf, + "ngtcp2_crypto_gnutls_configure_client_session failed\n")); return CURLE_QUIC_CONNECT_ERROR; } rc = gnutls_priority_set_direct(ctx->gtls->session, QUIC_PRIORITY, NULL); if(rc < 0) { - CF_DEBUGF(fprintf(stderr, "gnutls_priority_set_direct failed: %s\n", - gnutls_strerror(rc))); + DEBUGF(LOG_CF(data, cf, "gnutls_priority_set_direct failed: %s\n", + gnutls_strerror(rc))); return CURLE_QUIC_CONNECT_ERROR; } @@ -693,7 +675,7 @@ static int cb_stream_close(ngtcp2_conn *tconn, uint32_t flags, rv = nghttp3_conn_close_stream(ctx->h3conn, stream_id, app_error_code); - CF_DEBUGF(infof(data, QSTRM(cf, stream_id, "close -> %d"), rv)); + DEBUGF(LOG_CF(data, cf, "[qsid=%" PRIx64 "] close -> %d", stream_id, rv)); if(rv) { ngtcp2_connection_close_error_set_application_error( &ctx->last_error, nghttp3_err_infer_quic_app_error_code(rv), NULL, 0); @@ -717,7 +699,7 @@ static int cb_stream_reset(ngtcp2_conn *tconn, int64_t stream_id, (void)data; rv = nghttp3_conn_shutdown_stream_read(ctx->h3conn, stream_id); - CF_DEBUGF(infof(data, QSTRM(cf, stream_id, "reset -> %d"), rv)); + DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRIx64 "] reset -> %d", stream_id, rv)); if(rv) { return NGTCP2_ERR_CALLBACK_FAILURE; } @@ -906,7 +888,7 @@ static int cb_h3_stream_close(nghttp3_conn *conn, int64_t stream_id, (void)app_error_code; (void)cf; - CF_DEBUGF(infof(data, H3STRM(cf, stream_id, "close"))); + DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRIx64 "] close", stream_id)); stream->closed = TRUE; stream->error3 = app_error_code; Curl_expire(data, 0, EXPIRE_QUIC); @@ -954,8 +936,8 @@ static int cb_h3_recv_data(nghttp3_conn *conn, int64_t stream_id, (void)cf; result = write_data(stream, buf, buflen); - CF_DEBUGF(infof(data, H3STRM(cf, stream_id, "recv_data(len=%zu) -> %d"), - buflen, result)); + DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRIx64 "] recv_data(len=%zu) -> %d", + stream_id, buflen, result)); if(result) { return -1; } @@ -1027,8 +1009,8 @@ static int cb_h3_end_headers(nghttp3_conn *conn, int64_t stream_id, } } - CF_DEBUGF(infof(data, H3STRM(cf, stream_id, "end_headers(status_code=%d"), - stream->status_code)); + DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRIx64 "] end_headers(status_code=%d", + stream_id, stream->status_code)); if(stream->status_code / 100 != 1) { stream->bodystarted = TRUE; } @@ -1117,7 +1099,7 @@ static int cb_h3_reset_stream(nghttp3_conn *conn, int64_t stream_id, rv = ngtcp2_conn_shutdown_stream_write(ctx->qconn, stream_id, app_error_code); - CF_DEBUGF(infof(data, H3STRM(cf, stream_id, "reset -> %d"), rv)); + DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRIx64 "] reset -> %d", stream_id, rv)); if(rv && rv != NGTCP2_ERR_STREAM_NOT_FOUND) { return NGTCP2_ERR_CALLBACK_FAILURE; } @@ -1303,15 +1285,16 @@ static int cb_h3_acked_stream_data(nghttp3_conn *conn, int64_t stream_id, uint64_t datalen, void *user_data, void *stream_user_data) { + struct Curl_cfilter *cf = user_data; struct Curl_easy *data = stream_user_data; struct HTTP *stream = data->req.p.http; (void)user_data; + (void)cf; if(!data->set.postfields) { stream->h3out->used -= datalen; - CF_DEBUGF(infof(data, - "cb_h3_acked_stream_data, %zd bytes, %zd left unacked", - datalen, stream->h3out->used)); + DEBUGF(LOG_CF(data, cf, "cb_h3_acked_stream_data, %"PRIu64" bytes, " + "%zd left unacked", datalen, stream->h3out->used)); DEBUGASSERT(stream->h3out->used < H3_SEND_SIZE); if(stream->h3out->used == 0) { @@ -1329,9 +1312,11 @@ static nghttp3_ssize cb_h3_readfunction(nghttp3_conn *conn, int64_t stream_id, uint32_t *pflags, void *user_data, void *stream_user_data) { + struct Curl_cfilter *cf = user_data; struct Curl_easy *data = stream_user_data; size_t nread; struct HTTP *stream = data->req.p.http; + (void)cf; (void)conn; (void)stream_id; (void)user_data; @@ -1376,13 +1361,13 @@ static nghttp3_ssize cb_h3_readfunction(nghttp3_conn *conn, int64_t stream_id, if(!stream->upload_left) *pflags = NGHTTP3_DATA_FLAG_EOF; } - CF_DEBUGF(infof(data, "cb_h3_readfunction %zd bytes%s (at %zd unacked)", - nread, *pflags == NGHTTP3_DATA_FLAG_EOF?" EOF":"", - out->used)); + DEBUGF(LOG_CF(data, cf, "cb_h3_readfunction %zd bytes%s (at %zd unacked)", + nread, *pflags == NGHTTP3_DATA_FLAG_EOF?" EOF":"", + out->used)); } if(stream->upload_done && !stream->upload_len && (stream->upload_left <= 0)) { - CF_DEBUGF(infof(data, "cb_h3_readfunction sets EOF")); + DEBUGF(LOG_CF(data, cf, "cb_h3_readfunction sets EOF")); *pflags = NGHTTP3_DATA_FLAG_EOF; return nread ? 1 : 0; } @@ -1527,8 +1512,8 @@ static ssize_t cf_ngtcp2_send(struct Curl_cfilter *cf, struct Curl_easy *data, sent = len; } else { - CF_DEBUGF(infof(data, "ngh3_stream_send() wants to send %zd bytes", - len)); + DEBUGF(LOG_CF(data, cf, "ngh3_stream_send() wants to send %zd bytes", + len)); if(!stream->upload_len) { stream->upload_mem = buf; stream->upload_len = len; @@ -2413,9 +2398,10 @@ static CURLcode cf_ngtcp2_query(struct Curl_cfilter *cf, } -static const struct Curl_cftype cft_qng = { - "HTTP/3-NGTCP2", +struct Curl_cftype Curl_cft_http3 = { + "HTTP/3", CF_TYPE_IP_CONNECT | CF_TYPE_SSL | CF_TYPE_MULTIPLEX, + 0, cf_ngtcp2_destroy, cf_ngtcp2_connect, cf_ngtcp2_close, @@ -2447,7 +2433,7 @@ CURLcode Curl_cf_ngtcp2_create(struct Curl_cfilter **pcf, goto out; } - result = Curl_cf_create(&cf, &cft_qng, ctx); + result = Curl_cf_create(&cf, &Curl_cft_http3, ctx); if(result) goto out; @@ -2479,7 +2465,7 @@ bool Curl_conn_is_ngtcp2(const struct Curl_easy *data, (void)data; for(; cf; cf = cf->next) { - if(cf->cft == &cft_qng) + if(cf->cft == &Curl_cft_http3) return TRUE; if(cf->cft->flags & CF_TYPE_IP_CONNECT) return FALSE; diff --git a/lib/vquic/curl_quiche.c b/lib/vquic/curl_quiche.c index 8863fe0a3..8106444ff 100644 --- a/lib/vquic/curl_quiche.c +++ b/lib/vquic/curl_quiche.c @@ -50,13 +50,6 @@ #include "curl_memory.h" #include "memdebug.h" -#define DEBUG_CF 0 - -#if DEBUG_CF -#define CF_DEBUGF(x) x -#else -#define CF_DEBUGF(x) do { } while(0) -#endif #define QUIC_MAX_STREAMS (256*1024) #define QUIC_MAX_DATA (1*1024*1024) @@ -192,8 +185,8 @@ static CURLcode h3_add_event(struct Curl_cfilter *cf, } if(!mdata) { - CF_DEBUGF(infof(data, CFMSG(cf, "event for unknown stream %u, discarded"), - stream3_id)); + DEBUGF(LOG_CF(data, cf, "event for unknown stream %"PRId64", discarded", + stream3_id)); quiche_h3_event_free(ev); return CURLE_OK; } @@ -278,12 +271,12 @@ static ssize_t h3_process_event(struct Curl_cfilter *cf, break; } recvd = headers.nlen; - CF_DEBUGF(infof(data, CFMSG(cf, "h3[%u] HEADERS len=%d"), - stream3_id, (int)recvd)); + DEBUGF(LOG_CF(data, cf, "h3[%"PRId64"] HEADERS len=%d", + stream3_id, (int)recvd)); break; case QUICHE_H3_EVENT_DATA: - CF_DEBUGF(infof(data, CFMSG(cf, "h3[%u] DATA"), stream3_id)); + DEBUGF(LOG_CF(data, cf, "h3[%"PRId64"] DATA", stream3_id)); if(!stream->firstbody) { /* add a header-body separator CRLF */ buf[0] = '\r'; @@ -307,14 +300,14 @@ static ssize_t h3_process_event(struct Curl_cfilter *cf, break; case QUICHE_H3_EVENT_RESET: - CF_DEBUGF(infof(data, CFMSG(cf, "h3[%u] RESET"), stream3_id)); + DEBUGF(LOG_CF(data, cf, "h3[%"PRId64"] RESET", stream3_id)); streamclose(cf->conn, "Stream reset"); *err = CURLE_PARTIAL_FILE; recvd = -1; break; case QUICHE_H3_EVENT_FINISHED: - CF_DEBUGF(infof(data, CFMSG(cf, "h3[%u] FINISHED"), stream3_id)); + DEBUGF(LOG_CF(data, cf, "h3[%"PRId64"] FINISHED", stream3_id)); stream->closed = TRUE; streamclose(cf->conn, "End of stream"); *err = CURLE_OK; @@ -328,8 +321,8 @@ static ssize_t h3_process_event(struct Curl_cfilter *cf, break; default: - CF_DEBUGF(infof(data, CFMSG(cf, "h3[%u] unhandled event %d"), - stream3_id, quiche_h3_event_type(ev))); + DEBUGF(LOG_CF(data, cf, "h3[%"PRId64"] unhandled event %d", + stream3_id, quiche_h3_event_type(ev))); break; } return recvd; @@ -466,13 +459,13 @@ static ssize_t cf_quiche_recv(struct Curl_cfilter *cf, struct Curl_easy *data, quiche_h3_event *ev; struct HTTP *stream = data->req.p.http; - CF_DEBUGF(infof(data, CFMSG(cf, "recv[%u]"), stream->stream3_id)); + DEBUGF(LOG_CF(data, cf, "recv[%"PRId64"]", stream->stream3_id)); *err = CURLE_AGAIN; recvd = -1; if(cf_process_ingress(cf, data)) { - CF_DEBUGF(infof(data, "h3_stream_recv returns on ingress")); + DEBUGF(LOG_CF(data, cf, "h3_stream_recv returns on ingress")); *err = CURLE_RECV_ERROR; goto out; } @@ -504,7 +497,7 @@ static ssize_t cf_quiche_recv(struct Curl_cfilter *cf, struct Curl_easy *data, if(stream3_id != stream->stream3_id) { /* event for another transfer, preserver for later */ - CF_DEBUGF(infof(data, CFMSG(cf, "h3[%u] queuing event"), stream3_id)); + DEBUGF(LOG_CF(data, cf, "h3[%"PRId64"] queuing event", stream3_id)); if(h3_add_event(cf, data, stream3_id, ev) != CURLE_OK) { *err = CURLE_OUT_OF_MEMORY; goto out; @@ -517,7 +510,7 @@ static ssize_t cf_quiche_recv(struct Curl_cfilter *cf, struct Curl_easy *data, } if(cf_flush_egress(cf, data)) { - CF_DEBUGF(infof(data, CFMSG(cf, "recv(), flush egress failed"))); + DEBUGF(LOG_CF(data, cf, "recv(), flush egress failed")); *err = CURLE_SEND_ERROR; recvd = -1; goto out; @@ -534,8 +527,8 @@ static ssize_t cf_quiche_recv(struct Curl_cfilter *cf, struct Curl_easy *data, out: data->state.drain = (recvd >= 0) ? 1 : 0; - CF_DEBUGF(infof(data, CFMSG(cf, "recv[%u] -> %ld, err=%d"), - stream->stream3_id, (long)recvd, *err)); + DEBUGF(LOG_CF(data, cf, "recv[%"PRId64"] -> %ld, err=%d", + stream->stream3_id, (long)recvd, *err)); return recvd; } @@ -591,8 +584,8 @@ static CURLcode cf_http_request(struct Curl_cfilter *cf, stream3_id = quiche_h3_send_request(ctx->h3c, ctx->qconn, nva, nheader, stream->upload_left ? FALSE: TRUE); - CF_DEBUGF(infof(data, CFMSG(cf, "send_request(with_body=%d) -> %zd"), - !!stream->upload_left, stream3_id)); + DEBUGF(LOG_CF(data, cf, "send_request(with_body=%d) -> %"PRId64, + !!stream->upload_left, stream3_id)); if((stream3_id >= 0) && data->set.postfields) { ssize_t sent = quiche_h3_send_body(ctx->h3c, ctx->qconn, stream3_id, (uint8_t *)data->set.postfields, @@ -613,13 +606,13 @@ static CURLcode cf_http_request(struct Curl_cfilter *cf, Curl_safefree(nva); if(stream3_id < 0) { - CF_DEBUGF(infof(data, CFMSG(cf, "quiche_h3_send_request returned %ld"), - (long)stream3_id)); + DEBUGF(LOG_CF(data, cf, "quiche_h3_send_request returned %ld", + (long)stream3_id)); result = CURLE_SEND_ERROR; goto fail; } - CF_DEBUGF(infof(data, CFMSG(cf, "Using HTTP/3 Stream ID: %u"), stream3_id)); + DEBUGF(LOG_CF(data, cf, "Using HTTP/3 Stream ID: %"PRId64, stream3_id)); stream->stream3_id = stream3_id; Curl_pseudo_free(hreq); @@ -653,13 +646,12 @@ static ssize_t cf_quiche_send(struct Curl_cfilter *cf, struct Curl_easy *data, sent = 0; } else if(sent == QUICHE_H3_TRANSPORT_ERR_FINAL_SIZE) { - DEBUGF(infof(data, CFMSG(cf, "send_body(len=%zu) -> exceeds size"), - len)); + DEBUGF(LOG_CF(data, cf, "send_body(len=%zu) -> exceeds size", len)); *err = CURLE_SEND_ERROR; return -1; } else if(sent < 0) { - DEBUGF(infof(data, CFMSG(cf, "send_body(len=%zu) -> %zd"), len, sent)); + DEBUGF(LOG_CF(data, cf, "send_body(len=%zu) -> %zd", len, sent)); *err = CURLE_SEND_ERROR; return -1; } @@ -708,13 +700,13 @@ static bool cf_quiche_data_pending(struct Curl_cfilter *cf, for(node = ctx->pending; node; node = node->next) { if(node->stream3_id == stream->stream3_id) { - CF_DEBUGF(infof((struct Curl_easy *)data, - CFMSG(cf, "h3[%u] has data pending"), stream->stream3_id)); + DEBUGF(LOG_CF((struct Curl_easy *)data, cf, + "h3[%"PRId64"] has data pending", stream->stream3_id)); return TRUE; } } - CF_DEBUGF(infof((struct Curl_easy *)data, - CFMSG(cf, "h3[%u] no data pending"), stream->stream3_id)); + DEBUGF(LOG_CF((struct Curl_easy *)data, cf, "h3[%"PRId64"] no data pending", + stream->stream3_id)); return FALSE; } @@ -766,10 +758,10 @@ static CURLcode cf_verify_peer(struct Curl_cfilter *cf, X509_free(server_cert); if(result) goto out; - CF_DEBUGF(infof(data, CFMSG(cf, "Verified certificate just fine"))); + DEBUGF(LOG_CF(data, cf, "Verified certificate just fine")); } else - CF_DEBUGF(infof(data, CFMSG(cf, "Skipped certificate verification"))); + DEBUGF(LOG_CF(data, cf, "Skipped certificate verification")); ctx->h3config = quiche_h3_config_new(); if(!ctx->h3config) { @@ -935,8 +927,8 @@ static CURLcode cf_connect_start(struct Curl_cfilter *cf, offset += 1 + alpn_len; } - CF_DEBUGF(infof(data, CFMSG(cf, "Sent QUIC client Initial, ALPN: %s"), - alpn_protocols + 1)); + DEBUGF(LOG_CF(data, cf, "Sent QUIC client Initial, ALPN: %s", + alpn_protocols + 1)); } return CURLE_OK; @@ -1057,7 +1049,7 @@ static CURLcode cf_quiche_query(struct Curl_cfilter *cf, max_streams += quiche_conn_peer_streams_left_bidi(ctx->qconn); } *pres1 = (max_streams > INT_MAX)? INT_MAX : (int)max_streams; - CF_DEBUGF(infof(data, CFMSG(cf, "query: MAX_CONCURRENT -> %ld"), *pres1)); + DEBUGF(LOG_CF(data, cf, "query: MAX_CONCURRENT -> %d", *pres1)); return CURLE_OK; } default: @@ -1069,9 +1061,10 @@ static CURLcode cf_quiche_query(struct Curl_cfilter *cf, } -static const struct Curl_cftype cft_quiche = { - "HTTP/3-QUICHE", +struct Curl_cftype Curl_cft_http3 = { + "HTTP/3", CF_TYPE_IP_CONNECT | CF_TYPE_SSL | CF_TYPE_MULTIPLEX, + 0, cf_quiche_destroy, cf_quiche_connect, cf_quiche_close, @@ -1103,7 +1096,7 @@ CURLcode Curl_cf_quiche_create(struct Curl_cfilter **pcf, goto out; } - result = Curl_cf_create(&cf, &cft_quiche, ctx); + result = Curl_cf_create(&cf, &Curl_cft_http3, ctx); if(result) goto out; @@ -1135,7 +1128,7 @@ bool Curl_conn_is_quiche(const struct Curl_easy *data, (void)data; for(; cf; cf = cf->next) { - if(cf->cft == &cft_quiche) + if(cf->cft == &Curl_cft_http3) return TRUE; if(cf->cft->flags & CF_TYPE_IP_CONNECT) return FALSE; diff --git a/lib/vquic/vquic.h b/lib/vquic/vquic.h index 815804eef..565ccefb9 100644 --- a/lib/vquic/vquic.h +++ b/lib/vquic/vquic.h @@ -49,6 +49,8 @@ bool Curl_conn_is_http3(const struct Curl_easy *data, const struct connectdata *conn, int sockindex); +extern struct Curl_cftype Curl_cft_http3; + #else /* ENABLE_QUIC */ #define Curl_conn_is_http3(a,b,c) FALSE diff --git a/lib/vtls/mbedtls.c b/lib/vtls/mbedtls.c index e9aece437..acb9488b6 100644 --- a/lib/vtls/mbedtls.c +++ b/lib/vtls/mbedtls.c @@ -166,8 +166,8 @@ static int bio_cf_write(void *bio, const unsigned char *buf, size_t blen) DEBUGASSERT(data); nwritten = Curl_conn_cf_send(cf->next, data, (char *)buf, blen, &result); - /* DEBUGF(infof(data, CFMSG(cf, "bio_cf_out_write(len=%d) -> %d, err=%d"), - blen, (int)nwritten, result)); */ + DEBUGF(LOG_CF(data, cf, "bio_cf_out_write(len=%zu) -> %zd, err=%d", + blen, nwritten, result)); if(nwritten < 0 && CURLE_AGAIN == result) { nwritten = MBEDTLS_ERR_SSL_WANT_WRITE; } @@ -188,8 +188,8 @@ static int bio_cf_read(void *bio, unsigned char *buf, size_t blen) return 0; nread = Curl_conn_cf_recv(cf->next, data, (char *)buf, blen, &result); - /* DEBUGF(infof(data, CFMSG(cf, "bio_cf_in_read(len=%d) -> %d, err=%d"), - blen, (int)nread, result)); */ + DEBUGF(LOG_CF(data, cf, "bio_cf_in_read(len=%zu) -> %zd, err=%d", + blen, nread, result)); if(nread < 0 && CURLE_AGAIN == result) { nread = MBEDTLS_ERR_SSL_WANT_READ; } diff --git a/lib/vtls/openssl.c b/lib/vtls/openssl.c index 7abcfc0b4..389660e3d 100644 --- a/lib/vtls/openssl.c +++ b/lib/vtls/openssl.c @@ -97,9 +97,6 @@ #include "memdebug.h" -#define DEBUG_ME 0 - - /* Uncomment the ALLOW_RENEG line to a real #define if you want to allow TLS renegotiations when built with BoringSSL. Renegotiating is non-compliant with HTTP/2 and "an extremely dangerous protocol feature". Beware. @@ -710,10 +707,8 @@ static int bio_cf_out_write(BIO *bio, const char *buf, int blen) DEBUGASSERT(data); nwritten = Curl_conn_cf_send(cf->next, data, buf, blen, &result); -#if DEBUG_ME - DEBUGF(infof(data, CFMSG(cf, "bio_cf_out_write(len=%d) -> %d, err=%d"), - blen, (int)nwritten, result)); -#endif + DEBUGF(LOG_CF(data, cf, "bio_cf_out_write(len=%d) -> %d, err=%d", + blen, (int)nwritten, result)); BIO_clear_retry_flags(bio); connssl->backend->io_result = result; if(nwritten < 0) { @@ -737,10 +732,8 @@ static int bio_cf_in_read(BIO *bio, char *buf, int blen) return 0; nread = Curl_conn_cf_recv(cf->next, data, buf, blen, &result); -#if DEBUG_ME - DEBUGF(infof(data, CFMSG(cf, "bio_cf_in_read(len=%d) -> %d, err=%d"), - blen, (int)nread, result)); -#endif + DEBUGF(LOG_CF(data, cf, "bio_cf_in_read(len=%d) -> %d, err=%d", + blen, (int)nread, result)); BIO_clear_retry_flags(bio); connssl->backend->io_result = result; if(nread < 0) { @@ -2735,7 +2728,7 @@ static void ossl_trace(int direction, int ssl_ver, int content_type, } txt_len = msnprintf(ssl_buf, sizeof(ssl_buf), - CFMSG(cf, "%s (%s), %s, %s (%d):\n"), + "%s (%s), %s, %s (%d):\n", verstr, direction?"OUT":"IN", tls_rt_name, msg_name, msg_type); if(0 <= txt_len && (unsigned)txt_len < sizeof(ssl_buf)) { diff --git a/lib/vtls/rustls.c b/lib/vtls/rustls.c index 4b3383384..5a33899df 100644 --- a/lib/vtls/rustls.c +++ b/lib/vtls/rustls.c @@ -161,7 +161,7 @@ cr_recv(struct Curl_cfilter *cf, struct Curl_easy *data, io_error = rustls_connection_read_tls(rconn, read_cb, &io_ctx, &tls_bytes_read); if(io_error == EAGAIN || io_error == EWOULDBLOCK) { - infof(data, CFMSG(cf, "cr_recv: EAGAIN or EWOULDBLOCK")); + DEBUGF(LOG_CF(data, cf, "cr_recv: EAGAIN or EWOULDBLOCK")); } else if(io_error) { char buffer[STRERROR_LEN]; @@ -171,7 +171,7 @@ cr_recv(struct Curl_cfilter *cf, struct Curl_easy *data, return -1; } - infof(data, CFMSG(cf, "cr_recv: read %ld TLS bytes"), tls_bytes_read); + DEBUGF(LOG_CF(data, cf, "cr_recv: read %ld TLS bytes", tls_bytes_read)); rresult = rustls_connection_process_new_packets(rconn); if(rresult != RUSTLS_RESULT_OK) { @@ -189,8 +189,8 @@ cr_recv(struct Curl_cfilter *cf, struct Curl_easy *data, plainlen - plain_bytes_copied, &n); if(rresult == RUSTLS_RESULT_PLAINTEXT_EMPTY) { - infof(data, CFMSG(cf, "cr_recv: got PLAINTEXT_EMPTY. " - "will try again later.")); + DEBUGF(LOG_CF(data, cf, "cr_recv: got PLAINTEXT_EMPTY. " + "will try again later.")); backend->data_pending = FALSE; break; } @@ -207,7 +207,7 @@ cr_recv(struct Curl_cfilter *cf, struct Curl_easy *data, break; } else { - infof(data, CFMSG(cf, "cr_recv: got %ld plain bytes"), n); + DEBUGF(LOG_CF(data, cf, "cr_recv: got %ld plain bytes", n)); plain_bytes_copied += n; } } @@ -258,7 +258,7 @@ cr_send(struct Curl_cfilter *cf, struct Curl_easy *data, DEBUGASSERT(backend); rconn = backend->conn; - infof(data, CFMSG(cf, "cr_send: %ld plain bytes"), plainlen); + DEBUGF(LOG_CF(data, cf, "cr_send: %ld plain bytes", plainlen)); if(plainlen > 0) { rresult = rustls_connection_write(rconn, plainbuf, plainlen, @@ -282,8 +282,8 @@ cr_send(struct Curl_cfilter *cf, struct Curl_easy *data, io_error = rustls_connection_write_tls(rconn, write_cb, &io_ctx, &tlswritten); if(io_error == EAGAIN || io_error == EWOULDBLOCK) { - infof(data, CFMSG(cf, "cr_send: EAGAIN after %ld bytes"), - tlswritten_total); + DEBUGF(LOG_CF(data, cf, "cr_send: EAGAIN after %zu bytes", + tlswritten_total)); *err = CURLE_AGAIN; return -1; } @@ -299,7 +299,7 @@ cr_send(struct Curl_cfilter *cf, struct Curl_easy *data, *err = CURLE_WRITE_ERROR; return -1; } - infof(data, CFMSG(cf, "cr_send: wrote %ld TLS bytes"), tlswritten); + DEBUGF(LOG_CF(data, cf, "cr_send: wrote %zu TLS bytes", tlswritten)); tlswritten_total += tlswritten; } diff --git a/lib/vtls/sectransp.c b/lib/vtls/sectransp.c index 98fc61a5e..4897abcbd 100644 --- a/lib/vtls/sectransp.c +++ b/lib/vtls/sectransp.c @@ -137,14 +137,6 @@ #include "memdebug.h" -#define DEBUG_CF 0 - -#if DEBUG_CF -#define CF_DEBUGF(x) x -#else -#define CF_DEBUGF(x) do { } while(0) -#endif - /* From MacTypes.h (which we can't include because it isn't present in iOS: */ #define ioErr -36 #define paramErr -50 @@ -847,8 +839,8 @@ static OSStatus bio_cf_in_read(SSLConnectionRef connection, DEBUGASSERT(data); nread = Curl_conn_cf_recv(cf->next, data, buf, *dataLength, &result); - CF_DEBUGF(infof(data, CFMSG(cf, "bio_read(len=%zu) -> %zd, result=%d"), - *dataLength, nread, result)); + DEBUGF(LOG_CF(data, cf, "bio_read(len=%zu) -> %zd, result=%d", + *dataLength, nread, result)); if(nread < 0) { switch(result) { case CURLE_OK: @@ -883,8 +875,8 @@ static OSStatus bio_cf_out_write(SSLConnectionRef connection, DEBUGASSERT(data); nwritten = Curl_conn_cf_send(cf->next, data, buf, *dataLength, &result); - CF_DEBUGF(infof(data, CFMSG(cf, "bio_send(len=%zu) -> %zd, result=%d"), - *dataLength, nwritten, result)); + DEBUGF(LOG_CF(data, cf, "bio_send(len=%zu) -> %zd, result=%d", + *dataLength, nwritten, result)); if(nwritten <= 0) { if(result == CURLE_AGAIN) { rtn = errSSLWouldBlock; @@ -1657,7 +1649,7 @@ static CURLcode sectransp_connect_step1(struct Curl_cfilter *cf, DEBUGASSERT(backend); - CF_DEBUGF(infof(data, CFMSG(cf, "connect_step1"))); + DEBUGF(LOG_CF(data, cf, "connect_step1")); GetDarwinVersionNumber(&darwinver_maj, &darwinver_min); #endif /* CURL_BUILD_MAC */ @@ -2307,7 +2299,7 @@ static CURLcode verify_cert_buf(struct Curl_cfilter *cf, /* This is not a PEM file, probably a certificate in DER format. */ rc = append_cert_to_array(data, certbuf, buflen, array); if(rc != CURLE_OK) { - CF_DEBUGF(infof(data, CFMSG(cf, "append_cert for CA failed"))); + DEBUGF(LOG_CF(data, cf, "append_cert for CA failed")); result = rc; goto out; } @@ -2321,7 +2313,7 @@ static CURLcode verify_cert_buf(struct Curl_cfilter *cf, rc = append_cert_to_array(data, der, derlen, array); free(der); if(rc != CURLE_OK) { - CF_DEBUGF(infof(data, CFMSG(cf, "append_cert for CA failed"))); + DEBUGF(LOG_CF(data, cf, "append_cert for CA failed")); result = rc; goto out; } @@ -2337,7 +2329,7 @@ static CURLcode verify_cert_buf(struct Curl_cfilter *cf, goto out; } - CF_DEBUGF(infof(data, CFMSG(cf, "setting %d trust anchors"), n)); + DEBUGF(LOG_CF(data, cf, "setting %d trust anchors", n)); ret = SecTrustSetAnchorCertificates(trust, array); if(ret != noErr) { failf(data, "SecTrustSetAnchorCertificates() returned error %d", ret); @@ -2359,11 +2351,11 @@ static CURLcode verify_cert_buf(struct Curl_cfilter *cf, switch(trust_eval) { case kSecTrustResultUnspecified: /* what does this really mean? */ - CF_DEBUGF(infof(data, CFMSG(cf, "trust result: Unspecified"))); + DEBUGF(LOG_CF(data, cf, "trust result: Unspecified")); result = CURLE_OK; goto out; case kSecTrustResultProceed: - CF_DEBUGF(infof(data, CFMSG(cf, "trust result: Proceed"))); + DEBUGF(LOG_CF(data, cf, "trust result: Proceed")); result = CURLE_OK; goto out; @@ -2396,7 +2388,7 @@ static CURLcode verify_cert(struct Curl_cfilter *cf, size_t buflen; if(ca_info_blob) { - CF_DEBUGF(infof(data, CFMSG(cf, "verify_peer, CA from config blob"))); + DEBUGF(LOG_CF(data, cf, "verify_peer, CA from config blob")); certbuf = (unsigned char *)malloc(ca_info_blob->len + 1); if(!certbuf) { return CURLE_OUT_OF_MEMORY; @@ -2406,8 +2398,7 @@ static CURLcode verify_cert(struct Curl_cfilter *cf, certbuf[ca_info_blob->len]='\0'; } else if(cafile) { - CF_DEBUGF(infof(data, CFMSG(cf, "verify_peer, CA from file '%s'"), - cafile)); + DEBUGF(LOG_CF(data, cf, "verify_peer, CA from file '%s'", cafile)); if(read_cert(cafile, &certbuf, &buflen) < 0) { failf(data, "SSL: failed to read or invalid CA certificate"); return CURLE_SSL_CACERT_BADFILE; @@ -2543,7 +2534,7 @@ static CURLcode sectransp_connect_step2(struct Curl_cfilter *cf, || ssl_connect_2_reading == connssl->connecting_state || ssl_connect_2_writing == connssl->connecting_state); DEBUGASSERT(backend); - CF_DEBUGF(infof(data, CFMSG(cf, "connect_step2"))); + DEBUGF(LOG_CF(data, cf, "connect_step2")); /* Here goes nothing: */ check_handshake: @@ -3008,7 +2999,7 @@ static CURLcode sectransp_connect_step3(struct Curl_cfilter *cf, { struct ssl_connect_data *connssl = cf->ctx; - CF_DEBUGF(infof(data, CFMSG(cf, "connect_step3"))); + DEBUGF(LOG_CF(data, cf, "connect_step3")); /* There is no step 3! * Well, okay, let's collect server certificates, and if verbose mode is on, * let's print the details of the server certificates. */ @@ -3117,7 +3108,7 @@ sectransp_connect_common(struct Curl_cfilter *cf, struct Curl_easy *data, } if(ssl_connect_done == connssl->connecting_state) { - CF_DEBUGF(infof(data, CFMSG(cf, "connected"))); + DEBUGF(LOG_CF(data, cf, "connected")); connssl->state = ssl_connection_complete; *done = TRUE; } @@ -3163,7 +3154,7 @@ static void sectransp_close(struct Curl_cfilter *cf, struct Curl_easy *data) DEBUGASSERT(backend); if(backend->ssl_ctx) { - CF_DEBUGF(infof(data, CFMSG(cf, "close"))); + DEBUGF(LOG_CF(data, cf, "close")); (void)SSLClose(backend->ssl_ctx); #if CURL_BUILD_MAC_10_8 || CURL_BUILD_IOS if(SSLCreateContext) @@ -3207,7 +3198,7 @@ static int sectransp_shutdown(struct Curl_cfilter *cf, what = SOCKET_READABLE(cf->conn->sock[cf->sockindex], SSL_SHUTDOWN_TIMEOUT); - CF_DEBUGF(infof(data, CFMSG(cf, "shutdown"))); + DEBUGF(LOG_CF(data, cf, "shutdown")); while(loop--) { if(what < 0) { /* anything that gets here is fatally bad */ @@ -3276,7 +3267,7 @@ static int sectransp_check_cxn(struct Curl_cfilter *cf, DEBUGASSERT(backend); if(backend->ssl_ctx) { - CF_DEBUGF(infof(data, CFMSG(cf, "check connection"))); + DEBUGF(LOG_CF(data, cf, "check connection")); err = SSLGetSessionState(backend->ssl_ctx, &state); if(err == noErr) return state == kSSLConnected || state == kSSLHandshake; @@ -3297,7 +3288,7 @@ static bool sectransp_data_pending(struct Curl_cfilter *cf, DEBUGASSERT(backend); if(backend->ssl_ctx) { /* SSL is in use */ - CF_DEBUGF(infof(data, CFMSG(cf, "data_pending"))); + DEBUGF(LOG_CF((struct Curl_easy *)data, cf, "data_pending")); err = SSLGetBufferedReadSize(backend->ssl_ctx, &buffer); if(err == noErr) return buffer > 0UL; diff --git a/lib/vtls/vtls.c b/lib/vtls/vtls.c index 6a5cea681..36ef4fd7a 100644 --- a/lib/vtls/vtls.c +++ b/lib/vtls/vtls.c @@ -73,6 +73,7 @@ #include "curl_memory.h" #include "memdebug.h" + /* convenience macro to check if this handle is using a shared SSL session */ #define SSLSESSION_SHARED(data) (data->share && \ (data->share->specifier & \ @@ -1611,9 +1612,10 @@ static bool cf_ssl_is_alive(struct Curl_cfilter *cf, struct Curl_easy *data) return Curl_ssl->check_cxn(cf, data) != 0; } -static const struct Curl_cftype cft_ssl = { +struct Curl_cftype Curl_cft_ssl = { "SSL", CF_TYPE_SSL, + CURL_LOG_DEFAULT, ssl_cf_destroy, ssl_cf_connect, ssl_cf_close, @@ -1628,9 +1630,10 @@ static const struct Curl_cftype cft_ssl = { Curl_cf_def_query, }; -static const struct Curl_cftype cft_ssl_proxy = { +struct Curl_cftype Curl_cft_ssl_proxy = { "SSL-PROXY", CF_TYPE_SSL, + CURL_LOG_DEFAULT, ssl_cf_destroy, ssl_cf_connect, ssl_cf_close, @@ -1659,7 +1662,7 @@ static CURLcode cf_ssl_create(struct Curl_cfilter **pcf, goto out; } - result = Curl_cf_create(&cf, &cft_ssl, ctx); + result = Curl_cf_create(&cf, &Curl_cft_ssl, ctx); out: if(result) @@ -1707,7 +1710,7 @@ static CURLcode cf_ssl_proxy_create(struct Curl_cfilter **pcf, goto out; } - result = Curl_cf_create(&cf, &cft_ssl_proxy, ctx); + result = Curl_cf_create(&cf, &Curl_cft_ssl_proxy, ctx); out: if(result) @@ -1775,7 +1778,7 @@ CURLcode Curl_ssl_cfilter_remove(struct Curl_easy *data, (void)data; for(; cf; cf = cf->next) { - if(cf->cft == &cft_ssl) { + if(cf->cft == &Curl_cft_ssl) { if(Curl_ssl->shut_down(cf, data)) result = CURLE_SSL_SHUTDOWN_FAILED; Curl_conn_cf_discard(cf, data); @@ -1791,7 +1794,7 @@ static struct Curl_cfilter *get_ssl_cf_engaged(struct connectdata *conn, struct Curl_cfilter *cf, *lowest_ssl_cf = NULL; for(cf = conn->cfilter[sockindex]; cf; cf = cf->next) { - if(cf->cft == &cft_ssl || cf->cft == &cft_ssl_proxy) { + if(cf->cft == &Curl_cft_ssl || cf->cft == &Curl_cft_ssl_proxy) { lowest_ssl_cf = cf; if(cf->connected || (cf->next && cf->next->connected)) { /* connected or about to start */ @@ -1804,7 +1807,7 @@ static struct Curl_cfilter *get_ssl_cf_engaged(struct connectdata *conn, bool Curl_ssl_cf_is_proxy(struct Curl_cfilter *cf) { - return (cf->cft == &cft_ssl_proxy); + return (cf->cft == &Curl_cft_ssl_proxy); } struct ssl_config_data * @@ -1856,7 +1859,7 @@ Curl_ssl_get_primary_config(struct Curl_easy *data, struct Curl_cfilter *Curl_ssl_cf_get_ssl(struct Curl_cfilter *cf) { for(; cf; cf = cf->next) { - if(cf->cft == &cft_ssl || cf->cft == &cft_ssl_proxy) + if(cf->cft == &Curl_cft_ssl || cf->cft == &Curl_cft_ssl_proxy) return cf; } return NULL; diff --git a/lib/vtls/vtls.h b/lib/vtls/vtls.h index 57166b73d..d349d1f61 100644 --- a/lib/vtls/vtls.h +++ b/lib/vtls/vtls.h @@ -215,6 +215,9 @@ bool Curl_ssl_supports(struct Curl_easy *data, int ssl_option); void *Curl_ssl_get_internals(struct Curl_easy *data, int sockindex, CURLINFO info, int n); +extern struct Curl_cftype Curl_cft_ssl; +extern struct Curl_cftype Curl_cft_ssl_proxy; + #else /* if not USE_SSL */ /* When SSL support is not present, just define away these function calls */ -- cgit v1.2.1