5.1.1 関数呼び出しトレース
この関数呼び出しトレースを使用すると、処理の実行状況や、関数呼び出し時の引数の値を容易 に知ることができます。実際にデバッグ支援機能を使用して、さきほど作成したサンプルプログ ラムを動かしてみます。
(例として、『23ページ 3.2 GP-IB機器へのデータ送信』で作成したサンプルを使用します)
関数呼び出しトレースを指定して、ドライバを組み込みます。
(‘=’の前後にスペースは要りません)
# insmod rcp4304 rcp4304_debuglevel=1
次にI/Oモジュールの初期化、データ送信を行うモジュール(sendtask.o)を組み込みます。
# insmod sendtask.o
現段階では、PciGpibExInitBoard関数,PciGpibExSetIfc関数,PciGpibExSetRen関数,PciGpibExSendData 関数が3回呼び出されているはずです。
それでは、ログを確認してみましょう。
# less /var/log/messages
･･･
Jul 15 11:16:47 localhost kernel: init_module called
Jul 15 11:16:47 localhost kernel: rcp4304:PciGpibExInitBoard(0, 0) Jul 15 11:16:47 localhost kernel: Board open success!! [0]
Jul 15 11:16:47 localhost kernel: rcp4304:PciGpibExSetIfc(0, 1) Jul 15 11:16:47 localhost kernel: Set IFC success!! [0]
Jul 15 11:16:47 localhost kernel: rcp4304:PciGpibExSetRen(0) Jul 15 11:16:47 localhost kernel: Set REN success!! [0]
Jul 15 11:16:47 localhost kernel: send_task called arg=0
Jul 15 11:16:47 localhost kernel: rcp4304:PciGpibExSendData(0, [0xc69b94dc], 4, [0xc69b94e4], [0x0])
Jul 15 11:16:47 localhost kernel: SendData success!![0, *RST]
Jul 15 11:16:47 localhost kernel: rcp4304:PciGpibExSendData(0, [0xc69b94dc], 4, [0xc69b94e9], [0x0])
Jul 15 11:16:47 localhost kernel: SendData success!![0, *CLS]
Jul 15 11:16:47 localhost kernel: rcp4304:PciGpibExSendData(0, [0xc69b94dc], 20, [0xc69b94ee], [0x0])
Jul 15 11:16:47 localhost kernel: SendData success!![0, DISPlay:TEXT 'HELLO']
(END)
ログにもPciGpibExInitBoard関数,PciGpibExSetIfc関数,PciGpibExSetRen関数,PciGpibExSendData関 数が3回、順番に呼び出されていることが分かります。ログ中の[ ]で表されている部分は、引数が ポインタの場合の変数のアドレスを示しています。
次に組み込んだsendtask.oを取り外してみます。
# rmmod sendtask
ログを見てみます。PciGpibExFinish関数が呼び出されていることが分かります。
# less /var/log/messages
･･･
Jul 15 11:24:19 localhost kernel: cleanup_module called
Jul 15 11:24:19 localhost kernel: rcp4304:PciGpibExFinishBoard(0) Jul 15 11:24:19 localhost kernel: Board close success!! [0]
(END)
以上のように、関数が呼ばれた順番にログが残されています。
5.1.2 エラー情報
エラー情報を出力するように設定しておくと、関数のエラーコードよりも詳細なエラー情報を出 力します。
では、エラー情報出力を指定してドライバを組み込みます。
# insmod rcp4304 rcp4304_debuglevel=2
『List 5-1 sendtask.c』を以下のように修正してください。
この修正は、ulPrimaryAddressの値を異常な値に設定し、エラーを起こさせます。
List 5-1 sendtask.c修正
7386 87 88 89 90 91 92 93 94 95 96
72行目の後に挿入＞
GPIB_CONFIG cfg;
85行目の後に挿入＞
ret = PciGpibExGetConfig(GPIB_BOARDNO, &cfg);
if(ret){
rtl_printf("Get Config error[%d]:ret=%d¥n", GPIB_BOARDNO, ret);
return -1;
} cfg.ulPrimaryAddress = -1;
ret = PciGpibExSetConfig(GPIB_BOARDNO, &cfg);
if(ret){
rtl_printf("Set Config error[%d]:ret=%d¥n", GPIB_BOARDNO, ret);
return -1;
}
コンパイルしてモジュールを組み込んでください。
# make
# insmod sendtask.o
sendtask.o: init_module: 許可されていない操作です
Hint: insmod errors can be caused by incorrect module parameters, including invalid IO or IRQ parameters
エラーが出てドライバモジュールを組み込むことができません。
それでは、ログを見ます。
# less /var/log/message
Jul 15 13:49:30 localhost kernel: init_module called
Jul 15 13:49:30 localhost kernel: Board open success!! [0]
Jul 15 13:49:30 localhost kernel: rcp4304:PciGpibExSetConfig:
ulPrimaryAddress parameter error
Jul 15 13:49:30 localhost kernel: Set Config error[0]:ret=-2
最後の行には、プログラム中で記述した部分が表示され、エラーコードより、引数パラメータの 値が不正であることがわかります。さらに、その上の行を見ると、
ulPrimaryAddress parameter error
という文字が残されているため、ulPrimaryAddressメンバのパラメータ指定が間違っていることが
分かります。5.1.3 I/Oモジュールリソース情報
I/Oモジュールのリソースが正常かどうかを見ることにより、ソフトウェアが原因かハードウェア
が原因かを知ることができます。では、I/Oモジュールリソース情報を出力するようにしてみましょう。
# insmod rcp4304 rcp4304_debuglevel=4
I/Oモジュールリソース情報は、ドライバを組み込んだ時点で出力されます。
ではログを見てみましょう。
# less /var/log/messages
Jul 15 16:26:07 localhost kernel: rcp4304:DeviceNo0:
DeviceID=0x10d0, SubsystemID=0x1, RevisionID=0x1 Jul 15 16:26:07 localhost kernel: rcp4304:DeviceNo0:
I/O address=0xd400, Irq=3
拡張スロットに実装されているrcp4301/4304が対応しているPCII/Oモジュールのリソースが表示 されます。
項 目 内 容
DeviceNo
デバイス番号DeviceID
デバイスIDSubsystemID
サブシステムIDRevisionID
リビジョンIDI/O address
I/OポートアドレスIrq
割り込み番号この値が異常の場合(I/Oポートアドレスや割り込み番号が0と表示された場合)は、ハードウェアに 問題が発生していることも考えられます。
5.1.4 バスコマンド送信情報
I/Oモジュールから送信されるバスコマンド(インタフェース・メッセージ)情報を出力します。バ
スコマンドの送信データサイズ,送信データの先頭3バイトを16進数で出力します。では、バスコマンド送信情報を出力してみましょう。
# insmod rcp4304 rcp4304_debuglevel=16
sendtask.oを組み込みます。
# insmod sendtask.o
ログを見てみましょう。
# less /var/log/messages
Jul 15 14:07:12 localhost kernel: init_module called
Jul 15 14:07:12 localhost kernel: Board open success!! [0]
Jul 15 14:07:12 localhost kernel: Set IFC success!! [0]
Jul 15 14:07:12 localhost kernel: Set REN success!! [0]
Jul 15 14:07:12 localhost kernel: send_task called arg=0
Jul 15 14:07:12 localhost kernel: rcp4304:Send Command:length=3 data=3f 40 36
Jul 15 14:07:12 localhost kernel: SendData success!![0, *RST]
Jul 15 14:07:12 localhost kernel: rcp4304:Send Command:length=3 data=3f 40 36
Jul 15 14:07:12 localhost kernel: SendData success!![0, *CLS]
Jul 15 14:07:12 localhost kernel: rcp4304:Send Command:length=3 data=3f 40 36
Jul 15 14:07:12 localhost kernel: SendData success!![0, DISPlay:TEXT 'HELLO']
送信したバスコマンドのデータ長と先頭3バイトが表示されています。
5.1.5 データ送信情報
I/Oモジュールから送信されるデータの送信サイズと、データの先頭4バイトを16進数で出力しま
す。では、データ送信情報を出力してみましょう。
# insmod rcp4304 rcp4304_debuglevel=32
sendtask.oを組み込みます。
# insmod sendtask.o
ログを見てみましょう。
# less /var/log/messages
Jul 15 14:24:43 localhost kernel: init_module called
Jul 15 14:24:43 localhost kernel: Board open success!! [0]
Jul 15 14:24:43 localhost kernel: Set IFC success!! [0]
Jul 15 14:24:43 localhost kernel: Set REN success!! [0]
Jul 15 14:24:43 localhost kernel: send_task called arg=0
Jul 15 14:24:43 localhost kernel: rcp4304:Send Data:length=4 data=
2a 52 53 54
Jul 15 14:24:43 localhost kernel: SendData success!![0, *RST]
Jul 15 14:24:43 localhost kernel: rcp4304:Send Data:length=4 data=
2a 43 4c 53
Jul 15 14:24:43 localhost kernel: SendData success!![0, *CLS]
Jul 15 14:24:43 localhost kernel: rcp4304:Send Data:length=20 data=44 49 53 50
Jul 15 14:24:43 localhost kernel: SendData success!![0, DISPlay:TEXT 'HELLO']
sendtask.oでは、“*RST”,“*CLS”,“DISPlay:TEXT “HELLO”という3つのコマンドを送信しています。
ログの結果では、最初に送信されたデータは、データ長4で先頭4バイトのデータが2ah(*),52h(R),
53h(S),54h(T)となっています(ASCIIコード)。
次に送信されたデータは、同じくデータ長が4で先頭4バイトのデータが、2ah(*),43h(C),4ch(L),
53h(S)となっています。
最後に送信されたデータは、データ長が20で先頭4バイトのデータが、44h(D),49h(I),53h(S),50h(P) となっています。
5.1.6 データ受信情報
I/Oモジュールが受信するデータの受信サイズと、データの先頭4バイトを16進数で出力します。
『37ページ
4.1 周期的にデータの送受信を行う』で作成した、周期的なデータ送受信プログラ
ムを使用して、デバッグ情報を確認してみましょう。#insmod rcp4304 rcp4304_debuglevel=64
pt_transtask.oを組み込み、Linuxプロセスを実行します。
# insmod pt_transtask.o
# ./pt_datadisp_app
Linuxプロセスが以下のように受信データを出力し、プログラムが終了しました。
# ./pt_datadisp_app
…
7. recv data = +6.54310000E-05 8. recv data = +6.69950000E-05 9. recv data = +6.32500000E-05
datadisp_app: now sending commands to stop RT-tasks fd_cmd:0
fd_result:0
The Linux proccess is successfully completed.
それではログを見てみましょう。
# less /var/log/messages
･･･
Jul 15 14:31:43 localhost kernel: rcp4304:Receive Data:length=15 data=2b 36 2e 36
Jul 15 14:31:43 localhost kernel: RecvData success [0, 15, +6.69950000E-05]
Jul 15 14:31:43 localhost kernel: send_data called [MEASure:VOLTage:DC?]
Jul 15 14:31:43 localhost kernel: send_data success!! [ret=0]
Jul 15 14:31:44 localhost kernel: rcp4304:Receive Data:length=15 data=2b 36 2e 33
Jul 15 14:31:44 localhost kernel: RecvData success [0, 15, +6.32500000E-05]
Jul 15 14:31:44 localhost kernel: send_data called [MEASure:VOLTage:DC?]
Jul 15 14:31:44 localhost kernel: my_handler called fifo=1 Jul 15 14:31:44 localhost kernel: my_handler: get command id=1 Jul 15 14:31:44 localhost kernel: send_data success!! [ret=0]
Jul 15 14:31:44 localhost kernel: rcp4304:Receive Data:length=15 data=2b 36 2e 35
Jul 15 14:31:44 localhost kernel: RecvData success [0, 15, +6.58250000E-05]
Jul 15 14:31:44 localhost kernel: trans_task: get command id=1 Jul 15 14:31:44 localhost kernel: trans_task: stop transfer
最初のログは、受信データ長15、先頭4バイトが2bh(+),36h(6),2eh(.),36h(6)となっています(ASCII コード)。次のログは、同じく受信データ長15,先頭4バイトが2bh(+),36h(6),2eh(.),33h(3)となってい ます。
5.1.7 GP-IB バスライン情報
GP-IBバスライン情報出力のデバッグレベルを指定することによって、関数終了時のGP-IBバスラ
インの状態を出力します。では、GP-IBバスライン情報を出力してみましょう。
# insmod rcp4304 rcp4304_debuglevel=128
sendtask.oを組み込みます。
# insmod sendtask.o
ログを見てみましょう。
# less /var/log/messages
Jul 15 14:41:38 localhost kernel: init_module called
Jul 15 14:41:38 localhost kernel: rcp4304:GP-IB bus line:[EOI]
Jul 15 14:41:38 localhost kernel: Board open success!! [0]
Jul 15 14:41:38 localhost kernel: rcp4304:GP-IB bus line:[ATN][NDAC]
Jul 15 14:41:38 localhost kernel: Set IFC success!! [0]
Jul 15 14:41:38 localhost kernel: rcp4304:GP-IB bus line:
[ATN][NDAC][REN]
Jul 15 14:41:38 localhost kernel: Set REN success!! [0]
Jul 15 14:41:38 localhost kernel: send_task called arg=0
Jul 15 14:41:38 localhost kernel: rcp4304:GP-IB bus line:[NDAC][REN]
Jul 15 14:41:38 localhost kernel: SendData success!![0, *RST]
Jul 15 14:41:38 localhost kernel: rcp4304:GP-IB bus line:[NDAC][REN]
Jul 15 14:41:38 localhost kernel: SendData success!![0, *CLS]
Jul 15 14:41:38 localhost kernel: rcp4304:GP-IB bus line:[NDAC][REN]
Jul 15 14:41:38 localhost kernel: SendData success!![0, DISPlay:TEXT 'HELLO']
GP-IBバスラインの状態が出力されています。
★GP-IBバスライン情報について
GP-IB バスライン情報は、各関数終了時のバスの状態を出力します。従って、上記のように、GP-IB バ
スライン情報だけを出力したのでは、どの関数終了時のバスの状態なのかが分かりません。そのため、
GP-IB バスライン情報を出力する場合は、関数呼び出しトレースと組み合わせて使うと有効であるとい
えます。
また、例外としてPciGpibExFinishBoard関数呼び出し時のGP-IBバスラインの情報は、既に
I/O モジュールの使用を終了しているため、出力されませんのでご注意ください。これは次に述べる
GP-IBファンクションステータス情報についても同じことが言えます。
5.1.8 GP-IB ファンクションステータス情報
GP-IBファンクションステータス情報出力のデバッグレベルを指定することによって、関数終了時
のソースハンドシェークファンクション、アクセプタハンドシェークファンクションを出力しま す。では、GP-IBファンクションステータス情報を出力してみましょう。
# insmod rcp4301 rcp4301_debuglevel=256
s
endtask.oを組み込みます。
# insmod sendtask.o
ログを見てみましょう。
Jun 5 09:56:11 localhost kernel: rcp4301:GP-IB function status:SIDS AIDS Jun 5 09:56:11 localhost kernel: rcp4301:GP-IB function status:SGNS ACRS Jun 5 09:56:11 localhost kernel: rcp4301:GP-IB function status: SGNS ACRS Jun 5 09:56:11 localhost kernel: rcp4301:GP-IB function status: SGNS AIDS
ソースハンドシェークファンクション,アクセプタハンドシェークファンクションが出力されて います。