diff --git a/CHANGELOG.md b/CHANGELOG.md index a7cd479..37a0f9d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,15 @@ and versions are tracked in the repo-root `VERSION` file. ## [Unreleased] +### Changed + +- Added an optional `BASE_CLI_PRIMARY_LOG` diagnostic sink. Bash logging keeps + terminal verbosity unchanged while persisting the DEBUG-level stream to the + shared run primary log. +- Include the local numeric timezone offset in default structured log + timestamps and an explicit `UTC` marker when `LOG_UTC=1`, keeping Bash log + formatting aligned with Base's Python CLI logs. + ## [1.3.0] - 2026-07-16 ### Fixed diff --git a/lib/bash/std/README.md b/lib/bash/std/README.md index 54f90bc..7bfd77e 100644 --- a/lib/bash/std/README.md +++ b/lib/bash/std/README.md @@ -38,6 +38,11 @@ The library improves Bash-based scripting in a few practical ways: - **Base wrapper integration**: wrapper flags are recognized once and removed before command-specific argument parsing begins. +Log timestamps use the host's local timezone and include its numeric offset by +default, for example `2026-07-18 13:14:32 -0700`. Setting `LOG_UTC=1` switches +the timestamp to the explicit `UTC` form. Base's `--utc-wrapper` option sets +this variable for the complete Bash/Python runtime chain. + The goal is not to hide Bash. The goal is to make scripts fail in ways a user or developer can understand. diff --git a/lib/bash/std/lib_std.sh b/lib/bash/std/lib_std.sh index 39049d5..ef498d3 100644 --- a/lib/bash/std/lib_std.sh +++ b/lib/bash/std/lib_std.sh @@ -476,9 +476,9 @@ __log_timestamp__() { local result_name="$1" if [[ "${LOG_UTC:-}" == 1 ]]; then - TZ=UTC0 printf -v "$result_name" '%(%Y-%m-%d %H:%M:%S)T' -1 + TZ=UTC0 printf -v "$result_name" '%(%Y-%m-%d %H:%M:%S)T UTC' -1 else - printf -v "$result_name" '%(%Y-%m-%d %H:%M:%S)T' -1 + printf -v "$result_name" '%(%Y-%m-%d %H:%M:%S %z)T' -1 fi } @@ -516,13 +516,24 @@ __log_source_location__() { # __print_log_record__() { local color="$1" in_level="$2" source_location="$3" - shift 3 - local message timestamp log_line + local terminal_enabled="${4:-1}" persist_enabled="${5:-0}" + shift 5 + local message timestamp log_line primary_log message="$(__join_message__ "$@")" __log_timestamp__ timestamp printf -v log_line '%s %-7s %s %s' "$timestamp" "$in_level" "$source_location" "$message" - printf '%b%s%b\n' "$color" "$log_line" "$COLOR_OFF" >&2 + if ((terminal_enabled)); then + printf '%b%s%b\n' "$color" "$log_line" "$COLOR_OFF" >&2 + fi + if ((persist_enabled)); then + primary_log="${BASE_CLI_PRIMARY_LOG:-}" + if [[ -n "$primary_log" ]]; then + # The launcher creates the primary log with mode 0600. Direct + # library users may not, so keep the same private default here. + (umask 077; printf '%s\n' "$log_line" >>"$primary_log") || : + fi + fi } # @@ -603,6 +614,7 @@ __print_log__() { [[ -n "$in_level" ]] || return 1 shift local logger=default log_level_set log_level color source_location + local terminal_enabled persist_enabled if [[ "${1-}" == "-l" ]]; then if [[ -z "${2-}" ]]; then printf '%(%Y-%m-%d %H:%M:%S)T %s\n' -1 "WARN ${BASH_SOURCE[1]}:${BASH_LINENO[0]} Option '-l' needs an argument" >&2 @@ -614,7 +626,12 @@ __print_log__() { log_level="${_log_levels[$in_level]}" log_level_set="${_loggers_level_map[$logger]:-3}" - if ((log_level_set >= log_level)); then + terminal_enabled=0 + ((log_level_set >= log_level)) && terminal_enabled=1 + persist_enabled=0 + [[ -n "${BASE_CLI_PRIMARY_LOG:-}" ]] && ((log_level <= _log_levels[DEBUG])) && persist_enabled=1 + + if ((terminal_enabled || persist_enabled)); then # Select color based on log level case "$in_level" in FATAL|ERROR) color="$COLOR_RED";; @@ -625,7 +642,7 @@ __print_log__() { esac __log_source_location__ source_location "${BASH_SOURCE[2]:-}" "${BASH_LINENO[1]:-0}" - __print_log_record__ "$color" "$in_level" "$source_location" "$@" + __print_log_record__ "$color" "$in_level" "$source_location" "$terminal_enabled" "$persist_enabled" "$@" fi } @@ -658,7 +675,7 @@ __print_log_file__() { else local source_location __log_source_location__ source_location "${BASH_SOURCE[2]:-}" "${BASH_LINENO[1]:-0}" - __print_log_record__ "$COLOR_YELLOW" WARN "$source_location" "Unknown logger '$logger'" + __print_log_record__ "$COLOR_YELLOW" WARN "$source_location" 1 1 "Unknown logger '$logger'" fi } diff --git a/lib/bash/std/tests/lib_std.bats b/lib/bash/std/tests/lib_std.bats index 4c786e0..6d29694 100644 --- a/lib/bash/std/tests/lib_std.bats +++ b/lib/bash/std/tests/lib_std.bats @@ -629,13 +629,26 @@ EOF [[ "$(cat "$stderr_file")" == *"VERBOSE"* ]] } +@test "log wrappers persist the DEBUG diagnostic stream without changing terminal verbosity" { + local stderr_file="$TEST_TMPDIR/log-primary.err" + local primary_log="$TEST_TMPDIR/primary.log" + + BASE_CLI_PRIMARY_LOG="$primary_log" log_debug "persisted debug" 2>"$stderr_file" + [ ! -s "$stderr_file" ] + [[ "$(cat "$primary_log")" == *"DEBUG"*"persisted debug"* ]] + + BASE_CLI_PRIMARY_LOG="$primary_log" log_info "terminal info" 2>>"$stderr_file" + [[ "$(cat "$stderr_file")" == *"INFO"*"terminal info"* ]] + [[ "$(cat "$primary_log")" == *"INFO"*"terminal info"* ]] +} + @test "__print_log__ uses local timestamps by default" { local stderr_file="$TEST_TMPDIR/log-local-time.err" local expected_before expected_after output - expected_before="$(TZ=Pacific/Honolulu printf '%(%Y-%m-%d %H)T' -1)" + expected_before="$(TZ=Pacific/Honolulu printf '%(%Y-%m-%d %H:%M:%S %z)T' -1)" TZ=Pacific/Honolulu log_info "local timestamp" 2>"$stderr_file" - expected_after="$(TZ=Pacific/Honolulu printf '%(%Y-%m-%d %H)T' -1)" + expected_after="$(TZ=Pacific/Honolulu printf '%(%Y-%m-%d %H:%M:%S %z)T' -1)" output="$(cat "$stderr_file")" [[ "$output" == "$expected_before"* || "$output" == "$expected_after"* ]] @@ -646,11 +659,11 @@ EOF local stderr_file="$TEST_TMPDIR/log-utc-time.err" local expected_before expected_after output local_before local_after - expected_before="$(TZ=UTC printf '%(%Y-%m-%d %H)T' -1)" - local_before="$(TZ=Pacific/Honolulu printf '%(%Y-%m-%d %H)T' -1)" + expected_before="$(TZ=UTC printf '%(%Y-%m-%d %H:%M:%S)T UTC' -1)" + local_before="$(TZ=Pacific/Honolulu printf '%(%Y-%m-%d %H:%M:%S %z)T' -1)" TZ=Pacific/Honolulu LOG_UTC=1 log_info "utc timestamp" 2>"$stderr_file" - expected_after="$(TZ=UTC printf '%(%Y-%m-%d %H)T' -1)" - local_after="$(TZ=Pacific/Honolulu printf '%(%Y-%m-%d %H)T' -1)" + expected_after="$(TZ=UTC printf '%(%Y-%m-%d %H:%M:%S)T UTC' -1)" + local_after="$(TZ=Pacific/Honolulu printf '%(%Y-%m-%d %H:%M:%S %z)T' -1)" output="$(cat "$stderr_file")" [[ "$expected_before" != "$local_before" || "$expected_after" != "$local_after" ]]