背景

cronに仕込んだバッチは、echo文でログ・・・　よくある話です。
ちょっとした関数を用意しておけばログは楽に取れるので、私の手法を記録しておきます。
使っている変数のせいで、bash限定。

log関数をつくる

コード

たった5行のコード。
使う前に どこかでLOGFILE変数を設定する必要がある。
ログレベルみたいな便利なシロモノはない。

#!/bin/bash -
# You must set 'LOGFILE'
readonly PROCNAME=${0##*/}
function log() {
  local fname=${BASH_SOURCE[1]##*/}
  echo -e "$(date '+%Y-%m-%dT%H:%M:%S') ${PROCNAME} (${fname}:${BASH_LINENO[0]}:${FUNCNAME[1]}) $@" | tee -a ${LOGFILE}
}

出力フォーマットはただのecho文なので好きに直してください。-eオプションも不要かな・・・
PROCNAME変数は重複する可能性があるので、必要に応じて変えてください。

ログのフォーマット

上記実装だとこのように出力される。

2015-08-27T18:58:14 libtest.sh (libtest.sh:5:main) message

途中の()の中身は、コロン区切りでこんな感じ。

log関数を呼び出した スクリプト名
log関数を呼び出したスクリプトの 行番号
log関数を呼び出した 関数名

ホスト名は付けていないので、必要なら${HOSTNAME}とかを入れると良いんじゃないかと。
大元のプロセス名部分は不要だというなら、${PROCNAME}を削ってください。

使い方

echoと一緒。

log "message"

単一スクリプトでの実装例

先ほどのlog関数を実装したスクリプトを書いてみる。

実装

LOGFILE変数は最初に宣言している。
mainの途中に関数実装が挟まる素敵な例。

bash_log.sh

#!/bin/bash -
readonly LOGFILE="/tmp/${0##*/}.log"

readonly PROCNAME=${0##*/}
function log() {
  local fname=${BASH_SOURCE[1]##*/}
  echo -e "$(date '+%Y-%m-%dT%H:%M:%S') ${PROCNAME} (${fname}:${BASH_LINENO[0]}:${FUNCNAME[1]}) $@" | tee -a ${LOGFILE}
}


#
# MAIN
#

log "This is test message 1"
log "Test 2"
log "Test 3"

function logtest() {
  log "test from logtest function"
}

logtest

実行

$ cd /tmp
$ ./bash_log.sh
2015-08-27T15:56:23 bash_log.sh (bash_log.sh:13:main) This is test message 1
2015-08-27T15:56:23 bash_log.sh (bash_log.sh:14:main) Test 2
2015-08-27T15:56:23 bash_log.sh (bash_log.sh:15:main) Test 3
2015-08-27T15:56:23 bash_log.sh (bash_log.sh:18:logtest) test from logtest function

$ cat bash_log.sh.log
2015-08-27T15:56:23 bash_log.sh (bash_log.sh:13:main) This is test message 1
2015-08-27T15:56:23 bash_log.sh (bash_log.sh:14:main) Test 2
2015-08-27T15:56:23 bash_log.sh (bash_log.sh:15:main) Test 3
2015-08-27T15:56:23 bash_log.sh (bash_log.sh:18:logtest) test from logtest function

コンソールにも出力し、ログにも記録する。
プロセス名とかスクリプト名が冗長かな・・・

ライブラリ風の実装例

今度はライブラリのように、loglib.shを作成してみる。

実装(ライブラリ)

LOGFILE変数は、スクリプト毎に定義できるようにここでは定義していない。

loglib.sh

#!/bin/bash -
# You must set 'LOGFILE'
readonly PROCNAME=${0##*/}
function log() {
  local fname=${BASH_SOURCE[1]##*/}
  echo -e "$(date '+%Y-%m-%dT%H:%M:%S') ${PROCNAME} (${fname}:${BASH_LINENO[0]}:${FUNCNAME[1]}) $@" | tee -a ${LOGFILE}
}

実装(スクリプト本体)

作ったloglib.shを使うlibtest.shを書く。
LOGFILE変数は、ライブラリを使う 本体スクリプト側で定義する 例としている。

libtest.sh

#!/bin/bash -
LOGFILE="/tmp/test.log"
. /tmp/loglib.sh

log "test message from main"

function logtest() {
  log "test message from func"
}

logtest

. /tmp/libtest_sub.sh
sub_command

最後の2行で呼び出しているlib_test.shおよびsub_commmandの実装はこちら。

libtest_sub.sh

#!/bin/bash -

function sub_command() {
  log "This is sub script"
}

うーん。試験用とはいえ、我ながらとんでもない実装だ。

実行

$ ./libtest.sh
2015-08-27T18:58:14 libtest.sh (libtest.sh:5:main) test message from main
2015-08-27T18:58:14 libtest.sh (libtest.sh:8:logtest) test message from func
2015-08-27T18:58:14 libtest.sh (libtest_sub.sh:4:sub_command) This is sub script

$ cat /tmp/test.log
2015-08-27T18:58:14 libtest.sh (libtest.sh:5:main) test message from main
2015-08-27T18:58:14 libtest.sh (libtest.sh:8:logtest) test message from func
2015-08-27T18:58:14 libtest.sh (libtest_sub.sh:4:sub_command) This is sub script

よしよし。

どのスクリプトファイルのどの位置から呼ばれたかわかるので、複数人でメンテしているようなバッチに向いている出力になったと思う。

シェルスクリプトのロギングを楽にするtips

背景