JDM170/build
1
0
Fork 0
mirror of https://github.com/armbian/build synced 2025-09-24 19:47:06 +07:00
Code Issues Packages Projects Releases Wiki Activity

armbian-next: hopefully improved error logging; avoid logging errors up to 3x; subdued red stacktraces

Browse Source 
- reorg `display_alert()` so more frequent levels are handled first
- improve some ANSI color usage, still a mess
- don't write failed commands stackstrace as warnings to screen -- just to file (yes it's redundant, except if in test)
- more useful / subdued stacktraces, to make actual error more obvious...
This commit is contained in:
Ricardo Pardini
2023-01-18 22:43:25 +01:00
parent da1cf2b475
commit 8cedc82ec2
6 changed files with 74 additions and 58 deletions
Download Patch File Download Diff File Expand all files Collapse all files

76
lib/functions/logging/display-alert.sh
View File

@@ -12,24 +12,24 @@ function display_alert() {
declare message="${1}" level="${3}" # params
declare level_indicator="" inline_logs_color="" extra="" extra_file="" ci_log="" # this log
declare -i skip_screen=0 # setting to 1 will not write to screen
declare -i skip_screen=${display_alert_skip_screen:-0} # setting to 1 will not write to screen
declare -i skip_logfile=0 # setting to 1 will not write to logfile
case "${level}" in
err | error)
level_indicator="💥"
inline_logs_color="\e[1;31m"
ci_log="error"
debug)
if [[ "${SHOW_DEBUG}" != "yes" ]]; then # enable debug for many, many debugging msgs
skip_screen=1
fi
level_indicator="🐛"
inline_logs_color="\e[1;33m"
skip_logfile=1
;;
wrn | warn)
level_indicator="🚸"
inline_logs_color="\e[1;35m"
ci_log="warning"
;;
ext)
level_indicator="✨" # or ✅ ?
inline_logs_color="\e[1;32m"
command)
if [[ "${SHOW_COMMAND}" != "yes" ]]; then # enable to log all calls to external cmds
skip_screen=1
fi
level_indicator="🐸"
inline_logs_color="\e[0;36m" # a dim cyan
;;
info)
@@ -37,11 +37,6 @@ function display_alert() {
inline_logs_color="\e[0;32m"
;;
cachehit)
level_indicator="💖"
inline_logs_color="\e[0;32m"
;;
cleanup | trap)
if [[ "${SHOW_TRAPS}" != "yes" ]]; then # enable debug for many, many debugging msgs
skip_screen=1
@@ -51,15 +46,6 @@ function display_alert() {
skip_logfile=1
;;
debug)
if [[ "${SHOW_DEBUG}" != "yes" ]]; then # enable debug for many, many debugging msgs
skip_screen=1
fi
level_indicator="🐛"
inline_logs_color="\e[1;33m"
skip_logfile=1
;;
group)
if [[ "${SHOW_DEBUG}" != "yes" && "${SHOW_GROUPS}" != "yes" ]]; then # show when debugging, or when specifically requested
skip_screen=1
@@ -69,14 +55,6 @@ function display_alert() {
skip_logfile=1
;;
command)
if [[ "${SHOW_COMMAND}" != "yes" ]]; then # enable to log all calls to external cmds
skip_screen=1
fi
level_indicator="🐸"
inline_logs_color="\e[0;36m" # a dim cyan
;;
timestamp | fasthash)
if [[ "${SHOW_FASTHASH}" != "yes" ]]; then # timestamp-related debugging messages, very very verbose
skip_screen=1
@@ -122,6 +100,11 @@ function display_alert() {
skip_logfile=1
;;
cachehit)
level_indicator="💖"
inline_logs_color="\e[0;32m"
;;
# @TODO this is dead I think
aggregation)
if [[ "${SHOW_AGGREGATION}" != "yes" ]]; then # aggregation (PACKAGE LISTS), very very verbose
@@ -132,6 +115,25 @@ function display_alert() {
skip_logfile=1
;;
err | error | critical)
level="error"
level_indicator="💥"
inline_logs_color="\e[1;31m"
ci_log="error"
;;
wrn | warn | warning)
level="warning"
level_indicator="🚸"
inline_logs_color="\e[1;35m"
ci_log="warning"
;;
ext)
level_indicator="✨" # or ✅ ?
inline_logs_color="\e[1;32m"
;;
*)
level="${level:-info}" # for file logging.
level_indicator="🌿"
@@ -142,7 +144,7 @@ function display_alert() {
if [[ -n ${2} ]]; then
extra=" [${inline_logs_color} ${2} ${normal_color:-}]"
# extra_file=" [${inline_logs_color} ${2} ${normal_color}]" # too much color in logfile
extra_file=" [ ${2} ]"
extra_file=" [ ${inline_logs_color}${2}${normal_color} ]"
fi
# Log to journald, if asked to.

8
lib/functions/logging/export-logs.sh
View File

@@ -52,10 +52,10 @@ function export_ansi_logs() {
dim_line_separator=$(echo -e -n "${gray_color:-}")------------------------------------------------------------------------------------------------------------$(echo -e -n "${normal_color:-}")
cat <<- ANSI_HEADER > "${target_file}"
# Armbian logs for ${ARMBIAN_BUILD_UUID}
# Armbian build at $(LC_ALL=C LANG=C date) on $(hostname || true)
# Armbian ANSI build logs for ${ARMBIAN_BUILD_UUID} - use "less -SR" to view
$(echo -e -n "${bright_blue_color}")# Armbian build at $(LC_ALL=C LANG=C date) on $(hostname || true)
${dim_line_separator}
# ARGs: ${ARMBIAN_ORIGINAL_ARGV[@]@Q}
$(echo -e -n "${bright_blue_color}")# ARGs: ${ARMBIAN_ORIGINAL_ARGV[@]@Q}
${dim_line_separator}
ANSI_HEADER
@@ -95,7 +95,7 @@ function export_ansi_logs() {
logfile_title="$(echo "${logfile_base}" | sed -e 's/^[^.]*\.[^.]*\.//')"
cat <<- ANSI_ONE_LOGFILE >> "${target_file}"
$(echo -e -n "\033[94m")### ${logfile_title} $(echo -e -n "${normal_color}")
$(echo -e -n "${bright_blue_color}")### ${logfile_title} $(echo -e -n "${normal_color}")
$(cat "${logfile_full}" | sed -e "${prefix_sed_cmd}")
${dim_line_separator}
ANSI_ONE_LOGFILE

3
lib/functions/logging/logging.sh
View File

@@ -15,6 +15,9 @@ function logging_init() {
# globals
declare -g padding="" left_marker="[" right_marker="]"
declare -g normal_color="\x1B[0m" gray_color="\e[1;30m" # "bright black", which is grey
declare -g bright_red_color="\e[1;31m" red_color="\e[0;31m"
declare -g bright_blue_color="\e[1;34m" blue_color="\e[0;34m"
declare -g bright_magenta_color="\e[1;35m" magenta_color="\e[0;35m"
declare -g -i logging_section_counter=0 # -i: integer
declare -g tool_color="${gray_color}" # default to gray... (should be ok on terminals, @TODO: I've seen it too dark on a few random screenshots though
if [[ "${CI}" == "true" ]]; then # ... but that is too dark for Github Actions

7
lib/functions/logging/runners.sh
View File

@@ -209,10 +209,11 @@ function run_host_command_logged_raw() {
if [[ ${exit_code} != 0 ]]; then
if [[ -f "${CURRENT_LOGFILE}" ]]; then # echo -e "\033[91mBright Red\033[0m"
echo -e "\033[91m-->--> command failed with error code ${exit_code} after $((SECONDS - seconds_start)) seconds${normal_color:-}" >> "${CURRENT_LOGFILE}"
echo -e "${bright_red_color:-}-->--> command failed with error code ${exit_code} after $((SECONDS - seconds_start)) seconds${normal_color:-}" >> "${CURRENT_LOGFILE}"
fi
display_alert "cmd exited with code ${exit_code}" "$*" "wrn"
display_alert "stacktrace for failed command" "$(show_caller_full)" "wrn"
# @TODO: send these _ONLY_ to logfile. there's enough on screen already...
display_alert_skip_screen=1 display_alert "stacktrace for failed command" "exit code ${exit_code}:$*\n$(stack_color="${magenta_color:-}" show_caller_full)" "wrn"
# Obtain extra info about error, eg, log files produced, extra messages set by caller, etc.
logging_enrich_run_command_error_info

7
lib/functions/logging/stacktraces.sh
View File

@@ -42,8 +42,11 @@ function show_caller_full() {
((i++))
done | while read -r line_no function_name file_name; do
padded_function_name="$(printf "%30s" "$function_name()")"
short_file_name="${file_name/"${SRC}/"/"./"}"
echo -e "$padded_function_name --> $short_file_name:$line_no"
short_file_name="${file_name/"${SRC}/"/""}"
if [[ "${short_file_name}" == *"extension_function_definition.sh" ]]; then
short_file_name="<extension_magic>"
fi
echo -e "${stack_color:-"${red_color}"} $padded_function_name --> $short_file_name:$line_no"
done
} || true # always success
}

27
lib/functions/logging/traps.sh
View File

@@ -5,9 +5,9 @@
# This also implements the custom "cleanup" handlers, which always run at the end of build, or when exiting prematurely for any reason.
function traps_init() {
# shellcheck disable=SC2034 # Array of cleanup handlers.
declare -a trap_manager_cleanup_handlers=()
declare -g -a trap_manager_cleanup_handlers=()
# shellcheck disable=SC2034 # Global to avoid doubly reporting ERR/EXIT pairs.
declare -i trap_manager_error_handled=0
declare -g -i trap_manager_error_handled=0
trap 'main_trap_handler "ERR" "$?"' ERR
trap 'main_trap_handler "EXIT" "$?"' EXIT
trap 'main_trap_handler "INT" "$?"' INT
@@ -49,12 +49,14 @@ function main_trap_handler() {
# BASHPID is the current subshell; $$ is parent shell pid
if [[ "${BASHPID}" == "${$}" ]]; then
# Not in subshell, dump the error, complete with log, and show the stack.
if [[ ! ${trap_manager_error_handled} -gt 0 ]]; then
logging_error_show_log
display_alert "Error occurred in main shell" "code ${trap_exit_code} at ${short_stack}\n${stack_caller}\n" "err"
display_alert "Error ${trap_exit_code} occurred in main shell" "at ${short_stack}\n${stack_caller}\n" "err"
fi
else
# In a subshell. This trap will run again in the parent shell, so just output a message about it;
# When the parent shell trap runs, it will show the stack and log.
display_alert "Error occurred in SUBSHELL" "SUBSHELL: code ${trap_exit_code} at ${short_stack}" "err"
display_alert "Error ${trap_exit_code} occurred in SUBSHELL" "SUBSHELL at ${short_stack}" "err"
fi
trap_manager_error_handled=1
return # Nothing else to do here, let the EXIT trap do the cleanups.
@@ -63,7 +65,7 @@ function main_trap_handler() {
EXIT)
if [[ ${trap_manager_error_handled} -lt 1 ]] && [[ ${trap_exit_code} -gt 0 ]]; then
logging_error_show_log
display_alert "Exit with error detected" "${trap_exit_code} at ${short_stack} -\n${stack_caller}\n" "err"
display_alert "Exiting with error ${trap_exit_code}" "at ${short_stack}\n${stack_caller}\n" "err"
trap_manager_error_handled=1
fi
@@ -75,8 +77,8 @@ function main_trap_handler() {
bash < /dev/tty >&2 || true
fi
# Run the cleanup handlers, always.
run_cleanup_handlers || true
# Run the cleanup handlers, always. pass it the exit code so it keep the red theme of errors in its messages.
cleanup_exit_code="${trap_exit_code}" run_cleanup_handlers || true
# If global_final_exit_code is set, use it as the exit code. (used by docker CLI handler)
if [[ -n "${global_final_exit_code}" ]]; then
@@ -98,7 +100,11 @@ function run_cleanup_handlers() {
if [[ ${#trap_manager_cleanup_handlers[@]} -lt 1 ]]; then
return 0 # No handlers set, just return.
else
display_alert "Cleaning up" "please wait for cleanups to finish" "debug"
if [[ ${cleanup_exit_code:-0} -gt 0 ]]; then
display_alert "Cleaning up" "please wait for cleanups to finish" "error"
else
display_alert "Cleaning up" "please wait for cleanups to finish" "info"
fi
fi
# Loop over the handlers, execute one by one. Ignore errors.
# IMPORTANT: cleanups are added first to the list, so cleanups run in the reverse order they were added.
@@ -162,11 +168,12 @@ function exit_with_error() {
local _function=${FUNCNAME[1]}
local _line="${BASH_LINENO[0]}"
display_alert "error: ${1}" "${2} in ${_function}() at ${_file}:${_line}" "err"
display_alert "error!" "${1} ${2}" "err"
#display_alert "Build terminating..." "please wait for cleanups to finish" "err"
# @TODO: move this into trap handler
# @TODO: integrate both overlayfs and the FD locking with cleanup logic
display_alert "Build terminating... wait for cleanups..." "" "err"
overlayfs_wrapper "cleanup"
## This does not really make sense. wtf?