組み込みデバイスやIoTデバイスに対する処理作業を軽減するにつれて、アプリケーション内部の動きが見えなくなることがよくあります。 シェルターミナル、モニタ、キーボード、またはデバッガを介してデバイスにアクセスできない場合もあります。そのため、問題が発生してから数分～数時間経つまで障害に気付かない可能性もあります。
デバイスの正常性を保つためには、システムの状態をいつでも追跡および監視することで、ソフトウェアの問題を認知する必要があります。以前の記事でも述べたように、システムリソースを監視することで、リソース不足によって引き起こされるアプリケーションの不具合を最適化および防止することができます。 しかし、ソフトウェアの問題を識別するのに役立つ別のデータ源があります。それは、OSによって生成されたシステムログです。
この記事では、簡単にシステムログを監視する方法をお伝えします。
目次
- システムログとは
- システムログの監視方法
- 無料便利ツール「psymon」とは？
- psymonの無料ダウンロード・インストールはこちら
- psymonでシステムログを監視する方法
- psymonを使用する上での詳細ガイド
システムログとは
システムログはOSによって収集され、システムレベルの問題のトラブルシューティングに役立ちます。システムログには起動/シャットダウン、デバイスエラー、ドライバー、カーネルエラー、セキュリティ警告、デーモンプロセスログ、パッケージインストール等が含まれます。
これらのシステムログには、特定のアプリケーションに関する情報は含まれていないかもしれません。しかし、システムレベルのエラーがアプリケーションの不具合の間接的な原因になっている可能性があるのです。
たとえば、IoTデバイス上でhttpサーバーを実行した際、予期せずページ配信が停止になることがあります。/var/log/kern.logを確認すると、ネットワークアダプタが切断されたことを示す次のエントリが表示されます。
Jun 18 13:08:34 ubuntu NetworkManager[1113]:
[1560830914.2483] device (ens33): link disconnected (deferring action for 4 seconds)
Jun 18 13:08:34 ubuntu kernel: [ 8448.677912] e1000: ens33 NIC Link is Down
Jun 18 13:08:38 ubuntu NetworkManager[1113]:[1560830918.6801] device (ens33): link disconnected (calling deferred action)
システムログの監視方法
最近では、ログを統合して第三者分析およびデータストアと互換性のある出力を生成するのに役立つ、フル機能のログコレクター（例：fluentd、Beats）が多数存在します。エンタープライズレベルのサーバーで実行されているアプリケーションの一般的なシステムレベルのログ監視において、これらのツールが役立ちます。
組み込み環境では、プロセスの実行開始から終了までの間だけシステムログを監視する簡易なソリューションの方が適していることもあります。多くの場合、すべてのシステムログを無差別に収集することには意味がないため、プロセスが実行されている間のログエントリのみに注目していればよいです。そこで、プロセスの実行中に生成されたログエントリのみを追跡するのに役立つ「psymon」という無料ツールご紹介します。
無料便利ツール「psymon」とは？
psymonはUNIXベースのコマンドラインプログラムで、プログラム実行中に生成された新たなシステムログを自動で監視します。たとえば、ウェブサーバー起動後のすべてのログエントリーを監視したい場合は、次のコマンドを実行します。
psymon --logs ./my_web_server
psymon --logsから始まるコマンドを実行すると、プログラム実行中に生成された新たなシステムログを自動で定期的に監視します。
psymonの無料ダウンロード・インストールはこちら
psymonの無料最新版は下記のリンクからダウンロードできます：
https://bintray.com/psygig/releases/psyiage
詳しいインストール方法は上記リンク内の「Readme」をご覧ください。
psymonでシステムログを監視する方法
psymonを使えば、psymon --logsをコマンドの先頭に追加するだけで、アプリケーションの実行中に生成されたシステムログを簡単に記録することができます。
psymon --logs [command-to-run-your-program]
デフォルトでは、psymonはログエントリをJSONファイルに記録します。ただし、psymonはHTTPエンドポイント、MQTTトピック、CSVファイルなどの他の送信先およびフォーマットにログを記録するよう設定できます。これにより、組み込みアプリケーションのリモートモニタリングが可能になります。
psymonを使って収集されたログデータを含むサンプルJSONファイルは次の通りです。
"Logs": [
{
"FilePath": "/var/log/auth.log",
"Entries": [
{
"Duration": 5.011246204,
"Timestamp": 1561448608.770021677,
"TimeOfDay": "2019-06-25 16:43:28.770021677",
"LogFile": "/var/log/auth.log",
"LogText": "Jun 25 16:43:28 ubuntu sudo: pam_unix(sudo:session): session opened for user root by (uid=0)"
},
{
"Duration": 6.013681889,
"Timestamp": 1561448609.772457361,
"TimeOfDay": "2019-06-25 16:43:29.772457361",
"LogFile": "/var/log/auth.log",
"LogText": "Jun 25 16:43:29 ubuntu sudo: pam_unix(sudo:session): session closed for user root"
}
]
},
{
"FilePath": "/var/log/kern.log",
"Entries": [
{
"Duration": 6.014132977,
"Timestamp": 1561448609.772908449,
"TimeOfDay": "2019-06-25 16:43:29.772908449",
"LogFile": "/var/log/kern.log",
"LogText": "Jun 25 16:43:29 ubuntu NetworkManager[1113]:[1561448609.0488] device (lo): link disconnected"
}
]
},
{
"FilePath": "/var/log/messages",
"Entries": [
{
"Duration": 6.014571190,
"Timestamp": 1561448609.773346663,
"TimeOfDay": "2019-06-25 16:43:29.773346662",
"LogFile": "/var/log/messages",
"LogText": "Jun 25 16:43:29 ubuntu NetworkManager[1113]:[1561448609.0488] device (lo): link disconnected"
},
]
}
]
psymonを使用する上での詳細ガイド
リソースの監視以外にも、psymonには下記の便利機能があります。
- コードプロファイリング
- クラッシュレポート
- ログ監視
- システム情報収集
- アラート報告
上記で紹介した機能に加えて、psymonは組み込みアプリケーションの品質と安定性を向上するための便利機能を備えています。詳しい機能内容については、psymon公式ページ（https://bintray.com/psygig/releases/psyiage#）をご覧ください。
この記事を書いた人｜キース
アイスホッケーとお笑いをこよなく愛するみんなのムードメーカー、キース。サイギグの共同創業者兼チーフエンジニア。カナダ・バンクーバー出身。カナダの名門ブリティッシュコロンビア大学卒。SonyのPlayStationのハード/ソフト開発をリードしてきた組み込みエンジニア。カナダ出身なだけあって、平日の夜はアイスホッケーを楽しむスポーツマン。一時期ブルゾンちえみにハマっていた。プライベートは謎に包まれていることが多いため、最近の生態（マイブーム）は誰も知らない。
[English Below]
Monitor system logs for unusual activity in your embedded Linux applications
As we offload more processing work towards embedded or IoT devices, we often lose some visibility in the inner workings of the application. We may not have access to the device via a shell terminal, monitor, keyboard, or debugger. As such, we may not be aware of a failure until minutes or hours after it happened.
In order to ensure the health of the device, we need to track and monitor the state of the system at any given time, to identify any issues in the software.
As mentioned in a previous post, monitoring system resources will help us optimize and prevent failures in our applications caused by resource starvation. There is, however, another source of data to help identify issues in our software. These are system logs generated by the operating system.
What are system logs?
System logs are collected by the operating system, to help troubleshoot system-level issues. This includes bootup/shutdown events, device errors, driver events, kernel errors, security alerts, daemon process logs, package installation events.
While they may not contain information pertaining to our specific application, a system-level error may be the indirect cause to our application failure.
For example, we might run an http server on our IoT device which unexpectedly stops serving pages. After looking at the /var/log/kern.log, we would see the following entries indicating that our network adapter was disconnected.
Jun 18 13:08:34 ubuntu NetworkManager[1113]:
[1560830914.2483] device (ens33): link disconnected (deferring action for 4 seconds)
Jun 18 13:08:34 ubuntu kernel: [ 8448.677912] e1000: ens33 NIC Link is Down
Jun 18 13:08:38 ubuntu NetworkManager[1113]:[1560830918.6801] device (ens33): link disconnected (calling deferred action)
How do I monitor system logs?
There are many full-featured log collectors available (eg. fluentd, Beats) that help consolidate logs and produces output compatible with 3rd party analysis and data stores. For generic, system-level log monitoring of applications running on enterprise-level servers, these tools work well.
For embedded environments, we may want to look at a more lightweight solution that monitors system logs specific to the lifetime of a process. In many cases, it does not make sense to collect all system logs indiscriminately; we may only be interested in log entries while our process is running. There is one tool, psymon, that will help us track only the log entries that were generated during the lifetime of the process.
What is psymon?
psymon is a UNIX-based command line program that automatically monitors the system logs for new entries during the lifetime of our program. For example, if we want to monitor all log entries after starting our web server, we may run the following command
psymon --logs ./my_web_server
Running our command prefixed with psymon --logs will periodically monitor the system logs for new log entries for the lifetime of the program
Downloading and installing psymon
psymon is a free tool that you can get the latest version here:
https://bintray.com/psygig/releases/psyiage
Follow the instructions in the Readme to install.
Using psymon to monitor system logs
Logging system logs generated while our application is running is simple, as all we need to do is prepend the command with psymon --logs
psymon --logs [command-to-run-your-program]
By default, psymon will record log entries to a JSON file. However, psymon can be configured to log to other destinations and formats such as HTTP endpoints, MQTT topics, CSV file, etc. This enables the possibility of remote monitoring of our embedded applications.
Here is a sample JSON file containing the collected log data:
"Logs": [
{
"FilePath": "/var/log/auth.log",
"Entries": [
{
"Duration": 5.011246204,
"Timestamp": 1561448608.770021677,
"TimeOfDay": "2019-06-25 16:43:28.770021677",
"LogFile": "/var/log/auth.log",
"LogText": "Jun 25 16:43:28 ubuntu sudo: pam_unix(sudo:session): session opened for user root by (uid=0)"
},
{
"Duration": 6.013681889,
"Timestamp": 1561448609.772457361,
"TimeOfDay": "2019-06-25 16:43:29.772457361",
"LogFile": "/var/log/auth.log",
"LogText": "Jun 25 16:43:29 ubuntu sudo: pam_unix(sudo:session): session closed for user root"
}
]
},
{
"FilePath": "/var/log/kern.log",
"Entries": [
{
"Duration": 6.014132977,
"Timestamp": 1561448609.772908449,
"TimeOfDay": "2019-06-25 16:43:29.772908449",
"LogFile": "/var/log/kern.log",
"LogText": "Jun 25 16:43:29 ubuntu NetworkManager[1113]:[1561448609.0488] device (lo): link disconnected"
}
]
},
{
"FilePath": "/var/log/messages",
"Entries": [
{
"Duration": 6.014571190,
"Timestamp": 1561448609.773346663,
"TimeOfDay": "2019-06-25 16:43:29.773346662",
"LogFile": "/var/log/messages",
"LogText": "Jun 25 16:43:29 ubuntu NetworkManager[1113]:[1561448609.0488] device (lo): link disconnected"
},
]
}
]
Advanced instrumentation using psymon
Other than resource monitoring, psymon includes other instrumentation features such as:
- Code profiling
- Crash reporting
- Metrics monitoring
- System information collection
- Alert reporting
Take a look at the official psymon documentation page to see if any other the instrumentation features would be beneficial to improving the quality and robustness of your embedded applications.