Enhanced Tracing in libcurl and curl

docs/cmdline-opts/Makefile.inc

@@ -265,6 +265,7 @@ DPAGES = \
   tlsv1.d \
   tr-encoding.d \
   trace-ascii.d \
+  trace-config.d \
   trace-ids.d \
   trace-time.d \
   trace.d \

docs/cmdline-opts/trace-config.d

@@ -0,0 +1,21 @@
+c: Copyright (C) Daniel Stenberg, <daniel@haxx.se>, et al.
+SPDX-License-Identifier: curl
+Long: trace-config
+Arg: <string>
+Help: enable
+Mutexed: trace verbose
+Category: verbose
+Example: --trace-config ids,http/2 $URL
+Added: 8.3.0
+See-also: verbose trace
+Multi: append
+Scope: global
+---
+Set configuration for trace output. A comma-separated list of components
+where detailed output will be made available from. Names are case-insensitive.
+Specify 'all' to enable all trace components.
+
+In addition to trace component names, specify "ids" and "time" to
+avoid extra --trace-ids or --trace-time parameters.
+
+See the *curl_global_trace(3)* man page for more details.

docs/cmdline-opts/trace.d

@@ -7,7 +7,7 @@ Mutexed: verbose trace-ascii
 Category: verbose
 Example: --trace log.txt $URL
 Added: 7.9.7
-See-also: trace-ascii trace-ids trace-time
+See-also: trace-ascii trace-config trace-ids trace-time
 Multi: single
 Scope: global
 ---

docs/libcurl/Makefile.inc

@@ -54,6 +54,7 @@ man_MANS = \
  curl_global_cleanup.3 \
  curl_global_init.3 \
  curl_global_init_mem.3 \
+ curl_global_trace.3 \
  curl_global_sslset.3 \
  curl_mime_addpart.3 \
  curl_mime_data.3 \

docs/libcurl/curl_global_trace.3

@@ -0,0 +1,118 @@
+.\" **************************************************************************
+.\" *                                  _   _ ____  _
+.\" *  Project                     ___| | | |  _ \| |
+.\" *                             / __| | | | |_) | |
+.\" *                            | (__| |_| |  _ <| |___
+.\" *                             \___|\___/|_| \_\_____|
+.\" *
+.\" * Copyright (C) Daniel Stenberg, <daniel@haxx.se>, et al.
+.\" *
+.\" * This software is licensed as described in the file COPYING, which
+.\" * you should have received as part of this distribution. The terms
+.\" * are also available at https://curl.se/docs/copyright.html.
+.\" *
+.\" * You may opt to use, copy, modify, merge, publish, distribute and/or sell
+.\" * copies of the Software, and permit persons to whom the Software is
+.\" * furnished to do so, under the terms of the COPYING file.
+.\" *
+.\" * This software is distributed on an "AS IS" basis, WITHOUT WARRANTY OF ANY
+.\" * KIND, either express or implied.
+.\" *
+.\" * SPDX-License-Identifier: curl
+.\" *
+.\" **************************************************************************
+.TH curl_global_trace 3 "01 August 2023" "libcurl" "libcurl"
+.SH NAME
+curl_global_trace - Global libcurl logging configuration
+.SH SYNOPSIS
+.nf
+#include <curl/curl.h>
+
+CURLcode curl_global_trace(const char *config);
+.fi
+.SH DESCRIPTION
+This function configures the logging behavior, allowing to make some
+parts of curl more verbose or silent than others.
+
+This function may be called during the initialization phase of a program. It
+does not have to be. It can be called several times even, possibly overwriting
+settings of previous calls.
+
+Calling this function after transfers have been started is undefined. On
+some platforms/architectures it might take effect, on others not.
+
+This function is thread-safe since libcurl 8.3.0 if
+\fIcurl_version_info(3)\fP has the CURL_VERSION_THREADSAFE feature bit set
+(most platforms).
+
+If this is not thread-safe, you must not call this function when any other
+thread in the program (i.e. a thread sharing the same memory) is running.
+This does not just mean no other thread that is using libcurl. Because
+\fIcurl_global_init(3)\fP may call functions of other libraries that are
+similarly thread unsafe, it could conflict with any other thread that uses
+these other libraries.
+
+If you are initializing libcurl from a Windows DLL you should not initialize
+it from \fIDllMain\fP or a static initializer because Windows holds the loader
+lock during that time and it could cause a deadlock.
+
+The \fIconfig\fP string is a list of comma-separated component names. Names
+are case-insensitive and unknown names are ignored. The special name "all"
+applies to all components. Names may be prefixed with '+' or '-' to enable
+or disable detailed logging for a component.
+
+The list of component names is not part of curl's public API. Names may
+be added or disappear in future versions of libcurl. Since unknown names
+are silently ignored, outdated log configurations will not error when
+upgrading libcurl. Given that, some names can be expected to be fairly
+stable and are listed below for easy reference.
+
+Note that log configuration applies only to transfers where debug logging
+is enabled. See \fICURLOPT_VERBOSE(3)\fP or \fICURLOPT_DEBUGFUNCTION(3)\fP
+on how to control that.
+
+.SH TRACE COMPONENTS
+.IP tcp
+Tracing of TCP socket handling: connect, reads, writes.
+.IP ssl
+Tracing of SSL/TLS operations, whichever SSL backend is used in your build.
+.IP http/2
+Details about HTTP/2 handling: frames, events, I/O, etc.
+.IP http/3
+Details about HTTP/3 handling: connect, frames, events, I/O etc.
+.IP http-proxy
+Involved when transfers are tunneled through a HTTP proxy. "h1-proxy" or
+"h2-proxy" are also involved, depending on the HTTP version negotiated with
+the proxy.
+
+In order to find out all components involved in
+a transfer, run it with "all" configured. You will then see all names
+involved in your libcurl version in the trace.
+
+.SH EXAMPLE
+.nf
+ /* log details of HTTP/2 and SSL handling */
+ curl_global_trace("http/2,ssl");
+
+ /* log all details, except SSL handling */
+ curl_global_trace("all,-ssl");
+.fi
+
+Below is a trace sample where "http/2" was configured. The trace output
+of an enabled component appears at the beginning in brackets.
+.nf
+* [HTTP/2] [h2sid=1] cf_send(len=96) submit https://example.com/
+...
+* [HTTP/2] [h2sid=1] FRAME[HEADERS]
+* [HTTP/2] [h2sid=1] 249 header bytes
+...
+.fi
+
+.SH AVAILABILITY
+Added in 8.3
+.SH RETURN VALUE
+If this function returns non-zero, something went wrong and the configuration
+may not have any effects or may only been applied partially.
+.SH "SEE ALSO"
+.BR curl_global_init "(3), "
+.BR libcurl "(3) "

docs/options-in-versions

@@ -252,6 +252,7 @@
 --tr-encoding                        7.21.6
 --trace                              7.9.7
 --trace-ascii                        7.9.7
+--trace-config                       8.3.0
 --trace-ids                          8.2.0
 --trace-time                         7.14.0
 --unix-socket                        7.40.0

include/curl/curl.h

@@ -2731,6 +2731,20 @@ CURL_EXTERN CURLcode curl_global_init_mem(long flags,
  */
 CURL_EXTERN void curl_global_cleanup(void);
 
+/*
+ * NAME curl_global_trace()
+ *
+ * DESCRIPTION
+ *
+ * curl_global_trace() can be invoked at application start to
+ * configure which components in curl should participate in tracing.
+
+ * This function is thread-safe if CURL_VERSION_THREADSAFE is set in the
+ * curl_version_info_data.features flag (fetch by curl_version_info()).
+
+ */
+CURL_EXTERN CURLcode curl_global_trace(const char *config);
+
 /* linked-list structure for the CURLOPT_QUOTE option (and other) */
 struct curl_slist {
   char *data;

lib/Makefile.inc

@@ -124,7 +124,6 @@ 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   \
@@ -135,6 +134,7 @@ LIB_CFILES =         \
   curl_sasl.c        \
   curl_sspi.c        \
   curl_threads.c     \
+  curl_trc.c         \
   dict.c             \
   doh.c              \
   dynbuf.c           \
@@ -260,7 +260,6 @@ LIB_HFILES =         \
   curl_hmac.h        \
   curl_krb5.h        \
   curl_ldap.h        \
-  curl_log.h         \
   curl_md4.h         \
   curl_md5.h         \
   curl_memory.h      \
@@ -278,6 +277,7 @@ LIB_HFILES =         \
   curl_sha256.h      \
   curl_sspi.h        \
   curl_threads.h     \
+  curl_trc.h         \
   curlx.h            \
   dict.h             \
   doh.h              \

lib/cf-h1-proxy.c

@@ -41,7 +41,7 @@
 #include "cfilters.h"
 #include "cf-h1-proxy.h"
 #include "connect.h"
-#include "curl_log.h"
+#include "curl_trc.h"
 #include "curlx.h"
 #include "vtls/vtls.h"
 #include "transfer.h"
@@ -175,36 +175,36 @@ static void h1_tunnel_go_state(struct Curl_cfilter *cf,
   /* entering this one */
   switch(new_state) {
   case H1_TUNNEL_INIT:
-    DEBUGF(LOG_CF(data, cf, "new tunnel state 'init'"));
+    CURL_TRC_CF(data, cf, "new tunnel state 'init'");
     tunnel_reinit(ts, cf->conn, data);
     break;
 
   case H1_TUNNEL_CONNECT:
-    DEBUGF(LOG_CF(data, cf, "new tunnel state 'connect'"));
+    CURL_TRC_CF(data, cf, "new tunnel state 'connect'");
     ts->tunnel_state = H1_TUNNEL_CONNECT;
     ts->keepon = KEEPON_CONNECT;
     Curl_dyn_reset(&ts->rcvbuf);
     break;
 
   case H1_TUNNEL_RECEIVE:
-    DEBUGF(LOG_CF(data, cf, "new tunnel state 'receive'"));
+    CURL_TRC_CF(data, cf, "new tunnel state 'receive'");
     ts->tunnel_state = H1_TUNNEL_RECEIVE;
     break;
 
   case H1_TUNNEL_RESPONSE:
-    DEBUGF(LOG_CF(data, cf, "new tunnel state 'response'"));
+    CURL_TRC_CF(data, cf, "new tunnel state 'response'");
     ts->tunnel_state = H1_TUNNEL_RESPONSE;
     break;
 
   case H1_TUNNEL_ESTABLISHED:
-    DEBUGF(LOG_CF(data, cf, "new tunnel state 'established'"));
+    CURL_TRC_CF(data, cf, "new tunnel state 'established'");
     infof(data, "CONNECT phase completed");
     data->state.authproxy.done = TRUE;
     data->state.authproxy.multipass = FALSE;
     /* FALLTHROUGH */
   case H1_TUNNEL_FAILED:
     if(new_state == H1_TUNNEL_FAILED)
-      DEBUGF(LOG_CF(data, cf, "new tunnel state 'failed'"));
+      CURL_TRC_CF(data, cf, "new tunnel state 'failed'");
     ts->tunnel_state = new_state;
     Curl_dyn_reset(&ts->rcvbuf);
     Curl_dyn_reset(&ts->req);
@@ -416,7 +416,7 @@ static CURLcode on_resp_header(struct Curl_cfilter *cf,
     if(!auth)
       return CURLE_OUT_OF_MEMORY;
 
-    DEBUGF(LOG_CF(data, cf, "CONNECT: fwd auth header '%s'", header));
+    CURL_TRC_CF(data, cf, "CONNECT: fwd auth header '%s'", header);
     result = Curl_http_input_auth(data, proxy, auth);
 
     free(auth);
@@ -636,7 +636,7 @@ static CURLcode recv_CONNECT_resp(struct Curl_cfilter *cf,
           /* 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 */
-          DEBUGF(LOG_CF(data, cf, "CONNECT: no content-length or chunked"));
+          CURL_TRC_CF(data, cf, "CONNECT: no content-length or chunked");
           ts->keepon = KEEPON_DONE;
         }
       }
@@ -975,7 +975,7 @@ static CURLcode H1_CONNECT(struct Curl_cfilter *cf,
     switch(ts->tunnel_state) {
     case H1_TUNNEL_INIT:
       /* Prepare the CONNECT request and make a first attempt to send. */
-      DEBUGF(LOG_CF(data, cf, "CONNECT start"));
+      CURL_TRC_CF(data, cf, "CONNECT start");
       result = start_CONNECT(cf, data, ts);
       if(result)
         goto out;
@@ -984,7 +984,7 @@ static CURLcode H1_CONNECT(struct Curl_cfilter *cf,
 
     case H1_TUNNEL_CONNECT:
       /* see that the request is completely sent */
-      DEBUGF(LOG_CF(data, cf, "CONNECT send"));
+      CURL_TRC_CF(data, cf, "CONNECT send");
       result = send_CONNECT(data, cf->conn, ts, &done);
       if(result || !done)
         goto out;
@@ -993,7 +993,7 @@ static CURLcode H1_CONNECT(struct Curl_cfilter *cf,
 
     case H1_TUNNEL_RECEIVE:
       /* read what is there */
-      DEBUGF(LOG_CF(data, cf, "CONNECT receive"));
+      CURL_TRC_CF(data, cf, "CONNECT receive");
       result = recv_CONNECT_resp(cf, data, ts, &done);
       if(Curl_pgrsUpdate(data)) {
         result = CURLE_ABORTED_BY_CALLBACK;
@@ -1007,7 +1007,7 @@ static CURLcode H1_CONNECT(struct Curl_cfilter *cf,
       /* FALLTHROUGH */
 
     case H1_TUNNEL_RESPONSE:
-      DEBUGF(LOG_CF(data, cf, "CONNECT response"));
+      CURL_TRC_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
@@ -1019,7 +1019,7 @@ static CURLcode H1_CONNECT(struct Curl_cfilter *cf,
            * reset our tunnel state. To avoid recursion, we return
            * and expect to be called again.
            */
-          DEBUGF(LOG_CF(data, cf, "CONNECT need to close+open"));
+          CURL_TRC_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");
@@ -1073,7 +1073,7 @@ static CURLcode cf_h1_proxy_connect(struct Curl_cfilter *cf,
     return CURLE_OK;
   }
 
-  DEBUGF(LOG_CF(data, cf, "connect"));
+  CURL_TRC_CF(data, cf, "connect");
   result = cf->next->cft->do_connect(cf->next, data, blocking, done);
   if(result || !*done)
     return result;
@@ -1133,14 +1133,14 @@ static int cf_h1_proxy_get_select_socks(struct Curl_cfilter *cf,
 static void cf_h1_proxy_destroy(struct Curl_cfilter *cf,
                                 struct Curl_easy *data)
 {
-  DEBUGF(LOG_CF(data, cf, "destroy"));
+  CURL_TRC_CF(data, cf, "destroy");
   tunnel_free(cf, data);
 }
 
 static void cf_h1_proxy_close(struct Curl_cfilter *cf,
                               struct Curl_easy *data)
 {
-  DEBUGF(LOG_CF(data, cf, "close"));
+  CURL_TRC_CF(data, cf, "close");
   cf->connected = FALSE;
   if(cf->ctx) {
     h1_tunnel_go_state(cf, cf->ctx, H1_TUNNEL_INIT, data);