Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Set tracing target for networking messages. #12582

Merged
merged 1 commit into from
Aug 29, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
14 changes: 7 additions & 7 deletions src/cargo/core/package.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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)?;
Expand All @@ -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]
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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));
}
}
Expand Down Expand Up @@ -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| {
Expand All @@ -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 (?)");
}
});

Expand All @@ -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);
Expand Down
24 changes: 13 additions & 11 deletions src/cargo/sources/registry/http_remote.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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;
}
Expand Down Expand Up @@ -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;

Expand All @@ -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),
}
}
}
Expand Down Expand Up @@ -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)?;
Expand Down Expand Up @@ -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)?;

Expand All @@ -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");

Expand All @@ -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]
Expand Down Expand Up @@ -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()
);
Expand All @@ -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,
Expand Down
14 changes: 9 additions & 5 deletions src/cargo/util/network/http.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down Expand Up @@ -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)")
}
}
}
}
Expand Down
2 changes: 1 addition & 1 deletion src/cargo/util/network/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down
2 changes: 1 addition & 1 deletion src/doc/contrib/src/implementation/debugging.md
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
4 changes: 2 additions & 2 deletions src/doc/src/reference/config.md
Original file line number Diff line number Diff line change
Expand Up @@ -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!
Expand Down