Auto merge of #12582 - ehuss:network-target, r=epage

Set tracing target for networking messages.

This changes the log messages for messages related to network traffic to use the "network" tracing target. This makes it easier to do `CARGO_LOG=network=trace CARGO_HTTP_DEBUG=true` instead of trying to figure out which modules to include (and to avoid `CARGO_LOG=trace` which can be too noisy). For example, #12290 moved the location of some log messages to a different module, which broke the documented workflow of using `CARGO_LOG=cargo::ops::registry=debug` to get networking information.

Author: bors

src/cargo/core/package.rs

@@ -712,7 +712,7 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> {
         // happen during `wait_for_download`
         let token = self.next;
         self.next += 1;
-        debug!("downloading {} as {}", id, token);
+        debug!(target: "network", "downloading {} as {}", id, token);
         assert!(self.pending_ids.insert(id));
 
         let (mut handle, _timeout) = http_handle_and_timeout(self.set.config)?;
@@ -731,7 +731,7 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> {
         crate::try_old_curl_http2_pipewait!(self.set.multiplexing, handle);
 
         handle.write_function(move |buf| {
-            debug!("{} - {} bytes of data", token, buf.len());
+            debug!(target: "network", "{} - {} bytes of data", token, buf.len());
             tls::with(|downloads| {
                 if let Some(downloads) = downloads {
                     downloads.pending[&token]
@@ -812,7 +812,7 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> {
         let (dl, data) = loop {
             assert_eq!(self.pending.len(), self.pending_ids.len());
             let (token, result) = self.wait_for_curl()?;
-            debug!("{} finished with {:?}", token, result);
+            debug!(target: "network", "{} finished with {:?}", token, result);
 
             let (mut dl, handle) = self
                 .pending
@@ -873,7 +873,7 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> {
                     return Err(e.context(format!("failed to download from `{}`", dl.url)))
                 }
                 RetryResult::Retry(sleep) => {
-                    debug!("download retry {} for {sleep}ms", dl.url);
+                    debug!(target: "network", "download retry {} for {sleep}ms", dl.url);
                     self.sleeping.push(sleep, (dl, handle));
                 }
             }
@@ -969,7 +969,7 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> {
                     .perform()
                     .with_context(|| "failed to perform http requests")
             })?;
-            debug!("handles remaining: {}", n);
+            debug!(target: "network", "handles remaining: {}", n);
             let results = &mut self.results;
             let pending = &self.pending;
             self.set.multi.messages(|msg| {
@@ -978,7 +978,7 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> {
                 if let Some(result) = msg.result_for(handle) {
                     results.push((token, result));
                 } else {
-                    debug!("message without a result (?)");
+                    debug!(target: "network", "message without a result (?)");
                 }
             });
 
@@ -988,7 +988,7 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> {
             assert_ne!(self.remaining(), 0);
             if self.pending.is_empty() {
                 let delay = self.sleeping.time_to_next().unwrap();
-                debug!("sleeping main thread for {delay:?}");
+                debug!(target: "network", "sleeping main thread for {delay:?}");
                 std::thread::sleep(delay);
             } else {
                 let min_timeout = Duration::new(1, 0);

src/cargo/sources/registry/http_remote.rs

@@ -335,7 +335,7 @@ impl<'cfg> HttpRegistry<'cfg> {
                 }),
                 RetryResult::Err(e) => Err(e),
                 RetryResult::Retry(sleep) => {
-                    debug!("download retry {:?} for {sleep}ms", download.path);
+                    debug!(target: "network", "download retry {:?} for {sleep}ms", download.path);
                     self.downloads.sleeping.push(sleep, (download, handle));
                     continue;
                 }
@@ -551,7 +551,7 @@ impl<'cfg> RegistryData for HttpRegistry<'cfg> {
                         && path == Path::new(RegistryConfig::NAME)
                         && self.config.cli_unstable().registry_auth =>
                 {
-                    debug!("re-attempting request for config.json with authorization included.");
+                    debug!(target: "network", "re-attempting request for config.json with authorization included.");
                     self.fresh.remove(path);
                     self.auth_required = true;
 
@@ -568,9 +568,11 @@ impl<'cfg> RegistryData for HttpRegistry<'cfg> {
                                     }
                                 }
                                 Ok(challenge) => {
-                                    debug!("ignoring non-Cargo challenge: {}", challenge.scheme)
+                                    debug!(target: "network", "ignoring non-Cargo challenge: {}", challenge.scheme)
+                                }
+                                Err(e) => {
+                                    debug!(target: "network", "failed to parse challenge: {}", e)
                                 }
-                                Err(e) => debug!("failed to parse challenge: {}", e),
                             }
                         }
                     }
@@ -618,7 +620,7 @@ impl<'cfg> RegistryData for HttpRegistry<'cfg> {
 
         let mut handle = http_handle(self.config)?;
         let full_url = self.full_url(path);
-        debug!("fetch {}", full_url);
+        debug!(target: "network", "fetch {}", full_url);
         handle.get(true)?;
         handle.url(&full_url)?;
         handle.follow_location(true)?;
@@ -653,7 +655,7 @@ impl<'cfg> RegistryData for HttpRegistry<'cfg> {
                 self.auth_error_headers.clone(),
             )?;
             headers.append(&format!("Authorization: {}", authorization))?;
-            trace!("including authorization for {}", full_url);
+            trace!(target: "network", "including authorization for {}", full_url);
         }
         handle.http_headers(headers)?;
 
@@ -662,7 +664,7 @@ impl<'cfg> RegistryData for HttpRegistry<'cfg> {
         // We do that through this token. Each request (and associated response) gets one.
         let token = self.downloads.next;
         self.downloads.next += 1;
-        debug!("downloading {} as {}", path.display(), token);
+        debug!(target: "network", "downloading {} as {}", path.display(), token);
         let is_new = self.downloads.pending_paths.insert(path.to_path_buf());
         assert!(is_new, "path queued for download more than once");
 
@@ -671,7 +673,7 @@ impl<'cfg> RegistryData for HttpRegistry<'cfg> {
         // That thread-local is set up in `block_until_ready` when it calls self.multi.perform,
         // which is what ultimately calls this method.
         handle.write_function(move |buf| {
-            trace!("{} - {} bytes of data", token, buf.len());
+            trace!(target: "network", "{} - {} bytes of data", token, buf.len());
             tls::with(|downloads| {
                 if let Some(downloads) = downloads {
                     downloads.pending[&token]
@@ -772,7 +774,7 @@ impl<'cfg> RegistryData for HttpRegistry<'cfg> {
     }
 
     fn block_until_ready(&mut self) -> CargoResult<()> {
-        trace!(
+        trace!(target: "network",
             "block_until_ready: {} transfers pending",
             self.downloads.pending.len()
         );
@@ -787,15 +789,15 @@ impl<'cfg> RegistryData for HttpRegistry<'cfg> {
                     .perform()
                     .with_context(|| "failed to perform http requests")
             })?;
-            trace!("{} transfers remaining", remaining_in_multi);
+            trace!(target: "network", "{} transfers remaining", remaining_in_multi);
 
             if remaining_in_multi + self.downloads.sleeping.len() as u32 == 0 {
                 return Ok(());
             }
 
             if self.downloads.pending.is_empty() {
                 let delay = self.downloads.sleeping.time_to_next().unwrap();
-                debug!("sleeping main thread for {delay:?}");
+                debug!(target: "network", "sleeping main thread for {delay:?}");
                 std::thread::sleep(delay);
             } else {
                 // We have no more replies to provide the caller with,

src/cargo/util/network/http.rs

@@ -135,7 +135,7 @@ pub fn configure_http_handle(config: &Config, handle: &mut Easy) -> CargoResult<
 
     if let Some(true) = http.debug {
         handle.verbose(true)?;
-        tracing::debug!("{:#?}", curl::Version::get());
+        tracing::debug!(target: "network", "{:#?}", curl::Version::get());
         handle.debug_function(|kind, data| {
             enum LogLevel {
                 Debug,
@@ -167,16 +167,20 @@ pub fn configure_http_handle(config: &Config, handle: &mut Easy) -> CargoResult<
                             line = "set-cookie: [REDACTED]";
                         }
                         match level {
-                            Debug => debug!("http-debug: {prefix} {line}"),
-                            Trace => trace!("http-debug: {prefix} {line}"),
+                            Debug => debug!(target: "network", "http-debug: {prefix} {line}"),
+                            Trace => trace!(target: "network", "http-debug: {prefix} {line}"),
                         }
                     }
                 }
                 Err(_) => {
                     let len = data.len();
                     match level {
-                        Debug => debug!("http-debug: {prefix} ({len} bytes of data)"),
-                        Trace => trace!("http-debug: {prefix} ({len} bytes of data)"),
+                        Debug => {
+                            debug!(target: "network", "http-debug: {prefix} ({len} bytes of data)")
+                        }
+                        Trace => {
+                            trace!(target: "network", "http-debug: {prefix} ({len} bytes of data)")
+                        }
                     }
                 }
             }

src/cargo/util/network/mod.rs

@@ -29,7 +29,7 @@ macro_rules! try_old_curl {
         let result = $e;
         if cfg!(target_os = "macos") {
             if let Err(e) = result {
-                ::tracing::warn!("ignoring libcurl {} error: {}", $msg, e);
+                ::tracing::warn!(target: "network", "ignoring libcurl {} error: {}", $msg, e);
             }
         } else {
             use ::anyhow::Context;

src/doc/contrib/src/implementation/debugging.md

@@ -16,7 +16,7 @@ CARGO_LOG=debug cargo generate-lockfile
 CARGO_LOG=cargo::core::resolver=trace cargo generate-lockfile
 
 # This will print lots of info about the download process. `trace` prints even more.
-CARGO_HTTP_DEBUG=true CARGO_LOG=cargo::ops::registry=debug cargo fetch
+CARGO_HTTP_DEBUG=true CARGO_LOG=network=debug cargo fetch
 
 # This is an important command for diagnosing fingerprint issues.
 CARGO_LOG=cargo::core::compiler::fingerprint=trace cargo build

src/doc/src/reference/config.md

@@ -622,8 +622,8 @@ crate dependencies and accessing remote git repositories.
 * Environment: `CARGO_HTTP_DEBUG`
 
 If `true`, enables debugging of HTTP requests. The debug information can be
-seen by setting the `CARGO_LOG=cargo::ops::registry=debug` environment
-variable (or use `trace` for even more information).
+seen by setting the `CARGO_LOG=network=debug` environment
+variable (or use `network=trace` for even more information).
 
 Be wary when posting logs from this output in a public location. The output
 may include headers with authentication tokens which you don't want to leak!