Add warning and debug information when cargo metadata fails

[aibaars]

The errors are silently dropped elsewhere, which make it really hard to debug issues due to dependency download failures.

[Veykril]

Suggested change

	tracing::warn!(
	"`cargo metadata` failed on `{cargo_toml}`, but retry with `--no-deps` succeeded"
	);
	tracing::debug!("{e:?}");
	tracing::warn!(
	%cargo_toml,
	%e,
	"`cargo metadata` failed, but retry with `--no-deps` succeeded"
	);

[aibaars]

That looks better, but doesn't print the stderr though, while tracing::debug!("{e:?}"); does. I'd really like to see a short warning with a default log level and a detailed error message explaining the cause at debug/trace level. Not sure that the best way is to achieve that.

[Veykril]

but doesn't print the stderr though

it does though? %e is included. Imo warn being noisy here is fine

[aibaars]

For some reason it does not display the stderr as part of e. I suppose it is due to the use of :? in the format.

This just the warn! line I get:

WARN `cargo metadata` failed, but retry with `--no-deps` succeeded cargo_toml=/private/tmp/repo/Cargo.toml e=Failed to run `cd "/private/tmp/repo" && RUSTUP_TOOLCHAIN="/Users/user/.rustup/toolchains/1.84.0-aarch64-apple-darwin" "/Users/user/.cargo/bin/cargo" "metadata" "--format-version" "1" "--manifest-path" "/private/tmp/repo/Cargo.toml" "--filter-platform" "aarch64-apple-darwin"`

but with the additional debug! line I get the following, which is potentially too large for normal cases, but great for debugging:

WARN `cargo metadata` failed, but retry with `--no-deps` succeeded cargo_toml=/private/tmp/repo/Cargo.toml e=Failed to run `cd "/private/tmp/repo" && RUSTUP_TOOLCHAIN="/Users/user/.rustup/toolchains/1.84.0-aarch64-apple-darwin" "/Users/user/.cargo/bin/cargo" "metadata" "--format-version" "1" "--manifest-path" "/private/tmp/repo/Cargo.toml" "--filter-platform" "aarch64-apple-darwin"`
DEBUG Failed to run `cd "/private/tmp/repo" && RUSTUP_TOOLCHAIN="/Users/user/.rustup/toolchains/1.84.0-aarch64-apple-darwin" "/Users/user/.cargo/bin/cargo" "metadata" "--format-version" "1" "--manifest-path" "/private/tmp/repo/Cargo.toml" "--filter-platform" "aarch64-apple-darwin"`
Caused by:
    `cargo metadata` exited with an error:     Updating git repository `https://github.com/github/thing-proto.git`
    error: failed to get `thing-proto` as a dependency of package `thing v0.1.0 (/private/tmp/repo/crates/thing)`
    
    Caused by:
      failed to load source for dependency `thing-proto`
    
    Caused by:
      Unable to update https://github.com/github/thing-proto.git?rev=752736ed7162c42d63faeef37ecca6c7bcc207c8#752736ed
    
    Caused by:
      failed to fetch into: /tmp/cargo/git/db/thing-proto-9b6bd70b202f39a5
    
    Caused by:
      revision 752736ed7162c42d63faeef37ecca6c7bcc207c8 not found
    
    Caused by:
      failed to authenticate when downloading repository
    
      * attempted to find username/password via git's `credential.helper` support, but failed
    
      if the git CLI succeeds then `net.git-fetch-with-cli` may help here
      https://doc.rust-lang.org/cargo/reference/config.html#netgit-fetch-with-cli
    
    Caused by:
      failed to acquire username/password from local configuration
    
Stack backtrace:
   0: std::backtrace::Backtrace::create
   1: anyhow::error::<impl core::convert::From<E> for anyhow::Error>::from
   2: ra_ap_project_model::cargo_workspace::CargoWorkspace::fetch_metadata_
   3: ra_ap_project_model::cargo_workspace::CargoWorkspace::fetch_metadata
   4: ra_ap_project_model::workspace::ProjectWorkspace::load
   5: ra_ap_load_cargo::load_workspace_at
   6: single_arch_extractor::main
   7: std::sys::backtrace::__rust_begin_short_backtrace
   8: std::rt::lang_start::{{closure}}
   9: std::rt::lang_start_internal
  10: _main

[davidbarsky]

this should include the command's stderr:

tracing::warn!(
    %cargo_toml,
    ?e,
    "`cargo metadata` failed, but retry with `--no-deps` succeeded"
);

personally, I think including stderr is worth the noise, but.

[aibaars]

Ah yes, that makes sense, I can change to ?e . @Veykril what do you think?

[aibaars]

Thanks both! I applied @davidbarsky's suggestion and replaced %e with ?e .

[aibaars]

@Veykril I left the tracing::debug!("{e:?}"); line in for now. Do you have an idea how to achieve detailed logging in debug mode without having two tracing:: lines?

[davidbarsky]

I commented above, but see tracing's documentation on ? and % sigils: https://docs.rs/tracing/latest/tracing/#recording-fields. tracing doesn't have per-field levels, so you'll need to have two events or accept the higher verbosity.

[Veykril]

Thanks!