LoginSignup
4
3

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

More than 1 year has passed since last update.

@EjiriAkira(章 江尻)

log4bash4 ： Bash4のlogger

Last updated at Posted at 2018-03-20

#はじめに
　Bash4のloggerを作りました。名前は「log4bash4」です。
　　※当初は「log4sh」、「log4bash」としていたのですが、既にこの名前は使われていたため、「log4bash4」としました。
　Bash4.2のファンクションで実装しています。
　　※Badh固有の機能を使用しているため、Bash専用のロガーです。
　　※coprocを使用しているので、バージョンが4.0未満のBashでは動きません。

#機能

  • 指定されたメッセージを画面、ログファイルに出力します。
  • ログローテーションの機能はありませんが、ログファイルが所定のサイズを超えたときバックアップする機能はあります。
  • ログレベルはfatal、error、warn、info、debug、traceの６種類です。
API 機能
. log4bash4
または
source log4bash4		 log4bash4読み込み
log4bash_fatal メッセージ．．． 致命的ログ出力
log4bash_error メッセージ．．． エラーログ出力
log4bash_warn メッセージ．．． 警告ログ出力
log4bash_info メッセージ．．． 情報ログ出力
log4bash_debug メッセージ．．． デバッグログ出力
log4bash_trace メッセージ．．． トレースログ出力

#使用方法

　「log4bash4」を適当なディレクトリに配置し、sourceまたは.で読み込めば使えます、PATHを通していない場所に置く場合は、パス名で読み込む必要があります、実行権限の付与は不要です。
　ファイル名を変えても動きます、ファイル名に依存した処理はありません。

呼び出し元のshスクリプト
  1 #!/bin/bash
  2 
  3 . ./log4bash4
  4 
  5  log4bash_fatal "AAA" "aaa"
  6  log4bash_error "BBB" "bbb"
  7  log4bash_warn "CCC"
  8  log4bash_info "DDD"
  9  log4bash_debug "EEE"
 10  log4bash_trace "FFF"
実行結果
[2018/03/20 08:30:23.009684293] fatal [23390:23390:23361] [qwqw.sh(5):main] [LOGID_23390_0] AAA aaa
[2018/03/20 08:30:23.020500067] error [23390:23390:23361] [qwqw.sh(6):main] [LOGID_23390_0] BBB bbb
[2018/03/20 08:30:23.025035304] warn [23390:23390:23361] [qwqw.sh(7):main] [LOGID_23390_0] CCC
[2018/03/20 08:30:23.040970428] info [23390:23390:23361] [qwqw.sh(8):main] [LOGID_23390_0] DDD
[2018/03/20 08:30:23.074428430] debug [23390:23390:23361] [qwqw.sh(9):main] [LOGID_23390_0] EEE
[2018/03/20 08:30:23.103357501] trace [23390:23390:23361] [qwqw.sh(10):main] [LOGID_23390_0] FFF

※info、debug 、trace はデフォルトの設定では出力されません。

#ログ出力形式

　①　　　　　　　　　　　　　　　　　②　　　③　　　　　　　　　　④　　　　　　　　　　⑤　　　　　　　　⑥
[2018/03/20 08:30:23.103357501] trace [23390:23390:23361] [qwqw.sh(10):main] [LOGID_23390_0] FFF
No 項目 説明
① Date Time [yyyy/mm/dd hh:flag_mm:ss.ss]
Dateコマンドの書式の範囲で変更可
② ログレベル fatal、error、warn、info、debug、trace
③ プロセスID $$(PID):BASHPID:PPID
④ ロガー呼び出し元 ファイル名(行番号):関数名
関数の外の場合はmain
⑤ ログID LOGID_$$_${BASH_SUBSHELL}
⑥ メッセージ 利用者指定情報

#カスタマイズ

　環境変数の値を変えることにより、「log4bash4」のいくつかの機能について、振る舞いを変更することができます。
　log4bash4を利用するシェルスプリプトで直接環境変数を設定してもよいですし、
設定ファイル「log4bash.conf」に環境変数を定義し、実行するシェルスクリプトと同じディレクトリに置いてもよいです。
　設定ファイルのパス名を環境変数LOG4BASH_CONFに設定しておけば、そちらを参照します。

|環境変数|デフォルト|説明|
|:--|:--|:--|ふぉ
|__LOG4BASH_DATE_FORMAT|'+[%Y/%m/%d %H:%M:%S.%N]'|dateフォーマット|
|__LOG4BASH_EABLE_DISP|'1'|'1':画面表示有効
'0':画面表示無効|
|__LOG4BASH_DISP_TTY|'/dev/stdout'|画面表示先|
|__LOG4BASH_EABLE_LOG|'1'|'1'|'1':ログ記録有効
'0':ログ記録無効|
|__LOG4BASH_LOGFILE_PATH|'/tmp/log4bash.log'|ログファイル|
|__LOG4BASH_EABLE_LOG_BK|'1'|'1':ログファイルバックアップ有効
'0':ログファイルバックアップ無効|
|__LOG4BASH_LOGFILE_CHANGE_SIZE|'1000000'|ログファイル退避契機サイズ|
|__LOG4BASH_LOGFILE_BK_PATH|'/tmp/log4bash.log.bk'|ログバックアップファイル|
|__LOG4BASH_ENABLE_DYNAMIC_CHANGE_LOGLEVEL|'0'|'1':ログレベル動的変更有効
'0':ログレベル動的変更無効|
|__LOG4BASH_LOGLEVEL_FATAL|'1'|'1':有効
'0':無効|
|__LOG4BASH_LOGLEVEL_ERROR|'1'|'1':有効
'0':無効|
|__LOG4BASH_LOGLEVEL_WARN|'1'|'1':有効
'0':無効|
|__LOG4BASH_LOGLEVEL_INFO|'0'|'1':有効
'0':無効|
|__LOG4BASH_LOGLEVEL_DEBUG|'0'|'1':有効
'0':無効|
|__LOG4BASH_LOGLEVEL_TRACE|'0'|'1':有効
'0':無効|
|__LOG4BASH_STRICT_APPEND|'1'|'1':ファイルアペンド
'0':リダイレクト>>|
|__LOG4BASH_LOGID|"LOGID_$$_${BASH_SUBSHELL}"|ログID
ログを識別するために任意の文字列を指定することができます。|
|LOG4BASH_CONF|`dirname $0`/"log4bash.conf"|設定ファイル
環境変数を定義した設定ファイル|

#【log4bash4のソース】

log4bash4
#!/bin/bash
# log4bash4
# Copyright (c) 2018 EJIRI akira
# This software is released under the MIT License, see LICENSE.txt.
# http://opensource.org/licenses/mit-license.php
#
# pub
#
log4bash_trace(){
    local ret=$?
    __log4bash_log_common "${__LOG4BASH_LOGLEVEL_TRACE}" "trace" "$@"
    return "${ret}"
}
log4bash_debug(){
    local ret=$?
    __log4bash_log_common "${__LOG4BASH_LOGLEVEL_DEBUG}" "debug" "$@"
    return "${ret}"
}
log4bash_info(){
    local ret=$?
    __log4bash_log_common "${__LOG4BASH_LOGLEVEL_INFO}" "info" "$@"
    return "${ret}"
}
log4bash_warn(){
    local ret=$?
    __log4bash_log_common "${__LOG4BASH_LOGLEVEL_WARN}" "warn" "$@"
    return "${ret}"
}
log4bash_error(){
    local ret=$?
    __log4bash_log_common "${__LOG4BASH_LOGLEVEL_ERROR}" "error" "$@"
    return "${ret}"
}
log4bash_fatal(){
    local ret=$?
    __log4bash_log_common "${__LOG4BASH_LOGLEVEL_FATAL}" "fatal" "$@"
    return "${ret}"
}
#
# inner
#
__log4bash_source_user_conf(){
    if [ "${__LOG4BASH_ENABLE_DYNAMIC_CHANGE_LOGLEVEL}" = "1" ]
    then
        __log4bash_source_user_conf_impl
    fi
}
__log4bash_source_user_conf_impl(){
    local conf
    if [ "${LOG4BASH_CONF}" = "" ]
    then
        conf=`dirname $0`/"${__LOG4BASH_CONF}"
    else
        conf="${LOG4BASH_CONF}"
    fi
    if [ -f "${conf}" ] && [ -r "${conf}" ]
    then
        . "${conf}"
    fi
}
__log4bash_init(){
    eval __LOG4BASH_INIT='${__LOG4BASH_INIT_'${BASHPID}'}'
    if [ "${__LOG4BASH_INIT}" = "" ]
    then
        __LOG4BASH_INIT=1
        eval '__LOG4BASH_INIT_'${BASHPID}'=1'
        eval coproc LOG4BASH_${BASHPID}_COPROC '{ (__log4bash_init_impl) }' 2> /dev/null
    fi
}
__log4bash_init_impl(){
    local s
    while read s
    do
        if [ ${__LOG4BASH_STRICT_APPEND} != '0' ]
        then
            tee -a ${__LOG4BASH_LOGFILE_PATH} <<< "${s}" > /dev/null
        else
            printf "%s\n" "${s}" >> ${__LOG4BASH_LOGFILE_PATH}
        fi
        if [ "${__LOG4BASH_EABLE_LOG_BK}" != "0" ]
        then
            if [ $(stat -c %s "${__LOG4BASH_LOGFILE_PATH}") -gt ${__LOG4BASH_LOGFILE_CHANGE_SIZE} ]
            then
                __log4bash_lock
                if [ $(stat -c %s "${__LOG4BASH_LOGFILE_PATH}") -gt ${__LOG4BASH_LOGFILE_CHANGE_SIZE} ]
                then
                    mv -v -f "${__LOG4BASH_LOGFILE_PATH}" "${__LOG4BASH_LOGFILE_BK_PATH}"
                fi
                __log4bash_unlock
            fi
        fi
    done
}
__log4bash_log_common(){
    local loglevel=$1
    local kind=$2
    shift 2
    if [ "${__LOG4BASH_ENABLE_DYNAMIC_CHANGE_LOGLEVEL}" = "1" ]
    then
        __log4bash_source_user_conf
    fi
    if [ "${loglevel}" = "1" ]
    then
        __log4bash_log "${kind}" "$@"
    fi
}
__log4bash_log(){
        local output
    local msg_flg=0
    if ((__LOG4BASH_EABLE_DISP != 0))
    then
        __log4bash_log_impl "$@"
        msg_flg=1
        echo "${msg}" >> ${__LOG4BASH_DISP_TTY}
    fi
    if ((__LOG4BASH_EABLE_LOG != 0))
    then
        __log4bash_init
        if (( msg_flg == 0 ))
        then
            __log4bash_log_impl "$@"
        fi
        eval 'echo "${msg}" >&"${LOG4BASH_'${BASHPID}'_COPROC[1]}"'
    fi
}
__log4bash_log_impl(){
        local kind=$1
        shift
        local wk date_time func_name
                func_name=${FUNCNAME[4]}
                if [ "${func_name}" = "main" ] && [ "${FUNCNAME[5]}" = "" ] ; then
                        func_name="---"
                fi

        wk=""
        wk="${wk}[$$:${BASHPID}:${PPID}] "
        wk="${wk}[${BASH_SOURCE[4]}(${BASH_LINENO[3]}):${func_name}] "
        wk="${wk}[${__LOG4BASH_LOGID}]"
        date_time="$(date "${__LOG4BASH_DATE_FORMAT}")"
        msg="${date_time} ${kind} ${wk} $@"
}
__log4bash_lock(){
    local ret
    local lock="${__LOG4BASH_LOGFILE_PATH}".d
    while :
    do
        mkdir "${lock}"
        ret=$?
        if [ ${ret} = 0 ]
        then
            break
        else
            usleep 10000    #10ms
        fi
    done
}
__log4bash_unlock(){
    local lock="${__LOG4BASH_LOGFILE_PATH}".d
    rmdir "${lock}"
}

export __LOG4BASH_DATE_FORMAT=${__LOG4BASH_TIME_FORMAT:='+[%Y/%m/%d %H:%M:%S.%N]'}
export __LOG4BASH_EABLE_DISP=${__LOG4BASH_EABLE_DISP:='1'}
export __LOG4BASH_DISP_TTY=${__LOG4BASH_DISP_TTY:='/dev/stdout'}
export __LOG4BASH_EABLE_LOG=${__LOG4BASH_EABLE_LOG:='1'}
export __LOG4BASH_LOGFILE_PATH=${__LOG4BASH_LOGFILE_PATH:='/tmp/log4bash.log'}
export __LOG4BASH_EABLE_LOG_BK=${__LOG4BASH_EABLE_LOG_BK:='1'}
export __LOG4BASH_LOGFILE_CHANGE_SIZE=${__LOG4BASH_LOGFILE_CHANGE_SIZE:='1000000'}
export __LOG4BASH_LOGFILE_BK_PATH=${__LOG4BASH_LOGFILE_BK_PATH:='/tmp/log4bash.log.bk'}

export __LOG4BASH_ENABLE_DYNAMIC_CHANGE_LOGLEVEL=${__LOG4BASH_ENABLE_DYNAMIC_CHANGE_LOGLEVEL:='0'}
export __LOG4BASH_LOGLEVEL_FATAL=${__LOG4BASH_LOGLEVEL_FATAL:='1'}
export __LOG4BASH_LOGLEVEL_ERROR=${__LOG4BASH_LOGLEVEL_ERROR:='1'}
export __LOG4BASH_LOGLEVEL_WARN=${__LOG4BASH_LOGLEVEL_WARN:='0'}
export __LOG4BASH_LOGLEVEL_INFO=${__LOG4BASH_LOGLEVEL_INFO:='0'}
export __LOG4BASH_LOGLEVEL_DEBUG=${__LOG4BASH_LOGLEVEL_DEBUG:='0'}
export __LOG4BASH_LOGLEVEL_TRACE=${__LOG4BASH_LOGLEVEL_TRACE:='0'}
export __LOG4BASH_STRICT_APPEND=${__LOG4BASH_STRICT_APPEND:='1'}
export __LOG4BASH_LOGID=${__LOG4BASH_LOGID:="LOGID_$$_${BASH_SUBSHELL}"}
export __LOG4BASH_CONF=log4bash.conf
export -f log4bash_trace
export -f log4bash_debug
export -f log4bash_info
export -f log4bash_warn
export -f log4bash_error
export -f log4bash_fatal

export -f __log4bash_source_user_conf
export -f __log4bash_source_user_conf_impl
export -f __log4bash_init
export -f __log4bash_init_impl
export -f __log4bash_log_common
export -f __log4bash_log
export -f __log4bash_log_impl
export -f __log4bash_lock
export -f __log4bash_unlock

__log4bash_source_user_conf_impl

#環境
ホスト　Windows10 COREi7
VM　　　VirtualBox バージョン 5.2.6 r120293 (Qt5.6.2)
　　　　　CentOS Linux release 7.4.1708 (Core)
GNU bash, バージョン 4.2.46(2)-release (x86_64-redhat-linux-gnu)
date (GNU coreutils) 8.22

#注意

  • 複数のプロセスからログ出力することを想定し、ログファイルの切り替え時に排他をかけています。
    排他の開始でロックディレクトリ"${__LOG4BASH_LOGFILE_PATH}".dを作成し、排他の終了で削除しています。排他を開始してから終了までの間に異常終了（または強制終了）した場合、ロックディレクトリが残ってしまい、処理がハングアップします。こうなったら手動でロックディレクトリを削除しない
    とハングアップは解消しません。

  • coprocでCOプロセスが生成されます、COプロセスは&で起動した通常のプロセスと同じなのでwaitの待ち合わせ対象です。
    以下の例ではプロセスIDを指定してwaitしているためsleepが終了するとwaitが終了しますが、

OKの例

#!/bin/sh
. ./log4bash4

log4bash_info "最初のロギングでCOプロセスが生成される"
( echo "sleeping 5"; sleep 5;echo "sleeped 5"; )&
p1=$!
echo "waiting"
wait ${p1} #プロセスIDを指定してwaitしているためsleepが終了するとwaitから復帰します
echo "waited"

　以下の例ではプロセスIDを指定してwaitしていないため、waitはlog4bash_infoの処理で生成されたCOプロセスの終了も待ち合わせてしまい、sleepが終了しても、waitが終了しません。

NGの例
#!/bin/sh
. ./log4bash4

log4bash_info "最初のロギングでCOプロセスが生成される"
( echo "sleeping 5"; sleep 5;echo "sleeped 5"; )&
echo "waiting"
wait #プロセスIDを指定していないためsleepが終了してもwaitから復帰しません。COプロセスの終了を待っています。
echo "waited"

を

  • ログファイルの出力はCOプロセスで行っています、このため、ロギングを行うプロセスが終了した直後は、ログファイルの出力が完了していない場合があります。

#性能

No logger　 処理速度(ms/件) 処理件数 処理時間
1 log4bash(通常設定) 4.746 60,000 284.8
2 log4bash(速度重視設定) 1.258 60,000 75.5
3 log4sh 13.439 60,000 806.3

No1 log4bash通常設定

export __LOG4BASH_ENABLE_DYNAMIC_CHANGE_LOGLEVEL='1'
export __LOG4BASH_LOGLEVEL_INFO='1'
export __LOG4BASH_LOGLEVEL_DEBUG='1'
export __LOG4BASH_LOGLEVEL_TRACE='1'
export __LOG4BASH_STRICT_APPEND='1'
export __LOG4BASH_EABLE_DISP='0'
export __LOG4BASH_EABLE_LOG='1'

No2 log4bash(速度重視設定)

export __LOG4BASH_ENABLE_DYNAMIC_CHANGE_LOGLEVEL='0'
export __LOG4BASH_LOGLEVEL_INFO='1'
export __LOG4BASH_LOGLEVEL_DEBUG='1'
export __LOG4BASH_LOGLEVEL_TRACE='1'
export __LOG4BASH_STRICT_APPEND='0'
export __LOG4BASH_EABLE_DISP='1'
export __LOG4BASH_DISP_TTY='/tmp/log4bash.log'
export __LOG4BASH_EABLE_LOG='0'

#おわりに

  • Bash4のloggerを作ろうと思い立ったのは、coprocの存在しを知ったときでした。名前をlog4shにしようとしたのですが、既に存在していました。スケールは全然違いますが、車輪の再発明になるので、作成を断念するところでした。

  • その後、「log4shは遅い」旨の記事を見つけ（どこかは忘れました）、「遅そうな処理をCOプロセスに追い出せば」早くなるかもしれない、「存在意義があるかも」と気を取り直して、作業を再開しました。
    の

  • 機能が異なるので性能比較はあまり意味がないのですが、出来上がったlog4bash4はlog4shより約2.8倍早い結果となりました。100倍ぐらい早ければそれなりの意味があるのですが、ちょっと期待外れでした。

4
3
2

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
4
3

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?