From 9d26ee13739b5a7481c4763ea62664caa83e9448 Mon Sep 17 00:00:00 2001 From: Ricardo Pardini Date: Tue, 17 Jan 2023 01:15:28 +0100 Subject: [PATCH] armbian-next: logging: squash nasty leaking file descriptor bug due to "tee" - check and make sure the fd is closed before processing and/or deleting logs. - change from fd 3 to 13, for extra "this is evil". is it? is 13 an evil number? you decide. --- lib/functions/logging/logging.sh | 19 +++++++++++++++++++ lib/functions/logging/section-logging.sh | 9 +++++---- lib/functions/logging/trap-logging.sh | 7 +++++-- 3 files changed, 29 insertions(+), 6 deletions(-) diff --git a/lib/functions/logging/logging.sh b/lib/functions/logging/logging.sh index e05aaef06a..6a4e328d0a 100644 --- a/lib/functions/logging/logging.sh +++ b/lib/functions/logging/logging.sh @@ -100,7 +100,26 @@ function print_current_asset_log_base_file() { echo -n "${ASSET_LOGFILE_BASE}" } +function check_and_close_fd_13() { + if [[ -e /proc/self/fd/13 ]]; then + display_alert "Closing fd 13" "log still open" "cleanup" + exec 13>&- || true # close the file descriptor, lest sed keeps running forever. + display_alert "Waiting for tee to finish" "if it's still running" "cleanup" + wait || true # wait for the tee process to finish + display_alert "Done waiting for tee/fd13" "it's gone" "cleanup" + else + display_alert "fd 13 is not open" "nothing to do" "cleanup" + fi +} + function discard_logs_tmp_dir() { + # if we're in a logging section and logging to file when an error happened, and we're now cleaning up, + # the "tee" process created for fd 13 in do_with_logging() is still running, and holding a reference to the log file, + # which resides precisely in LOGDIR. So we need to kill it. + + # Check if fd 13 is still open; close it and wait for tee to die. + check_and_close_fd_13 + # Do not delete the dir itself, since it might be a tmpfs mount. if [[ "$(uname)" == "Linux" ]]; then rm -rf --one-file-system "${LOGDIR:?}"/* # Note this is protected by :? diff --git a/lib/functions/logging/section-logging.sh b/lib/functions/logging/section-logging.sh index 8e65f3e211..a3af3fe4ae 100644 --- a/lib/functions/logging/section-logging.sh +++ b/lib/functions/logging/section-logging.sh @@ -49,15 +49,16 @@ function do_with_logging() { prefix_sed_contents="$(logging_echo_prefix_for_pv "tool") $(echo -n -e "${tool_color}")" # spaces are significant local prefix_sed_cmd="s/^/${prefix_sed_contents}/;" - # This is sick. Create a 3rd file descriptor sending it to sed. https://unix.stackexchange.com/questions/174849/redirecting-stdout-to-terminal-and-file-without-using-a-pipe + # Create a 13rd file descriptor sending it to sed. https://unix.stackexchange.com/questions/174849/redirecting-stdout-to-terminal-and-file-without-using-a-pipe # Also terrible: don't hold a reference to cwd by changing to SRC always - exec 3> >( + # There's handling of this fd 13 in check_and_close_fd_13() + exec 13> >( cd "${SRC}" || exit 2 # First, log to file, then add prefix via sed for what goes to screen. tee -a "${CURRENT_LOGFILE}" | sed -u -e "${prefix_sed_cmd}" ) - "$@" >&3 - exec 3>&- # close the file descriptor, lest sed keeps running forever. + "$@" >&13 + exec 13>&- # close the file descriptor, lest sed keeps running forever. else # If not showing the log, just send stdout to logfile. stderr will flow to screen. "$@" >> "${CURRENT_LOGFILE}" diff --git a/lib/functions/logging/trap-logging.sh b/lib/functions/logging/trap-logging.sh index 38edea2d45..8c4d7bcf04 100644 --- a/lib/functions/logging/trap-logging.sh +++ b/lib/functions/logging/trap-logging.sh @@ -19,6 +19,9 @@ function trap_handler_cleanup_logging() { local target_path="${DEST}/logs" mkdir_recursive_and_set_uid_owner "${target_path}" # @TODO: this might be full of logs and is slow + # Check if fd 13 is still open; close it and wait for tee to die. This is done again in discard_logs_tmp_dir() + check_and_close_fd_13 + # Before writing new logfile, compress and move existing ones to archive folder. # - Unless running under CI. # - Also not if signalled via SKIP_LOG_ARCHIVE=yes @@ -29,10 +32,10 @@ function trap_handler_cleanup_logging() { for one_old_logfile in "${existing_log_files_array[@]}"; do old_logfile_fn="$(basename "${one_old_logfile}")" if [[ "${old_logfile_fn}" == *${ARMBIAN_BUILD_UUID}* ]]; then - display_alert "Skipping archiving of current logfile" "${old_logfile_fn}" "warn" + display_alert "Skipping archiving of current logfile" "${old_logfile_fn}" "cleanup" continue fi - display_alert "Archiving old logfile" "${old_logfile_fn}" "warn" + display_alert "Archiving old logfile" "${old_logfile_fn}" "cleanup" mkdir_recursive_and_set_uid_owner "${target_archive_path}" # @TODO: slow # Check if we have `zstdmt` at this stage; if not, use standard gzip