feat: log errors pushing config to watchdog

README.md

@@ -49,7 +49,10 @@ and creating a PR with the changes.
 3. Set up the host to push to the config repo:
    1. Add the required environment variables, see [`check-and-push-config.sh`].
    2. Add [Config Change Track] to the codebase and enable.
-   3. Schedule [`check-and-push-config.sh`] to run regularly.
+   3. Schedule [`check-and-push-config.sh`] to run regularly, from the project
+      root so drush can bootstrap Drupal.
+   4. If config stops arriving, run `drush watchdog:show --type=update_config`:
+      the script logs every failure there, with credentials redacted.
 4. Set up the Drupal site repo to pull from the config repo:
    1. In the site repo, go to _Settings → Actions → General_ and enable
       **Allow GitHub Actions to create and approve pull requests**.

scripts/check-and-push-config.sh

@@ -12,16 +12,77 @@
 #
 # Note the repo's access token can be passed with the repo URL, eg.
 # https://ABC123:@github.com/MyOrg/MySiteConfig
+#
+# Any failure is logged to the Drupal watchdog on the channel 'update_config',
+# with credentials in URLs redacted. That requires drush to be able to bootstrap
+# Drupal from the directory cron starts in, so run this from the project root.
+# Diagnose a stalled export with `drush watchdog:show --type=update_config`.
+
+set -Eeuo pipefail
+
+# Capture everything the run produces so a failure can be logged with its
+# output. The exit handler replays it to the real stdout/stderr, so cron mail
+# is unaffected; the cost is that an interactive run shows nothing until it
+# finishes.
+start_dir=$PWD # drush bootstraps here; $temp_dir is not a Drupal root.
+output_file=$(mktemp)
+exec 3>&1 4>&2
+exec >"$output_file" 2>&1
+
+redact() {
+  # The config repo token rides in $CONFIG_REPO_URL and git prints the URL back
+  # in auth errors; watchdog is readable by anyone with 'access site reports'.
+  sed -E 's#(://)[^/@[:space:]]+@#\1***@#g'
+}
+
+on_exit() {
+  local status=$1
+  # No recursion, and don't let a failing command in here abort the handler.
+  trap - ERR EXIT
+  set +e
 
-set -eu
+  exec 1>&3 2>&4
+  redact < "$output_file"
+
+  if [[ $status -ne 0 ]]; then
+    local message
+    message=$(printf '%s failed (exit %s, line %s).\n--- last output ---\n%s\n' \
+      "$(basename "$0")" "$status" "${failure_line:-unknown}" \
+      "$(tail -c 2000 "$output_file" | redact)")
+    cd "$start_dir"
+    # Drush has no watchdog-writing command, so go through php:eval. The
+    # message is passed in the environment and bound as a placeholder, never
+    # interpolated into the snippet.
+    UPDATE_CONFIG_LOG_MESSAGE="$message" drush php:eval \
+      '\Drupal::logger("update_config")->error("@message", ["@message" => getenv("UPDATE_CONFIG_LOG_MESSAGE")]);' \
+      || printf 'Could not write the failure to the Drupal watchdog.\n' >&2
+  fi
+
+  rm -f "$output_file"
+  # The handler's own commands have overwritten $?, so restore the real status.
+  exit "$status"
+}
+
+# A `set -u` abort doesn't fire the ERR trap, only EXIT, so EXIT does the
+# logging and ERR only records where things went wrong.
+failure_line=
+trap 'failure_line=$LINENO' ERR
+trap 'on_exit $?' EXIT
+
+: "${CONFIG_REPO_URL:?CONFIG_REPO_URL is not set}"
 
 commit_message="Export config from Prod"
 config_repo_branch=${CONFIG_REPO_BRANCH:-main}
 
-# Check if config needs to be exported
-if [[ $(drush config-change-track:needs-export) == "0" ]]; then
-  exit # No changes to export so early out.
-fi
+# Check if config needs to be exported. Assign rather than test the command
+# substitution inline: `[[ $(drush …) == "0" ]]` doesn't trip `set -e`, so a
+# failing or missing drush command would fall through to exporting and pushing.
+needs_export=$(drush config-change-track:needs-export)
+case "$needs_export" in
+  0) exit ;; # No changes to export so early out.
+  1) ;;
+  *) echo "Unexpected needs-export output: $needs_export" >&2; exit 1 ;;
+esac
 
 temp_dir=${CONFIG_REPO_TEMP_DIR-/tmp/config_change_track}
 mkdir -p "$temp_dir"

tests/check-and-push-config.bats

@@ -19,19 +19,23 @@ setup() {
     git config --global init.defaultBranch "main"
     git config --global push.default "simple"
 
-    # Drush stub: all subcommand invocations appended to DRUSH_CALL_LOG.
-    # Behaviour controlled per-test via NEEDS_EXPORT and EXPORT_FILES_DIR.
+    # Drush stub: all subcommand invocations appended to DRUSH_CALL_LOG, and
+    # watchdog messages written via php:eval appended to WATCHDOG_LOG.
+    # Behaviour controlled per-test via NEEDS_EXPORT, EXPORT_FILES_DIR and the
+    # *_EXIT knobs, which inject a failing drush command.
     local bin_dir="$BATS_TEST_TMPDIR/bin"
     mkdir -p "$bin_dir"
     export DRUSH_CALL_LOG="$BATS_TEST_TMPDIR/drush-calls.log"
-    touch "$DRUSH_CALL_LOG"
+    export WATCHDOG_LOG="$BATS_TEST_TMPDIR/watchdog.log"
+    touch "$DRUSH_CALL_LOG" "$WATCHDOG_LOG"
     cat > "$bin_dir/drush" << 'STUB'
 #!/usr/bin/env bash
 subcommand="$1"; shift
 echo "$subcommand $*" >> "$DRUSH_CALL_LOG"
 case "$subcommand" in
   config-change-track:needs-export)
     echo "${NEEDS_EXPORT:-0}"
+    exit "${NEEDS_EXPORT_EXIT:-0}"
     ;;
   config:export)
     dest=""
@@ -48,6 +52,13 @@ case "$subcommand" in
     if [[ -n "$dest" ]]; then
       printf 'deny from all\n' > "$dest/.htaccess"
     fi
+    exit "${EXPORT_EXIT:-0}"
+    ;;
+  php:eval)
+    # Stands in for \Drupal::logger('update_config')->error(), which the script
+    # hands its message to through the environment.
+    printf '%s\n' "${UPDATE_CONFIG_LOG_MESSAGE-}" >> "$WATCHDOG_LOG"
+    exit "${EVAL_EXIT:-0}"
     ;;
 esac
 STUB
@@ -74,11 +85,13 @@ STUB
     echo "exported" > "$EXPORT_FILES_DIR/config.yml"
 
     unset CONFIG_REPO_BRANCH UPDATE_CONFIG_GIT_NAME UPDATE_CONFIG_GIT_EMAIL \
-          UPDATE_CONFIG_GIT_MESSAGE NEEDS_EXPORT
+          UPDATE_CONFIG_GIT_MESSAGE NEEDS_EXPORT NEEDS_EXPORT_EXIT \
+          EXPORT_EXIT EVAL_EXIT
 }
 
 _remote_commit_count() { git -C "$1" rev-list HEAD --count; }
 _remote_head()         { git -C "$1" rev-parse "${2:-HEAD}"; }
+_watchdog_log()        { cat "$WATCHDOG_LOG"; }
 
 # Early out
 
@@ -92,6 +105,8 @@ _remote_head()         { git -C "$1" rev-parse "${2:-HEAD}"; }
     ! grep -q "config:export" "$DRUSH_CALL_LOG"
     ! grep -q "set-last-export" "$DRUSH_CALL_LOG"
     [[ "$(_remote_head "$CONFIG_REPO_URL")" == "$initial_head" ]]
+    # A clean early-out is not a failure: nothing goes to watchdog.
+    [ ! -s "$WATCHDOG_LOG" ]
 }
 
 # Fresh clone
@@ -106,6 +121,8 @@ _remote_head()         { git -C "$1" rev-parse "${2:-HEAD}"; }
     # Exported file present in the pushed commit.
     git -C "$CONFIG_REPO_URL" show HEAD:config.yml
     grep -q "set-last-export --time" "$DRUSH_CALL_LOG"
+    # A successful run stays silent.
+    [ ! -s "$WATCHDOG_LOG" ]
 }
 
 # Existing checkout (fetch + reset path)
@@ -323,3 +340,130 @@ _remote_head()         { git -C "$1" rev-parse "${2:-HEAD}"; }
     # config.yml must appear on config-branch in the bare repo.
     git -C "$custom_bare" show refs/heads/config-branch:config.yml
 }
+
+# Failure logging to the Drupal watchdog
+
+@test "logs a failed clone to watchdog and exits non-zero" {
+    export NEEDS_EXPORT=1
+    export CONFIG_REPO_URL="$BATS_TEST_TMPDIR/no-such-repo.git"
+
+    run "$SCRIPT"
+
+    [ "$status" -ne 0 ]
+    local logged; logged=$(_watchdog_log)
+    [[ "$logged" == *"check-and-push-config.sh failed"* ]]
+    [[ "$logged" == *"exit $status"* ]]
+    # The git error itself is carried through, not just "something failed".
+    [[ "$logged" == *"no-such-repo.git"* ]]
+}
+
+@test "logs a rejected push to watchdog and leaves the remote unchanged" {
+    export NEEDS_EXPORT=1
+
+    # Reject anything pushed to the bare repo.
+    cat > "$CONFIG_REPO_URL/hooks/pre-receive" << 'HOOK'
+#!/usr/bin/env bash
+echo "rejected by test hook" >&2
+exit 1
+HOOK
+    chmod +x "$CONFIG_REPO_URL/hooks/pre-receive"
+
+    local initial_head; initial_head=$(_remote_head "$CONFIG_REPO_URL")
+
+    run "$SCRIPT"
+
+    [ "$status" -ne 0 ]
+    [[ "$(_remote_head "$CONFIG_REPO_URL")" == "$initial_head" ]]
+    [[ "$(_watchdog_log)" == *"rejected by test hook"* ]]
+    # The export is only marked done after a successful push.
+    ! grep -q "set-last-export" "$DRUSH_CALL_LOG"
+}
+
+@test "logs a failed config:export to watchdog and pushes nothing" {
+    export NEEDS_EXPORT=1
+    export EXPORT_EXIT=1
+
+    local initial_head; initial_head=$(_remote_head "$CONFIG_REPO_URL")
+
+    run "$SCRIPT"
+
+    [ "$status" -ne 0 ]
+    [[ "$(_remote_head "$CONFIG_REPO_URL")" == "$initial_head" ]]
+    [[ "$(_watchdog_log)" == *"check-and-push-config.sh failed"* ]]
+    ! grep -q "set-last-export" "$DRUSH_CALL_LOG"
+}
+
+@test "logs a failed needs-export to watchdog without exporting or pushing" {
+    export NEEDS_EXPORT_EXIT=1
+
+    local initial_head; initial_head=$(_remote_head "$CONFIG_REPO_URL")
+
+    run "$SCRIPT"
+
+    [ "$status" -ne 0 ]
+    [[ "$(_remote_head "$CONFIG_REPO_URL")" == "$initial_head" ]]
+    [[ "$(_watchdog_log)" == *"check-and-push-config.sh failed"* ]]
+    # A drush that can't answer must not be read as "no changes" *or* fall
+    # through to an export.
+    ! grep -q "config:export" "$DRUSH_CALL_LOG"
+    ! grep -q "set-last-export" "$DRUSH_CALL_LOG"
+}
+
+@test "logs unexpected needs-export output to watchdog without exporting or pushing" {
+    export NEEDS_EXPORT="banana"
+
+    run "$SCRIPT"
+
+    [ "$status" -ne 0 ]
+    local logged; logged=$(_watchdog_log)
+    [[ "$logged" == *"check-and-push-config.sh failed"* ]]
+    [[ "$logged" == *"Unexpected needs-export output: banana"* ]]
+    ! grep -q "config:export" "$DRUSH_CALL_LOG"
+    ! grep -q "set-last-export" "$DRUSH_CALL_LOG"
+}
+
+@test "redacts credentials embedded in the repo URL before logging" {
+    export NEEDS_EXPORT=1
+    # Port 1 is refused instantly, so this needs no network. transfer.
+    # credentialsInUrl=die makes git print the URL back with the username
+    # intact -- git redacts the password but not the user, and this project
+    # puts the access token in the *username* position.
+    git config --global transfer.credentialsInUrl die
+    export CONFIG_REPO_URL="https://s3cr3t:@127.0.0.1:1/nope.git"
+
+    run "$SCRIPT"
+
+    [ "$status" -ne 0 ]
+    local logged; logged=$(_watchdog_log)
+    [[ "$logged" != *"s3cr3t"* ]]
+    [[ "$logged" == *"https://***@127.0.0.1:1/nope.git"* ]]
+    # And the replayed output the caller (cron) sees is redacted too.
+    [[ "$output" != *"s3cr3t"* ]]
+}
+
+@test "keeps the original failure status when the watchdog write itself fails" {
+    export NEEDS_EXPORT=1
+    export EVAL_EXIT=1
+    export CONFIG_REPO_URL="$BATS_TEST_TMPDIR/no-such-repo.git"
+
+    # Establish the status a working watchdog write would have produced.
+    run env EVAL_EXIT=0 "$SCRIPT"
+    local expected_status="$status"
+    [ "$expected_status" -ne 0 ]
+    rm -rf "$CONFIG_REPO_TEMP_DIR"
+
+    run "$SCRIPT"
+
+    [ "$status" -eq "$expected_status" ]
+    [[ "$output" == *"Could not write the failure to the Drupal watchdog."* ]]
+}
+
+@test "replays captured output to the caller so cron mail still gets it" {
+    export NEEDS_EXPORT=1
+    export CONFIG_REPO_URL="$BATS_TEST_TMPDIR/no-such-repo.git"
+
+    run "$SCRIPT"
+
+    [ "$status" -ne 0 ]
+    [[ "$output" == *"no-such-repo.git"* ]]
+}