この記事の狙い
Bash スクリプトの観測可能性を高めるために、ログ(stderr・syslog)とトレース(set -x)を安全・低摩擦で運用する流儀を示します。PS4 でのトレース行フォーマット、BASH_XTRACEFD による出力分離、logger による syslog 連携、秘密情報のマスキングをコピペ可の形でまとめます。
前提と対象
- Bash 4+(
BASH_XTRACEFDは 4.1+) set -Eeuo pipefail前提- Linux(
logger経由で syslog/journald に出す前提)
TL;DR(最小実装・コピペ可)
#!/usr/bin/env bash
set -Eeuo pipefail
# ==== ログ(stderr) + syslog 併用 ====
: "${APP_NAME:=myapp}"
log(){ printf '%s %s\n' "$(date +'%Y-%m-%dT%H:%M:%S%z')" "$*" >&2; }
log_sys(){ command -v logger >/dev/null && logger -t "$APP_NAME[$$]" -p user.info -- "$*"; }
log_info(){ log "INFO $*"; log_sys "INFO $*"; }
log_warn(){ log "WARN $*"; log_sys "WARN $*"; }
log_err(){ log "ERROR $*"; log_sys "ERROR $*"; }
# ==== トレース(-x)を専用ファイルへ、PS4 で整形 ====
enable_trace(){
local file="${1:-/tmp/${APP_NAME}.trace}"
exec {__xfd}>"$file"
export BASH_XTRACEFD=$__xfd
# 軽量版(遅延少):ファイル名:行:関数名 を付与
export PS4='+ [$$] [${BASH_SOURCE##*/}:${LINENO}:${FUNCNAME[0]}] '
set -x
}
disable_trace(){
set +x
[[ -n ${BASH_XTRACEFD-} ]] && eval "exec ${BASH_XTRACEFD}>&-"
unset BASH_XTRACEFD
}
# ==== 使い方 ====
log_info "start"
# 秘密の直前は必ずトレースOFFに
enable_trace "/tmp/${APP_NAME}.trace"
# ... 重めの処理 ...
disable_trace
log_info "done"
設計の要点(原則)
- stdout=結果、stderr=ログを徹底(パイプ下流を汚さない)
- ログ出力は 1 箇所に集約(関数
log_*を経由) set -xは常用しない。必要な範囲でオン/オフし、専用 FD に分離(BASH_XTRACEFD)PS4で PID / 位置情報(ファイル:行:関数) を付け、後解析を容易に- 秘密値はトレース禁止区間を設けて回避(
set +x)し、ログ側ではマスクする
ログ設計(stderr と syslog)
最小ログ API(stderr 基本・syslog 併用)
: "${APP_NAME:=myapp}" : "${APP_LOG_LEVEL:=info}" # env で制御
__should(){ # info|warn|error
local lvl="$1" want="$APP_LOG_LEVEL"
[[ "$want" == error && "$lvl" != error ]] && return 1
[[ "$want" == warn && "$lvl" == info ]] && return 1
return 0
}
_log_emit(){ # level msg...
__should "$1" || return 0
local ts; ts="$(date +'%Y-%m-%dT%H:%M:%S%z')"
printf '%s %-5s %s\n' "$ts" "$1" "${*:2}" >&2
command -v logger >/dev/null && logger -t "$APP_NAME[$$]" -p "user.$1" -- "${*:2}" || :
}
log_info(){ _log_emit info "$@"; }
log_warn(){ _log_emit warn "$@"; }
log_err(){ _log_emit err "$@"; }
- レベル制御は環境変数で。CI/本番で切替しやすい
logger -t TAG -p FACILITY.LEVEL -- "message"で syslog へ(journald 環境でもjournalctl -t TAGで追える)
機密値のマスク
mask_secret(){ sed -E 's/(token|password)=\S+/\1=****/g'; }
log_info "$(printf 'calling API token=%s' "$API_TOKEN" | mask_secret)"
トレース設計(set -x / PS4)
BASH_XTRACEFD による出力分離
set -x の既定出力は stderr。アプリのログと混ざると可読性が落ちます。BASH_XTRACEFD にファイル記述子を指定すると、トレースだけ別ファイルに出せます。
exec {XFD}>"/tmp/my.trace"
export BASH_XTRACEFD=$XFD
set -x
# ... トレースしたい区間 ...
set +x
exec {XFD}>&-
PS4 で位置情報を付ける
export PS4='+ [$$] [${BASH_SOURCE##*/}:${LINENO}:${FUNCNAME[0]}] '
$$(PID)、${BASH_SOURCE##*/}(ファイル名)、${LINENO}、${FUNCNAME[0]}- 日時も付けたい場合は次(ただし遅くなる。大量トレースには不向き)
export PS4='+ [$(date +%H:%M:%S)] [$$] [${BASH_SOURCE##*/}:${LINENO}:${FUNCNAME[0]}] '
部分的にオン/オフ(秘密の前後で切替)
set +x # ここから秘密処理は追跡しない
# use $API_TOKEN ...
set -x
パイプラインのトレース
set -o pipefail と併用し、失敗点をトレースで迅速特定。
set -o pipefail
set -x
grep -E '^[0-9]+$' file | awk '{s+=$1} END{print s}'
set +x
運用レシピ
1) すべての標準出力をログとファイルに二重化
exec {LOGFD}> >(tee -a "/var/log/${APP_NAME}.log" >&2)
log(){ printf '%s %s\n' "$(date +'%F %T')" "$*" >&$LOGFD; }
2) 関数単位でトレース
trace_fn(){ set -x; "$@"; local st=$?; set +x; return "$st"; }
trace_fn deploy_to prod
3) エラー時だけトレースダンプ
trap 'st=$?; set +x; [[ -f $TRACE ]] && log_err "see $TRACE"; exit "$st"' EXIT
TRACE="/tmp/${APP_NAME}.trace"
enable_trace "$TRACE" # 成功なら最後に消す運用でも可
失敗しやすい点(アンチパターン)
set -xを常時ON:大量出力で機密漏洩・性能劣化
→ 区間限定、BASH_XTRACEFDで分離- トレースを stderr に流す:アプリの stderr ログと混線
→BASH_XTRACEFDを使う - ログを stdout に出す:下流のデータ処理が壊れる
→ ログは stderr、結果は stdout - 秘密値をそのままログ/トレース
→ 秘密の直前でset +x、ログはマスキング
“コピペ可”テストブロック(最小)
#!/usr/bin/env bash
set -Eeuo pipefail
TMP="$(mktemp -d)"; trap 'rm -rf "$TMP"' EXIT
APP_NAME=testapp
# 1) stderr にレベル付きで出るか
out="$("$BASH" -lc '
set -Eeuo pipefail
APP_NAME=testapp
log(){ printf "%s %-5s %s\n" "2025-01-01T00:00:00+0000" "$1" "$2" >&2; }
log info "hello"
' 2>&1 >/dev/null)"
grep -q 'INFO hello' <<<"$out" || { echo "log-stderr NG"; exit 1; }
# 2) set -x を別ファイルへ分離できるか
trace="$TMP/x.trace"
"$BASH" -lc "
exec {XFD}>\"$trace\"; export BASH_XTRACEFD=\$XFD
export PS4='+ [\$\$] [\${BASH_SOURCE##*/}:\${LINENO}:\${FUNCNAME[0]}] '
set -x; echo ok >/dev/null; set +x; exec {XFD}>&-
"
grep -q '\[.*\] \[.*sh:' "$trace" || { echo "xtrace NG"; exit 1; }
echo "PASS"
セキュリティと安全設計
- 秘密(トークン・パスワード・クッキー)はトレース禁止区間を徹底し、ログではマスク
- syslog 送信に失敗しても本処理を止めない(
logger || :) - ログファイルには適切な権限(例:
umask 077、ローテーション設定)
パフォーマンスの勘所(短く)
set -xは1 行ごとに I/Oが発生。広範囲 ON は避けるPS4に$(date ...)を入れると毎行サブプロセスで重い。PID/位置情報だけの軽量版を常用- syslog 送信を大量に行う場合はバッチ化またはレベル制御で間引く
