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

stdenv: log build hooks as they run #290081

Merged
merged 3 commits into from
Mar 3, 2024
Merged
Show file tree
Hide file tree
Changes from 2 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
2 changes: 1 addition & 1 deletion doc/stdenv/stdenv.chapter.md
Original file line number Diff line number Diff line change
Expand Up @@ -432,7 +432,7 @@ The propagated equivalent of `depsTargetTarget`. This is prefixed for the same r

#### `NIX_DEBUG` {#var-stdenv-NIX_DEBUG}

A number between 0 and 7 indicating how much information to log. If set to 1 or higher, `stdenv` will print moderate debugging information during the build. In particular, the `gcc` and `ld` wrapper scripts will print out the complete command line passed to the wrapped tools. If set to 6 or higher, the `stdenv` setup script will be run with `set -x` tracing. If set to 7 or higher, the `gcc` and `ld` wrapper scripts will also be run with `set -x` tracing.
A number between 0 and 7 indicating how much information to log. If set to 1 or higher, `stdenv` will print moderate debugging information during the build. In particular, the `gcc` and `ld` wrapper scripts will print out the complete command line passed to the wrapped tools. If set to 2 or higher, multiline build hooks will be printed literally. If set to 6 or higher, the `stdenv` setup script will be run with `set -x` tracing. If set to 7 or higher, the `gcc` and `ld` wrapper scripts will also be run with `set -x` tracing.

### Attributes affecting build properties {#attributes-affecting-build-properties}

Expand Down
43 changes: 43 additions & 0 deletions pkgs/stdenv/generic/setup.sh
Original file line number Diff line number Diff line change
Expand Up @@ -50,6 +50,42 @@ getAllOutputNames() {
######################################################################
# Hook handling.

# Log a hook, to be run before the hook is actually called.
# logging for "implicit" hooks -- the ones specified directly
# in derivation's arguments -- is done in _callImplicitHook instead.
Qyriad marked this conversation as resolved.
Show resolved Hide resolved
_logHook() {
local hookKind="$1"
local hookExpr="$2"
shift 2

if declare -F "$hookExpr" > /dev/null 2>&1; then
echo "calling '$hookKind' function hook '$hookExpr'" "$@"
elif type -p "$hookExpr" > /dev/null; then
echo "sourcing '$hookKind' script hook '$hookExpr'"
elif [[ "$hookExpr" != "_callImplicitHook"* ]]; then
# Here we have a string hook to eval.
# Join lines onto one with literal \n characters unless NIX_DEBUG >= 2.
local exprToOutput
if (( "${NIX_DEBUG:-0}" >= 2 )); then
exprToOutput="$hookExpr"
else
while IFS= read -r hookExprLine; do
# These lines often have indentation,
# so let's remove leading whitespace.
hookExprLine="${hookExprLine#"${hookExprLine%%[![:space:]]*}"}"
# If this line wasn't entirely whitespace,
# then add it to our output.
if [[ -n "$hookExprLine" ]]; then
exprToOutput+="$hookExprLine\\n "
fi
done <<< "$hookExpr"

# And then remove the final, unnecessary, \n
exprToOutput="${exprToOutput%%\\n }"
Comment on lines +72 to +84
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is cute, but what's the damage just showing the log-viewing user what the hook value is directly? How many of these are there?

Copy link
Member Author

@Qyriad Qyriad Feb 27, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not many. I only know of one, which is autoPatchelfHook. I ran rg -U -t sh 'hook.?\+?=\(.\n' to try to find other examples but I couldn't find any, though I'm not confidant that regex is all-inclusive. By far most hooks are either functions, or single-line if [[ -z "${dontDoHookThing-}" ]]; then doHookThing; fi. I am fine with splatting out potential multiline hooks, and autoPatchelfHook could easily be changed to do its multiline logic in its hook function instead of inline.

fi
echo "evaling '$hookKind' string hook '$exprToOutput'"
fi
}

# Run all hooks with the specified name in the order in which they
# were added, stopping if any fails (returns a non-zero exit
Expand All @@ -64,6 +100,7 @@ runHook() {
# Hack around old bash being bad and thinking empty arrays are
# undefined.
for hook in "_callImplicitHook 0 $hookName" ${!hooksSlice+"${!hooksSlice}"}; do
_logHook "$hookName" "$hook" "$@"
_eval "$hook" "$@"
done

Expand All @@ -81,6 +118,7 @@ runOneHook() {
local hook ret=1
# Hack around old bash like above
for hook in "_callImplicitHook 1 $hookName" ${!hooksSlice+"${!hooksSlice}"}; do
_logHook "$hookName" "$hook" "$@"
if _eval "$hook" "$@"; then
ret=0
break
Expand All @@ -100,10 +138,13 @@ _callImplicitHook() {
local def="$1"
local hookName="$2"
if declare -F "$hookName" > /dev/null; then
echo "calling implicit '$hookName' function hook"
"$hookName"
elif type -p "$hookName" > /dev/null; then
echo "sourcing implicit '$hookName' script hook"
source "$hookName"
elif [ -n "${!hookName:-}" ]; then
echo "evaling implicit '$hookName' string hook"
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For instance, here you don't do the trick with "${NIX_DEBUG:-0}" >= 2 and just splat it out.

Copy link
Member Author

@Qyriad Qyriad Feb 27, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actually this part doesn't splat out the hook string — since implicit hooks are for specifying "one-off" hooks right in a derivation, they're going to be specified by the derivation being built itself. Those often are multiline, but since they're also by far the most obvious hooks, I went with just logging the name. So something like

preConfigure = ''
  some foo commands
'';

Gets logged as evaling implicit 'preConfigure' hook without printing the text itself. If you have something better I'm absolutely all ears 🙂

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That's definitely good enough. Thanks for the example.

I wonder (and this isn't for this review) whether "implicit" is the right name for this concept, and whether "immediate" or "derivation-supplied" might be a better name. In fact, from the perspective of the derivation or package author, they might be thought of as "explicit" hooks as opposed to the "implicit" ones that come from elsewhere. An irony if so.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A lot of my time spent debugging this ended up actually amounting to figuring out what implicit hooks are and where they come from and why there's a separate, special mechanism for them in stdenv 😅

So I completely agree; a rename of the concept would be very helpful. "Immediate" is decent, but further bikeshedding can be at a later date

eval "${!hookName}"
else
return "$def"
Expand Down Expand Up @@ -644,6 +685,7 @@ activatePackage() {
(( hostOffset <= targetOffset )) || exit 1

if [ -f "$pkg" ]; then
echo "sourcing setup hook '$pkg'"
source "$pkg"
fi

Expand All @@ -667,6 +709,7 @@ activatePackage() {
fi

if [[ -f "$pkg/nix-support/setup-hook" ]]; then
echo "sourcing setup hook '$pkg/nix-support/setuphook'"
source "$pkg/nix-support/setup-hook"
fi
}
Expand Down
Loading