ログ出力機能

アプリケーションプログラムやセンサーシステムを構築するときに、要求仕様などでもあまり明示的に指定されることもなく、分析・設計時点でもあまり表にはでない機能なのですが、運用中はもちろん、トラブル発生時、開発、テスト時など全てのフェーズにおいて、一番役に立つ機能がログ出力機能です。

下記はDeviceServer のログの出力例です。

2012/04/10 14:50:32 falcon     UIOUSB_EVENT_DATA    0 温度 18.6℃  明るさ 962
2012/04/10 14:52:44 falcon     SESSION              0 CreateDocument: new session created, token = ST03114ED2C61896 user =  terminal =  webpxyappsvr =
2012/04/10 14:52:44 falcon     PERIODIC_TIMER       0 renew public session [PUBLIC_SESSION_TOKEN]: ST03114EA6C6184A -> ST03114ED2C61896
2012/04/10 14:52:44 falcon     ALARMDEVICE_RESET    0 start..
2012/04/10 14:52:44 falcon     XBEE_TDCP_DATA       0 Device2[0B02,0013A200404AC397] TDCPData = $$$41038,1
2012/04/10 14:52:45 falcon     XBEE_TDCP_DATA       0 Device2[0B02,0013A200404AC397] TDCPData = $$$41168,1
2012/04/10 14:54:30 falcon     XBEE_TDCP_DATA       0 Device2[0B02,0013A200404AC397] TDCPData = $$$,LIVE,0B02,9
2012/04/10 14:59:40 falcon     XBEE_TDCP_DATA       0 Device4[0D04,0013A20040558026] TDCPData = $$$,SAMPLING,0D04,8,FF,168,0,0,0,50
2012/04/10 14:59:40 falcon     REGISTER_ACTIVITY    0 Device4 IR-count = 168 temperature = 12.5
2012/04/10 15:00:00 falcon     SESSION              0 CreateDocument: new session created, token = ST03114F0002EE18 user = guest terminal = falcon webpxyappsvr =
2012/04/10 15:00:00 falcon     USER                 0 LoginUser: login success, user = guest session = ST03114F0002EE18
2012/04/10 15:00:00 falcon     ALARMDEVICE_CLOCK    0 start..
2012/04/10 15:00:00 falcon     USER                 0 LogoutUser: logout success, user = guest session = ST03114F0002EE18
2012/04/10 15:00:32 falcon     UIOUSB_EVENT_DATA    0 COM9 EventData = $$$,SAMPLING,01,0,40,973,761,498
2012/04/10 15:00:32 falcon     UIOUSB_EVENT_DATA    0 温度 19.5℃  明るさ 973
2012/04/10 15:02:44 falcon     ALARMDEVICE_RESET    0 start..
2012/04/10 15:03:44 falcon     SESSION              0 CreateDocument: new session created, token = ST03114F0EC618B0 user =  terminal =  webpxyappsvr =
2012/04/10 15:03:44 falcon     PERIODIC_TIMER       0 renew public session [PUBLIC_SESSION_TOKEN]: ST03114ED2C61896 -> ST03114F0EC618B0
2012/04/10 15:03:44 falcon     XBEE_TDCP_DATA       0 Device2[0B02,0013A200404AC397] TDCPData = $$$35454,1
2012/04/10 15:03:45 falcon     XBEE_TDCP_DATA       0 Device2[0B02,0013A200404AC397] TDCPData = $$$53531,1
2012/04/10 15:04:59 falcon     WEBPROXY             0 command GET /command/json/session_login received from 192.168.100.51:61522
2012/04/10 15:04:59 falcon     SESSION              0 CreateDocument: new session created, token = ST03114F13B69537 user = user terminal = 192.168.100.51 webpxyappsvr =
2012/04/10 15:04:59 falcon     USER                 0 LoginUser: login success, user = user session = ST03114F13B69537
2012/04/10 15:05:00 falcon     WEBPROXY             0 command GET /command/json/script received from 192.168.100.51:61523
2012/04/10 15:05:00 falcon     GET_DEV_STATUS       0 start..
2012/04/10 15:05:07 falcon     WEBPROXY             0 command GET /command/json/script received from 192.168.100.51:61524
2012/04/10 15:05:07 falcon     SET_XBEE_DIO         0 start..

ABS-9000 DeviceServer をインストールすると2つの Windows サービスが登録されるのですが、1つがアプリケーションサービスプログラム本体で、もう一つが専用のログサービスプログラムになっています。

DeviceServer インストール時に登録されるサービス一覧

なぜ2つのサービスに分けてあるかといいますと、サーバーアプリ側が停止するような事態になったときでも、ログにメッセージを確実に残せるようにするためです。また、システムが一度に大量のログメッセージを出力するときに、アプリケーションサーバーの性能に影響を与えないように、ログを処理できるように2段構えで構成されています。

サーバーではない通常のアプリケーションでは、ログ出力はファイルの終端にアペンドしていくような簡単な仕組みで十分なのですが、サーバーシステムなどの複数スレッドから発生するログを、ファイル I/O のみで処理するとアプリケーションのパフォーマンスが低下して、最悪システムがハングしてしまいます。DeviceServer では UDP パケットを使用してログサービスプログラムのメモリ中にメッセージを保存して定期的にファイルに書き出す方法で構築しています。リアルタイムのログについても参照したいことが多いので、本来のログ保存とは別にコンソールにもメッセージを並行して出力できるようにしています。

ログを眺めていると、システムが設計通りに動作しているかが一目で分かりますので、ログ出力をフルに活用してシステムを構築してください。

それではまた。

コメントは受け付けていません。