boost.Logの使い方を勉強した (｡･ｘ･)ゝ
デーモン系のプログラムになるとログは必須です。
C++でお仕事プログラムを書く時は、標準的にログプログラムが無いのでいつも悩みます。
最近(???)、boostにboost.Logというライブラリが入りました。
個人的には、C++ == C++ with Boost libなのでライブラリを使ってみた実験記録です。
実験で使用したboostバージョンは1.55となります。
しかし、改めて思ったが、boost難しい(ﾉД`)ｼｸｼｸ
(今までのライブラリは、先人の方々の情報を参照参照させて頂けていたので、
何とかなっていましたが今回はヽ(;´Д｀)ﾉ )
今回作りたいもの
・コンソールにログを吐く。
・指定されたログレベルでフィルタする。
・ログ出力時のファイル名、行数、関数名を合わせて出力する。
・実行時刻等のログに必要な情報を表示する。
基本的な考え方
boost.Logでは以下な考え方で動いています。
- ロガーオブジェクト
ロギング処理の基本となるオブジェクトです。
個々のログ情報を保持している、
ログレコードオブジェクトもロガーオブジェクトのインスタンスより生成します。
ライブラリ標準で定義されているグローバルなロガーオブジェクト(trivial)も存在します。
今回は、勉強のために、ユーザー独自のロガーオブジェクトを定義します。
- ログレコード
発行されたログは「レコード」という単位で管理されます。
ログというと、メッセージが主体となりますが、
以下に示す属性も含んでいます。
- 属性
ログレコードに付加出来る情報です。
属性は、ライブラリに事前に定義されているモノ(ログの発生時刻、ログのレベル、スレッドID等)
を使用する事が出来ます*1。
また、ユーザーが独自に拡張した属性を追加する事も出来ます。
今回は、ライブラリが持つ属性に加えて、ログ発生行関数名等の追加属性も定義してみます。
- sink
データの取り込み口という意味のようです。(。
(↑と勝手に思っている。)
sinkには、フロントエンドとバックエンドを指定する事が出来ます。
名前の通り、フロントエンドは入力されたログに対するフォーマットの定義や、
フィルタリングを行います。
バックエンドは、最終的にログファイルを何処に書き出すかの定義を行います。
ユーザー独自定義のグローバルロガー定義
ログを記録するためには、ロガーオブジェクトを生成する必要が有ります。
システムが持つグローバルなログオブジェクトであるtrivialログ*2を使用する事も可能です。
しかし、システム標準のロガーオブジェクトの場合、ロガーオブジェクトが生成する
ログレコードオブジェクトに対して、追加のログ属性、ユーザー定義のログレベル等を追加する事は出来ません。
今回は、ユーザー独自のロガーオブジェクトを定義します。
ここで、問題となる事はロガーオブジェクトをどのように定義するかという事です。
ログ出力が必要なクラス等のメンバとして持たせる事も可能ですが、
プログラム横断的な機能となるロギングのために、ロガーのインスタンスへの参照を
各モジュール間で引き回すという事はかなり面倒ですヽ(;´Д｀)ﾉ
このような用途に対する対応策としては、グローバル変数というかシングルトンを使用する事が
一般的です。
boost::logライブラリでは、ユーザー独自のロガーをシングルトン化するマクロが定義されており、
同マクロを使用する事で、シングルトン化する事が出来ます。*3
シングルトンの定義は、ヘッダ側とソース側で訳て行う事が出来ます。
ヘッダ側の定義は以下のようにります。
各行の意味を説明すると、以下となります。
| 要素 | 説明 |
|---|---|
| BOOST_LOG_GLOBAL_LOGGER | 定義用マクロ |
| glob_logger | 定義対象のオブジェクト |
| boost::log::sources::severity_logger_mt | ユーザー独自定義ロガーの定義元となるロガーオブジェクト(ちなみに、mtとはマルチスレッドの意味です。) |
| severity_level | ユーザーが独自定期したログレベル(自体はenum) |
namespace my_namespace { // ログレベルを定義する enum severity_level { debug, notification, warning, error, critical }; //ログレベルを定義する BOOST_LOG_ATTRIBUTE_KEYWORD(severity, "Severity", severity_level); //[参考] //http://boost-log.sourceforge.net/libs/log/doc/html/log/detailed/sources.html#log.detailed.sources.global_stor\ age BOOST_LOG_GLOBAL_LOGGER( glob_logger , boost::log::sources::severity_logger_mt<severity_level> ); }
ソースコード側では、ロガーに対して独自の属性等を定義します。
各要素の意味は以下となります。
| 要素 | 説明 |
|---|---|
| boost::log::sources::severity_logger_mt | ロガーオブジェクト |
| add_attribute("TimeStamp" | このログオブジェクトを用いて生成したログレコードに対して、設定される属性です。 |
namespace my_namespace { //グローバルロガーを設定する BOOST_LOG_GLOBAL_LOGGER_INIT( glob_logger, boost::log::sources::severity_logger_mt<severity_level> ) { //ログレコードの属性を設定する auto r = boost::log::sources::severity_logger_mt<severity_level>(); //[ログに含まれる属性を設定する] //以下の共通属亭定義関数で定義する事も可能である。 //boost::log::add_common_attributes(); // //ここでは、独自に必要な属性の定義を行う { //タイムスタンプを設定する r.add_attribute("TimeStamp", boost::log::attributes::local_clock()); } return std::move(r); } }
これらの定義を行う事で、グローバルなロガーオブジェクトを使用する事が出来るようになります。
例えば、マクロを使用して以下のように使用する事が可能です。
(以下のマクロ定義の意味は後で説明します。)
//ログ展開用のマクロ #define MY_GLOBAL_LOGGER(sv) BOOST_LOG_SEV( my_namespace::glob_logger::get(), sv) \ << boost::log::add_value("RecordLine", __LINE__) \ << boost::log::add_value("SrcFile", __FILE__) \ << boost::log::add_value("CurrentFunction", BOOST_CURRENT_FUNCTION) \ int main() { MY_GLOBAL_LOGGER( my_namespace::debug ) << "logging test!"; }
sinkの設定
ユーザー独自定義のグローバルロガーを定義する事が出来ました。
次はロガーが生成したログレコードをログ出力先に書き出す必要が有ります。
ユーザー独自のログ書き出し処理は、sinkと呼ばれています。
(水回りで使われている「シンク」という意味と同じで、データの取り込み口という意味のようです。)
sink自体はライブラリが持つコアオブジェクトシングルトンに定義を行います。
sink自体は複数の定義が可能であり、ログの出力先、ログの出力フォーマット等により、
定義を変化して登録する事が出来ます。
ライブラリに対して、ログが発行されると、コアオブジェクトシングルトンに定義されたロガーオブジェクトは、
登録されている全てのsinkに対して処理依頼されます。
各sinkでは、引き渡されたログレコードオブジェクトをフィルタリング、生成して登録された出力先に出力します。
ちょっと長いですが、sinkの登録は以下となります。
//ログ出力用の設定を行う void init_log_system( void ) { //バックエンドを生成 typedef boost::log::sinks::text_ostream_backend our_backend; auto backend = boost::make_shared< our_backend >(); { boost::shared_ptr<std::ostream> stream_out(&std::cout, boost::empty_deleter()); backend -> add_stream(stream_out); //ログ書き出し時に自動的にフラッシュを行うように設定する。 //バッファリングはされなくなるが、プログラムがクラッシュした場合には安定性が高い backend -> auto_flush(true); } //フロントエンドを定義 auto frontend = boost::make_shared< boost::log::sinks::synchronous_sink<our_backend> >( backend ); //ログフォーマットを定義 frontend -> set_formatter ( boost::log::expressions::format("%1%\t%2%\t%3%\t%4%\t[%5%]\t%6%\t%7%\t%8%\t%9%") % boost::log::expressions::format_date_time<boost::posix_time::ptime> ( "TimeStamp", "%Y-%m-%d %H:%M:%S" ) % boost::log::expressions::attr< std::string >("SrcFile") % boost::log::expressions::attr< int >("RecordLine") % boost::log::expressions::attr< std::string >("CurrentFunction") % my_namespace::severity % boost::log::expressions::message % boost::log::expressions::attr< boost::log::attributes::current_process_id::value_type >("ProcessID") % boost::log::expressions::attr< boost::log::attributes::current_thread_id::value_type >("ThreadID") % boost::log::expressions::attr< boost::log::attributes::current_process_name::value_type >("Process") ); //ログレベルを設定 #if 0 //c++11のlambaを使用すると以下のように書けるらしい //ちょっと、冗長過ぎるかもヽ(;´Д｀)ﾉ //c++11のlambaを使用すると以下のように書けるらしい //ちょっと、冗長過ぎるかもヽ(;´Д｀)ﾉ frontend->set_filter ( []( boost::log::attribute_value_set const & t) { const auto v = t["Severity"]; if(v) { const auto a = v.extract<my_namespace::severity_level>(); if( a.get() >= my_namespace::warning ) { //指定レベル以上だったら、ログ対象に含める return true; } } return false; } ); #endif //ライブラリ側の定義を使うと以下な感じでも書けるしい。 frontend->set_filter( my_namespace::severity >= my_namespace::warning ); //frontend->set_filter( my_namespace::severity >= my_namespace::debug ); //ライブラリのコアに登録する boost::log::core::get()->add_sink(frontend); }
処理を分割して説明します。
まずは、バックエンドの生成です。*4
バックエンドとは、実際にログ情報の書き出を行う部分の定義となります。
今回は同期型で稼働して、ログ情報を標準出力に書き出すように作成します。
//バックエンドを生成 typedef boost::log::sinks::text_ostream_backend our_backend; auto backend = boost::make_shared< our_backend >(); { boost::shared_ptr<std::ostream> stream_out(&std::cout, boost::empty_deleter()); backend -> add_stream(stream_out); //ログ書き出し時に自動的にフラッシュを行うように設定する。 //バッファリングはされなくなるが、プログラムがクラッシュした場合には安定性が高い backend -> auto_flush(true); }
次に、フロントエンドを定義します。*5
フロントエンドとは、ロガーが生成したログレコードを受け取り、
フォーマット、フィルタリングを行うオブジェクトとなります。
フォーマット、フィルタリングの定義の仕方はややこしいので後回しにします。
//フロントエンドを定義 auto frontend = boost::make_shared< boost::log::sinks::synchronous_sink<our_backend> >( backend ); //ログのフィルタを定義する ・・・ //ログフォーマットを定義 ・・・ //ライブラリのコアに登録する boost::log::core::get()->add_sink(frontend);
ログのフィルタリングに関して説明します。
正直、ここが一番複雑でした。
boost::log自体は、c++03にも対応できるようにするために、Boost::phoenixを用いて
lamba式の定義が出来るようになっています。
しかし、「C++ってC++11の事だよなぁ┐(´∀｀)┌ﾔﾚﾔﾚ」と思い、
普通にC++11のlambaを使おうとしたら、思った以上に強敵でした(ﾉД`)ｼｸｼｸ
(えっ、何の型が来るのみたいな...。)
まず、C++11側の定義から説明します。
フィルタ処理は、frontendオブジェクトのset_filter関数を用いて定義します。*6
同関数で渡す事が出来る関数オブジェクトのoperater()関数は
実行時にboost::log::attribute_value_set const &型*7を引数に取ります。
引数として渡される、attribute_value_setオブジェクトはログレコードオブジェクトが保持している
属性一覧を持ったオブジェクトとなります。
今回のフィルタリングでは、ログレベルを判断基準とします。
ログレベルに関しては、グローバルロガーを定義した段階で定義してあります。
定義時に、参照名として「Severity」というキーワードを付けており、
attribute_value_setオブジェクトからもキーワードを指定する事で参照が可能となります。
キーワードを指定して、属性を取得したら、該当情報が入っているか確認します。
情報が含まれている事が確認出来たら、内部からログレベル情報を取り出します。
この時、取り出すべき型を指定する必要が有ります。
(boost::anyみたいな感じ。)
情報の取り出しに成功したら、レベル判定を行い、ロギング対象であるログレコードの場合には、
関数の戻り値としてtrueを返します。
C++11で書くと思った以上に大変でしたヽ(;´Д｀)ﾉ
サンプルコードに有るように、ライブラリが持つ定義を使うと
かなり(*´Д｀)ｽｷｰﾘとしたコードが書けるようです。*8
C++11のlambaの方が、全然知らない人が読んだときは読みやすいですが、
どっちが良いかは結構悩むレベルです...。
//ログレベルを設定 #ifdef IS_C++_11_MODE //c++11のlambaを使用すると以下のように書けるらしい //ちょっと、冗長過ぎるかもヽ(;´Д｀)ﾉ frontend->set_filter ( []( boost::log::attribute_value_set const & t) { const auto v = t["Severity"]; if(v) { const auto a = v.extract<my_namespace::severity_level>(); if( a.get() >= my_namespace::warning ) { //指定レベル以上だったら、ログ対象に含める return true; } } return false; } ); #else //C++03用の定義 //ライブラリ側の定義を使うと以下な感じでも書けるしい。 frontend->set_filter( my_namespace::severity >= my_namespace::warning ); #endif
ログフォーマットの定義を行います*9。
ログフォーマットの定義にも、何種類かの定義方法を使用する事が出来ます。
個人的には、Boost::formatの形式に一番慣れているので、
Boost::format形式の定義を使用します。
Boost::feomatと異なるポイントとして、置換文字指定で%||が使えません。
frontend -> set_formatter
( boost::log::expressions::format("%1%\t%2%\t%3%\t%4%\t[%5%]\t%6%\t%7%\t%8%\t%9%")
% boost::log::expressions::format_date_time<boost::posix_time::ptime>
( "TimeStamp", "%Y-%m-%d %H:%M:%S" )
% boost::log::expressions::attr< std::string >("SrcFile")
% boost::log::expressions::attr< int >("RecordLine")
% boost::log::expressions::attr< std::string >("CurrentFunction")
% my_namespace::severity
% boost::log::expressions::message
% boost::log::expressions::attr< boost::log::attributes::current_process_id::value_type >("ProcessID")
% boost::log::expressions::attr< boost::log::attributes::current_thread_id::value_type >("ThreadID")
% boost::log::expressions::attr< boost::log::attributes::current_process_name::value_type >("Process")
);
コンパイルに必要なライブラリ
boost::Logを使ったプログラムを作成する場合、
必要とされるライブラリはboostlogだけでなく、以下となるようです。
boost_log_setup
boost_log
boost_system
boost_thread
ソースコード一覧
今回使ったソースコードをまとめて表記すると以下となります。
main.cpp
#include <iostream> #include <string> //-----------ロガー設定の定義 #include <boost/make_shared.hpp> #include <boost/log/core.hpp> #include <boost/log/common.hpp> #include <boost/log/expressions.hpp> #include <boost/log/utility/setup/console.hpp> #include <boost/log/utility/setup/common_attributes.hpp> #include <boost/utility/empty_deleter.hpp> #include <boost/log/support/date_time.hpp> #include <boost/log/expressions/formatters/date_time.hpp> #include <boost/log/attributes/current_thread_id.hpp> #include <boost/log/attributes/current_process_name.hpp> #include <boost/log/sinks/text_ostream_backend.hpp> #include <boost/log/sinks/sync_frontend.hpp> #include <boost/log/utility/value_ref.hpp> //独自定義したグローバルロガーオブジェクト #include "my_gloabl_log.h" namespace { //ログ出力用の設定を行う void init_log_system( void ) { //バックエンドを生成 typedef boost::log::sinks::text_ostream_backend our_backend; auto backend = boost::make_shared< our_backend >(); { boost::shared_ptr<std::ostream> stream_out(&std::cout, boost::empty_deleter()); backend -> add_stream(stream_out); //ログ書き出し時に自動的にフラッシュを行うように設定する。 //バッファリングはされなくなるが、プログラムがクラッシュした場合には安定性が高い backend -> auto_flush(true); } //フロントエンドを定義 auto frontend = boost::make_shared< boost::log::sinks::synchronous_sink<our_backend> >( backend ); //ログフォーマットを定義 frontend -> set_formatter ( boost::log::expressions::format("%1%\t%2%\t%3%\t%4%\t[%5%]\t%6%\t%7%\t%8%\t%9%") % boost::log::expressions::format_date_time<boost::posix_time::ptime> ( "TimeStamp", "%Y-%m-%d %H:%M:%S" ) % boost::log::expressions::attr< std::string >("SrcFile") % boost::log::expressions::attr< int >("RecordLine") % boost::log::expressions::attr< std::string >("CurrentFunction") % my_namespace::severity % boost::log::expressions::message % boost::log::expressions::attr< boost::log::attributes::current_process_id::value_type >("ProcessID") % boost::log::expressions::attr< boost::log::attributes::current_thread_id::value_type >("ThreadID") % boost::log::expressions::attr< boost::log::attributes::current_process_name::value_type >("Process") ); //ログレベルを設定 #if 0 //c++11のlambaを使用すると以下のように書けるらしい //ちょっと、冗長過ぎるかもヽ(;´Д｀)ﾉ frontend->set_filter ( []( boost::log::attribute_value_set const & t) { const auto v = t["Severity"]; if(v) { const auto a = v.extract<my_namespace::severity_level>(); if( a.get() >= my_namespace::warning ) { //指定レベル以上だったら、ログ対象に含める return true; } } return false; } ); #else //ライブラリ側の定義を使うと以下な感じでも書けるしい。 frontend->set_filter( my_namespace::severity >= my_namespace::warning ); //frontend->set_filter( my_namespace::severity >= my_namespace::debug ); #endif //ライブラリのコアに登録する boost::log::core::get()->add_sink(frontend); } //---------------色々とテストプログラム--------------- namespace local { namespace local2 { template< typename T> void t( const T & t ) { MY_GLOBAL_LOGGER( my_namespace::debug ) << "in function"; } } } } int main() { //ログを初期化 init_log_system( ); MY_GLOBAL_LOGGER( my_namespace::debug ) << "logging test!"; auto j = 0; for(size_t i =0 ;i< 10;++i) { MY_GLOBAL_LOGGER( my_namespace::debug ) << "logging test!" << j++; local::local2::t(10); std::cout << i << std::endl; } MY_GLOBAL_LOGGER( my_namespace::warning ) << "end"; std::cout << "num : " << j << std::endl; }
my_global_log.h
グローバルロガーの定義
#ifndef _MY_GLOABL_LOG_H_ #define _MY_GLOABL_LOG_H_ //BOOST_LOG_GLOBAL_LOGGERの定義 #include <boost/log/sources/global_logger_storage.hpp> //BOOST_LOG_SEVの定義 #include <boost/log/sources/severity_feature.hpp> //add_valueの定義 #include <boost/log/utility/manipulators/add_value.hpp> //severity_loggerの定義 #include <boost/log/sources/severity_logger.hpp> #include <boost/log/expressions/keyword.hpp> //現在の関数名を取得 #include <boost/current_function.hpp> //ログ展開用のマクロ #define MY_GLOBAL_LOGGER(sv) BOOST_LOG_SEV( my_namespace::glob_logger::get(), sv) \ << boost::log::add_value("RecordLine", __LINE__) \ << boost::log::add_value("SrcFile", __FILE__) \ << boost::log::add_value("CurrentFunction", BOOST_CURRENT_FUNCTION) \ namespace my_namespace { // We define our own severity levels enum severity_level { debug, notification, warning, error, critical }; // The operator puts a human-friendly representation of the severity level to the stream inline std::ostream& operator<< (std::ostream& strm, severity_level level) { static const char* strings[] = { "debug", "notification", "warning", "error", "critical" }; if (static_cast< std::size_t >(level) < sizeof(strings) / sizeof(*strings)) strm << strings[level]; else strm << static_cast< int >(level); return strm; } BOOST_LOG_ATTRIBUTE_KEYWORD(severity, "Severity", severity_level); //グローバルロガーを追加する //[参考] //http://boost-log.sourceforge.net/libs/log/doc/html/log/detailed/sources.html#log.detailed.sources.global_storage BOOST_LOG_GLOBAL_LOGGER( glob_logger, boost::log::sources::severity_logger_mt<severity_level> ); } // _MY_GLOABL_LOG_H_ #endif
my_global_log.cpp
グローバルロガーの実態
//! 独自定義のグローバルロガー #include <boost/log/utility/setup/common_attributes.hpp> #include <boost/log/support/date_time.hpp> #include <boost/log/expressions/formatters/date_time.hpp> #include <boost/log/sources/severity_logger.hpp> #include <boost/log/attributes/current_thread_id.hpp> #include <boost/log/attributes/current_process_name.hpp> //独自定義したグローバルロガーの定義 #include "my_gloabl_log.h" namespace my_namespace { //グローバルロガーを設定する BOOST_LOG_GLOBAL_LOGGER_INIT( glob_logger, boost::log::sources::severity_logger_mt<severity_level> ) { //ログレコードの属性を設定する auto r = boost::log::sources::severity_logger_mt<severity_level>(); //[ログに含まれる属性を設定する] //以下の共通属亭定義関数で定義する事も可能である。 //boost::log::add_common_attributes(); // //ここでは、独自に必要な属性の定義を行う { //タイムスタンプを設定する r.add_attribute("TimeStamp", boost::log::attributes::local_clock()); r.add_attribute("ProcessID", boost::log::attributes::current_process_id()); r.add_attribute("Process", boost::log::attributes::current_process_name()); r.add_attribute("ThreadID", boost::log::attributes::current_thread_id()); } return std::move(r); } }
*1:http://boost-log.sourceforge.net/libs/log/doc/html/log/detailed/attributes.html:Attributes
*2:http://boost-log.sourceforge.net/libs/log/doc/html/log/tutorial.html#log.tutorial.trivial:http://boost-log.sourceforge.net/libs/log/doc/html/log/tutorial.html#log.tutorial.trivial
*3:http://boost-log.sourceforge.net/libs/log/doc/html/log/detailed/sources.html#log.detailed.sources.global_storage:Global storage for loggers
*4:http://www.boost.org/doc/libs/1_55_0/libs/log/doc/html/log/detailed/sink_backends.html:Sink backends
*5:http://www.boost.org/doc/libs/1_55_0/libs/log/doc/html/log/detailed/sink_frontends.html:Sink frontends
*6:http://boost-log.sourceforge.net/libs/log/doc/html/boost/log/filter.html:filter
*7:http://www.boost.org/doc/libs/1_55_0/libs/log/doc/html/boost/log/attribute_value_set.html:attribute_value_set
*8:http://boost-log.sourceforge.net/libs/log/doc/html/log/tutorial/advanced_filtering.html:Filtering revisited
*9:http://boost-log.sourceforge.net/libs/log/doc/html/log/detailed/expressions.html#log.detailed.expressions.formatters:Formatting expressions
