Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 9 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
5 changes: 5 additions & 0 deletions lib/bash/std/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -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.

Expand Down
33 changes: 25 additions & 8 deletions lib/bash/std/lib_std.sh
Original file line number Diff line number Diff line change
Expand Up @@ -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
}

Expand Down Expand Up @@ -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
}

#
Expand Down Expand Up @@ -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
Expand All @@ -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";;
Expand All @@ -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
}

Expand Down Expand Up @@ -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
}

Expand Down
25 changes: 19 additions & 6 deletions lib/bash/std/tests/lib_std.bats
Original file line number Diff line number Diff line change
Expand Up @@ -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"* ]]
Expand All @@ -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" ]]
Expand Down
Loading