🐚

シェルスクリプトのロギングに便利、標準エラー出力に任意の情報を自動追加

2024/05/22に公開

シェルスクリプト製の簡易アプリをコンテナで動作させる場合は JSON Lines のような凝った形式の実装が難しいので、単純に標準出力を info レベル、標準エラー出力を error レベルと扱い、error レベルを Slack 通知しています。
これでエラー発生には気づけるので問題ないのですが、1点だけちょっとした不便がありました。

その不便とは、コマンドがエラー終了した場合にそのコマンドが出力する内容だけで十分な情報が得られればいいのですが、コマンドによっては追加情報がないとよく分からないことがあります。
そこで今回は標準エラー出力だけに任意の追加情報を付与する方法を紹介します。

前提

本記事は bash のシェルスクリプトを前提としていて、プロセス置換を利用しています。
処理内容を理解するにはプロセス置換の知識が必要ですが、コピペでそのまま利用するだけなら深い知識は必要ありません。

具体的な問題

例えば複数のディレクトリをたどって順次 git pull -q を実行する以下のコードを考えます。

ls | while read f; do
  (
    cd $f
    git pull -q
  )
done

この処理はリポジトリ状態によって以下のようなエラーが出ますが、この内容だけ Slack 通知されてもどのリポジトリで問題が発生したか分かりません。

fatal: Not possible to fast-forward, aborting.

すぐに思い付く方法は二つあります

  1. git pull -q の前に echo $f を実行しておく
  2. 直前のコマンドの終了ステータスを $? で都度調べてエラーなら追加情報を標準エラー出力に出力する

前者は echo $f の実行結果が info ログとしては記録されますが、Slack に通知される error ログには含まれないので不便ですし、エラーが起きてもいないのに info ログをたくさん生成したくないこともあります。
後者はエラーの発生源が1コマンドだけならいいのですが、沢山のコマンドを実行している場合は都度終了ステータスを確認してエラーハンドリングするのは正直面倒です。
(※一部の処理でエラーが起きても処理を継続したいので set -e は利用していない状況とします)

そこで本記事は以下のようなロギングの実現をゴールとします。つまり特別に意識しなくてもコマンドにエラーが発生したら標準エラー出力に追加情報を付与してくれます。

[repo3] fatal: Not possible to fast-forward, aborting.

方法

まずは実現するサンプルコード全体を示します。

(
    # 標準エラー出力を保持しておく
    exec {stderr}>&2

    # 標準エラー出力に任意の文字列を付与して標準エラー出力に流す関数
    function stderr_logging() {
        header=
        if [ "$1" != "" ]; then
            header="[$1] "
        fi
        while read f; do
            echo "${header}${f}" >&$stderr
        done
    }

    # 擬似的なメイン処理
    echo -e "repo1\nrepo2\nrepo3\nrepo4" | while read f; do
        # 標準エラー出力を stderr_logging にリダイレクトする、これで出力時に $f の値が先頭に出力される
        exec 2> >(stderr_logging $f)

        # repo3 を擬似的にエラーとして扱う
        if [ "$f" = "repo3" ]; then
            # python で 標準エラー出力へ擬似的なエラーを出力 ※本来は任意コマンドでエラーが発生した場合の想定
            python3 -c 'import sys; print("fatal: Not possible to fast-forward, aborting.", file=sys.stderr)'
        else
            echo "Success"
        fi

        # 標準エラー出力を元に戻す
        exec 2>&${stderr}
    done
) > /dev/null

実行結果

[repo3] fatal: Not possible to fast-forward, aborting.

解説

(
    ...
) > /dev/null

標準エラー出力(= error レベルのログ)だけを表示する状況を再現するために、全体をサブシェルで実行して標準出力(= info レベルのログ)を > /dev/null で捨てています。

# 標準エラー出力を保持しておく
exec {stderr}>&2

標準エラー出力を都度上書きするため、exec {stderr}>&2 で標準エラー出力を $stderr にコピーしておきます。
exec 10>&2 のように固定のファイルディスクリプタ(この場合は 10)にコピーすることもできますが、exec {stderr}>&2 とすることで、空いているファイルディスクリプタを自動的に割り当てて $stderr 変数にファイルディスクリプタの数値を保存してくれます。

# 標準エラー出力に任意の文字列を付与して標準エラー出力に流す関数
function stderr_logging() {
    header=
    if [ "$1" != "" ]; then
        header="[$1] "
    fi
    while read f; do
        echo "${header}${f}" >&$stderr
    done
}

function stderr_logging() は引数に渡された文字列を [any_text] message... という形式で付与して $stderr に保持しておいた元々の標準エラー出力に流します。

ここからが擬似的なメイン処理です。

$ echo -e "repo1\nrepo2\nrepo3\nrepo4"
repo1
repo2
repo3
repo4

echo で複数行の文字列を返して、次のように while$f に1行ごとに値を入れながらループします。

echo -e "repo1\nrepo2\nrepo3\nrepo4" | while read f; do
    ...
done

ここからがループ内の処理です。

# 標準エラー出力を stderr_logging にリダイレクトする、これで出力時に $f の値が先頭に出力される
exec 2> >(stderr_logging $f)

exec 2> >(stderr_logging $f) で標準エラー出力(2)をプロセス置換で stderr_logging $f に接続しています。
これ以降、標準エラー出力は stderr_logging $f に送られます。

# repo3 を擬似的にエラーとして扱う
if [ "$f" = "repo3" ]; then
    # python で 標準エラー出力へ擬似的なエラーを出力 ※本来は任意コマンドでエラーが発生した場合の想定
    python3 -c 'import sys; print("fatal: Not possible to fast-forward, aborting.", file=sys.stderr)'
else
    echo "Success"
fi

次は擬似的にエラーを発生させます。

ここでは仮に repo3 だった場合だけエラーとしますが、実際のエラーではなく python3 コマンドで標準エラー出力に fatal: Not possible to fast-forward, aborting. と書き込むことで代替しています。
repo3 に対して git pull -q を実行するとエラーが発生したと思ってください。

# 標準エラー出力を元に戻す
exec 2>&${stderr}

最後に stderr_logging $f へ繋いでいた標準エラー出力を元の ${stderr} につなぎ直すと出力は元に戻ります。
ここでは標準エラー出力を元に戻すために exec 2>&${stderr} を利用していますが、その代わりにループ内をサブシェルで実行しても問題ありません。

# 擬似的なメイン処理
echo -e "repo1\nrepo2\nrepo3\nrepo4" | while read f; do
    (
        # 標準エラー出力を stderr_logging にリダイレクトする、これで出力時に $f の値が先頭に出力される
        exec 2> >(stderr_logging $f)
    
        # repo3 を擬似的にエラーとして扱う
        if [ "$f" = "repo3" ]; then
            # python で 標準エラー出力へ擬似的なエラーを出力 ※本来は任意コマンドでエラーが発生した場合の想定
            python3 -c 'import sys; print("fatal: Not possible to fast-forward, aborting.", file=sys.stderr)'
        else
            echo "Success"
        fi
    )
done

このように while ループ内の処理を ( ... ) で囲むと、サブシェル終了のタイミングで exec 2> >(stderr_logging $f) の効果が切れて元の状態に戻ります。

まとめ

プロセス置換についてさらに詳しく知りたい場合は以前執筆した、bashのプロセス置換で遊んでみよう! という記事を是非ご覧ください。
ファイルディスクリプタについて知識を深めたい場合はこの問題を解けたらスゴい!?シェルスクリプトとファイルディスクリプタの話もオススメです。

Discussion