dmesg でカーネルログを確認する
ドライバ開発では「カーネルが何を言っているか」を読むことが何より大切です。カーネルやモジュールが出力するメッセージはカーネルリングバッファに溜まり、dmesg コマンドで確認できます。モジュールを組み込んだ直後や、USB機器を挿した瞬間に dmesg を見ると、認識のログやエラーが時系列で並びます。自作モジュール内で printk を使って出したメッセージも、ここに表示されます。-T で人間に読みやすい時刻表示、-w で新着の追従ができます。
ドライバ開発で何よりも大切なのは、「カーネルがいま何を言っているか」を読む力です。ユーザ空間で動く普通のアプリなら、画面に文字を出して様子を確かめられますが、カーネル空間で動くドライバは、普通の方法では画面に直接メッセージを出すことができません。そこで使うのが、カーネルやモジュールが出力するメッセージを記録しておく専用の置き場と、それを読むためのコマンドです。これがあるおかげで、モジュールが正しく動いたのか、どこでエラーになったのかを、後から落ち着いて追いかけられます。ドライバ開発における状態把握と原因の切り分けの第一手は、いつもこのカーネルログの確認から始まります。
カーネルリングバッファという置き場
カーネルが出すメッセージは、まずカーネルリングバッファと呼ばれるメモリ上の領域に溜められます。リング(輪)という名前のとおり、決まった大きさの場所に新しいメッセージを次々と書き続け、いっぱいになると古いものから順に上書きされていく、という構造になっています。ここには、起動時のログ、機器が認識されたという記録、ドライバが出したエラー、そして後で説明する printk という関数からの出力などが、起きた順に時系列で並びます。このバッファは、あくまで「いま手元で起きていることの記録」であり、システムを再起動すると基本的に消えてしまう、その場かぎりのものだと捉えておくとよいでしょう。だからこそ、必要なログはその場で確認することが大切になります。
dmesg で読む
このカーネルリングバッファの中身を表示するのが dmesg というコマンドです。実行すると、これまでに溜まったメッセージが一気に画面へ流れます。とくに役立つ場面が2つあります。ひとつは、モジュールを組み込んだ直後です。insmod や modprobe でモジュールを読み込んだすぐ後に dmesg を見ると、初期化が成功したログや、うまくいかなかった場合のエラーメッセージを確認できます。もうひとつは、機器を物理的につないだときで、たとえばUSB機器を挿した瞬間に dmesg を見れば、カーネルがその機器をどのように認識したかが時系列で並んで見えます。「何か操作をしたら、その前後で dmesg を見る」を習慣にすると、自分の操作が何を引き起こしたのかをつかめるようになります。
よく使うオプション
dmesg には、知っておくと便利なオプションがいくつかあります。何も付けない素のままの表示では、各メッセージの先頭に、起動してからの経過秒数が数字で並んでいて、少し読みにくく感じます。そこで -T を付けると、その部分が人間に読みやすい日付と時刻の形式に変わり、調査の途中で「これはいつ起きた出来事か」を把握しやすくなります。そしてとりわけ強力なのが -w です。これを付けて実行すると、新しいメッセージが追記されるたびに、その行が画面へリアルタイムに流れ続けます。端末を2つ開いておき、片方で先に dmesg -w を走らせておいてから、もう片方でモジュールを組み込む、という使い方をすると、組み込んだその瞬間に出てくるログを、見逃さずその場で目撃できます。流れ続ける表示を止めたいときは Ctrl + c を押します。
printk と自作モジュール
自作したモジュールの中からログを出したいときに使うのが、printk という関数です。アプリで使う printf によく似た名前と使い方ですが、両者はまったくの別物なので注意が必要です。printf がユーザ空間で画面に文字を出すための関数であるのに対し、printk はカーネル空間からカーネルリングバッファへメッセージを書き込むための関数です。ドライバはカーネル空間で動いていて画面に直接書き出せないため、ログを残す手段としてこの printk が用意されているわけです。つまり、自分のモジュールの初期化関数や終了関数の中に printk を仕込んでおけば、その出力が dmesg を通して読める、ということになります。「ここまで処理が進んだ」「このときの値はこうなっていた」といった目印を、printk で要所要所に点々と置いていくのが、カーネル空間で動くドライバをデバッグするときの基本のスタイルです。アプリでいう、画面に途中経過を表示しながら原因を探っていく作業に相当します。
ログレベルという考え方
printk で出すメッセージには、その緊急度を示すログレベルを付けることができます。レベルは全部で8段階あり、数字が小さいほど緊急度が高い、という決まりになっています。いちばん深刻なものから順に、システムが使用不能、ただちに対処が必要、危機的な状況、エラー、警告、正常だが重要、単なる情報、そしてデバッグ用、という並びです。このようにレベルで仕分けておくと、「どのレベル以上のメッセージを画面に表示するか」をシステムの側で設定できるようになります。ふだんは重要なものだけを表示して静かにしておき、調査が必要なときだけ、細かいデバッグ用のメッセージまで表示させる、といった調整が可能になるわけです。大事な知らせと、にぎやかなだけの記録とを仕分ける仕組みだ、と捉えておきましょう。
実務の使いどころ
まとめると、dmesg はドライバ開発における「観察」の中心にあるコマンドです。モジュールがちゃんと組み込まれたのか、機器が正しく認識されたのか、どこでエラーが起きたのか——その答えは、たいていカーネルリングバッファの中に残されています。「組み込む前に、別の端末で dmesg -w を流しておき、組み込んだ瞬間のログをその場で見る」「思ったように動かなければ、まず dmesg にエラーが出ていないかを確かめる」という手順を身につければ、当てずっぽうではなく、根拠を持ってドライバを直していけます。自分のコードに printk で目印を置き、それを dmesg で読み取る——この地道な往復こそが、ドライバ開発を地に足のついたものにしてくれます。