「ソフテックだより」では、ソフトウェア開発に関する情報や開発現場における社員の取り組みなどを定期的にお知らせしています。
さまざまなテーマを取り上げていますので、他のソフテックだよりも、ぜひご覧下さい。
ソフテックだより(発行日順)のページへ
ソフテックだより 技術レポート(技術分野別)のページへ
ソフテックだより 現場の声(シーン別)のページへ
近年のマイコンを利用したシステムは、大規模かつ複雑になってきており、トラブル解析・調査が非常に難しくなってきております。
そのため、トラブル解析・調査をサポートするような仕組みが必要になってきました。
その仕組みが有効であれば、解析・調査時間の短縮につながり、システム開発時だけでなくエンドユーザーにとっても大きなメリットとなります。
幸いなことに以前のシステムと比べて、メモリの容量が大きくなり情報を保存する余裕が生まれてきています。そこを有効に使うため、パソコンソフトウェアのように数種類のログを保存して、トラブル解析に役立てるようにしました。
今回は、それぞれのログの有効な使用法を紹介します。
なお、本文で出てくるトラブル解析とは、ソフトの不具合解析だけでなく、ソフトの問題かハードの問題かの切り分けや仕様通りの動作になっているのか確認する作業も含んでいます。
ログによって目的が異なり、主にトラブル解析に使われるものやトラブル解析よりも平常時の履歴を確認するために使われるものなどがあります。
それぞれどのようなログ内容で、どのようなときに使われるか説明します。
システムで操作や制御などのイベントが発生したときに記録を行います。
監視システムの場合は、仕様として、具備されていることが多いログ機能です。
ログに残す内容は、機能仕様に記載されているような基本的な機能がほとんどです。
システム動作ログは、平常時でも使われることがありますが、トラブル解析時には、初期段階で使うことが多いです。
ログに残すことによって、そのデータをもとにそのときの状況を話し合うことで、的確な情報伝達ができるようになります。そうすることで、この段階で問題の動作を想像することができます。
また、ログの結果と仕様動作を比較して、仕様確認を行うときにも使います。
<例>
No | 日時 | 機能分類 | その他情報 |
---|---|---|---|
000220 | 2011/05/17 10:15:00 | システム起動 | |
000221 | 2011/05/17 10:15:00 | ○○制御 | 実行 |
000222 | 2011/05/17 10:15:00 | ステップ1実行 | |
000223 | 2011/05/17 10:17:00 | ステップ2実行 | |
000224 | 2011/05/17 10:17:02 | ○○停止 | 停止操作 |
000225 | 2011/05/17 10:20:00 | ○○異常 | 発生 |
イメージとしては、パソコンソフトのデバッグで使うTRACE文と同じですが、特に異常を検出したときのログを残すようにしています。
ログ内容は、開発時に担当者が考えます。一見デバッグ機能と考えてしまう人もいるかもしれませんが、ポイントを絞った効率の良い解析を行うことが可能になります。
システム動作だけでは、原因がつかめないときに有効でより詳細な内容を記録しています。時には、ソフトは正しく動作していて、ハードに問題がある場合もログの内容から読み取れる時もあります。
原因がわからない場合でも、発生要因をより詳しく知ることができるので、次の手段を考えやすくなります。
<例>
No | 日時 | メッセージ |
---|---|---|
001423 | 2011/10/13 15:17:00 | CTRL_ERROR_ RX |
001424 | 2011/10/13 15:17:10 | ○○_CONFIG_ERROR |
001425 | 2011/10/13 15:17:30 | ○○_RETRY_COUNT 1 |
001426 | 2011/10/13 15:17:30 | ○○○_TIMEOUT |
001427 | 2011/10/13 15:17:30 | ○○_RETRY_COUNT 2 |
001428 | 2011/10/13 15:17:30 | ○○○_COUNT_ERROR |
メイン基板とサブ基板で構成されるシステムの基板間の通信履歴やシステム−システム間の通信履歴があります。
送信、受信のタイミングで通信データをログに残します。
通信といってもプロトコルによって、内容が様々ですので、ログに残す際は解析しやすいようにする工夫が必要です。
小さいシステムですと目で見ればどのように動作しているか予測できそうですが、システムが大規模になるにつれ、様々な機器、システムと通信を行うようになり、目で見ただけでは、全く分からなくなります。
そのようなときに、一度ログファイルにして確認することによって、どのような処理・動作を行っているかが見えてきます。
<例>
No | 日時 | 送信/受信 | コマンド | データ |
---|---|---|---|---|
021455 | 2011/11/01 20:33:00 | S | A1 | 000001 |
021456 | 2011/11/01 20:33:00 | R | A1 | |
021457 | 2011/11/01 20:33:30 | R | B1 | 01 |
021458 | 2011/11/01 20:33:30 | S | B1 | 048801 |
021459 | 2011/11/01 20:34:00 | S | C1 | 02 |
021460 | 2011/11/01 20:34:00 | S | C1 | 02 |
021461 | 2011/11/01 20:34:00 | S | C1 | 02 |
021462 | 2011/11/01 20:34:00 | S | C1 | 02 |
なにかしらトラブルが発生したとき、内容に応じてログを使い分けて、トラブル解析に有効活用しています。
ここでは、実例を交えつつ解析方法を説明します。
トラブル解析のはじめに行う情報収集(操作内容、制御内容、システム状態の確認)は、基本的にそのときのエンドユーザーの記憶頼りになってしまう問題があります。また、電話やメールで状況を確認しても情報が不足していて肝心な部分が伝わらないなどすれ違いが生じてしまいます。
問題の原因を突き止めるというより、問題動作の確認や再現手順の確認に使うことが多いです。
ある機能が正常に動作しないという問題が発生したとき、最初は、メールや電話などで連絡を受けます。連絡を受けたとおりに動作させても再現せず、システム動作ログを確認したところ、不足部分がありその条件を合わせたところ、すぐに再現したということがありました。
複数の要因が絡む通信異常が発生した時にシステム動作ログからは、前後の操作・制御と通信異常になったタイミング(日時)しかわかりません。
手順通りに動作させても再現しない場合は、ログから内部の状況を確認して、どのような異常を検出しているか、通信異常の監視開始から異常確定までの内部動作を確認することができます。
リトライなどの通信異常要因を検出したときに異常検出ログに残すようにしておりました。
規定回数リトライを続けない限り、システム動作ログ上では、通信異常になりませんが、異常検出ログでは、1回毎のリトライが記録されており、内在している通信処理の問題部分を早期に発見することができました。
その他、複雑な機能では、正常に動作しないときに内部のデータ管理をログに残して、確認することによって、順を追って問題の解析が行えます。
特に、リアルタイムOS(RTOS)を使ったシステムでは、ログに残すことでタスクごとの動きを時系列で追いかけることができます。
単体動作では問題がなく、負荷をかけた時に問題があり、想定できていない状態、順序で処理が行われているときがありました。このときは、異常検出ログからどのタスクで異常となっているのか根本問題の解析ができ適切な対応を行うことができました。
ログの内容からソースのどの部分で問題が出たか特定できるので、調査プロセスを短縮できます。
システムで目に見えていなかった部分を見えるようにしているので、システムとしては、問題にならない小さな問題を開発時に見つけることができます。このように小さな問題から対応を行うことによって、大きな問題を生み出しにくくなり、システムの品質の向上にもつながります。
解析・調査用として、トラブル時には一番活躍します。
通信間の異常の確認をするときに通信ログを確認することで、どちら側に問題があるか確認することができます。
このときに問題がありそうな部分として、入力基板、入出力管理基板、出力基板がありました。このようなときは、入力から出力されるまでの順を追って問題がある部分を切り分けることができます。
通信が絡むときは、システムの動作ログと通信ログの動作を比較して、状況を的確に認識するために使います。
今回は、「トラブルの解析のため」ということでログ保存について、紹介しました。ログは、トラブル解析には優れておりますが、マイコンで実現する場合に以下のような課題もあります。
上記のような考慮は必要ですが、それでもメリットのほうが多いと感じております。
システムによっては、使えないかもしれませんが、性能面で余裕があるシステムでしたらメモリを増やしてでもお薦めしたい機能です。
(T.M.)
関連ページへのリンク
関連するソフテックだより