From a603b9d6c2c8d54024d3273dd55e5aef6dee7f98 Mon Sep 17 00:00:00 2001 From: Daniel Hilst <392820+dhilst@users.noreply.github.com> Date: Mon, 14 Sep 2026 15:49:07 -0300 Subject: [PATCH] fix(xcat-core): otherpkgs sends the package manager output to syslog as one truncated message The otherpkgs postscript passes the whole package manager transaction to logger as a single message argument. rsyslog escapes every newline to #012 and cuts the message at 8 KiB, which is where the Failed:, Error: and summary lines sit. A line that starts with -- is also read as a logger option. The seven sites in xCAT/postscripts/otherpkgs that log $result now pipe it to logger. logger without a message argument reads standard input and sends one message per line. postscripts_otherpkgs.bats drives the upgrade block and the two preremove blocks with logger and the package manager shadowed, and counts the messages. Against the unfixed script the three tests report one message where three are expected. Signed-off-by: Daniel Hilst <392820+dhilst@users.noreply.github.com> --- xCAT-test/bats/postscripts_otherpkgs.bats | 155 ++++++++++++++++++++++ xCAT/postscripts/otherpkgs | 14 +- 2 files changed, 162 insertions(+), 7 deletions(-) create mode 100644 xCAT-test/bats/postscripts_otherpkgs.bats diff --git a/xCAT-test/bats/postscripts_otherpkgs.bats b/xCAT-test/bats/postscripts_otherpkgs.bats new file mode 100644 index 000000000..1a1d3a6f2 --- /dev/null +++ b/xCAT-test/bats/postscripts_otherpkgs.bats @@ -0,0 +1,155 @@ +#!/usr/bin/env bats + +load 'helpers/shell_source' + +setup() +{ + OTHERPKGS="$(repo_path 'xCAT/postscripts/otherpkgs')" + [ -r "$OTHERPKGS" ] || skip "$OTHERPKGS is required" + LOGGER_LOG="${BATS_TEST_TMPDIR}/logger.log" + CMD_LOG="${BATS_TEST_TMPDIR}/cmd.log" + : >"$LOGGER_LOG" + : >"$CMD_LOG" + export OTHERPKGS LOGGER_LOG CMD_LOG +} + +# logger writes one line per message it sends. A message that carries newlines stays on one +# line, with the newlines shown as "\n", so the line count is the message count. +shadow_logger() +{ + logger() + { + local msg="" + while [ $# -gt 0 ]; do + case "$1" in + -p | -t) shift 2 ;; + *) + msg="$*" + break + ;; + esac + done + if [ -n "$msg" ]; then + printf '%s\n' "${msg//$'\n'/\\n}" >>"$LOGGER_LOG" + else + local line + while IFS= read -r line; do + printf '%s\n' "$line" >>"$LOGGER_LOG" + done + fi + } +} + +logger_call() +{ + sed -n "${1}p" "$LOGGER_LOG" +} + +logger_calls() +{ + wc -l <"$LOGGER_LOG" | tr -d ' ' +} + +cmd_call() +{ + sed -n "${1}p" "$CMD_LOG" +} + +# A package manager that answers with PKG_STATUS and prints a three line transaction. +shadow_pkg_manager() +{ + fake_pkg() + { + printf '%s\n' "$*" >>"$CMD_LOG" + printf -- '--> Running transaction check\n' + printf 'Installed: foo-1.0\n' + printf 'Error: nothing provides bar\n' + return "${PKG_STATUS:-0}" + } + zypper() { fake_pkg "$@"; } + apt-get() { fake_pkg "$@"; } + xcat_apt_get() { fake_pkg "$@"; } + apt_get_update_if_repos_changed() { :; } +} + +# Answers with the shell if-block that starts at the first line after the anchor. +otherpkgs_block() +{ + local tail="${BATS_TEST_TMPDIR}/tail-$$" + awk -v anchor="$1" 'index($0, anchor) { copy = 1 } copy { print }' "$OTHERPKGS" >"$tail" + extract_shell_if_block "$tail" "$2" +} + +run_upgrade_block() +{ + local block + block="$(otherpkgs_block '#now update the existing rpms' 'if [ $hasyum -eq 1 ]; then')" || return 99 + local hasyum=0 haszypper=0 hasapt=0 + eval "$1=1" + local envlist="" yumcmd=fake_pkg VERBOSE= log_label=otherpkgs RETURNVAL=0 REPOFILE=/dev/null result="" + shadow_logger + shadow_pkg_manager + eval "$block" + printf 'RETURNVAL=%s\n' "$RETURNVAL" +} + +run_repo_preremove_block() +{ + local block + block="$(otherpkgs_block '#Now we have parsed the input' 'if [ "$repo_pkgs_preremove" != "" ]; then')" || return 99 + local hasyum=0 haszypper=0 hasapt=0 + eval "$1=1" + local envlist="" yumcmd=fake_pkg VERBOSE= log_label=otherpkgs RETURNVAL=0 REPOFILE=/dev/null result="" + local repo_pkgs_preremove="oldfoo" + shadow_logger + shadow_pkg_manager + eval "$block" + printf 'RETURNVAL=%s\n' "$RETURNVAL" +} + +run_plain_preremove_block() +{ + local block + block="$(otherpkgs_block '#Now we have parsed the input' 'if [ "$plain_pkgs_preremove" != "" ]; then')" || return 99 + local envlist="" VERBOSE= log_label=otherpkgs RETURNVAL=0 result="" + local sremovecommand=fake_pkg plain_pkgs_preremove="oldfoo" + shadow_logger + shadow_pkg_manager + eval "$block" + printf 'RETURNVAL=%s\n' "$RETURNVAL" +} + +@test "otherpkgs sends the package manager transaction to syslog one line per message" { + run run_upgrade_block hasyum + [ "$status" -eq 0 ] + [ "$(logger_calls)" -eq 3 ] + [ "$(logger_call 1)" = "--> Running transaction check" ] + [ "$(logger_call 2)" = "Installed: foo-1.0" ] + [ "$(logger_call 3)" = "Error: nothing provides bar" ] +} + +@test "the zypper and apt upgrade paths also send one message per output line" { + run run_upgrade_block haszypper + [ "$status" -eq 0 ] + [ "$(logger_calls)" -eq 3 ] + + : >"$LOGGER_LOG" + run run_upgrade_block hasapt + [ "$status" -eq 0 ] + [ "$(logger_calls)" -eq 3 ] +} + +@test "the remove paths also send one message per output line" { + local manager + for manager in hasyum haszypper hasapt; do + : >"$LOGGER_LOG" + run run_repo_preremove_block "$manager" + [ "$status" -eq 0 ] + [ "$(logger_calls)" -eq 3 ] + done + + : >"$LOGGER_LOG" + run run_plain_preremove_block + [ "$status" -eq 0 ] + [ "$(logger_calls)" -eq 3 ] +} diff --git a/xCAT/postscripts/otherpkgs b/xCAT/postscripts/otherpkgs index c89256e86..7e8549357 100755 --- a/xCAT/postscripts/otherpkgs +++ b/xCAT/postscripts/otherpkgs @@ -884,7 +884,7 @@ EOF` if [ $R -ne 0 ]; then RETURNVAL=$R fi - logger -p local4.info -t $log_label "$result" + printf '%s\n' "$result" | logger -p local4.info -t $log_label if [ $VERBOSE ]; then echo "$result" fi @@ -898,7 +898,7 @@ EOF` if [ $R -ne 0 ]; then RETURNVAL=$R fi - logger -p local4.info -t $log_label "$result" + printf '%s\n' "$result" | logger -p local4.info -t $log_label if [ $VERBOSE ]; then echo "$result" fi @@ -912,7 +912,7 @@ EOF` if [ $R -ne 0 ]; then RETURNVAL=$R fi - logger -p local4.info -t $log_label "$result" + printf '%s\n' "$result" | logger -p local4.info -t $log_label if [ $VERBOSE ]; then echo "$result" fi @@ -933,7 +933,7 @@ EOF` if [ $R -ne 0 ]; then RETURNVAL=$R fi - logger -p local4.info -t $log_label "$result" + printf '%s\n' "$result" | logger -p local4.info -t $log_label if [ $VERBOSE ]; then echo "$result" fi @@ -946,7 +946,7 @@ EOF` if [ $R -ne 0 ]; then RETURNVAL=$R fi - logger -p local4.info -t $log_label "$result" + printf '%s\n' "$result" | logger -p local4.info -t $log_label if [ $VERBOSE ]; then echo "$result" fi @@ -960,7 +960,7 @@ EOF` if [ $R -ne 0 ]; then RETURNVAL=$R fi - logger -p local4.info -t $log_label "$result" + printf '%s\n' "$result" | logger -p local4.info -t $log_label if [ $VERBOSE ]; then echo "$result" fi @@ -976,7 +976,7 @@ EOF` if [ $R -ne 0 ]; then RETURNVAL=$R fi - logger -p local4.info -t $log_label "$result" + printf '%s\n' "$result" | logger -p local4.info -t $log_label if [ $VERBOSE ]; then echo "$result" fi