Presentation of build script errors is noisy, difficult to understand

[kornelski]

Problem

When a custom build script fails, Cargo prints a very verbose output. It's often difficult to find the actual error message from the build script among all other debugging information printed just in case.

For example, it's common for pkg-config crate to fail, but the name of the library that user needs to install is buried under 30 other lines (and even worse with RUST_BACKTRACE=1)

error: failed to run custom build command for `tst v0.1.0 (/private/tmp/tst)`

Caused by:
  process didn't exit successfully: `/private/tmp/tst/target/debug/build/tst-2429227eb6585f3e/build-script-build` (exit status: 101)
  --- stdout
  cargo:rerun-if-env-changed=IDONTEXIST_NO_PKG_CONFIG
  cargo:rerun-if-env-changed=PKG_CONFIG_aarch64-apple-darwin
  cargo:rerun-if-env-changed=PKG_CONFIG_aarch64_apple_darwin
  cargo:rerun-if-env-changed=HOST_PKG_CONFIG
  cargo:rerun-if-env-changed=PKG_CONFIG
  cargo:rerun-if-env-changed=IDONTEXIST_STATIC
  cargo:rerun-if-env-changed=IDONTEXIST_DYNAMIC
  cargo:rerun-if-env-changed=PKG_CONFIG_ALL_STATIC
  cargo:rerun-if-env-changed=PKG_CONFIG_ALL_DYNAMIC
  cargo:rerun-if-env-changed=PKG_CONFIG_PATH_aarch64-apple-darwin
  cargo:rerun-if-env-changed=PKG_CONFIG_PATH_aarch64_apple_darwin
  cargo:rerun-if-env-changed=HOST_PKG_CONFIG_PATH
  cargo:rerun-if-env-changed=PKG_CONFIG_PATH
  cargo:rerun-if-env-changed=PKG_CONFIG_LIBDIR_aarch64-apple-darwin
  cargo:rerun-if-env-changed=PKG_CONFIG_LIBDIR_aarch64_apple_darwin
  cargo:rerun-if-env-changed=HOST_PKG_CONFIG_LIBDIR
  cargo:rerun-if-env-changed=PKG_CONFIG_LIBDIR
  cargo:rerun-if-env-changed=PKG_CONFIG_SYSROOT_DIR_aarch64-apple-darwin
  cargo:rerun-if-env-changed=PKG_CONFIG_SYSROOT_DIR_aarch64_apple_darwin
  cargo:rerun-if-env-changed=HOST_PKG_CONFIG_SYSROOT_DIR
  cargo:rerun-if-env-changed=PKG_CONFIG_SYSROOT_DIR

  --- stderr
  thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: `"pkg-config" "--libs" "--cflags" "idontexist"` did not exit successfully: exit status: 1

  --- stderr
  Package idontexist was not found in the pkg-config search path.
  Perhaps you should add the directory containing `idontexist.pc'
  to the PKG_CONFIG_PATH environment variable
  No package 'idontexist' found
  ', build.rs:2:45
  note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

It would be nice to trim this output and perhaps extract the error message from the build script and present it like "native" Cargo/Rust errors.

Steps

fn main() {
    pkg_config::probe_library("idontexist").unwrap();
}

Possible Solution(s)

It needs multiple steps:

• Cargo could hide valid directives like cargo:rerun-if-env-changed= from the stdout output, unless run with --verbose (with a note about it, similar to how backtrace is hidden).

• It would be nice if Cargo could recognize when a build script panics, and present such information as an explicit build error. Instead of printing "--- stderr thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: `oops`" print just "error: oops" at the top with other Cargo/Rust errors. I'm not sure what the communication protocol for this could look like. Just parsing stderr for "thread 'main' panicked" might work, but feels inelegant.

• Perhaps support cargo:error= directive, similar to cargo:warning=, but also support it in stderr output, so that errors printed due to .unwrap() can use it.

Notes

No response

Version

cargo 1.58.0

[joshtriplett]

We talked about this in today's @rust-lang/cargo meeting.

We agreed that cargo:error= sounds like a great idea. That doesn't need a full RFC or similar; a PR and a team FCP will suffice. Rough behavior sketch:

• Emit the message as an error just as with cargo:warning=.
• Treat the script as having errored whether or not it returns an error code.

The idea of parsing it out of stderr seems a little harder, primarily because we don't currently parse anything out of stderr, so I don't think we'd want to do that in a first pass.

[joshtriplett]

Separately from the discussion in the meeting: I personally think cleaning up error messages in these cases seems like a good idea.

Hiding the extensive stdout behind --verbose and a summary (e.g. "N cargo directives hidden, pass --verbose to see them") seems potentially reasonable. People will want that output if they're debugging the build script, but not everyone experiencing a build script error is actively developing and debugging the build script and its cargo directives.

[kornelski]

Thank you @joshtriplett

Do you think it would be worthwhile to make a distinction between workspace crates and non-workspace?

I'm thinking that a verbose build script output is important for debugging of the build script itself during its development. However, once the build script is done, and is used by others as a dependency, only the result (reported error) of the build script is relevant to users. The heuristic for choosing between "developer of build.rs" vs "user of build.rs" could be whether the crate with a build script belongs to the current workspace.

[kornelski]

In the end I've decided against making exceptions for local/workspace crates, because crate authors should be able to see the same error formatting as their downstream users.

[kornelski]

I decided not to make cargo:error= imply script failure. Scripts are still required to return a failure exit code as before, and cargo:error= is just handling display of errors, not success/failure.

1. It's technically not backwards-comaptible to fail on cargo:error=. Cargo supports cargo:key=value and there may be scripts out there that set "error" key on their success path and expect that to work. Not failing the script on that is fully backwards-compatible, because arbitrary metadata is not used when scripts fail with an exit code.

2. It could be annoying when combining multiple build-time crates. A 3rd party crate could print cargo:error= when it fails, and fail the whole script, even if the script had a fallback for it (e.g. a sys crate has pkg-config print cargo:error, but the sys crate can build from source too).

3. Scripts are supposed to communicate an exit code. Guessing "did you mean to fail?" from their text output seems sloppy, and makes "public API" of build scripts more ambiguous.

So I suggest to keep using exit code, and threat cargo:error in a successful script as an authoring mistake and just warn about it.

[epage]

It's technically not backwards-comaptible to fail on cargo:error=. Cargo supports cargo:key=value and there may be scripts out there that set "error" key on their success path and expect that to work. Not failing the script on that is fully backwards-compatible, because arbitrary metadata is not used when scripts fail with an exit code.

Personally, I think its a problem that we can't add new directives and we should find a way to resolve this.

It could be annoying when combining multiple build-time crates. A 3rd party crate could print cargo:error= when it fails, and fail the whole script, even if the script had a fallback for it (e.g. a sys crate has pkg-config print cargo:error, but the sys crate can build from source too).

imo if something isn't an error, it shouldn't be reported as such

Scripts are supposed to communicate an exit code. Guessing "did you mean to fail?" from their text output seems sloppy, and makes "public API" of build scripts more ambiguous.

I see this being like compile_error!. I also think showing errors without erroring out would be confusing to users.

[epage]

@kornelski the cargo team talked about your compatibly concern which I broke out into #11461. In there is a proposed solution from the cargo team.

We understand that a dependency might emit an error but the build.rs wants to swallow it and not automatically fail the build.rs independent of exit code. We feel that is an API negotiation between the build.rs author and the dependency but we should have a note of caution about that within the build script documentation as part of the PR adding cargo::error.

[kornelski]

This has been sitting for a year now, and continues to be a problem, e.g. https://users.rust-lang.org/t/problems-building-a-package/103268

[epage]

#12201 finished FCP and I just kicked off bors which unblocks adding error= directives.

[torhovland]

We understand that a dependency might emit an error but the build.rs wants to swallow it and not automatically fail the build.rs independent of exit code. We feel that is an API negotiation between the build.rs author and the dependency but we should have a note of caution about that within the build script documentation as part of the PR adding cargo::error.

How is that a negotiation between the build.rs author and the dependency? If the dependency chooses to emit a cargo::error and we take that to mean the build must fail, there isn't much the build.rs author can do about it, is there?

[Gnurfos]

I'm sorry if I'm coming here with a maybe off-topic or naive question, but how feasible would it be to have build.rs not just exposing a main() function, but exposing a function taking (or a type that implementing) some pre-defined trait like "CargoBuildScriptContext", wherein both logging, and outcome/severity would be much more explicit, controlled, and structured ?

[torhovland]

Some questions about behaviour. The docs state that:

Warnings are only shown for path dependencies
(that is, those you're working on locally), so for example warnings printed
out in [crates.io] crates are not emitted by default. The -vv "very verbose"
flag may be used to have Cargo display warnings for all crates.

• How about when an external crate panics? Should it still not emit any warnings unless -vv is set?
• How about when an external crate logs a cargo::error? It should emit the error message and fail the build, but should it also emit any warnings (even when -vv isn't set)?

I believe the answer to the second question should be yes. Any warnings may provide valuable context to make sense of the error message. And if the answer to the second question is yes, I think it should be the same for the first question, for consistency.

EDIT: The docs just aren't precise. A code comment says this about warnings:

/// These are only displayed if this is a "local" package, `-vv` is used,
/// or there is a build error for any target in this package.

I'll update the docs.

[epage]

How is that a negotiation between the build.rs author and the dependency? If the dependency chooses to emit a cargo::error and we take that to mean the build must fail, there isn't much the build.rs author can do about it, is there?

Either the dependency needs to not use cargo::error, reporting the problem up to the caller to decide, or the dependency needs to have some flags to control its behavior.

[epage]

I'm sorry if I'm coming here with a maybe off-topic or naive question, but how feasible would it be to have build.rs not just exposing a main() function, but exposing a function taking (or a type that implementing) some pre-defined trait like "CargoBuildScriptContext", wherein both logging, and outcome/severity would be much more explicit, controlled, and structured ?

The interface between Cargo and a build script is the calling of a binary. That means we can't use any Rust types for the bare bones interface. We are interested in providing an API to encapsulate that interface, see #12432

[epage]

How about when an external crate logs a cargo::error? It should emit the error message and fail the build, but should it also emit any warnings (even when -vv isn't set)?

I believe the answer to the second question should be yes. Any warnings may provide valuable context to make sense of the error message. And if the answer to the second question is yes, I think it should be the same for the first question, for consistency.

We'll likely have to try and see. Thankfully this is a question of UX and we can change it.

[kornelski]

I still think it's a mistake to have two redundant ways of reporting build failures.

A script returning success code and a fatal error text at the same time is giving an incoherent response. This should be treated as a bug in the build script.