From eb28e5e72ef912629ded3e265f7344ca21d115b9 Mon Sep 17 00:00:00 2001 From: Qyriad Date: Fri, 16 Feb 2024 14:00:50 -0700 Subject: [PATCH 1/3] stdenv: log build hooks as they run --- doc/stdenv/stdenv.chapter.md | 2 +- pkgs/stdenv/generic/setup.sh | 43 ++++++++++++++++++++++++++++++++++++ 2 files changed, 44 insertions(+), 1 deletion(-) diff --git a/doc/stdenv/stdenv.chapter.md b/doc/stdenv/stdenv.chapter.md index a948c6757c4a0..b7f3606392253 100644 --- a/doc/stdenv/stdenv.chapter.md +++ b/doc/stdenv/stdenv.chapter.md @@ -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} diff --git a/pkgs/stdenv/generic/setup.sh b/pkgs/stdenv/generic/setup.sh index efb233312b571..cafc1abcda93c 100644 --- a/pkgs/stdenv/generic/setup.sh +++ b/pkgs/stdenv/generic/setup.sh @@ -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. +_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 removing 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 }" + 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 @@ -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 @@ -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 @@ -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" eval "${!hookName}" else return "$def" @@ -644,6 +685,7 @@ activatePackage() { (( hostOffset <= targetOffset )) || exit 1 if [ -f "$pkg" ]; then + echo "sourcing setup hook '$pkg'" source "$pkg" fi @@ -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 } From 9aef09586ea26be9d2cf8bfa0564539ddcbe0129 Mon Sep 17 00:00:00 2001 From: Qyriad Date: Sun, 25 Feb 2024 22:19:37 -0700 Subject: [PATCH 2/3] prev: apply fixes from code review Addresses the following review comments: - https://github.com/NixOS/nixpkgs/pull/290081/files/eb28e5e72ef912629ded3e265f7344ca21d115b9#r1501466125 - https://github.com/NixOS/nixpkgs/pull/290081/files/eb28e5e72ef912629ded3e265f7344ca21d115b9#r1501466232 This will be squashed into the previous commit pending review. --- pkgs/stdenv/generic/setup.sh | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/pkgs/stdenv/generic/setup.sh b/pkgs/stdenv/generic/setup.sh index cafc1abcda93c..f6fde45aee65b 100644 --- a/pkgs/stdenv/generic/setup.sh +++ b/pkgs/stdenv/generic/setup.sh @@ -71,13 +71,13 @@ _logHook() { else while IFS= read -r hookExprLine; do # These lines often have indentation, - # so let's removing leading whitespace. + # 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 + if [[ -n "$hookExprLine" ]]; then + exprToOutput+="$hookExprLine\\n " + fi done <<< "$hookExpr" # And then remove the final, unnecessary, \n From ff372db9b4e4eab33bf2c48a2d4ee8c644fe4f78 Mon Sep 17 00:00:00 2001 From: Qyriad Date: Mon, 26 Feb 2024 19:59:01 -0700 Subject: [PATCH 3/3] prev: per-review: reword comment regarding logging of implicit hooks Addresses the following review comment: https://github.com/NixOS/nixpkgs/pull/290081#discussion_r1503503065 This will be squashed into the previous commit pending review. Co-authored-by: Philip Taron --- pkgs/stdenv/generic/setup.sh | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/pkgs/stdenv/generic/setup.sh b/pkgs/stdenv/generic/setup.sh index f6fde45aee65b..efd3c8c36e12a 100644 --- a/pkgs/stdenv/generic/setup.sh +++ b/pkgs/stdenv/generic/setup.sh @@ -51,8 +51,8 @@ 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. +# This only logs explicit hooks; "implicit" hooks, those specified directly +# in a derivation's arguments, are logged in `_callImplicitHook` instead. _logHook() { local hookKind="$1" local hookExpr="$2"