log4cplusは, プログラムの出力を書き出すライブラリーです．

は？ write(*,*) 'FORTRAN'とか puts("C99") で，かけるじゃんか，と思う人もいるでしょう，でも，それではダメなケースが多いのです．いや，本格計算ではほとんどダメなんじゃないか？

MPIやOpenMPでプログラムを書きました．そしたら，こげな画面になってしまいました．よ，読めねえよ・・・

nt=12n542432nt=1244 col=2t=32n
542444 col=212542444 col=3
232t=232
nt=125412542444 col=2324
44 col=2323223232

ジョブで実行してたらタイムアウトしてしまいました．すると，タイムアウトで画面出力を全て失いました．
- 困りましたね，途中でデータ保存した時の時間ステップの現在の数値が不明です．バックアップが役に立たねえ・・・全部やり直しだ
ジョブで，わさわさ画面に書き出していたら，
- 計算ノードのディスクを使い果たしししまい，肝心の最終データが出力できませんでした．無念
- 画面出力が900GBになりました．その巨大ファイルをエディターで開こうとしたら2日かかりました．開きましたが，コンピュータが反応しなくなりました．
- ディスクIOが渋滞して計算が前に進みません．CPU利用率が20%になった
- 大量に画面出力するジョブを打ってしまった．ジョブなので終わるまでミスに気づかず，3TBも書いちまった
- 計算自体は30分で終わったのに，ジョブが終了しない・・・と思ったら，3TBのログのお持ち帰りに，あと2時間かかるのであった．途中でキャンセルしたら計算結果も初期データも全部壊れたwww
  - 嫌なこと思い出したぞ・・・この時潰れた初期データを作るのに1ヶ月かかった
ジョブで実行して，画面出力をファイルに書き出すことにしました．
- バッファーされちまって，画面出力が計算終了まで出てこないよ・・・
- どのくらいの計算速度か，見たかったのに・・・

画面出力なんて，役に立たないのです．そこで，ログ書きライブラリーの登場です．ログ書きサーバーにログを送りつけることが可能になるので，データファイルとログが別個に管理されることになり，上記の問題が解消されるわけです．ま，もちろん

プログラム実行中に，画面に何も出力しなくなる
- そりゃ指定した記録デバイスに全部書かれているんだから，そこの画面には出ねえってば

という欠点が出てきますけどね．あ，それから，以下の説明はVersion 2.0.4, CentOS8のやつだからね. Macも同じだけどな

ローカルロガー

最初にローカルファイルに書き出す「ローカルロガー」を説明しましょう．

接続インスタンス作成

#include <log4cplus/socketappender.h>  //ネットワークロガー
#include <log4cplus/configurator.h>         //ローカルロガー
#include <log4cplus/spi/loggingevent.h>  
#include <log4cplus/loggingmacros.h>
#include <log4cplus/logger.h>
#include <boost/filesystem.hpp>
...
namespace FS=boost::filesystem;
...
int main(){
...
    FS::path home_folder=std::getenv("HOME");
    FS::path log4_file=home_folder/"log"/"mymy.cfg";   //設定ファイル mymy.cfg の置き場所を指定
    if (!FS::exists(log4_file)) {
        std::cerr << "Can not find log4c++ configuration:" << log4_file.string() << std::endl;
        return EXIT_FAILURE;
    }
    log4cplus::PropertyConfigurator config(log4_file.string());
    config.configure();
    log4cplus::initialize();
    log4cplus::Logger logger=log4cplus::Logger::getInstance(LOG4CPLUS_TEXT("mymy")); //設定ファイルの項目を指定

これでログ書きインスタンスloggerが作成される.

設定ファイル

プログラムを動かすには, 設定ファイル（上の例では mymy.cfg ）で項目mymyを指定しなければならない：

log4cplus.rootLogger=DEBUG,mymy
log4cplus.appender.mymy=log4cplus::RollingFileAppender
log4cplus.appender.mymy.File=${HOME}/log/mymy.log    ←ログを記録するファイル名を指定. 青字のとこ間違えるとハマるよ
log4cplus.appender.mymy.MaxFileSize=50MB          ← 1ファイル50MBで切り替える
log4cplus.appender.mymy.MaxBackupIndex=1000   ← 1000回分は保存しておく
log4cplus.appender.mymy.layout=log4cplus::PatternLayout
log4cplus.appender.mymy.layout.ConversionPattern=%D{%m/%d/%y %H:%M:%S} [%i] %p <%x> %m%n

最後の行の雰囲気から分かるように, この設定では, ログファイルに

01/13/20 09:33:25 [12234] INFO <context> メッセージ

という出力になる. 最初はメッセージの日時，[プロセスID] メッセージ種別 <後で述べるコンテキスト> ，である．また, 1ファイルのサイズは最大50MBで, 1000回分以上は自動で消去されるので, 50GB以上のログサイズには決して到達しないことになる.

＊mymy.Fileのとこで，「そのマシンでのHOMEフォルダ」を適用したいなんて思うあなたは，${HOME}/相対パスと書いてね.

＊不可解なハナモゲラ記号の意味は

%d	日付。これは %d{yyyy-MMM-dd HH:mm:ss,SSS} みたいに細かく書けるし、TTCCLayout で使ったシンボルを使って、 %d{ISO8601} みたいに書いても良い。
%t	ログを生成したスレッド名
%p	ログレベル(FATAL, INFO, ....)
%x	NDC名
%m	メッセージ
%l	%F%L
%F	ファイル名
%L	行番号
%n	改行

ログ書き

実際のログ出力は，下のように記述する:

LOG4CPLUS_INFO(logger,"Hell World");   // INFO文字列を出力
LOG4CPLUS_INFO(logger,std::hex << std::this_thread::get_id() << std::dec << "<<" << message);  // 画面出力みたい
LOG4CPLUS_WARN(logger,"This is warning"); // ログファイルにWARNをつけて出力
LOG4CPLUS_ERROR(logger,"This is error"); // ログファイルにERRORをつけて出力

ビルド

あんたのCMakeLists.txtにちょびっと追加したらふつーにビルドできると思うよ：

#....
find_package(PkgConfig)
pkg_check_modules(LOG4CPLUS REQUIRED log4cplus)
#.....
link_directories(${LOG4CPLUS_LIBRARY_DIRS})
target_link_libraries(貴様の実行ファイル ${LOG4CPLUS_LIBRARIES} ${Boost_Libraries} )

コンテキスト

メッセージをどの部分で出力したのか，が明らかになるように, コンテキストを追加することができる.

log4cplus::getNDC().push(LOG4CPLUS_TEXT("con1"));;
//旧 log4cplus::NDCContextCreator* _context=new log4cplus::NDCContextCreator(LOG4CPLUS_TEXT("con1"));

以上により，ログファイルに<con1>が追加されるようになる. さらに

log4cplus::getNDC().push(LOG4CPLUS_TEXT("con2"));
//旧 log4cplus::NDCContextCreator* _context2=new log4cplus::NDCContextCreator(LOG4CPLUS_TEXT("con2"));

とすると, どちらも有効になって, ログファイルに<con1><con2>が追加される. pushしたコンテキストはremove(全部消す)とかpop(最後のだけ消す)可能である:

log4cplus::getNDC().pop();
log4cplus::getNDC().remove();

なお, コンテキストはスレッド毎に別の値になる:

log4cplus::getNDC().push(LOG4CPLUS_TEXT("main"));;
std::thread v([&]{ LOG4CPLUS_INFO(logger,"New thread"); });
LOG4CPLUS_INFO(logger,"Org thread");

であると, ログは

01/13/20 14:05:25 [18411] INFO <main> Org thread
01/13/20 14:05:25 [18411] INFO <> New thread

となってしまい, スレ違いは文脈がちゃうという認識である.

log4cplus::NDCContextCreator* _context=new log4cplus::NDCContextCreator(LOG4CPLUS_TEXT("main-thread"));
std::thread v([&]{
    std::ostringstream oss; oss<<"new"<<std::hex<<std::this_thread::get_id();
    log4cplus::NDCContextCreator* _context=new log4cplus::NDCContextCreator(LOG4CPLUS_TEXT(oss.str()));
    LOG4CPLUS_INFO(logger,"New thread"); 
});
LOG4CPLUS_INFO(logger,"Org thread");

であると, ログは

01/13/20 14:19:19 [18761] INFO <main> Org thread
01/13/20 14:19:19 [18761] INFO <new7fe6d2232700> New thread

となる. スレッドごとに別なんてありえねえ，メインスレッドと全部同じにしやがれ的な場合，

auto KeepMainThreadNDCStackHere=log4cplus::getNDC().cloneStack(); //メインスレッドでNDC状態を保存
std::thread([...,&KeepMainThreadNDCStackHere](...){
    ...
    log4cplus::getNDC().inherit(KeepMainThreadNDCStackHere);
    ...
}):

これでスレッドも同じNDCだ！

ローカルSYSLOG

OS付属のロガーにファイルを書かせることも可能である. とはいえ, OSであるので，まずは許可を出さねばならぬ. rootユーザーで, /etc/rsyslog.d/mymy.conf に設定を書く:

/etc/rsyslog.d/mymy.conf:
local3.info /var/log/mymy.log

これは, このマシンのlocal3ログを, /var/log/mymy.log に出力せよ, という命令である. このようにユーザーが使って良いチャンネルは local0, local1,..., local7 の7つしかないので注意. 準備が終わったら

systemctl restart rsyslog

これで, /var/log/mymy.log が出現することを確認(出現しなければ logger -p local3.info STAND-UP-MYMY とでも入力してみる).

設定ファイル

設定ファイルはこんな感じになる:

log4cplus.rootLogger=DEBUG,mymy
log4cplus.appender.mymy=log4cplus::SysLogAppender
log4cplus.appender.tcp.facility=local3  ←上で指定したやつだよ
log4cplus.appender.mymy.layout=log4cplus::PatternLayout
log4cplus.appender.mymy.layout.ConversionPattern=%p <%x> %m%n

これで, /var/log/mymy.log にはこんな記録が残ることになる:

Jan 13 16:46:23 h225 mymy[22111]: INFO <main> Org thread
Jan 13 16:46:23 h225 mymy[22111]: INFO <new7f986812b700> New thread

ええっと, /var/log/mymy.log がrootしか読み書きできねえのは, 起動時のなんかほれ，設定するやつでなんとかなるだろう．

リモートSYSLOG

どうせだから，そのソフトウェアシステムのログを1台のマシンに集約させたいと思うでしょう．これも簡単です．集約先のマシンで，SYSLOGの設定をするついでに，ネットワーク機能を有効にしときます．しゅなわち，

/etc/rsyslog.conf:
...
# Provides UDP syslog reception
# for parameters see http://www.rsyslog.com/doc/imudp.html
module(load="imudp") # needs to be done just once   ←餡コメント
input(type="imudp" port="514")   ←餡コメント
# Provides TCP syslog reception
# for parameters see http://www.rsyslog.com/doc/imtcp.html
module(load="imtcp") # needs to be done just once    ←餡コメント
input(type="imtcp" port="514")    ←餡コメント

準備が終わったら

systemctl restart rsyslog

設定ファイル

設定ファイルはこんな感じになる:

log4cplus.rootLogger=DEBUG,mymy
log4cplus.appender.mymy=log4cplus::SysLogAppender
log4cplus.appender.tcp.facility=local3
log4cplus.appender.mymy.layout=log4cplus::PatternLayout
log4cplus.appender.mymy.layout.ConversionPattern=%p <%x> %m%n
log4cplus.appender.mymy.host=10.249.229.225 ←集約先のホスト名とかアドレス
log4cplus.appender.mymy.tcp=true     ← こだわりがなければ mymy.udp=true でもいいけど
log4cplus.appender.mymy.port=514

ううん, TCPで送りつけると，ログマシンがダウンしている間に計算ノードの計算が止まるかもしれぬ．そのときの考え方は人間に対する依存性が存在する：

記録が取れないのに，計算進めるなよボケが
記録が取れないくらいで，計算止めるなクソ野郎

ううん．これはだからTCPかUDPかは，選ばないとダメなのでは．

これで, /var/log/mymy.log にはこんな記録が残ることになる(面白いので，一部別のマシンで実行した)

Jan 13 08:00:06 h225.229.249.10.1016485.vlan.kuins.net [22604] INFO <main> Org thread
Jan 13 08:00:06 h225.229.249.10.1016485.vlan.kuins.net [22604] INFO <new7ffa903a7700> New thread
Jan 13 08:00:58 h224.229.249.10.1016485.vlan.kuins.net [885] INFO <main> Org thread
Jan 13 08:00:58 h224.229.249.10.1016485.vlan.kuins.net [885] INFO <new7f403caf5700> New thread

ロギングサーバ

SYSLOGで集約できるとはいえ，OS付属のものですし動かない場合も多々ございましたので，自作ログサーバを使うという手もあります．

サーバコード

log4c++に添付されているサーバーコードを利用して作成します．WebMixのやつだとこんな感じ：

int netlog(std::string ip,boost::filesystem::path conf,unsigned int port){
    unsigned long serial=0;
    const log4cplus::tstring configFile = conf.string();
    log4cplus::PropertyConfigurator config(configFile);
    config.configure();
    log4cplus::helpers::ServerSocket serverSocket(port);
    if (!serverSocket.isOpen()) throw(std::runtime_error("netlog::Could not open socket, may
      be port " << port << " is in use."));
    Reaper reaper;
    ClientThread *thr;
    for (;;thr->start()) thr=new ClientThread(serverSocket.accept(),reaper,serial++);
    return static_cast<int>(EXIT_t::SUCCESS);
};

重要そうなクラスReaperとClientThreadのコードは, log4c++のsimpleserver/フォルダーに転がっていますのでコピペです. あ？main()はテキトーに足す必要があります．

スレッドで上記関数を呼び出して，片方がサーバー，片方がクライアントで動かそうとしたら，動かなかった．
仕方ねえので，fork()してexec()で，動いた. そりゃな．

SYSLOG方式と異なるのは，log4c++の設定ファイルはサーバー「のみ」で与えるってことです．

接続インスタンス作成

#include <log4cplus/socketappender.h>  //ネットワークロガー
#include <log4cplus/configurator.h>         //ローカルロガー
#include <log4cplus/spi/loggingevent.h>  
#include <log4cplus/loggingmacros.h>
#include <log4cplus/logger.h>
#include <boost/filesystem.hpp>
...
namespace FS=boost::filesystem;
...
int main(){
    ...
    std::string logger_host="サーバーのホスト名";
    unsigned int logger_port=サーバーのポート番号
    log4cplus::initialize();    ←いきなりのinitialize
    log4cplus::tstring serverName = logger_host;
    log4cplus::SharedAppenderPtr SockApp(new log4cplus::SocketAppender(logger_host, logger_port, serverName));
    SockApp->setName(LOG4CPLUS_TEXT("mymy"));  ← ん？今見ると，これ，必要なのかな？しらねーや
    log4cplus::Logger::getRoot().addAppender(SockApp);
    log4cplus::Logger logger=log4cplus::Logger::getInstance(LOG4CPLUS_TEXT("mymy")); //設定ファイルの項目を指定

これでログ書きインスタンスloggerが作成. クライアント側には，設定ファイルはありません．

添付	サイズ
localロガーのサンプルプログラム	2.36 KB