Enhanced Tracing in libcurl and curl by icing · Pull Request #11421 · curl/curl

icing · 2023-07-11T09:46:25Z

Making detailed logging availabel in libcurl and curl:

curl_global_log_config() for setting log configration in libcurl
- --trace-config command line option for curl
man pages
convert DEBUGF(LOG_CF(..)) code to CURL_LOG_CF() that is available in non-debug builds
protect infof() execution by verbosity check, saving some cycles when not verbose
test adjustments for new function

Examples:

Add HTTP/2 details to verbose output:

        curl -v --trace-config http/2 URL

Add HTTP/2, SSL and id details to verbose output:

        curl -v --trace-config http/2,ssl,ids URL

Enable all details in verbose output, including times and ids and all components in libcurl:

        curl -v --trace-config all URL

Enable all details, but not about SSL or TCP:

        curl -v --trace-config all,-ssl,-tcp URL

vszakats · 2023-08-01T21:31:05Z

We'll need to update libcurl.def with the new API:

--- a/libcurl.def
+++ b/libcurl.def
@@ -28,6 +28,7 @@ curl_getenv
 curl_global_cleanup
 curl_global_init
 curl_global_init_mem
+curl_global_log_config
 curl_global_sslset
 curl_maprintf
 curl_mfprintf

bagder · 2023-08-01T21:37:01Z

We'll need to update libcurl.def with the new API:

Can't we generate that list? Or at worst make a CI job that checks that the list is up-to-date?

vszakats · 2023-08-01T22:27:15Z

@bagder PR ready for checking it: #11570. I can't imagine a way to dynamically generate this from both CMake and Makefile.mk (and perhaps others that may be using this in the future). Converting it a raw list (without the EXPORTS header) and re-using it for more than .def purposes might work, so that a single list needs to be maintained, but it's non-trivial.

icing · 2023-08-02T08:09:57Z

curl_global_log_config

Added this in the recent push. Thanks for noticing

icing · 2023-08-02T08:41:30Z

Some local measurement on my macOS dev machine. I see no real difference in performance between non-debug builds on master and this PR. Meaning the guarded log statements have no impact.

curl 8.3.0-DEV (x86_64-apple-darwin22.5.0) libcurl/8.3.0-DEV OpenSSL/3.0.9 zlib/1.2.11 brotli/1.0.9 zstd/1.5.5 c-ares/1.19.1 libidn2/2.3.4 libssh2/1.11.0 nghttp2/1.55.0 ngtcp2/0.17.0 nghttp3/0.13.0 librtmp/2.3

Downloads from httpd:
> python3 tests/http/scorecard.py -d --httpd h2
              Size       Single       Serial     Parallel
master:      100MB     703 MB/s     972 MB/s     934 MB/s
this PR:     100MB     710 MB/s     986 MB/s     959 MB/s

Small requests:
> python3 tests/http/scorecard.py -r --httpd h2

Requests, max in parallel
         Size        1            6           25           50          100
master:  10KB     1665 r/s     3428 r/s     3537 r/s     3522 r/s     3475 r/s
this PR: 10KB     1676 r/s     3439 r/s     3536 r/s     3515 r/s     3227 r/s

bagder

Thought about how this can be tested, at least rudimentary?

bagder · 2023-08-02T09:08:10Z

docs/libcurl/curl_global_log_config.3

What do you think of naming it curl_global_trace() ? It is shorter and I think that is slightly more fitting name that avoids the word "log" which might have a negative connotation. We also use the word trace for this for the command line option.

Sure, can do.

Changed in recent push.

bagder · 2023-08-02T09:08:55Z

docs/libcurl/curl_global_log_config.3

But we still need to document the existing available component names here, don't we? Otherwise it seems very hard to use this function!

There is a trade off with this, of course. Do we want to document these names as part of the public API? Do we keep the names then in future versions?

icing · 2023-08-02T11:34:26Z

Thought about how this can be tested, at least rudimentary?

Added test cases in pytest.

- WIP: app init method is missing. CURL_DEBUG env var only parsed on debug builds. - add format attributes to infof() and failf() declarations - protect `infof()` execution by verbosity check, saving some cycles when not verbose - change patterns `DEBUGF(LOG_CF(...))` to `CURL_LOG_CF(...)`

- added curl_log_configure(config) to set log configuration explicitly - log config extended - 'all' for all known components - +/- prefix to enable/disable

- curl_global_log_config() for setting log configration in libcurl - --trace-config command line option for curl - man pages - test adjustments for new function

- curl_log.[ch] is not curl_trc.[ch] - curl_global_log_config() is now curl_global_trace() - CURL_LOG_CF() is now CURL_TRC_CF() etc.

icing · 2023-08-03T15:29:16Z

Ready from my side.

Add --trace-config to curl Add curl_global_trace() to libcurl Closes curl#11421

- enable symbol hiding manually to match cmake/autotools. - enable variadic macros. These macros became required in curl 8.3.0 with curl/curl#11421. These macros will no longer be needed with curl 8.5.0 after curl/curl#12167. - set `HAVE_SNPRINTF`. curl's `config-win32.h` missed to set it, causing a minor difference in the generated binaries compared to cmake/autotools builds. Ref: curl/curl#12325 With these changes GNU Make builds are in sync again with cmake/autotools.

github-actions bot added the tests label Jul 11, 2023

icing added the logging label Jul 11, 2023

icing force-pushed the enhanced-logging branch from 26ebec0 to ee075b0 Compare August 1, 2023 13:57

github-actions bot added cmdline tool libcurl API labels Aug 1, 2023

icing changed the title ~~Logging, make filter logging available in non-debug builds~~ Enhanced Logging in libcurl and curl Aug 1, 2023

bagder reviewed Aug 2, 2023

View reviewed changes

icing changed the title ~~Enhanced Logging in libcurl and curl~~ Enhanced Tracing in libcurl and curl Aug 2, 2023

icing force-pushed the enhanced-logging branch from 316fea2 to 3e13028 Compare August 3, 2023 12:27

icing added 15 commits August 3, 2023 14:38

void cf_types on non-debug builds

8279079

sectransport, some infof arg type formats

336c972

Adjustments after rebase on master

cadcfbd

New curl_log_configure() and config options

91a6ff0

- added curl_log_configure(config) to set log configuration explicitly - log config extended - 'all' for all known components - +/- prefix to enable/disable

Adding new global function and command line option

4245f9b

- curl_global_log_config() for setting log configration in libcurl - --trace-config command line option for curl - man pages - test adjustments for new function

Fixes on spelling and quiche build detected in CI

0b3ac4e

behaviour is behavior

5f32235

adding new libcurl function to libcurl.def

f661a25

Rename 'logging' to 'tracing' and adjust function/files

3dc4bf9

- curl_log.[ch] is not curl_trc.[ch] - curl_global_log_config() is now curl_global_trace() - CURL_LOG_CF() is now CURL_TRC_CF() etc.

Add tracing test cases

78e506c

Documentation on trace component names, some example output.

75e2229

spelling checks strike

2e00b1e

Replace strtok_r with strtok in curl tool_getparam.c for portability.

7f1a3d6

adjusting libcurl.def order for new test check

1fe83b8

icing force-pushed the enhanced-logging branch from 3e13028 to 1fe83b8 Compare August 3, 2023 12:57

bagder approved these changes Aug 3, 2023

View reviewed changes

bagder closed this in e12b39e Aug 3, 2023

ptitSeb pushed a commit to wasix-org/curl that referenced this pull request Sep 25, 2023

trace: make tracing available in non-debug builds

5168a12

Add --trace-config to curl Add curl_global_trace() to libcurl Closes curl#11421

Uh oh!

Conversation

icing commented Jul 11, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

vszakats commented Aug 1, 2023

Uh oh!

bagder commented Aug 1, 2023

Uh oh!

vszakats commented Aug 1, 2023

Uh oh!

icing commented Aug 2, 2023

Uh oh!

icing commented Aug 2, 2023

Uh oh!

bagder left a comment

Choose a reason for hiding this comment

Uh oh!

bagder Aug 2, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

icing Aug 2, 2023

Choose a reason for hiding this comment

Uh oh!

icing Aug 2, 2023

Choose a reason for hiding this comment

Uh oh!

bagder Aug 2, 2023

Choose a reason for hiding this comment

Uh oh!

icing Aug 2, 2023

Choose a reason for hiding this comment

Uh oh!

icing commented Aug 2, 2023

Uh oh!

icing commented Aug 3, 2023

Uh oh!

Reviewers

Assignees

Labels

Milestone

Development

Uh oh!

3 participants

icing commented Jul 11, 2023 •

edited

Loading

bagder Aug 2, 2023 •

edited

Loading