From f06cc4f85e976a6aaf710123761d391c1aab2116 Mon Sep 17 00:00:00 2001 From: Stefan Eissing Date: Sun, 11 Jun 2023 11:02:29 +0200 Subject: [PATCH] tool: add curl command line option `--trace-ids` - added and documented --trace-ids to prepend (after the timestamp) the transfer and connection identifiers to each verbose log line - format is [n-m] with `n` being the transfer id and `m` being the connection id. In case there is not valid connection id, print 'x'. - Log calls with a handle that has no transfer id yet, are written without any ids. Closes #11185 --- docs/TheArtOfHttpScripting.md | 11 +++++++ docs/cmdline-opts/Makefile.inc | 1 + docs/cmdline-opts/trace-ids.d | 12 ++++++++ docs/cmdline-opts/trace.d | 2 +- docs/options-in-versions | 1 + src/tool_cb_dbg.c | 52 +++++++++++++++++++++++++--------- src/tool_cfgable.h | 1 + src/tool_getparam.c | 4 +++ src/tool_listhelp.c | 3 ++ 9 files changed, 73 insertions(+), 14 deletions(-) create mode 100644 docs/cmdline-opts/trace-ids.d diff --git a/docs/TheArtOfHttpScripting.md b/docs/TheArtOfHttpScripting.md index 694ff08bb..ffa8fe089 100644 --- a/docs/TheArtOfHttpScripting.md +++ b/docs/TheArtOfHttpScripting.md @@ -64,6 +64,17 @@ curl --trace-ascii d.txt --trace-time http://example.com/ +## See which Transfer + + When doing parallel transfers, it is relevant to see which transfer is + doing what. When response headers are received (and logged) you need to + know which transfer these are for. + [`--trace-ids`](https://curl.se/docs/manpage.html#--trace-ids) option + is what you need. It will prepend the transfer and connection identifier + to each trace output line: + + curl --trace-ascii d.txt --trace-ids http://example.com/ + ## See the Response By default curl sends the response to stdout. You need to redirect it diff --git a/docs/cmdline-opts/Makefile.inc b/docs/cmdline-opts/Makefile.inc index 10cc14b03..d265e5374 100644 --- a/docs/cmdline-opts/Makefile.inc +++ b/docs/cmdline-opts/Makefile.inc @@ -265,6 +265,7 @@ DPAGES = \ tlsv1.d \ tr-encoding.d \ trace-ascii.d \ + trace-ids.d \ trace-time.d \ trace.d \ unix-socket.d \ diff --git a/docs/cmdline-opts/trace-ids.d b/docs/cmdline-opts/trace-ids.d new file mode 100644 index 000000000..7b8ce6f70 --- /dev/null +++ b/docs/cmdline-opts/trace-ids.d @@ -0,0 +1,12 @@ +c: Copyright (C) Daniel Stenberg, , et al. +SPDX-License-Identifier: curl +Long: trace-ids +Help: Add transfer and connection identifiers to trace/verbose output +Added: 8.2.0 +Category: verbose +Example: --trace-ids --trace-ascii output $URL +See-also: trace verbose +Multi: boolean +Scope: global +--- +Prepends the transfer and connection identifiers to each trace or verbose line that curl displays. diff --git a/docs/cmdline-opts/trace.d b/docs/cmdline-opts/trace.d index 1b422c2f0..cc3087a8c 100644 --- a/docs/cmdline-opts/trace.d +++ b/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-time +See-also: trace-ascii trace-ids trace-time Multi: single Scope: global --- diff --git a/docs/options-in-versions b/docs/options-in-versions index d11d139e0..885d4c091 100644 --- a/docs/options-in-versions +++ b/docs/options-in-versions @@ -252,6 +252,7 @@ --tr-encoding 7.21.6 --trace 7.9.7 --trace-ascii 7.9.7 +--trace-ids 8.2.0 --trace-time 7.14.0 --unix-socket 7.40.0 --upload-file (-T) 4.0 diff --git a/src/tool_cb_dbg.c b/src/tool_cb_dbg.c index 7ea22cebf..d53a43978 100644 --- a/src/tool_cb_dbg.c +++ b/src/tool_cb_dbg.c @@ -34,7 +34,7 @@ #include "memdebug.h" /* keep this as LAST include */ -static void dump(const char *timebuf, const char *text, +static void dump(const char *timebuf, const char *idsbuf, const char *text, FILE *stream, const unsigned char *ptr, size_t size, trace tracetype, curl_infotype infotype); @@ -67,7 +67,8 @@ static const char *hms_for_sec(time_t tv_sec) return hms_buf; } -static void log_line_start(FILE *log, const char *intro, curl_infotype type) +static void log_line_start(FILE *log, const char *timebuf, + const char *idsbuf, curl_infotype type) { /* * This is the trace look that is similar to what libcurl makes on its @@ -76,12 +77,15 @@ static void log_line_start(FILE *log, const char *intro, curl_infotype type) static const char * const s_infotype[] = { "* ", "< ", "> ", "{ ", "} ", "{ ", "} " }; - if(intro && *intro) - fprintf(log, "%s%s", intro, s_infotype[type]); + if((timebuf && *timebuf) || (idsbuf && *idsbuf)) + fprintf(log, "%s%s%s", timebuf, idsbuf, s_infotype[type]); else fputs(s_infotype[type], log); } +#define TRC_IDS_FORMAT_IDS_1 "[%" CURL_FORMAT_CURL_OFF_T "-x] " +#define TRC_IDS_FORMAT_IDS_2 "[%" CURL_FORMAT_CURL_OFF_T "-%" \ + CURL_FORMAT_CURL_OFF_T "] " /* ** callback for CURLOPT_DEBUGFUNCTION */ @@ -95,6 +99,13 @@ int tool_debug_cb(CURL *handle, curl_infotype type, const char *text; struct timeval tv; char timebuf[20]; + /* largest signed 64bit is: 9,223,372,036,854,775,807 + * max length in decimal: 1 + (6*3) = 19 + * formatted via TRC_IDS_FORMAT_IDS_2 this becomes 2 + 19 + 1 + 19 + 2 = 43 + * negative xfer-id are not printed, negative conn-ids use TRC_IDS_FORMAT_1 + */ + char idsbuf[60]; + curl_off_t xfer_id, conn_id; (void)handle; /* not used */ @@ -106,6 +117,20 @@ int tool_debug_cb(CURL *handle, curl_infotype type, else timebuf[0] = 0; + if(handle && config->traceids && + !curl_easy_getinfo(handle, CURLINFO_XFER_ID, &xfer_id) && xfer_id >= 0) { + if(!curl_easy_getinfo(handle, CURLINFO_CONN_ID, &conn_id) && + conn_id >= 0) { + msnprintf(idsbuf, sizeof(idsbuf), TRC_IDS_FORMAT_IDS_2, + xfer_id, conn_id); + } + else { + msnprintf(idsbuf, sizeof(idsbuf), TRC_IDS_FORMAT_IDS_1, xfer_id); + } + } + else + idsbuf[0] = 0; + if(!config->trace_stream) { /* open for append */ if(!strcmp("-", config->trace_dump)) @@ -139,7 +164,7 @@ int tool_debug_cb(CURL *handle, curl_infotype type, for(i = 0; i < size - 1; i++) { if(data[i] == '\n') { /* LF */ if(!newl) { - log_line_start(output, timebuf, type); + log_line_start(output, timebuf, idsbuf, type); } (void)fwrite(data + st, i - st + 1, 1, output); st = i + 1; @@ -147,7 +172,7 @@ int tool_debug_cb(CURL *handle, curl_infotype type, } } if(!newl) - log_line_start(output, timebuf, type); + log_line_start(output, timebuf, idsbuf, type); (void)fwrite(data + st, i - st + 1, 1, output); } newl = (size && (data[size - 1] != '\n')) ? TRUE : FALSE; @@ -156,7 +181,7 @@ int tool_debug_cb(CURL *handle, curl_infotype type, case CURLINFO_TEXT: case CURLINFO_HEADER_IN: if(!newl) - log_line_start(output, timebuf, type); + log_line_start(output, timebuf, idsbuf, type); (void)fwrite(data, size, 1, output); newl = (size && (data[size - 1] != '\n')) ? TRUE : FALSE; traced_data = FALSE; @@ -172,7 +197,7 @@ int tool_debug_cb(CURL *handle, curl_infotype type, function */ if(!config->isatty || ((output != stderr) && (output != stdout))) { if(!newl) - log_line_start(output, timebuf, type); + log_line_start(output, timebuf, idsbuf, type); fprintf(output, "[%zu bytes data]\n", size); newl = FALSE; traced_data = TRUE; @@ -190,7 +215,7 @@ int tool_debug_cb(CURL *handle, curl_infotype type, switch(type) { case CURLINFO_TEXT: - fprintf(output, "%s== Info: %.*s", timebuf, (int)size, data); + fprintf(output, "%s%s== Info: %.*s", timebuf, idsbuf, (int)size, data); /* FALLTHROUGH */ default: /* in case a new one is introduced to shock us */ return 0; @@ -215,12 +240,12 @@ int tool_debug_cb(CURL *handle, curl_infotype type, break; } - dump(timebuf, text, output, (unsigned char *) data, size, config->tracetype, - type); + dump(timebuf, idsbuf, text, output, (unsigned char *) data, size, + config->tracetype, type); return 0; } -static void dump(const char *timebuf, const char *text, +static void dump(const char *timebuf, const char *idsbuf, const char *text, FILE *stream, const unsigned char *ptr, size_t size, trace tracetype, curl_infotype infotype) { @@ -233,7 +258,8 @@ static void dump(const char *timebuf, const char *text, /* without the hex output, we can fit more on screen */ width = 0x40; - fprintf(stream, "%s%s, %zu bytes (0x%zx)\n", timebuf, text, size, size); + fprintf(stream, "%s%s%s, %zu bytes (0x%zx)\n", timebuf, idsbuf, + text, size, size); for(i = 0; i < size; i += width) { diff --git a/src/tool_cfgable.h b/src/tool_cfgable.h index 7cd6e12ec..b35abaf7a 100644 --- a/src/tool_cfgable.h +++ b/src/tool_cfgable.h @@ -308,6 +308,7 @@ struct GlobalConfig { bool trace_fopened; trace tracetype; bool tracetime; /* include timestamp? */ + bool traceids; /* include xfer-/conn-id? */ int progressmode; /* CURL_PROGRESS_BAR / CURL_PROGRESS_STATS */ char *libcurl; /* Output libcurl code to this file name */ bool fail_early; /* exit on first transfer error */ diff --git a/src/tool_getparam.c b/src/tool_getparam.c index f24ab887b..25d6acacb 100644 --- a/src/tool_getparam.c +++ b/src/tool_getparam.c @@ -205,6 +205,7 @@ static const struct LongShort aliases[]= { {"$Z", "compressed-ssh", ARG_BOOL}, {"$~", "happy-eyeballs-timeout-ms", ARG_STRING}, {"$!", "retry-all-errors", ARG_BOOL}, + {"$%", "trace-ids", ARG_BOOL}, {"0", "http1.0", ARG_NONE}, {"01", "http1.1", ARG_NONE}, {"02", "http2", ARG_NONE}, @@ -1407,6 +1408,9 @@ ParameterError getparameter(const char *flag, /* f or -long-flag */ return err; /* 0 is a valid value for this timeout */ break; + case '%': /* --trace-ids */ + global->traceids = toggle; + break; } break; case '#': diff --git a/src/tool_listhelp.c b/src/tool_listhelp.c index 1e6bd7227..b1eaf60eb 100644 --- a/src/tool_listhelp.c +++ b/src/tool_listhelp.c @@ -759,6 +759,9 @@ const struct helptxt helptext[] = { {" --trace-ascii ", "Like --trace, but without hex output", CURLHELP_VERBOSE}, + {" --trace-ids", + "Add transfer/connection identifiers to trace/verbose output", + CURLHELP_VERBOSE}, {" --trace-time", "Add time stamps to trace/verbose output", CURLHELP_VERBOSE},