JP2018005546A - 情報処理装置、プログラム実行状態表示方法およびプログラム実行状態表示プログラム - Google Patents

Abstract

【課題】間欠的なサンプリングログを用いたループ処理の分析を容易にする。
【解決手段】複数の関数１３ｂ，１３ｃ，１３ｄを用いた処理を繰り返すループ１３ａを含む対象プログラム１３を実行したときに算出された先頭時刻１４ａ，１４ｂ，１４ｃ，１４ｄを示す先頭時刻情報１４を取得する。また、間欠的なサンプリングによって生成されたサンプリングログ１５ａ，１５ｂ，１５ｃを取得する。サンプリング時刻１６ａ，１６ｂ，１６ｃを、直前の先頭時刻からの時刻差分１７ａ，１７ｂ，１７ｃに変換する。サンプリングログ１５ａ，１５ｂ，１５ｃを時刻差分区間１８ａ，１８ｂ，１８ｃに分類し、各時刻差分区間について関数１３ｂ，１３ｃ，１３ｄそれぞれの実行が検出された回数をカウントする。カウントした回数を用いて、時刻差分区間１８ａ，１８ｂ，１８ｃと関数１３ｂ，１３ｃ，１３ｄの実行との対応関係を示す時系列情報１８を表示させる。
【選択図】図１

Description

本発明は情報処理装置、プログラム実行状態表示方法およびプログラム実行状態表示プログラムに関する。

アプリケーションプログラムの実行中に、間欠的にプロセッサに割り込みを発生させてサンプリングログを収集し、収集したサンプリングログを用いてアプリケーションプログラムの挙動を分析することがある。例えば、一定周期で割り込みを発生させる機能を有するプロセッサにアプリケーションプログラムを実行させ、割り込みの発生毎に、実行中の命令の命令アドレスなどの状態情報をサンプリングログとして収集することがある。

このようなアプリケーションプログラムの挙動分析を、「タイムベースサンプリングによるプロファイリング」と言うことがある。「タイムベースサンプリングによるプロファイリング」によれば、例えば、収集したサンプリングログを時系列に並べることで、プログラムモジュールの実行順序や所要実行時間などを確認することができる。

一例として、アプリケーションプログラムに含まれる関数の呼び出し状況を解析する解析装置が提案されている。提案の解析装置は、アプリケーションプログラムの実行中、一定周期でプロセッサに割り込みを発生させる。解析装置は、割り込みが発生する毎にメモリのスタック領域から、呼び出し中の関数のアドレスを含む関数呼び出し情報を収集する。解析装置は、収集した関数呼び出し情報に基づいて、各関数がどのタイミングで呼び出されたかを示す時系列情報を表示する。また、解析装置は、収集した関数呼び出し情報に基づいて、各関数が呼び出された回数をカウントして表示する。

特開２０００−２５０７８０号公報

サンプリングログを収集するにあたり、サンプリング間隔を短くした方が、アプリケーションプログラムの挙動を詳細に分析することが可能となる。ただし、メモリ容量などの計算リソースの制限から、サンプリング間隔を短くすることが難しい場合がある。また、サンプリング間隔を短くし過ぎると、サンプリング自体の負荷によって、アプリケーションプログラムの挙動が本来の挙動から変わってしまう可能性がある。そのため、サンプリングログは十分な間隔を空けて収集されることが多い。

しかし、間欠的なサンプリングログをそのままサンプリング時刻の順に並べても、アプリケーションプログラムに含まれるループについては有用な分析結果が得られないことがあるという問題がある。これは、ループ処理の繰り返し周期とサンプリング間隔とがずれる可能性が高く、ループ実行中に収集される各サンプリングログは、ループ内で実行される命令のうちの任意の命令を指し示しているに過ぎないためである。

例えば、ループ内で関数ｆ１，ｆ２，ｆ３を順に呼び出すアプリケーションプログラムを考える。このループ内の処理が繰り返し実行されると、関数ｆ１，ｆ２，ｆ３が繰り返し呼び出されることになる。ループの実行中に間欠的にサンプリングログを収集した場合、１つ目のサンプリング時刻では関数ｆ１、２つ目のサンプリング時刻では関数ｆ３、３つ目のサンプリング時刻では関数ｆ２、４つ目のサンプリング時刻では関数ｆ２が実行中である可能性がある。しかしながら、実行中の関数をサンプリング時刻の順にｆ１，ｆ３，ｆ２，ｆ２，…と並べた分析結果は、ループ内での関数呼び出しの順序を示しているわけではなく、関数ｆ１，ｆ２，ｆ３の所要実行時間を示しているわけでもない。

１つの側面では、本発明は、間欠的なサンプリングログを用いたループ処理の分析が容易となる情報処理装置、プログラム実行状態表示方法およびプログラム実行状態表示プログラムを提供することを目的とする。

１つの態様では、記憶部と表示制御部とを有する情報処理装置が提供される。記憶部は、複数の関数を用いた処理を繰り返すループを含む対象プログラムを実行したときに算出された複数の先頭時刻を示す情報であって、複数の先頭時刻は処理の繰り返し毎における処理の先頭の実行時刻を示している先頭時刻情報を記憶する。また、記憶部は、対象プログラムを実行したときに間欠的なサンプリングによって生成されたログであって、それぞれがサンプリング時刻と複数の関数のうち実行中の関数の特定に用いられる状態情報とを含む複数のサンプリングログを記憶する。表示制御部は、複数のサンプリングログそれぞれのサンプリング時刻を、複数の先頭時刻のうち当該サンプリング時刻の直前の先頭時刻からの時刻差分に変換する。表示制御部は、時刻差分に基づいて複数のサンプリングログを複数の時刻差分区間に分類し、各時刻差分区間について、当該時刻差分区間に属するサンプリングログの状態情報に基づいて複数の関数それぞれの実行が検出された回数をカウントする。表示制御部は、カウントした回数を用いて、時刻差分に従って並べた複数の時刻差分区間と複数の関数の実行との対応関係を示す時系列情報を表示させる。

また、１つの態様では、情報処理装置が実行するプログラム実行状態表示方法が提供される。また、１つの態様では、コンピュータに実行させるプログラム実行状態表示プログラムが提供される。

１つの側面では、間欠的なサンプリングログを用いたループ処理の分析が容易となる。

第１の実施の形態の情報処理装置の例を示す図である。 情報処理装置のハードウェア例を示すブロック図である。 ＣＰＵのハードウェア例を示すブロック図である。 サンプリング情報の第１の可視化例を示す図である。 サンプリング情報の第２の可視化例を示す図である。 サンプリング情報の第３の可視化例を示す図である。 情報処理装置のソフトウェア例を示すブロック図である。 情報処理装置で実行されるプロセスの例を示すブロック図である。 対象プログラムの編集例を示す図である。 サンプリングテーブルの例を示す図である。 先頭時刻テーブルの例を示す図である。 関数判定テーブルの例を示す図である。 ループ実行テーブルの例を示す図である。 可視化テーブルの例を示す図である。 サンプリング制御の手順例を示すフローチャートである。 割り込み処理の手順例を示すフローチャートである。 ループ処理の手順例を示すフローチャートである。 ループ分析の手順例を示すフローチャートである。 ループ分析の手順例を示すフローチャート（続き）である。

以下、本実施の形態を図面を参照して説明する。
［第１の実施の形態］
第１の実施の形態を説明する。

図１は、第１の実施の形態の情報処理装置の例を示す図である。
第１の実施の形態の情報処理装置１０は、対象プログラム１３の挙動を分析する。情報処理装置１０は、例えば、対象プログラム１３のデバッグや運用保守の際に使用される。情報処理装置１０は、ユーザが操作するクライアントコンピュータでもよいし、クライアントコンピュータからアクセスされるサーバコンピュータでもよい。

情報処理装置１０は、記憶部１１および表示制御部１２を有する。記憶部１１は、ＲＡＭ（Random Access Memory）などの揮発性の半導体メモリでもよいし、ＨＤＤ（Hard Disk Drive）やフラッシュメモリなどの不揮発性の記憶装置でもよい。表示制御部１２は、ＣＰＵ（Central Processing Unit）やＤＳＰ（Digital Signal Processor）などのプロセッサでもよい。また、表示制御部１２は、ＡＳＩＣ（Application Specific Integrated Circuit）やＦＰＧＡ（Field Programmable Gate Array）などの特定用途の電子回路を含んでもよい。プロセッサは、ＲＡＭなどのメモリ（記憶部１１でもよい）に記憶されたプログラムを実行する。プロセッサが実行するプログラムには、以下に説明する処理を記載したプログラム実行状態表示プログラムが含まれる。複数のプロセッサの集合を、「マルチプロセッサ」または単に「プロセッサ」と言うこともある。

記憶部１１は、先頭時刻情報１４と、サンプリングログ１５ａ，１５ｂ，１５ｃを含む複数のサンプリングログを記憶する。先頭時刻情報１４および複数のサンプリングログは、対象プログラム１３を実行したときに生成されたものである。

対象プログラム１３は、分析対象のプログラムである。対象プログラム１３は、人間が可読なソースコードでもよいし、機械可読なオブジェクトコードでもよい。対象プログラム１３は、ループ１３ａを含む。ループ１３ａは、関数１３ｂ（ｆ１）、関数１３ｃ（ｆ２）および関数１３ｄ（ｆ３）を含む複数の関数を用いたループ内処理を繰り返す。ここで言う「関数」は、他の処理単位から呼び出し可能なプログラム上の処理単位であればよく、メソッド、手続き、セクションなど他の名称で呼ばれることもある。所定のループ条件が満たされれば、ループ内処理が２回以上繰り返されることがある。関数１３ｂ，１３ｃ，１３ｄは、対象プログラム１３に含まれていてもよい。例えば、ループ内処理１回につき、これら３つの関数が関数１３ｂ、関数１３ｃ、関数１３ｄの順に呼び出される。なお、対象プログラム１３が記憶部１１に記憶されていてもよい。

先頭時刻情報１４は、対象プログラム１３を実行したときに算出された複数の先頭時刻を示す。複数の先頭時刻は、ループ内処理の繰り返し毎におけるループ内処理の先頭の実行時刻を示している。例えば、先頭時刻情報１４は先頭時刻１４ａ，１４ｂ，１４ｃ，１４ｄを示す。先頭時刻１４ａは１回目のループ内処理の先頭の実行時刻、先頭時刻１４ｂは２回目のループ内処理の先頭の実行時刻、先頭時刻１４ｃは３回目のループ内処理の先頭の実行時刻、先頭時刻１４ｄは４回目のループ内処理の先頭の実行時刻である。

先頭時刻情報１４は、情報処理装置１０によって生成されてもよいし、他の情報処理装置によって生成されてもよい。表示制御部１２は、ループ内処理の繰り返し毎にループ内処理の先頭の実行時刻を出力する命令が挿入された対象プログラム１３を起動させることで、先頭時刻情報１４を生成してもよい。例えば、ループ１３ａの中で関数１３ｂ，１３ｃ，１３ｄが順に呼び出される場合、ループ１３ａ内部の先頭など関数１３ｂの呼び出しの前に命令が挿入される。命令の挿入は、ユーザが対象プログラム１３を編集することで行われてもよい。また、命令の挿入は、コンパイラなどのツールを用いて支援されてもよい。また、命令の挿入は、分析ツールによって自動で行われてもよい。命令の挿入はソースコード上で行われてもよいし、オブジェクトコード上で行われてもよい。

サンプリングログ１５ａ，１５ｂ，１５ｃを含む複数のサンプリングログは、対象プログラム１３を実行したときに間欠的なサンプリングによって生成されたログである。例えば、対象プログラム１３の実行中に所定の時間間隔で周期的にサンプリングログが生成される。各サンプリングログは、そのサンプリングログが生成されたサンプリング時刻と、サンプリング時刻において実行中であった関数の特定に用いられる状態情報とを含む。状態情報は、例えば、実行中の命令の命令アドレスを含む。なお、先頭時刻およびサンプリング時刻は、ＯＳ（Operating System）が管理するリアルタイムクロックによって計測されてもよい。また、先頭時刻およびサンプリング時刻は、対象プログラム１３を実行するプロセッサが有するカウンタ（クロックカウンタなど）によって計測されてもよい。

複数のサンプリングログは、情報処理装置１０によって生成されてもよいし、他の情報処理装置によって生成されてもよい。表示制御部１２は、対象プログラム１３を起動させ、対象プログラム１３の実行中に間欠的なサンプリングを行ってもよい。

例えば、サンプリングログ１５ａは、サンプリング時刻１６ａと関数１３ｃを示す状態情報とを含む。サンプリングログ１５ａは、１回目のループ内処理の実行中に生成されている。サンプリングログ１５ｂは、サンプリング時刻１６ｂと関数１３ｄを示す状態情報とを含む。サンプリングログ１５ｂは、２回目のループ内処理の実行中に生成されている。サンプリングログ１５ｃは、サンプリング時刻１６ｃと関数１３ｄを示す状態情報とを含む。サンプリングログ１５ｃは、４回目のループ内処理の実行中に生成されている。

表示制御部１２は、対象プログラム１３の挙動を分析して分析結果を表示させる。分析結果を表示するディスプレイは、情報処理装置１０が備えていてもよいし、情報処理装置１０に直接接続されていてもよいし、情報処理装置１０と通信可能な他の情報処理装置が備えていてもよい。他の情報処理装置が備えるディスプレイに分析結果を表示させる場合、例えば、表示制御部１２はネットワークを介して分析結果データを送信する。

表示制御部１２は、先頭時刻情報１４および複数のサンプリングログを取得する。表示制御部１２は、複数のサンプリングログそれぞれのサンプリング時刻を、先頭時刻情報１４が示す複数の先頭時刻のうち当該サンプリング時刻の直前の先頭時刻からの時刻差分に変換する。あるサンプリング時刻において第Ｎ回目（Ｎは１以上の整数）のループ内処理が実行されていた場合、当該サンプリング時刻は、第Ｎ回目のループ内処理の先頭時刻からのオフセットに変換されることになる。

例えば、表示制御部１２は、サンプリングログ１５ａについて、サンプリング時刻１６ａとその直前の先頭時刻１４ａ（第１回目のループ内処理の先頭時刻）との差を時刻差分１７ａとして算出する。また、表示制御部１２は、サンプリングログ１５ｂについて、サンプリング時刻１６ｂとその直前の先頭時刻１４ｂ（第２回目のループ内処理の先頭時刻）との差を時刻差分１７ｂとして算出する。また、表示制御部１２は、サンプリングログ１５ｃについて、サンプリング時刻１６ｃとその直前の先頭時刻１４ｄ（第４回目のループ内処理の先頭時刻）との差を時刻差分１７ｃとして算出する。

表示制御部１２は、算出した時刻差分に基づいて、複数のサンプリングログを複数の時刻差分区間に分類する。複数の時刻差分区間は、連続する時刻差分（時間軸）を複数区間に分割したものである。例えば、複数の時刻差分区間はそれぞれ所定の時間幅をもつ。分類にあたり、表示制御部１２は、時刻差分の小さい順に複数のサンプリングログを並べ替えてもよい。ここでは、時刻差分１７ｃよりも時刻差分１７ａが大きく、時刻差分１７ａよりも時刻差分１７ｂが更に大きいとする。その場合、表示制御部１２は、サンプリングログ１５ａ，１５ｂ，１５ｃを、時刻差分１７ａ，１７ｂ，１７ｃの小さい順に、サンプリングログ１５ｃ、サンプリングログ１５ａ、サンプリングログ１５ｂと並べ替える。

一例として、複数の時刻差分区間には、時刻差分区間１８ａ，１８ｂ，１８ｃが含まれる。時刻差分区間１８ａは、時刻差分＝０を含む区間である。時刻差分区間１８ｂは、時間軸上で時刻差分区間１８ａに続く区間である。時刻差分区間１８ｃは、時間軸上で時刻差分区間１８ｂに続く区間である。時刻差分１７ａが時刻差分区間１８ｂに属する場合、表示制御部１２は、サンプリングログ１５ａを時刻差分区間１８ｂに分類する。時刻差分１７ｂが時刻差分区間１８ｃに属する場合、表示制御部１２は、サンプリングログ１５ｂを時刻差分区間１８ｃに分類する。時刻差分１７ｃが時刻差分区間１８ａに属する場合、表示制御部１２は、サンプリングログ１５ｃを時刻差分区間１８ａに分類する。

表示制御部１２は、複数の時刻差分区間それぞれについて、当該時刻差分区間に属するサンプリングログの状態情報に基づいて、各関数の実行が検出された回数をカウントする。状態情報が実行中の命令の命令アドレスを含む場合、表示制御部１２は、命令アドレスと関数との対応関係を示す関数情報を参照して実行中の関数を判定してもよい。命令アドレスと関数との対応関係は、ユーザが作成してもよいし、対象プログラム１３を分析することで情報処理装置１０または他の情報処理装置が生成してもよい。

表示制御部１２は、カウントした回数を用いて、時刻差分に従って並べた複数の時刻差分区間と関数１３ｂ，１３ｃ，１３ｄの実行との対応関係を示す時系列情報１８を表示させる。好ましくは、時刻差分の小さい順に複数の時刻差分区間が並べられ、それら複数の時刻差分区間における関数１３ｂ，１３ｃ，１３ｄの実行状態が時系列に表示される。例えば、表示制御部１２は、複数の時刻差分区間それぞれについて、カウントした回数に基づいて、関数１３ｂ，１３ｃ，１３ｄの実行割合を算出する。そして、表示制御部１２は、関数１３ｂ，１３ｃ，１３ｄの実行割合の変化を示す時系列情報１８を表示させる。

一例として、時刻差分区間１８ａに属するサンプリングログは全て関数１３ｂの実行を示し、時刻差分区間１８ｂに属するサンプリングログは全て関数１３ｃの実行を示し、時刻差分区間１８ｃに属するサンプリングログは全て関数１３ｄの実行を示しているとする。この場合、例えば、時刻差分区間１８ａでは関数１３ｂの実行割合が１００％であり、時刻差分区間１８ｂでは関数１３ｃの実行割合が１００％であり、時刻差分区間１８ｃでは関数１３ｄの実行割合が１００％であることを示す時系列情報１８が表示される。これにより、ループ１３ａで行われる１回のループ内処理では、関数１３ｂ，１３ｃ，１３ｄが、関数１３ｂ、関数１３ｃ、関数１３ｄの順に実行されていることが表現される。

第１の実施の形態の情報処理装置１０によれば、ループ内処理の繰り返し毎の先頭時刻を示す先頭時刻情報１４と、対象プログラム１３の実行中に生成されたサンプリングログ１５ａ，１５ｂ，１５ｃとが取得される。先頭時刻情報１４に基づいて、サンプリング時刻１６ａ，１６ｂ，１６ｃが時刻差分１７ａ，１７ｂ，１７ｃに変換され、サンプリングログ１５ａ，１５ｂ，１５ｃが時刻差分区間１８ａ，１８ｂ，１８ｃに分類される。そして、時刻差分区間１８ａ，１８ｂ，１８ｃと関数１３ｂ，１３ｃ，１３ｄの実行との対応関係を示す時系列情報１８が表示される。

これにより、サンプリング時刻１６ａ，１６ｂ，１６ｃの順にサンプリングログ１５ａ，１５ｂ，１５ｃを表示する場合よりも、ループ１３ａ内での関数１３ｂ，１３ｃ，１３ｄの呼び出し順序などの時系列性を適切に表現することができる。また、サンプリングログ１５ａ，１５ｂ，１５ｃを時刻差分区間１８ａ，１８ｂ，１８ｃに分類することで、１回のループ内処理の状態情報を短いサンプリング間隔でサンプリングした場合と同等の効果が得られる。よって、サンプリング間隔が長くてもループ内処理の分析が容易となる。また、サンプリング間隔を長くすることで、メモリなどの計算リソースを節約することができる。また、サンプリング自体が対象プログラム１３の挙動に与える影響を低減でき、対象プログラム１３の挙動の測定精度が向上する。

［第２の実施の形態］
次に、第２の実施の形態を説明する。
図２は、情報処理装置のハードウェア例を示すブロック図である。

第２の実施の形態の情報処理装置１００は、ＣＰＵ１０１、ＲＡＭ１０２、ＨＤＤ１０３、画像信号処理部１０４、入力信号処理部１０５、媒体リーダ１０６および通信インタフェース１０７を有する。情報処理装置１００の上記ユニットは、バス１０８に接続されている。なお、情報処理装置１００は、第１の実施の形態の情報処理装置１０に対応する。ＣＰＵ１０１は、第１の実施の形態の表示制御部１２に対応する。ＲＡＭ１０２またはＨＤＤ１０３は、第１の実施の形態の記憶部１１に対応する。また、情報処理装置１００は、クライアントコンピュータでもよいしサーバコンピュータでもよい。

ＣＰＵ１０１は、プログラムの命令を実行する演算回路を含むプロセッサである。ＣＰＵ１０１は、ＨＤＤ１０３に記憶されたプログラムやデータの少なくとも一部をＲＡＭ１０２にロードし、プログラムを実行する。なお、ＣＰＵ１０１が複数のプロセッサコアを備えてもよいし、情報処理装置１００が複数のプロセッサを備えてもよい。以下で説明する処理を、複数のプロセッサまたはプロセッサコアを用いて並列に実行してもよい。複数のプロセッサの集合（マルチプロセッサ）を「プロセッサ」と言うこともある。

ＲＡＭ１０２は、ＣＰＵ１０１が実行するプログラムやＣＰＵ１０１が演算に用いるデータを一時的に記憶する揮発性の半導体メモリである。なお、情報処理装置１００は、ＲＡＭ以外の種類のメモリを備えてもよいし、複数個のメモリを備えてもよい。

ＨＤＤ１０３は、ＯＳやミドルウェアやアプリケーションソフトウェアなどのソフトウェアのプログラム、および、データを記憶する不揮発性の記憶装置である。プログラムには、プログラム実行状態表示プログラムが含まれる。なお、情報処理装置１００は、フラッシュメモリやＳＳＤなどの他の種類の記憶装置を備えてもよいし、複数の不揮発性の記憶装置を備えてもよい。

画像信号処理部１０４は、ＣＰＵ１０１からの命令に従って、情報処理装置１００に接続されたディスプレイ１１１に画像を出力する。ディスプレイ１１１としては、ＣＲＴ（Cathode Ray Tube）ディスプレイ、液晶ディスプレイ（ＬＣＤ：Liquid Crystal Display）、プラズマディスプレイ、有機ＥＬ（ＯＥＬ：Organic Electro-Luminescence）ディスプレイなど、任意の種類のディスプレイを用いることができる。

入力信号処理部１０５は、情報処理装置１００に接続された入力デバイス１１２から入力信号を取得し、ＣＰＵ１０１に出力する。入力デバイス１１２としては、マウスやタッチパネルやタッチパッドやトラックボールなどのポインティングデバイス、キーボード、リモートコントローラ、ボタンスイッチなどを用いることができる。また、情報処理装置１００に、複数の種類の入力デバイスが接続されていてもよい。

媒体リーダ１０６は、記録媒体１１３に記録されたプログラムやデータを読み取る読み取り装置である。記録媒体１１３として、例えば、磁気ディスク、光ディスク、光磁気ディスク（ＭＯ：Magneto-Optical disk）、半導体メモリなどを使用できる。磁気ディスクには、フレキシブルディスク（ＦＤ：Flexible Disk）やＨＤＤが含まれる。光ディスクには、ＣＤ（Compact Disc）やＤＶＤ（Digital Versatile Disc）が含まれる。

媒体リーダ１０６は、例えば、記録媒体１１３から読み取ったプログラムやデータを、ＲＡＭ１０２やＨＤＤ１０３などの他の記録媒体にコピーする。読み取られたプログラムは、例えば、ＣＰＵ１０１によって実行される。なお、記録媒体１１３は、可搬型記録媒体であってもよく、プログラムやデータの配布に用いられることがある。また、記録媒体１１３やＨＤＤ１０３を、コンピュータ読み取り可能な記録媒体と言うことがある。

通信インタフェース１０７は、ネットワーク１１４に接続され、ネットワーク１１４を介して他の装置と通信を行うインタフェースである。通信インタフェース１０７は、スイッチなどの通信装置とケーブルで接続される有線通信インタフェースでもよいし、基地局と無線リンクで接続される無線通信インタフェースでもよい。

図３は、ＣＰＵのハードウェア例を示すブロック図である。
ＣＰＵ１０１は、命令アドレスレジスタ１２１、タイムスタンプレジスタ１２２、割り込み制御レジスタ１２３、カウントアップレジスタ１２４、割り込み発行部１２５および命令実行部１２６を有する。なお、図３では、ＣＰＵ１０１が有する種々の回路のうち、主にタイムベースサンプリングに関連する回路を示している。

命令アドレスレジスタ１２１は、ＣＰＵ１０１が実行している命令の命令アドレスを記憶する揮発性の記憶回路である。タイムスタンプレジスタ１２２は、ＣＰＵ１０１が起動してからの経過時間を示すタイムスタンプを記憶する揮発性の記憶回路である。タイムスタンプは、所定数のクロックが発生する毎に１ずつカウントアップしていく。

割り込み制御レジスタ１２３は、定期的な割り込みを発生させるか否かを示す割り込み発生フラグを記憶する。割り込み発生フラグがＯＮ（例えば、「１」）であることは、定期的な割り込みを発生させることを示す。割り込み発生フラグがＯＦＦ（例えば、「０」）であることは、定期的な割り込みを発生させないことを示す。割り込み制御レジスタ１２３には、ソフトウェアによって割り込み発生フラグを書き込むことができる。

カウントアップレジスタ１２４は、設定された初期値から始めてカウントアップしていくカウントを記憶する揮発性の記憶回路である。カウントアップレジスタ１２４には、ソフトウェアによってカウントの初期値を書き込むことができる。カウントは、所定数のクロックが発生する毎に１ずつカウントアップしていく。カウントアップレジスタ１２４に記憶可能なカウントには上限値があり、カウントアップによってカウントが上限値を超えると、カウントアップレジスタ１２４にオーバーフローが発生する。

割り込み発行部１２５は、割り込み制御レジスタ１２３に記憶された割り込み発生フラグがＯＮであり、かつ、カウントアップレジスタ１２４にオーバーフローが発生したとき、命令実行部１２６に対して割り込みを発行する。ソフトウェアによってカウントアップレジスタ１２４に書き込まれる初期値を調整することで、所望の周期で割り込み発行部１２５に割り込みを発行させることが可能となる。なお、カウントアップレジスタ１２４には、オーバーフローが発生する毎に初期値を再書き込みすることになる。

命令実行部１２６は、ＲＡＭ１０２からプログラムの命令を読み出し命令を実行する。割り込み発行部１２５が割り込みを発行すると、命令実行部１２６は、現在実行中のアプリケーションプログラムを中断して、所定の割り込みハンドラプログラムを開始する。割り込みハンドラプログラムが終了すると、命令実行部１２６は、直前に実行していたアプリケーションプログラムを再開する。

情報処理装置１００は、上記のＣＰＵ１０１の機能を利用して、「タイムベースサンプリングによるプロファイリング」により対象プログラムの挙動を分析する。すなわち、情報処理装置１００は、ＣＰＵ１０１に定期的に割り込みを発生させ、割り込み発生時に対象プログラムの実行状態を示すサンプリング情報を取得する。情報処理装置１００は、定期的に取得したサンプリング情報を分析し、分析結果をディスプレイ１１１に表示する。第２の実施の形態では主に、対象プログラムに含まれるループの挙動を分析する。

次に、ループの挙動の可視化について説明する。
図４は、サンプリング情報の第１の可視化例を示す図である。
グラフ２１は、タイムスタンプの昇順にサンプリング情報を並べた場合のグラフである。グラフ２１に用いられているタイムスタンプは、ＣＰＵ１０１のタイムスタンプレジスタ１２２に記憶されたタイムスタンプである。ここでは、対象プログラムに含まれるループのループ内処理が１６回以上繰り返し実行されたものとする。

ループ内処理の周期は「１０」である。ループ内処理の１回目（ｉ＝１）は、時刻「１０」に開始されている。ループ内処理の２回目（ｉ＝２）は、時刻「２０」に開始されている。ループ内処理の３回目（ｉ＝３）は、時刻「３０」に開始されている。ループ内処理の４回目（ｉ＝４）は、時刻「４０」に開始されている。ループ内処理の５回目（ｉ＝５）は、時刻「５０」に開始されている。ループ内処理の６回目（ｉ＝６）は、時刻「６０」に開始されている。ループ内処理の７回目（ｉ＝７）は、時刻「７０」に開始されている。ループ内処理の８回目（ｉ＝８）は、時刻「８０」に開始されている。

ループ内処理の９回目（ｉ＝９）は、時刻「９０」に開始されている。ループ内処理の１０回目（ｉ＝１０）は、時刻「１００」に開始されている。ループ内処理の１１回目（ｉ＝１１）は、時刻「１１０」に開始されている。ループ内処理の１２回目（ｉ＝１２）は、時刻「１２０」に開始されている。ループ内処理の１３回目（ｉ＝１３）は、時刻「１３０」に開始されている。ループ内処理の１４回目（ｉ＝１４）は、時刻「１４０」に開始されている。ループ内処理の１５回目（ｉ＝１５）は、時刻「１５０」に開始されている。ループ内処理の１６回目（ｉ＝１６）は、時刻「１６０」に開始されている。

一方、サンプリング周期は「１８」である。サンプリングの１回目は、時刻「１５」に行われている。サンプリングの２回目は、時刻「３３」に行われている。サンプリングの３回目は、時刻「５１」に行われている。サンプリングの４回目は、時刻「６９」に行われている。サンプリングの５回目は、時刻「８７」に行われている。サンプリングの６回目は、時刻「１０５」に行われている。サンプリングの７回目は、時刻「１２３」に行われている。サンプリングの８回目は、時刻「１４１」に行われている。サンプリングの９回目は、時刻「１５９」に行われている。

対象プログラムには、関数ａ，ｂ，ｃ，ｄが含まれている。ループ内処理では、関数ａ，ｂ，ｃ，ｄが呼び出される。時刻「１５」では関数ｃが実行されている。時刻「３３」では関数ｂが実行されている。時刻「５１」では関数ａが実行されている。時刻「６９」では関数ｄが実行されている。時刻「８７」では関数ｃが実行されている。時刻「１０５」では関数ｃが実行されている。時刻「１２３」では関数ｂが実行されている。時刻「１４１」では関数ａが実行されている。時刻「１５９」では関数ｃが実行されている。

しかし、グラフ２１のようにサンプリング情報が示す関数をサンプリング時刻の昇順に並べても、ループ内処理の挙動を理解することは難しい。グラフ２１が示す関数ｃ、関数ｂ、関数ａ、関数ｄ、関数ｃ、関数ｃ、関数ｂ、関数ａ、関数ｃという関数列は、ループ内での関数呼び出しの順序を表しているわけではない。そこで、第２の実施の形態の情報処理装置１００は、グラフ２１と異なる方法でサンプリング情報を可視化する。

図５は、サンプリング情報の第２の可視化例を示す図である。
情報処理装置１００は、各サンプリング情報のサンプリング時刻を、その直前の先頭時刻からの時刻オフセットに変換する。サンプリング時刻の直前の先頭時刻は、サンプリング時点で実行されていたループ内処理の先頭の実行時刻である。サンプリング時点でＮ回目（Ｎは１以上の整数）のループ内処理が実行されていた場合、時刻オフセットは、サンプリング時刻とＮ回目のループ内処理の先頭時刻との差になる。

ここでは、図４と同様のサンプリング情報が取得されたものとする。サンプリング時刻「１５」は、直前の先頭時刻「１０」からの時刻オフセット「５」に変換される。サンプリング時刻「３３」は、直前の先頭時刻「３０」からの時刻オフセット「３」に変換される。サンプリング時刻「５１」は、直前の先頭時刻「５０」からの時刻オフセット「１」に変換される。サンプリング時刻「６９」は、直前の先頭時刻「６０」からの時刻オフセット「９」に変換される。サンプリング時刻「８７」は、直前の先頭時刻「８０」からの時刻オフセット「７」に変換される。

サンプリング時刻「１０５」は、直前の先頭時刻「１００」からの時刻オフセット「５」に変換される。サンプリング時刻「１２３」は、直前の先頭時刻「１２０」からの時刻オフセット「３」に変換される。サンプリング時刻「１４１」は、直前の先頭時刻「１４０」からの時刻オフセット「１」に変換される。サンプリング時刻「１５９」は、直前の先頭時刻「１５０」からの時刻オフセット「９」に変換される。

情報処理装置１００は、サンプリング情報を時刻オフセットの昇順に並び替える。これにより、収集されたサンプリング情報が、概ねループの先頭からの相対位置に応じて並べられることになる。情報処理装置１００は、時刻オフセットを複数のオフセット区間に分割し、オフセット区間毎に関数ａ，ｂ，ｃ，ｄの検出回数をカウントする。その結果、情報処理装置１００は、グラフ２２をディスプレイ１１１に表示する。グラフ２２は、オフセット区間毎に関数ａ，ｂ，ｃ，ｄの検出割合を表した積み上げ棒グラフである。

ここでは、時刻オフセットが幅「２」のオフセット区間に分割されるとする。０以上２未満のオフセット区間には、３番目と８番目のサンプリング情報が分類される。２以上４未満のオフセット区間には、２番目と７番目のサンプリング情報が分類される。４以上６未満のオフセット区間には、１番目と６番目のサンプリング情報が分類される。６以上８未満のオフセット区間には、５番目のサンプリング情報が分類される。８以上１０未満のオフセット区間には、４番目と９番目のサンプリング情報が分類される。

よって、０以上２未満のオフセット区間では、関数ａが１００％の確率で実行されている。２以上４未満のオフセット区間では、関数ｂが１００％の確率で実行されている。４以上６未満のオフセット区間では、関数ｃが１００％の確率で実行されている。６以上８未満のオフセット区間では、関数ｃが１００％の確率で実行されている。８以上１０未満のオフセット区間では、関数ｃが５０％の確率で実行され、関数ｄが５０％の確率で実行されている。グラフ２２によれば、１回のループ内処理における関数ａ，ｂ，ｃ，ｄの呼び出し順序や関数ａ，ｂ，ｃ，ｄの所要実行時間を推定することができる。

なお、サンプリング間隔は、例えば、５０ミリ秒程度とすることが考えられる。また、オフセット区間の幅は、例えば、１ミリ秒程度とすることが考えられる。サンプリング間隔が長い場合であっても、繰り返し回数の多いループについては、実質的にサンプリング間隔を短くした場合と同等の分析結果を得ることができる。

図６は、サンプリング情報の第３の可視化例を示す図である。
ここでは、図４，５とは異なるサンプリング情報が取得され、そのサンプリング情報に基づいて図５の方法に従ってグラフが生成される場合を考える。図６に示すグラフ２３は、図４，５とは異なるサンプリング情報に基づいて生成されたものである。

グラフ２３は、グラフ２２と同様に、オフセット区間毎に関数の検出割合を表した積み上げ棒グラフである。図６の例では、３つの関数の検出割合がグラフ２３に表されている。ループの繰り返し回数を増やすことで、精度の高い時系列データを得ることができる。グラフ２３から、例えば、想定外の関数呼び出しの存在を発見することができる。想定外の関数呼び出しが発見された場合、例えば、その関数呼び出しが発生しないように対象プログラムをデバッグすることが考えられる。また、グラフ２３から、例えば、処理遅延の原因となっているボトルネック関数を発見することができる。ボトルネック関数が発見された場合、例えば、ボトルネック関数の所要実行時間が短くなるように対象プログラムをチューニングすることが考えられる。

次に、情報処理装置１００の機能について説明する。
図７は、情報処理装置のソフトウェア例を示すブロック図である。
情報処理装置１００のＲＡＭ１０２には、情報を一時的に記憶するバッファメモリ領域として先頭時刻バッファ１３１およびサンプリングバッファ１３２が確保される。情報処理装置１００のＨＤＤ１０３には、対象プログラム１３３，１３４、関数判定テーブル１３５、先頭時刻テーブル１３６、サンプリングテーブル１３７、ループ実行テーブル１３８および可視化テーブル１３９が記憶される。また、ＨＤＤ１０３には、プログラム編集プログラム１４１、サンプリング制御プログラム１４２、割り込みハンドラプログラム１４３および分析プログラム１４４が記憶される。ＨＤＤ１０３に記憶されたプログラムおよびテーブルは、使用されるときに一時的にＲＡＭ１０２にロードされることがある。

先頭時刻バッファ１３１は、対象プログラム１３４の実行中に、ループ内処理の先頭のタイムスタンプを一時的に記憶するバッファメモリ領域である。先頭時刻バッファ１３１は、対象プログラム１３４によってＲＡＭ１０２に確保される。サンプリングバッファ１３２は、割り込み発生フラグがＯＮである間に定期的に取得されるサンプリング情報を一時的に記憶するバッファメモリ領域である。サンプリングバッファ１３２は、サンプリング制御プログラム１４２によってＲＡＭ１０２に確保される。

対象プログラム１３３は、分析対象のプログラムであって、プログラミング言語を用いて記述されたソースコードである。対象プログラム１３３は、プログラム編集プログラム１４１によって編集されることがある。対象プログラム１３４は、分析対象のプログラムであって、機械可読なオブジェクトコードである。対象プログラム１３４は、例えば、対象プログラム１３３をコンパイルすることで生成される。

関数判定テーブル１３５は、命令アドレスと関数の対応関係を記憶する。関数判定テーブル１３５を参照することで、ある命令アドレスをもつ命令が何れの関数に含まれる命令であるか特定できる。関数判定テーブル１３５は、ユーザによって作成されてもよいし、プログラム編集プログラム１４１によって自動的に生成されてもよい。

先頭時刻テーブル１３６は、ループ内処理の繰り返し毎に対象プログラム１３４によって出力された、ループ内処理の先頭が実行された時刻である先頭時刻を記憶する。先頭時刻テーブル１３６には、先頭時刻バッファ１３１に一時的に蓄積された情報が転送される。サンプリングテーブル１３７は、ＣＰＵ１０１の割り込み機能を利用して定期的に取得したサンプリング情報を記憶する。サンプリングテーブル１３７には、サンプリングバッファ１３２に一時的に蓄積された情報が転送される。

ループ実行テーブル１３８は、サンプリング情報を分析する過程で生成されるテーブルであり、時刻オフセットと関数の対応関係を記憶する。ループ実行テーブル１３８は、分析プログラム１４４によって生成される。可視化テーブル１３９は、分析結果として、グラフ２２，２３などのグラフの表示に用いられる可視化情報を記憶する。可視化テーブル１３９は、分析プログラム１４４によって生成される。

プログラム編集プログラム１４１は、対象プログラム１３４の実行時に先頭時刻が出力されるように、対象プログラム１３３または対象プログラム１３４を編集するプログラムである。プログラム編集プログラム１４１は、対象プログラム１３３を対象プログラム１３４に変換するコンパイラプログラムを含んでもよい。サンプリング制御プログラム１４２は、編集後の対象プログラム１３４を起動させると共に、対象プログラム１３４の実行中にサンプリングが行われるようＣＰＵ１０１を制御するプログラムである。

割り込みハンドラプログラム１４３は、ＣＰＵ１０１が割り込みを発行したときに呼び出されるプログラムである。割り込みハンドラプログラム１４３が呼び出されると、対象プログラム１３４などのアプリケーションプログラムの実行が一時的に停止し、割り込みハンドラプログラム１４３が優先的に実行される。割り込みハンドラプログラム１４３は、ＯＳに組み込まれていてもよい。割り込みハンドラプログラム１４３は、サンプリング情報を取得するサンプリングプログラムでもある。

分析プログラム１４４は、対象プログラム１３４の終了後にサンプリング情報を分析し、対象プログラム１３４の実行状態を可視化するプログラムである。分析プログラム１４４は、ディスプレイ１１１に情報を表示させる表示プログラムでもある。

プログラム編集プログラム１４１、サンプリング制御プログラム１４２、割り込みハンドラプログラム１４３および分析プログラム１４４は、ＣＰＵ１０１によって実行される。これらプログラムの機能の詳細は後述する。なお、プログラム編集プログラム１４１、サンプリング制御プログラム１４２、割り込みハンドラプログラム１４３および分析プログラム１４４のうちの２以上のプログラムの機能が、１つのプログラムに統合されていてもよい。例えば、サンプリング制御プログラム１４２と分析プログラム１４４が１つに統合されてもよい。また、プログラム編集プログラム１４１とサンプリング制御プログラム１４２と分析プログラム１４４が１つに統合されてもよい。

図８は、情報処理装置で実行されるプロセスの例を示すブロック図である。
情報処理装置１００は、プログラム編集部１５１、サンプリング制御部１５２、割り込みハンドラ１５３および分析部１５４を有する。

プログラム編集部１５１は、ＣＰＵ１０１がプログラム編集プログラム１４１を実行することで生成されるプロセスに対応する。サンプリング制御部１５２は、ＣＰＵ１０１がサンプリング制御プログラム１４２を実行することで生成されるプロセスに対応する。割り込みハンドラ１５３は、ＣＰＵ１０１が割り込みハンドラプログラム１４３を実行することで生成されるプロセスに対応する。分析部１５４は、ＣＰＵ１０１が分析プログラム１４４を実行することで生成されるプロセスに対応する。

以下では、プログラム編集部１５１、サンプリング制御部１５２、割り込みハンドラ１５３および分析部１５４を動作主体として、情報処理装置１００の処理を説明することがある。ただし、動作主体を、プログラム編集プログラム１４１、サンプリング制御プログラム１４２、割り込みハンドラプログラム１４３および分析プログラム１４４を実行するＣＰＵ１０１と読み替えることもできる。

プログラム編集部１５１は、ループ内処理の繰り返し毎に先頭時刻が出力されるように対象プログラム１３３または対象プログラム１３４を編集する。
例えば、プログラム編集部１５１は、ソースコードである対象プログラム１３３をディスプレイ１１１に表示させ、ユーザからソースコードを編集する入力を受け付けると、入力に従って対象プログラム１３３を更新する。プログラム編集部１５１は、ユーザにより編集された対象プログラム１３３をコンパイルして、オブジェクトコードである対象プログラム１３４を生成してもよい。編集された対象プログラム１３３に特殊な定義命令文が含まれる場合、プログラム編集部１５１は、プリプロセッサ機能などを用いて特殊な定義命令文を展開してもよい。また、プログラム編集部１５１は、コンパイル時に所定のデバッグオプションが指定された場合のみ、当該特殊な定義命令文を展開してもよい。

または、プログラム編集部１５１は、ソースコードである対象プログラム１３３を分析して、自動的に対象プログラム１３３に命令文を挿入する。例えば、プログラム編集部１５１は、対象プログラム１３３からループを検出する。ループを示す命令文の形式は、対象プログラム１３３の記述に用いられたプログラミング言語に依存する。プログラム編集部１５１は、検出したループの前に、先頭時刻バッファ１３１をＲＡＭ１０２に確保する命令文を挿入する。プログラム編集部１５１は、検出したループに含まれる命令文の集合の先頭に、その時点のタイムスタンプレジスタ１２２のタイムスタンプ（先頭時刻）を先頭時刻バッファ１３１に格納する命令文を挿入する。また、プログラム編集部１５１は、検出したループの後に、先頭時刻バッファ１３１に記憶されたタイムスタンプを先頭時刻テーブル１３６に出力する命令文を挿入する。プログラム編集部１５１は、自動的に編集された対象プログラム１３３をコンパイルして対象プログラム１３４を生成してもよい。

または、プログラム編集部１５１は、オブジェクトコードである対象プログラム１３４を分析して、自動的に対象プログラム１３４に命令を挿入する。
また、プログラム編集部１５１は、関数判定テーブル１３５を生成する。例えば、プログラム編集部１５１は、ユーザからの入力に従って関数判定テーブル１３５を生成する。例えば、命令アドレスの範囲に対して、ユーザが関数名を指定する。または、プログラム編集部１５１は、対象プログラム１３４を分析して、自動的に関数判定テーブル１３５を生成する。例えば、プログラム編集部１５１は、オブジェクトコードである対象プログラム１３４から関数を検出し、検出した関数の名称と当該関数に含まれる命令群のアドレス範囲を関数判定テーブル１３５に登録する。

サンプリング制御部１５２は、プログラム編集部１５１による編集が反映された対象プログラム１３４を起動させ、対象プログラム１３４の実行中にサンプリングが行われるよう制御する。サンプリング制御部１５２は、対象プログラム１３４の起動前に、サンプリングバッファ１３２をＲＡＭ１０２に確保する。また、サンプリング制御部１５２は、サンプリング間隔に応じた初期値をカウントアップレジスタ１２４に書き込み、割り込み制御レジスタ１２３の割り込み発生フラグをＯＮに設定する。サンプリング制御部１５２は、対象プログラム１３４の終了後、割り込み制御レジスタ１２３の割り込み発生フラグをＯＦＦに設定する。また、サンプリング制御部１５２は、サンプリングバッファ１３２に記憶されたサンプリング情報をサンプリングテーブル１３７に出力する。

割り込みハンドラ１５３は、割り込み発行部１２５が割り込みを発行する毎に実行されるイベントハンドラである。割り込みハンドラ１５３は、命令アドレスレジスタ１２１から命令アドレスを読み出し、タイムスタンプレジスタ１２２からタイムスタンプを読み出す。また、割り込みハンドラ１５３は、情報処理装置１００で実行されているＯＳから、割り込み直前に実行されていたプロセスの識別情報（プロセスＩＤ）を取得する。割り込みハンドラ１５３は、命令アドレスとタイムスタンプとプロセスＩＤとを含むサンプリング情報を、サンプリングバッファ１３２に格納する。

分析部１５４は、対象プログラム１３４の終了後、収集されたサンプリング情報を分析する。分析部１５４は、サンプリングテーブル１３７からサンプリング情報を読み出し、先頭時刻テーブル１３６に登録されたタイムスタンプに基づいて、各サンプリング情報のサンプリング時刻を時刻オフセットに変換する。また、分析部１５４は、関数判定テーブル１３５に登録された関数名とアドレス範囲に基づいて、各サンプリング情報に含まれる対象プログラム１３４の命令アドレスを関数名に変換する。分析部１５４は、時刻オフセットと関数名をループ実行テーブル１３８に登録する。

分析部１５４は、ループ実行テーブル１３８に登録された関数名を時刻オフセットの昇順に並べ替える。分析部１５４は、時刻オフセットを複数のオフセット区間に分割し、オフセット区間毎に当該オフセット区間で検出された関数を特定し、関数名をカウントすることで関数の検出割合を算出する。分析部１５４は、オフセット区間と関数の検出割合を含む可視化情報を可視化テーブル１３９に登録する。そして、分析部１５４は、可視化テーブル１３９に登録された可視化情報に基づいて、グラフ２２，２３のような積み上げ棒グラフを生成しディスプレイ１１１に表示させる。

図９は、対象プログラムの編集例を示す図である。
ここでは、理解を容易にするため、ソースコードである対象プログラム１３３を編集する場合を考える。このような対象プログラム１３３をコンパイルすることで、先頭時刻を出力する対象プログラム１３４を生成することができる。図９に示す命令文の挿入は、ユーザ入力によって行われてもよいし、プログラム編集部１５１が自動で行ってもよい。

図９に示す例では、対象プログラム１３３はループと関数ａ，ｂ，ｃ，ｄを含む。ここで言う「関数」には、メソッドや手続きなど他の名称で呼ばれる処理単位も含まれる。ループ内では、関数ａ，ｂ，ｃ，ｄが順に呼び出される。図９ではｆｏｒ文を用いてループを表現しているが、ｗｈｉｌｅ文など他の制御文を用いてループを表現してもよい。

編集後の対象プログラム１３３は、ループの前に、先頭時刻バッファ１３１を定義する命令文と、先頭時刻バッファ１３１に自身のプロセスＩＤを格納する命令文を含んでいる。また、編集後の対象プログラム１３３は、ループ内の先頭、すなわち、関数ａを呼び出す関数呼び出し文の前に、先頭時刻バッファ１３１にタイムスタンプを格納する命令文を含んでいる。図９では、ｒｄｔｓｃ（）というＡＰＩ（Application Programming Language）を用いることで、タイムスタンプレジスタ１２２の値が参照されるものとしている。ループ内の先頭の命令文は、ループ内処理が繰り返される毎に実行される。図９の例では、先頭時刻バッファ１３１にタイムスタンプを格納する命令文は１６回実行される。

また、編集後の対象プログラム１３３は、ループの後に、先頭時刻バッファ１３１に記憶されたデータをファイルに出力する命令文を含んでいる。以上の追加命令文は、ユーザまたはプログラム編集部１５１によって対象プログラム１３３に挿入された命令文であり、オリジナルの対象プログラム１３３に含まれていなかった命令文である。

図１０は、サンプリングテーブルの例を示す図である。
サンプリングテーブル１３７は、プロセスＩＤ、タイムスタンプおよび命令アドレスの項目を含む。プロセスＩＤの項目には、割り込みの直前に実行されていたプロセスの識別情報が登録される。第２の実施の形態では、プロセスＩＤとして主に、対象プログラム１３４から起動されたプロセスのプロセスＩＤを想定している。タイムスタンプの項目には、サンプリング時刻を示すタイムスタンプが登録される。命令アドレスの項目には、割り込みの直前に実行されていた命令の命令アドレスが登録される。

図１１は、先頭時刻テーブルの例を示す図である。
先頭時刻テーブル１３６は、プロセスＩＤと複数のタイムスタンプを列挙した配列である。先頭時刻テーブル１３６のプロセスＩＤは、先頭時刻テーブル１３６のタイムスタンプを出力したプロセスの識別情報、すなわち、対象プログラム１３４から起動されたプロセスの識別情報である。先頭時刻テーブル１３６のタイムスタンプは、対象プログラム１３４によって出力された、ループ内処理の先頭における先頭時刻を示す。

図１２は、関数判定テーブルの例を示す図である。
関数判定テーブル１３５は、プログラムＩＤ、関数名およびアドレス範囲の項目を有する。プログラムＩＤの項目には、対象プログラム１３４の識別情報が登録される。プログラムＩＤは、プロセスＩＤと同じでもよいし異なってもよい。後者の場合、例えば、情報処理装置１００で実行されているＯＳからプログラムＩＤとプロセスＩＤの対応関係を取得することで、プログラムＩＤとプロセスＩＤを紐付けることができる。

関数名の項目には、対象プログラム１３４に含まれる関数の名称が登録される。関数名は、対象プログラム１３３または対象プログラム１３４を分析することで自動的に抽出されてもよい。アドレス範囲の項目には、関数に含まれる命令群の命令アドレスの範囲、すなわち、関数の先頭の命令アドレスと関数の末尾の命令アドレスが登録される。命令アドレスは、オブジェクトコードである対象プログラム１３４内のアドレスである。

図１３は、ループ実行テーブルの例を示す図である。
ループ実行テーブル１３８には、サンプリングテーブル１３７のレコード（サンプリング情報）に対応するレコードが登録される。ループ実行テーブル１３８は、プロセスＩＤ、時刻オフセットおよび関数名の項目を有する。プロセスＩＤの項目には、サンプリングテーブル１３７と同様のプロセスＩＤが登録される。時刻オフセットの項目には、サンプリング情報のタイムスタンプから変換された時刻オフセットが登録される。関数名の項目には、サンプリング情報の命令アドレスが属する関数の関数名が登録される。

すなわち、サンプリングテーブル１３７のタイムスタンプが、先頭時刻テーブル１３６に基づいて時刻オフセットに変換される。サンプリングテーブル１３７に複数のプロセスのサンプリング情報が混在している場合、分析部１５４は、所望のプロセスについてのサンプリング情報をサンプリングテーブル１３７から抽出してもよい。サンプリングテーブル１３７の情報と先頭時刻テーブル１３６の情報とは、プロセスＩＤによって紐付けることができる。複数の対象プログラムに対応する複数の先頭時刻テーブルが存在する場合、分析部１５４は、プロセスＩＤに基づいて、複数の先頭時刻テーブルのうち所望のプロセスについての先頭時刻テーブルを選択するようにしてもよい。

また、サンプリングテーブル１３７の命令アドレスが、関数判定テーブル１３５に基づいて関数名に変換される。サンプリングテーブル１３７の情報と関数判定テーブル１３５の情報とは、プロセスＩＤとプログラムＩＤによって紐付けることができる。複数の対象プログラムに対応する複数の関数判定テーブルが存在する場合、分析部１５４は、プログラムＩＤに基づいて、複数の関数判定テーブルのうち所望の対象プログラムについての関数判定テーブルを選択するようにしてもよい。なお、ループ実行テーブル１３８に含まれる複数のレコードは、時刻オフセットの昇順にソートされる。

図１４は、可視化テーブルの例を示す図である。
可視化テーブル１３９は、プロセスＩＤ、オフセット区間および関数割合の項目を有する。プロセスＩＤの項目には、対象プログラム１３４から起動されたプロセスのプロセスＩＤが登録される。オフセット区間の項目には、時刻オフセットの範囲、すなわち、オフセット区間の始点の時刻オフセットと終点の時刻オフセットが登録される。図１４の例では、０以上１０未満の時刻オフセットが、０以上２未満、２以上４未満、４以上６未満、６以上８未満、８以上１０未満の５個のオフセット区間に分割されている。関数割合の項目には、実行が検出された関数の関数名と当該関数の検出割合とが登録される。関数割合は、ループ実行テーブル１３８の関数名をカウントすることで算出できる。なお、可視化テーブル１３９に含まれる複数のレコードは、オフセット区間の昇順にソートされる。

次に、情報処理装置１００の処理手順について説明する。
図１５は、サンプリング制御の手順例を示すフローチャートである。
サンプリング制御の処理は、プログラム編集プログラム１４１およびサンプリング制御プログラム１４２を実行することで実現される。

（Ｓ１０）ここでは、プログラム編集部１５１がソースコードである対象プログラム１３３を編集する場合を考える。プログラム編集部１５１は、対象プログラム１３３を分析し、対象プログラム１３３に含まれるループを検出する。ループは、例えば、ｆｏｒ文やｗｈｉｌｅ文を用いて対象プログラム１３３に記載されている。ただし、対象プログラム１３３の中から、分析対象のループをユーザが選択してもよい。

（Ｓ１１）プログラム編集部１５１は、ステップＳ１０で検出したループの前に、先頭時刻バッファ１３１を定義する命令文（領域確保の命令文）を挿入する。例えば、先頭時刻バッファ１３１を示す変数を宣言するようにする。また、プログラム編集部１５１は、検出したループの前に、先頭時刻バッファ１３１にプロセスＩＤを追記する命令文を挿入する。ただし、ループ前への命令文の挿入は、ユーザが手作業で行ってもよい。

（Ｓ１２）プログラム編集部１５１は、ステップＳ１０で検出したループ内の先頭位置に、タイムスタンプレジスタ１２２のタイムスタンプを先頭時刻バッファ１３１に追記する命令文（時刻記録の命令文）を挿入する。ループ内の先頭位置の命令文は、ループ内処理の繰り返し毎に最初に実行される命令文である。ただし、先頭時刻を記録する命令文の挿入は、ユーザが手作業で行ってもよい。

（Ｓ１３）プログラム編集部１５１は、ステップＳ１０で検出したループの後に、先頭時刻バッファ１３１に記憶されたデータをＨＤＤ１０３上のファイルに書き出す命令文（ファイル出力の命令文）を挿入する。出力先ファイルは、先頭時刻テーブル１３６である。ただし、ファイル出力の命令文の挿入は、ユーザが手作業で行ってもよい。

プログラム編集部１５１は、例えば、上記のようにして編集された対象プログラム１３３をコンパイルすることで、対象プログラム１３４を生成する。
（Ｓ１４）プログラム編集部１５１は、対象プログラム１３４を分析し、対象プログラム１３４に含まれる複数の関数を検出する。ただし、対象プログラム１３４の中から、分析対象の関数をユーザが選択するようにしてもよい。

（Ｓ１５）プログラム編集部１５１は、ステップＳ１４で検出した複数の関数それぞれについて、対象プログラム１３４の中で当該関数が存在する位置を示すアドレス範囲を算出する。プログラム編集部１５１は、対象プログラム１３４のプログラムＩＤと関数名とアドレス範囲を、関数判定テーブル１３５に登録する。ただし、関数名は、ソースコードである対象プログラム１３３を参照して抽出するようにしてもよい。また、関数名とアドレス範囲の対応付けを、ユーザが手作業で行ってもよい。

以上のようにして対象プログラム１３４と関数判定テーブル１３５が用意されると、サンプリング情報の収集を開始することが可能となる。このとき、ユーザがサンプリング制御部１５２を起動するコマンドを情報処理装置１００に入力してもよい。

（Ｓ１６）サンプリング制御部１５２は、ＣＰＵ１０１のカウントアップレジスタ１２４を初期化する。すなわち、サンプリング制御部１５２は、初期値をカウントアップレジスタ１２４に書き込む。初期値は、ＣＰＵ１０１のアーキテクチャや動作クロック周波数、所望のサンプリング間隔などを考慮して予め決めておく。初期値が小さいほど、カウントアップレジスタ１２４がオーバーフローするまでの時間が長くなり、サンプリング間隔が大きくなる。初期値が大きいほど、カウントアップレジスタ１２４がオーバーフローするまでの時間が短くなり、サンプリング間隔が小さくなる。

（Ｓ１７）サンプリング制御部１５２は、サンプリングバッファ１３２をＲＡＭ１０２に確保する。また、サンプリング制御部１５２は、ＣＰＵ１０１の割り込み制御レジスタ１２３に記憶された割り込み発生フラグを、ＯＮ（例えば、「１」）に書き換える。これにより、割り込み発行部１２５が定期的に割り込みを発行することになる。

（Ｓ１８）サンプリング制御部１５２は、ＣＰＵ１０１に、ステップＳ１１〜Ｓ１３の編集が反映された対象プログラム１３４を起動させる。
（Ｓ１９）サンプリング制御部１５２は、対象プログラム１３４の終了を検出する。対象プログラム１３４の終了は、例えば、対象プログラム１３４から生成されたプロセスが消滅したことによって検出することができる。

（Ｓ２０）サンプリング制御部１５２は、ＣＰＵ１０１の割り込み制御レジスタ１２３に記憶された割り込み発生フラグを、ＯＦＦ（例えば、「０」）に書き換える。これにより、割り込み発行部１２５は割り込みの発行を停止することになる。

（Ｓ２１）サンプリング制御部１５２は、ステップＳ１７とＳ２０の間にサンプリングバッファ１３２に格納されたデータを、ＨＤＤ１０３上のファイルに書き出す。出力先ファイルは、サンプリングテーブル１３７である。

図１６は、割り込み処理の手順例を示すフローチャートである。
割り込み発行部１２５が割り込みを発行する毎に、図１６の処理が実行される。割り込み処理は、割り込みハンドラプログラム１４３を実行することで実現される。

（Ｓ３０）割り込みハンドラ１５３は、カウントアップレジスタ１２４でオーバーフローが発生したことによる割り込みを検出する。
（Ｓ３１）割り込みハンドラ１５３は、情報処理装置１００で実行されているＯＳから、割り込みの直前に実行されていたプロセスのプロセスＩＤを取得する。

（Ｓ３２）割り込みハンドラ１５３は、ＣＰＵ１０１の命令アドレスレジスタ１２１から命令アドレスを取得する。また、割り込みハンドラ１５３は、ＣＰＵ１０１のタイムスタンプレジスタ１２２からタイムスタンプを取得する。

（Ｓ３３）割り込みハンドラ１５３は、取得したプロセスＩＤと命令アドレスとタイムスタンプとを含むサンプリング情報を、サンプリングバッファ１３２に追記する。
（Ｓ３４）割り込みハンドラ１５３は、ＣＰＵ１０１のカウントアップレジスタ１２４を初期化する。すなわち、割り込みハンドラ１５３は、初期値をカウントアップレジスタ１２４に書き込む。書き込む初期値は、前述のステップＳ１６と同じでよい。

図１７は、ループ処理の手順例を示すフローチャートである。
ＣＰＵ１０１が対象プログラム１３４を起動することで、図１７の処理が実行される。ループ処理は、対象プログラム１３４を実行することで実現される。

（Ｓ４０）命令実行部１２６は、対象プログラム１３４に従い、先頭時刻バッファ１３１をＲＡＭ１０２に確保する。また、命令実行部１２６は、対象プログラム１３４に従い、自身のプロセスＩＤを取得して先頭時刻バッファ１３１に追記する。

（Ｓ４１）命令実行部１２６は、対象プログラム１３４に従い、ループ内処理の繰り返しを継続するか判定する。例えば、命令実行部１２６は、ループ変数の値が閾値未満であることなどの判定条件を満たしているか確認し、判定条件を満たす場合に繰り返しを継続すると判定し、判定条件を満たさない場合に繰り返しを継続しないと判定する。

（Ｓ４２）命令実行部１２６は、ステップＳ４１において、ループ内処理の繰り返しを継続しない（ループから抜ける）と判定したか判断する。ループから抜ける場合はステップＳ４６に処理が進み、ループから抜けない場合はステップＳ４３に処理が進む。

（Ｓ４３）命令実行部１２６は、対象プログラム１３４に従い、ＣＰＵ１０１のタイムスタンプレジスタ１２２からタイムスタンプを取得する。
（Ｓ４４）命令実行部１２６は、対象プログラム１３４に従い、ステップＳ４３で取得したタイムスタンプを先頭時刻バッファ１３１に追記する。

（Ｓ４５）命令実行部１２６は、対象プログラム１３４に従い、ステップＳ４４より後の命令をループの末尾まで実行する。そして、ステップＳ４１に処理が進む。
（Ｓ４６）命令実行部１２６は、対象プログラム１３４に従い、先頭時刻バッファ１３１に記憶されているデータを、ＨＤＤ１０３上のファイルに書き出す。出力先ファイルは、先頭時刻テーブル１３６である。

図１８は、ループ分析の手順例を示すフローチャートである。
上記の図１５のサンプリング制御が終わった後、図１８の処理が実行される。ループ分析は、分析プログラム１４４を実行することで実現される。

（Ｓ５０）分析部１５４は、先頭時刻テーブル１３６に含まれるタイムスタンプから、分析対象のループが実行されていた時間範囲を算出する。例えば、分析部１５４は、先頭時刻テーブル１３６に含まれるタイムスタンプのうち、最小のタイムスタンプを時間範囲の先頭とし、最大のタイムスタンプを時間範囲の末尾とする。

（Ｓ５１）分析部１５４は、サンプリングテーブル１３７に含まれるレコード（サンプリング情報）を１つ選択する。なお、分析部１５４は、あるサンプリング情報に含まれるプロセスＩＤが所望のプロセス（対象プログラム１３４に関するプロセス）のプロセスＩＤでない場合、当該サンプリング情報を無視してもよい。

（Ｓ５２）分析部１５４は、ステップＳ５１で選択したレコードのタイムスタンプ（サンプリング時刻）が、ステップＳ５０で算出した時間範囲に入っているか判断する。サンプリング時刻が時間範囲に入っている場合はステップＳ５３に処理が進み、サンプリング時刻が時間範囲に入っていない場合はステップＳ５７に処理が進む。

（Ｓ５３）分析部１５４は、先頭時刻テーブル１３６から、サンプリング時刻の直前の先頭時刻を検索する。すなわち、分析部１５４は、先頭時刻テーブル１３６から、サンプリング時刻より小さいタイムスタンプの中で最大のものを検索する。なお、複数の対象プログラムに対応する複数の先頭時刻テーブルが存在する場合、分析部１５４は、所望の対象プログラムに対応する先頭時刻テーブル以外のテーブルを無視してもよい。

（Ｓ５４）分析部１５４は、ステップＳ５３で検索した先頭時刻を用いて、サンプリング時刻を時刻オフセットに変換する。すなわち、分析部１５４は、サンプリング時刻から先頭時刻を引いた値（両者の差を示す０以上の値）を時刻オフセットとする。

（Ｓ５５）分析部１５４は、関数判定テーブル１３５から、ステップＳ５１で選択したサンプリング情報の命令アドレスが属するアドレス範囲を検索し、検索されたアドレス範囲に対応する関数名を取得する。なお、分析部１５４は、関数判定テーブル１３５に含まれるレコードのうち、対象プログラム１３４のプログラムＩＤ以外のプログラムＩＤをもつレコードを無視してもよい。

（Ｓ５６）分析部１５４は、サンプリング情報の命令アドレスを関数名に変換する。分析部１５４は、対象プログラム１３４に対応するプロセスＩＤと時刻オフセットと関数名とを含むレコードを、ループ実行テーブル１３８に登録する。

（Ｓ５７）分析部１５４は、ステップＳ５１においてサンプリングテーブル１３７に含まれる全てのサンプリング情報を選択したか判断する。全てのサンプリング情報を選択した場合はステップＳ５８に処理が進み、それ以外の場合はステップＳ５１に処理が進む。

（Ｓ５８）分析部１５４は、ループ実行テーブル１３８に含まれるレコードを、時刻オフセットの昇順にソートする。
なお、分析部１５４は、プロセスＩＤやプログラムＩＤを用いて、関数判定テーブル１３５、先頭時刻テーブル１３６およびサンプリングテーブル１３７から不要なレコードをフィルタリングしてもよい。これにより、ＣＰＵ１０１が複数のプロセスを並行に実行する場合であっても、着目するループに限定して分析することができる。

図１９は、ループ分析の手順例を示すフローチャート（続き）である。
（Ｓ５９）分析部１５４は、時刻オフセットを複数のオフセット区間に分割する。サンプリング間隔やオフセット区間は、予め決めておく。例えば、サンプリング間隔を５０ミリ秒、オフセット区間の幅を１ミリ秒とする。

（Ｓ６０）分析部１５４は、オフセット区間を１つ選択する。
（Ｓ６１）分析部１５４は、ループ実行テーブル１３８から、ステップＳ６０で選択したオフセット区間に時刻オフセットが入っているレコードを検索する。分析部１５４は、検索されたレコードの中で各関数名の出現回数をカウントする。

（Ｓ６２）分析部１５４は、ステップＳ６１でカウントした出現回数に基づいて、各関数名の出現割合を算出する。例えば、分析部１５４は、各関数名の出現回数を当該オフセット区間に属するレコードの総数で割る。分析部１５４は、対象プログラム１３４に対応するプロセスＩＤとオフセット区間と各関数名の出現割合とを含むレコードを、可視化テーブル１３９に登録する。

（Ｓ６３）分析部１５４は、ステップＳ６０において全てのオフセット区間を選択したか判断する。全てのオフセット区間を選択した場合はステップＳ６４に進み、未選択のオフセット区間がある場合はステップＳ６０に処理が進む。

（Ｓ６４）分析部１５４は、可視化テーブル１３９のオフセット区間を横軸とし、可視化テーブル１３９の関数割合を縦軸とするグラフ領域を生成する。横軸に並べる複数のオフセット区間は、時刻オフセットの昇順にソートされる。例えば、横軸の最も左側に位置するオフセット区間は、時刻オフセット＝０を含むオフセット区間であり、ループの先頭付近の実行状態に対応する。また、例えば、横軸の最も右側に位置するオフセット区間は、ループの末尾付近の実行状態に対応する。

（Ｓ６５）分析部１５４は、ステップＳ６４で生成したグラフ領域内において、オフセット区間毎に各関数名の出現割合を表した積み上げ棒グラフを生成する。分析部１５４は、積み上げ棒グラフをディスプレイ１１１に表示させる。積み上げ棒グラフは、例えば、棒の高さの合計を１００％とし、各関数の実行割合に応じて各関数に棒の高さを割り当てたものである。これにより、ループの先頭から末尾に向かって、最も実行割合の大きい関数の時系列変化を把握することが容易となる。

第２の実施の形態の情報処理装置１００によれば、ループ内処理の繰り返し毎に先頭時刻が出力されるように対象プログラム１３４が生成され、対象プログラム１３４が起動される。対象プログラム１３４の実行中、ＣＰＵ１０１の割り込み機能を用いて一定周期でサンプリング情報が収集される。先頭時刻に基づいてサンプリング時刻が時刻オフセットに変換されると共に、サンプリング情報に含まれる命令アドレスから実行中の関数が判定される。そして、時刻オフセットと実行中の関数の対応関係が表示される。

これにより、単にサンプリング時刻の順に関数名を列挙する場合よりも、ループ内での関数の呼び出し順序などの時系列性を適切に表現することができる。また、サンプリング時刻順でなく時刻オフセット順にサンプリング情報を並べ替えることで、１回のループ内処理の実行状態を短いサンプリング間隔でサンプリングした場合と同等の分析結果を表示できる。よって、サンプリング間隔が長くてもループ内処理の分析が容易となる。また、サンプリング間隔を長くすることで、ＣＰＵ１０１の能力やＲＡＭ１０２の容量などの計算リソースを節約できる。また、サンプリング自体が対象プログラム１３４の挙動に与える影響を低減でき、対象プログラム１３４の挙動の分析精度が向上する。

１０ 情報処理装置
１１ 記憶部
１２ 表示制御部
１３ 対象プログラム
１３ａ ループ
１３ｂ，１３ｃ，１３ｄ 関数
１４ 先頭時刻情報
１４ａ，１４ｂ，１４ｃ，１４ｄ 先頭時刻
１５ａ，１５ｂ，１５ｃ サンプリングログ
１６ａ，１６ｂ，１６ｃ サンプリング時刻
１７ａ，１７ｂ，１７ｃ 時刻差分
１８ 時系列情報
１８ａ，１８ｂ，１８ｃ 時刻差分区間

Claims (6)

1. 複数の関数を用いた処理を繰り返すループを含む対象プログラムを実行したときに算出された複数の先頭時刻を示す情報であって、前記複数の先頭時刻は前記処理の繰り返し毎における前記処理の先頭の実行時刻を示している先頭時刻情報と、
   前記対象プログラムを実行したときに間欠的なサンプリングによって生成されたログであって、それぞれがサンプリング時刻と前記複数の関数のうち実行中の関数の特定に用いられる状態情報とを含む複数のサンプリングログと、
   を記憶する記憶部と、
   前記複数のサンプリングログそれぞれの前記サンプリング時刻を、前記複数の先頭時刻のうち当該サンプリング時刻の直前の先頭時刻からの時刻差分に変換し、
   前記時刻差分に基づいて前記複数のサンプリングログを複数の時刻差分区間に分類し、各時刻差分区間について、当該時刻差分区間に属するサンプリングログの前記状態情報に基づいて前記複数の関数それぞれの実行が検出された回数をカウントし、
   カウントした前記回数を用いて、前記時刻差分に従って並べた前記複数の時刻差分区間と前記複数の関数の実行との対応関係を示す時系列情報を表示させる、
   表示制御部と、
   を有する情報処理装置。
2. 前記表示制御部は、前記複数の時刻差分区間それぞれについて前記複数の関数の実行割合を算出し、前記時系列情報として前記実行割合の時系列変化を表示させる、
   請求項１記載の情報処理装置。
3. 前記表示制御部は、前記処理の繰り返し毎に前記処理の先頭の実行時刻を出力する命令が挿入された前記対象プログラムを起動させることで、前記先頭時刻情報を生成する、
   請求項１記載の情報処理装置。
4. 前記表示制御部は、前記対象プログラムを起動させ、前記対象プログラムの実行中に前記間欠的なサンプリングを行うことで前記複数のサンプリングログを生成する、
   請求項１記載の情報処理装置。
5. 情報処理装置が実行するプログラム実行状態表示方法であって、
   複数の関数を用いた処理を繰り返すループを含む対象プログラムを実行したときに算出された複数の先頭時刻を示す情報であって、前記複数の先頭時刻は前記処理の繰り返し毎における前記処理の先頭の実行時刻を示している先頭時刻情報を取得し、
   前記対象プログラムを実行したときに間欠的なサンプリングによって生成されたログであって、それぞれがサンプリング時刻と前記複数の関数のうち実行中の関数の特定に用いられる状態情報とを含む複数のサンプリングログを取得し、
   前記複数のサンプリングログそれぞれの前記サンプリング時刻を、前記複数の先頭時刻のうち当該サンプリング時刻の直前の先頭時刻からの時刻差分に変換し、
   前記時刻差分に基づいて前記複数のサンプリングログを複数の時刻差分区間に分類し、各時刻差分区間について、当該時刻差分区間に属するサンプリングログの前記状態情報に基づいて前記複数の関数それぞれの実行が検出された回数をカウントし、
   カウントした前記回数を用いて、前記時刻差分に従って並べた前記複数の時刻差分区間と前記複数の関数の実行との対応関係を示す時系列情報を表示させる、
   プログラム実行状態表示方法。
6. コンピュータに、
   複数の関数を用いた処理を繰り返すループを含む対象プログラムを実行したときに算出された複数の先頭時刻を示す情報であって、前記複数の先頭時刻は前記処理の繰り返し毎における前記処理の先頭の実行時刻を示している先頭時刻情報を取得し、
   前記対象プログラムを実行したときに間欠的なサンプリングによって生成されたログであって、それぞれがサンプリング時刻と前記複数の関数のうち実行中の関数の特定に用いられる状態情報とを含む複数のサンプリングログを取得し、
   前記複数のサンプリングログそれぞれの前記サンプリング時刻を、前記複数の先頭時刻のうち当該サンプリング時刻の直前の先頭時刻からの時刻差分に変換し、
   前記時刻差分に基づいて前記複数のサンプリングログを複数の時刻差分区間に分類し、各時刻差分区間について、当該時刻差分区間に属するサンプリングログの前記状態情報に基づいて前記複数の関数それぞれの実行が検出された回数をカウントし、
   カウントした前記回数を用いて、前記時刻差分に従って並べた前記複数の時刻差分区間と前記複数の関数の実行との対応関係を示す時系列情報を表示させる、
   処理を実行させるプログラム実行状態表示プログラム。

Images