armbian-oleg: logging: new logfile format; SHOW_LOG=yes default; introduce DEBUG=yes

- default `SHOW_LOG=yes` if user on terminal
- shortcut: `DEBUG=yes` defaults both `SHOW_LOG=yes` & `SHOW_DEBUG=yes`
- much simpler logging format for log file
- skip all display_alert()'s more verbose than DEBUG from logfile
  - set `DEBUG=yes` to log everything again
- skip Markdown assets from being included in ANSI log
- use of `ccze`
- introduce internal var for controlling COMMAND-level log
- remove unused `run_on_sdcard()` that somehow was left there
- drop `export_html_logs()` and `EXPORT_HTML_LOG` -- are no more
This commit is contained in:
Ricardo Pardini 2023-01-12 19:00:06 +01:00
parent 7493ce1b09
commit d24f363187
No known key found for this signature in database
GPG Key ID: 3D38CA12A66C5D02
5 changed files with 71 additions and 119 deletions

View File

@ -6,9 +6,10 @@ function display_alert() {
return 0
fi
local message="${1}" level="${3}" # params
local level_indicator="" inline_logs_color="" extra="" ci_log="" # this log
local skip_screen=0 # setting to 1 will write to logfile only
declare message="${1}" level="${3}" # params
declare level_indicator="" inline_logs_color="" extra="" ci_log="" # this log
declare -i 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="💥"
@ -43,14 +44,16 @@ function display_alert() {
fi
level_indicator="🧽"
inline_logs_color="\e[1;33m"
skip_logfile=1
;;
debug | deprecation)
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)
@ -59,6 +62,7 @@ function display_alert() {
fi
level_indicator="🦋"
inline_logs_color="\e[1;34m" # blue; 36 would be cyan
skip_logfile=1
;;
command)
@ -75,6 +79,7 @@ function display_alert() {
fi
level_indicator="🐜"
inline_logs_color="${tool_color}" # either gray or normal, a bit subdued.
skip_logfile=1
;;
extensions)
@ -83,6 +88,7 @@ function display_alert() {
fi
level_indicator="🎣" # fishing pole and "hook"
inline_logs_color="\e[0;36m" # a dim cyan
skip_logfile=1
;;
extensionstrace)
@ -91,6 +97,7 @@ function display_alert() {
fi
level_indicator="🐾"
inline_logs_color="\e[0;36m" # a dim cyan
skip_logfile=1
;;
git)
@ -99,6 +106,7 @@ function display_alert() {
fi
level_indicator="🔖"
inline_logs_color="${tool_color}" # either gray or normal, a bit subdued.
skip_logfile=1
;;
ccache)
@ -107,14 +115,17 @@ function display_alert() {
fi
level_indicator="🙈"
inline_logs_color="\e[1;34m" # blue; 36 would be cyan
skip_logfile=1
;;
# @TODO this is dead I think
aggregation)
if [[ "${SHOW_AGGREGATION}" != "yes" ]]; then # aggregation (PACKAGE LISTS), very very verbose
skip_screen=1
fi
level_indicator="📦"
inline_logs_color="\e[0;32m"
skip_logfile=1
;;
*)
@ -129,15 +140,18 @@ function display_alert() {
echo -e "${level}: ${1} [ ${2} ]" | sed 's/\x1b\[[0-9;]*m//g' | systemd-cat --identifier="${ARMBIAN_LOGS_JOURNAL_IDENTIFIER:-armbian}"
fi
# Now, log to file. This will be colorized later by ccze and such, so remove any colors it might already have.
# See also the stuff done in runners.sh for logging exact command lines and runtimes.
# the "echo" runs in a subshell due to the "sed" pipe (! important !), so we store BASHPID (current subshell) outside the scope
# BASHPID is the current subshell; $$ is parent's?; $_ is the current bashopts
local CALLER_PID="${BASHPID}"
# Attention: do not pipe the output before writing to the logfile.
# For example, to remove ansi colors.
# If you do that, "echo" runs in a subshell due to the "sed" pipe (! important !)
# for the future: BASHPID is the current subshell; $$ is parent's?; $_ is the current bashopts
if [[ -f "${CURRENT_LOGFILE}" ]]; then
# ANSI-less version
#echo -e "--> ${level_indicator} $(printf "%4s" "${SECONDS}"): $$ - ${CALLER_PID} - ${BASHPID}: $-: ${level}: ${1} [ ${2} ]" >> "${CURRENT_LOGFILE}" # | sed 's/\x1b\[[0-9;]*m//g'
echo -e "--> ${level_indicator} $(printf "%4s" "${SECONDS}"): $$ - ${CALLER_PID} - ${BASHPID}: $-: ${level}: ${1} [ ${2} ]" >> "${CURRENT_LOGFILE}" # | sed 's/\x1b\[[0-9;]*m//g'
# If not asked to skip, or debugging is enabled, log to file.
if [[ ${skip_logfile} -lt 1 || "${DEBUG}" == "yes" ]]; then
echo -e "--> (${SECONDS}) ${level^^}: ${1} [ ${2} ]" >> "${CURRENT_LOGFILE}" # bash ^^ is "to upper case"
fi
fi
if [[ ${skip_screen} -eq 1 ]]; then
@ -159,12 +173,12 @@ function display_alert() {
bashopts_info="${tool_color}(${normal_color}$-${tool_color})" # $- is the currently active bashopts
fi
[[ -n $2 ]] && extra=" [${inline_logs_color} ${2} ${normal_color}]"
[[ -n ${2} ]] && extra=" [${inline_logs_color} ${2} ${normal_color}]"
echo -e "${normal_color}${left_marker}${padding}${level_indicator}${padding}${normal_color}${right_marker}${timing_info}${pids_info}${bashopts_info} ${normal_color}${message}${extra}${normal_color}" >&2
# Now write to CI, if we're running on it. Remove ANSI escapes which confuse GitHub Actions.
if [[ "${CI}" == "true" ]] && [[ "${ci_log}" != "" ]]; then
echo -e "::${ci_log} ::" "$@" | sed 's/\x1b\[[0-9;]*m//g' >&2
echo -e "::${ci_log} ::" "${1} ${2}" | sed 's/\x1b\[[0-9;]*m//g' >&2
fi
return 0 # make sure to exit with success, always

View File

@ -59,15 +59,14 @@ function export_ansi_logs() {
if [[ -n "$(command -v git)" && -d "${SRC}/.git" ]]; then
display_alert "Gathering git info for logs" "Processing git information, please wait..." "debug"
cat <<- GIT_ANSI_HEADER >> "${target_file}"
----------------------------------------------------------------------------------------------------------------
# Last revision:
$(LC_ALL=C LANG=C git --git-dir="${SRC}/.git" log -1 --color --format=short --decorate)
$(LC_ALL=C LANG=C git --git-dir="${SRC}/.git" log -1 --color --format=short --decorate || true)
----------------------------------------------------------------------------------------------------------------
# Git status:
$(LC_ALL=C LANG=C git -c color.status=always --work-tree="${SRC}" --git-dir="${SRC}/.git" status)
$(LC_ALL=C LANG=C git -c color.status=always --work-tree="${SRC}" --git-dir="${SRC}/.git" status || true)
----------------------------------------------------------------------------------------------------------------
# Git changes:
$(LC_ALL=C LANG=C git --work-tree="${SRC}" --git-dir="${SRC}/.git" diff -u --color)
$(LC_ALL=C LANG=C git --work-tree="${SRC}" --git-dir="${SRC}/.git" diff -u --color || true)
----------------------------------------------------------------------------------------------------------------
GIT_ANSI_HEADER
fi
@ -80,71 +79,14 @@ function export_ansi_logs() {
for logfile_full in "${logfiles_array[@]}"; do
local logfile_base="$(basename "${logfile_full}")"
cat <<- ANSI_ONE_LOGFILE_NO_CCZE >> "${target_file}"
------------------------------------------------------------------------------------------------------------
# skip if logfile_base ends in ".md"; those are handled in the markdown version of logs
[[ "${logfile_base}" =~ \.md$ ]] && continue
cat <<- ANSI_ONE_LOGFILE >> "${target_file}"
## ${logfile_base}
$(cat "${logfile_full}")
------------------------------------------------------------------------------------------------------------
ANSI_ONE_LOGFILE_NO_CCZE
ANSI_ONE_LOGFILE
done
display_alert "Built ANSI log file" "${target_file}"
}
# Export logs in HTML format. (EXPORT_HTML_LOG=yes) -- very slow.
function export_html_logs() {
display_alert "Preparing HTML log from" "${LOGDIR}" "debug"
cat <<- ANSI_HEADER > "${target_file}"
<html>
<head>
<title>Armbian logs for ${ARMBIAN_BUILD_UUID}</title>
<style>
html, html pre { background-color: black !important; color: white !important; font-family: JetBrains Mono, monospace, cursive !important; }
hr { border: 0; border-bottom: 1px dashed silver; }
</style>
</head>
<body>
<h2>Armbian build at $(LC_ALL=C LANG=C date) on $(hostname || true)</h2>
<h2>${ARMBIAN_ORIGINAL_ARGV[@]@Q}</h2>
<hr/>
$(LC_ALL=C LANG=C git --git-dir="${SRC}/.git" log -1 --color --format=short --decorate | ansi2html --no-wrap --no-header)
<hr/>
$(LC_ALL=C LANG=C git -c color.status=always --work-tree="${SRC}" --git-dir="${SRC}/.git" status | ansi2html --no-wrap --no-header)
<hr/>
$(LC_ALL=C LANG=C git --work-tree="${SRC}" --git-dir="${SRC}/.git" diff -u --color | ansi2html --no-wrap --no-header)
<hr/>
ANSI_HEADER
# Find and sort the files there, store in array one per logfile
declare -a logfiles_array
mapfile -t logfiles_array < <(find "${LOGDIR}" -type f | LC_ALL=C sort -h)
for logfile_full in "${logfiles_array[@]}"; do
local logfile_base="$(basename "${logfile_full}")"
if [[ -f /usr/bin/ccze ]] && [[ -f /usr/bin/ansi2html ]]; then
cat <<- HTML_ONE_LOGFILE_WITH_CCZE >> "${target_file}"
<h3>${logfile_base}</h3>
<div style="padding: 1em">
$(ccze -o nolookups --raw-ansi < "${logfile_full}" | ansi2html --no-wrap --no-header)
</div>
<hr/>
HTML_ONE_LOGFILE_WITH_CCZE
else
cat <<- ANSI_ONE_LOGFILE_NO_CCZE >> "${target_file}"
<h3>${logfile_base}</h3>
<pre>$(cat "${logfile_full}")</pre>
ANSI_ONE_LOGFILE_NO_CCZE
fi
done
cat <<- HTML_FOOTER >> "${target_file}"
</body></html>
HTML_FOOTER
display_alert "Built HTML log file" "${target_file}"
display_alert "ANSI log file built; inspect it by running:" "less -R ${target_file}"
}

View File

@ -1,21 +1,32 @@
#!/usr/bin/env bash
function logging_init() {
# defaults.
# if stdout is a terminal, then default SHOW_LOG to yes
[[ -t 1 ]] && declare -g SHOW_LOG="${SHOW_LOG:-"yes"}"
# if DEBUG=yes (via env only, at this point) is set then default both log & debug to yes
if [[ "${DEBUG}" == "yes" ]]; then
declare -g SHOW_LOG="${SHOW_LOG:-"yes"}"
declare -g SHOW_DEBUG="${SHOW_DEBUG:-"yes"}"
fi
# globals
export padding="" left_marker="[" right_marker="]"
export normal_color="\x1B[0m" gray_color="\e[1;30m" # "bright black", which is grey
declare -i logging_section_counter=0 # -i: integer
export logging_section_counter
export tool_color="${gray_color}" # default to gray... (should be ok on terminals)
if [[ "${CI}" == "true" ]]; then # ... but that is too dark for Github Actions
export tool_color="${normal_color}"
declare -g padding="" left_marker="[" right_marker="]"
declare -g normal_color="\x1B[0m" gray_color="\e[1;30m" # "bright black", which is grey
declare -i logging_section_counter=0 # -i: integer
declare -g logging_section_counter
declare -g tool_color="${gray_color}" # default to gray... (should be ok on terminals)
if [[ "${CI}" == "true" ]]; then # ... but that is too dark for Github Actions
declare -g tool_color="${normal_color}"
declare -g SHOW_LOG="${SHOW_LOG:-"yes"}" # if in CI/GHA, default to showing log
fi
if [[ "${ARMBIAN_RUNNING_IN_CONTAINER}" == "yes" ]]; then # if in container, add a cyan "whale emoji" to the left marker wrapped in dark gray brackets
local container_emoji="🐳" # 🐳 or 🐋
export left_marker="${gray_color}[${container_emoji}|${normal_color}"
declare -g left_marker="${gray_color}[${container_emoji}|${normal_color}"
elif [[ "$(uname -s)" == "Darwin" ]]; then # if on Mac, add a an apple emoji to the left marker wrapped in dark gray brackets
local mac_emoji="🍏" # 🍏 or 🍎
export left_marker="${gray_color}[${mac_emoji}|${normal_color}"
declare -g left_marker="${gray_color}[${mac_emoji}|${normal_color}"
fi
}
@ -32,13 +43,8 @@ function logging_error_show_log() {
local prefix_sed_cmd="s/^/${prefix_sed_contents}/;"
display_alert " 👇👇👇 Showing logfile below 👇👇👇" "${logfile_to_show}" "err"
if [[ -f /usr/bin/ccze ]]; then # use 'ccze' to colorize the log, making errors a lot more obvious.
# shellcheck disable=SC2002 # my cat is great. thank you, shellcheck.
cat "${logfile_to_show}" | grep -v -e "^$" | /usr/bin/ccze -o nolookups -A | sed -e "${prefix_sed_cmd}" 1>&2 # write it to stderr!!
else
# shellcheck disable=SC2002 # my cat is great. thank you, shellcheck.
cat "${logfile_to_show}" | grep -v -e "^$" | sed -e "${prefix_sed_cmd}" 1>&2 # write it to stderr!!
fi
# shellcheck disable=SC2002 # my cat is great. thank you, shellcheck.
cat "${logfile_to_show}" | grep -v -e "^$" | sed -e "${prefix_sed_cmd}" 1>&2 # write it to stderr!!
display_alert " 👆👆👆 Showing logfile above 👆👆👆" "${logfile_to_show}" "err"
else

View File

@ -1,5 +1,8 @@
#!/usr/bin/env bash
# All those runner helper functions have a particular non-quoting style.
# callers might need to force quote with bash's @Q modifier.
# shortcut
function chroot_sdcard_apt_get_install() {
chroot_sdcard_apt_get --no-install-recommends install "$@"
@ -76,12 +79,14 @@ function chroot_sdcard_apt_get() {
# please, please, unify around this function.
function chroot_sdcard() {
TMPDIR="" run_host_command_logged_raw chroot "${SDCARD}" /bin/bash -e -o pipefail -c "$*"
raw_command="$*" raw_extra="chroot_sdcard" TMPDIR="" \
run_host_command_logged_raw chroot "${SDCARD}" /bin/bash -e -o pipefail -c "$*"
}
# please, please, unify around this function.
function chroot_mount() {
TMPDIR="" run_host_command_logged_raw chroot "${MOUNT}" /bin/bash -e -o pipefail -c "$*"
raw_command="$*" raw_extra="chroot_mount" TMPDIR="" \
run_host_command_logged_raw chroot "${MOUNT}" /bin/bash -e -o pipefail -c "$*"
}
# This should be used if you need to capture the stdout produced by the command. It is NOT logged, and NOT run thru bash, and NOT quoted.
@ -104,13 +109,13 @@ function chroot_custom_long_running() {
# fi
# return $_exit_code
TMPDIR="" run_host_command_logged_raw chroot "${target}" /bin/bash -e -o pipefail -c "$*"
raw_command="$*" raw_extra="chroot_custom_long_running" TMPDIR="" run_host_command_logged_raw chroot "${target}" /bin/bash -e -o pipefail -c "$*"
}
function chroot_custom() {
local target=$1
shift
TMPDIR="" run_host_command_logged_raw chroot "${target}" /bin/bash -e -o pipefail -c "$*"
raw_command="$*" raw_extra="chroot_custom" TMPDIR="" run_host_command_logged_raw chroot "${target}" /bin/bash -e -o pipefail -c "$*"
}
# for deb building.
@ -136,7 +141,7 @@ function run_host_command_logged_long_running() {
#return $_exit_code
# Run simple and exit with it's code. Sorry.
run_host_command_logged_raw /bin/bash -e -o pipefail -c "$*"
raw_command="$*" run_host_command_logged_raw /bin/bash -e -o pipefail -c "$*"
}
# For installing packages host-side. Not chroot!
@ -178,7 +183,7 @@ function run_host_x86_binary_logged() {
# run_host_command_logged is the very basic, should be used for everything, but, please use helpers above, this is very low-level.
function run_host_command_logged() {
run_host_command_logged_raw /bin/bash -e -o pipefail -c "$*"
raw_command="$*" run_host_command_logged_raw /bin/bash -e -o pipefail -c "$*"
}
# for interactive, dialog-like host-side invocations. no redirections performed, but same bash usage and expansion, for consistency.
@ -189,7 +194,8 @@ function run_host_command_dialog() {
# do NOT use directly, it does NOT expand the way it should (through bash)
function run_host_command_logged_raw() {
# Log the command to the current logfile, so it has context of what was run.
display_alert "Command debug" "$*" "command" # A special 'command' level.
# The real command might be very long, so, if raw_command is defined, log that instead.
display_alert "${raw_command:-"$*"}" "" "command" # A special 'command' level.
# In this case I wanna KNOW exactly what failed, thus disable errexit, then re-enable immediately after running.
set +e
@ -209,9 +215,6 @@ function run_host_command_logged_raw() {
# Obtain extra info about error, eg, log files produced, extra messages set by caller, etc.
logging_enrich_run_command_error_info
elif [[ -f "${CURRENT_LOGFILE}" ]]; then
echo "-->--> command run successfully after $((SECONDS - seconds_start)) seconds" >> "${CURRENT_LOGFILE}"
fi
logging_clear_run_command_error_info # clear the error info vars, always, otherwise they'll leak into the next invocation.
@ -241,9 +244,7 @@ function logging_enrich_run_command_error_info() {
LOG_ASSET="chroot_error_context__$(basename "${found_file}")" do_with_log_asset cat "${found_file}"
display_alert "File contents for error context" "${found_file}" "err"
# shellcheck disable=SC2002 # cat is not useless, ccze _only_ takes stdin
cat "${found_file}" | ccze -A 1>&2 # to stderr
# @TODO: 3x repeated ccze invocation, lets refactor it later
cat "${found_file}" 1>&2 # to stderr
done
### if_error_detail_message, array: messages to display if the command failed.
@ -251,8 +252,3 @@ function logging_enrich_run_command_error_info() {
display_alert "Error context msg" "${if_error_detail_message}" "err"
fi
}
# @TODO: logging: used by desktop.sh exclusively. let's unify?
run_on_sdcard() {
chroot_sdcard "${@}"
}

View File

@ -55,12 +55,6 @@ function trap_handler_cleanup_logging() {
export_markdown_logs
reset_uid_owner "${target_file}"
if [[ "${EXPORT_HTML_LOG}" == "yes" ]]; then
local target_file="${target_path}/armbian-${ARMBIAN_LOG_CLI_ID}-${ARMBIAN_BUILD_UUID}.html"
export_html_logs
reset_uid_owner "${target_file}"
fi
local target_file="${target_path}/armbian-${ARMBIAN_LOG_CLI_ID}-${ARMBIAN_BUILD_UUID}.ansitxt.log"
export_ansi_logs
reset_uid_owner "${target_file}"