ログには最後のエラーメッセージだけが残り、何十ものコマンドのうちどこで問題が起きたか追跡できない。複雑な自動化スクリプトほど、こうした状況に陥りやすい。
この記事では、bashのtrap DEBUGとBASH_COMMAND変数を組み合わせたコマンド実行ログの自動記録設計を解説します。RHEL 9系／Ubuntu 24.04 LTSを想定環境として説明します。
set -xとは異なるアプローチで、スクリプトの動作をタイムスタンプ付きのログとしてファイルに残す実装パターンを紹介します。
この記事のポイント
・trap DEBUGはコマンド実行直前に毎回呼ばれるbashの疑似シグナルである
・BASH_COMMAND変数には「これから実行されるコマンド文字列」が格納される
・タイムスタンプと組み合わせてファイルに書くと長時間バッチの実行追跡に使える
・set -xと違い、ログの書き先・フォーマット・フィルタリングを自由に設計できる
でも安心してください。プロのエンジニアはコマンドを暗記していません。
「現場で使える型」を効率よく使いこなしているだけです。
trap DEBUGとBASH_COMMANDの仕組み
bashにはEXIT・ERR・SIGTERMといったシグナル以外に、DEBUGという疑似シグナルがある。trap 関数名 DEBUGをセットすると、スクリプト内でコマンドが実行される直前に毎回、登録した関数が呼ばれる。このときbashが自動的にセットする組み込み変数
BASH_COMMANDには、「これから実行されるコマンド文字列」がそのまま格納されている。例えば次のシンプルなスクリプトを実行してみる。#!/bin/bash trap 'echo "CMD: $BASH_COMMAND"' DEBUG echo "hello" ls /tmp date
CMD: echo "hello" hello CMD: ls /tmp （/tmpの内容） CMD: date 2026年10月31日 09:00:00 JST
trap DEBUGが呼ばれるタイミングは「コマンド実行直前」であって「実行後」ではない。そのため「コマンドが成功したかどうか」の判定は、trap DEBUG単体ではできない。終了ステータスを取りたい場合はtrap ERRやPIPESTATUSを別途組み合わせる。
基本的な使い方
1. DEBUGトラップを設定する
最小の構成は関数を1つ定義してtrapに登録するだけだ。#!/bin/bash _debug_log() { echo "[DEBUG] $BASH_COMMAND" } trap '_debug_log' DEBUG
trap '...' DEBUGのシングルクォートにより、BASH_COMMANDはコマンド実行のたびに評価される。2. タイムスタンプ付きコマンドログを実装する
実務では実行時刻を付与することで「どの時点でどの処理にいたか」が後から把握できるようになる。#!/bin/bash _debug_log() { printf '%(%Y-%m-%dT%H:%M:%S)T [CMD] %s\n' -1 "$BASH_COMMAND" } trap '_debug_log' DEBUG
printf '%(%Y-%m-%dT%H:%M:%S)T' -1はbash 4.2以降で使えるタイムスタンプ取得の組み込み機能だ。外部コマンドのdateを毎回フォークしないため、$(date +...)より高速で動く。ハンドラ内でdateを呼ぶと「コマンド数の2倍のプロセスフォーク」が発生してスクリプト全体の速度が下がるため、できるかぎりbash組み込みで完結させる。出力例（環境により異なります）
2026-10-31T09:00:01 [CMD] ls /var/log 2026-10-31T09:00:01 [CMD] gzip /var/log/messages.1 2026-10-31T09:00:02 [CMD] find /var/log -mtime +30 -delete
3. ログをファイルに書き出す設計
標準エラーではなく専用のログファイルに書き出すにはリダイレクトを使う。#!/bin/bash LOG_FILE="/var/log/myscript-debug.log" _debug_log() { printf '%(%Y-%m-%dT%H:%M:%S)T [CMD] %s\n' -1 "$BASH_COMMAND" >> "$LOG_FILE" } trap '_debug_log' DEBUG # スクリプト開始時にログを初期化する : > "$LOG_FILE"
: > "$LOG_FILE"は実行のたびにログを空にする書き方だ。古いログが積み重なって肥大化しないよう、スクリプト開始時に必ず初期化する設計を入れておく。本番では日付ローテーションと組み合わせて運用することが多い。set -xとの違いと使い分け
set -xとtrap DEBUGはどちらも「実行されるコマンドを追跡する」機能だが、設計上の特性が大きく異なる。| 比較項目 | set -x | trap DEBUG |
|---|---|---|
| 出力先 | 標準エラー（固定） | 自由（ファイル・変数・フィルタ可） |
| フォーマット | PS4変数で制限あり | 完全に自由（printfで整形可） |
| フィルタリング | 不可（全コマンドが対象） | 可（条件付きで特定区間のみ記録） |
| パフォーマンス影響 | 低い | 中程度（関数呼び出しが発生） |
| 主な用途 | 開発中・対話的なデバッグ確認 | 本番ログ・監査ログ・実行追跡 |
set -xが手軽だ。一方、本番スクリプトの実行を構造化したログファイルに記録しておきたい場合はtrap DEBUGが適している。シェルスクリプトの設計全般を体系的に習得したい方はシェルスクリプト実践講座も参照してほしい。実務での活用パターン
1. 長時間バッチスクリプトの実行追跡
夜間に動くバックアップや集計スクリプトが「想定の2倍かかっている」という状況が起きたとき、どのコマンドに時間がかかったかを特定するのは難しい。trap DEBUGでタイムスタンプ付きのログを残しておけば、後から各コマンドの実行時刻を確認して詰まり箇所を特定できる。#!/bin/bash LOG="/var/log/batch-trace.log" _trace() { printf '%(%Y-%m-%dT%H:%M:%S)T [TRACE] %s\n' -1 "$BASH_COMMAND" >> "$LOG" } trap '_trace' DEBUG : > "$LOG" # 実際の処理 rsync -av /data/source/ /data/backup/ tar -czf /data/backup/snapshot.tar.gz /data/source/ find /data/backup/ -mtime +30 -delete
$LOGに記録される。rsyncに想定外の時間がかかっていれば、ログの時刻差からすぐに特定できる。2. 特定の処理区間だけをトレースする
スクリプト全体をトレースするとログが膨大になる。危険な操作（大量削除・DB更新・権限変更）だけを記録したい場合は、フラグで区間を管理する設計が有効だ。#!/bin/bash LOG="/var/log/sensitive-ops.log" _TRACE_ON=0 _trace() { [[ $_TRACE_ON -eq 1 ]] || return 0 printf '%(%Y-%m-%dT%H:%M:%S)T [SENSITIVE] %s\n' -1 "$BASH_COMMAND" >> "$LOG" } trap '_trace' DEBUG : > "$LOG" echo "前処理（ログ対象外）" some_safe_preparation # ここからトレース開始 _TRACE_ON=1 find /var/www -name "*.tmp" -delete chown -R www-data:www-data /var/www/html # ここでトレース終了 _TRACE_ON=0 echo "後処理（ログ対象外）"
_TRACE_ON=1の区間のコマンドだけがログに記録される。ハンドラ内のreturn 0もDEBUGトラップを呼ぶが、フラグ判定を単純な整数比較にとどめることで余分なネストを防げる。3. サブシェルへのDEBUGトラップ継承設計
bashのtrapはデフォルトではサブシェルに継承されない。( ... )やコマンド置換$( ... )の中ではtrap DEBUGが無効になる。関数内やサブシェルでもトラップを有効にしたい場合はset -T（functrace）と組み合わせる。#!/bin/bash # set -T でERRトラップとDEBUGトラップをサブシェル・関数に継承する set -T LOG="/var/log/full-trace.log" _trace() { printf '%(%Y-%m-%dT%H:%M:%S)T [TRACE] %s\n' -1 "$BASH_COMMAND" >> "$LOG" } trap '_trace' DEBUG : > "$LOG" do_work() { # set -T によりこの関数内でもtrap DEBUGが有効になる cp /src/app.conf /etc/myapp/ chmod 640 /etc/myapp/app.conf } do_work
set -Tを使うと関数・サブシェル・コマンド置換でもDEBUGトラップが有効になる。全コマンドが対象になりログ量が増えるため、継承が本当に必要な場合にのみ有効にすることを推奨する。注意点とトラブルシュート
パフォーマンスへの影響trap DEBUGはコマンドごとにハンドラ関数を呼び出すため、コマンド数が多いループではオーバーヘッドが積み重なる。ハンドラ内では外部コマンドを呼ばず、
printf '%(%Y-%m-%dT%H:%M:%S)T'などのbash組み込みだけで完結させるのが鉄則だ。ハンドラ内の再帰呼び出し問題
_trace関数の中でも再びDEBUGトラップが発火するため、意図せず大量のログが生成されることがある。これを防ぐには、ハンドラで使うコマンドをbash組み込み（printf・local・[[ ]]）だけに絞るのが最も現実的な設計だ。どうしても外部コマンドが必要な場合は、ハンドラ先頭でtrap '' DEBUG（空トラップで一時無効化）してから処理し、末尾で再登録する方法もあるが実装が複雑になる。BASH_COMMANDの内容が期待と異なるケース
for・whileのヘッダー行・条件式[[ ... ]]・算術式(( ... ))は、式全体として1コマンド分のDEBUGトラップを発火させる。ループ本体の各コマンドも個別に記録されるため、ログを解析する際は「ループヘッダー＋本体コマンド」が交互に並ぶことを念頭に置く。パイプライン中のBASH_COMMANDの挙動
cmd1 | cmd2のようなパイプラインでは、cmd1とcmd2がそれぞれ個別にDEBUGトラップを発火させる。パイプライン全体の成否はPIPESTATUSで別途確認する必要がある。本記事のまとめ
| やりたいこと | 実装のポイント |
|---|---|
| コマンド実行を追跡したい | trap '_func' DEBUG + $BASH_COMMAND |
| タイムスタンプ付きでログに残したい | printf '%(%Y-%m-%dT%H:%M:%S)T' -1 でbash組み込み時刻を取得 |
| 特定の処理区間だけを記録したい | フラグ変数でDEBUGハンドラの出力を制御する |
| 関数内でもトラップを有効にしたい | set -T（functrace）をスクリプト先頭に設定する |
| set -xと使い分けたい | 開発中はset -x、本番ログ記録はtrap DEBUGが適切 |
| パフォーマンスを下げたくない | ハンドラをbash組み込みコマンドのみで実装する |
3,100名以上が実践した「型」を無料で公開中
プロのエンジニアはコマンドを暗記していません。
「現場で使える型」を効率よく使いこなしているだけです。
その「型」を図解60Pにまとめた入門マニュアルを、完全無料でプレゼントしています。
姓・名・メールの3つだけ／30秒／解除は3秒 ／ 詳細はこちら
- 前のページへ：シェルスクリプト実行権限を安全に管理する｜setuidを使わない配布設計
- この記事の属するカテゴリ：シェルスクリプトへ戻る
無料メルマガで学習を続ける
Linuxの実践スキルをメールで毎週お届け。
登録は30秒、解除もいつでも可。
登録無料・いつでも解除できます