printkの出力先はカーネルのバッファ(=メモリ)

Linux プログラミング

printk処理の(時間的な)オーバーヘッドを知りたくて、調べてみた。
printkの直接の出力先は、"log_buf"というバッファ(=メモリ)。
→カーネルのソース「kernel/printk.c」で定義されている
/var/log/messagesのようなファイルへの書き込みは、ユーザプロセスである"syslogd"がAPIを使ってカーネルバッファからログ情報を読みだして書き込んでいる。

printkの処理時間を計測してみた。
以下のprintkの前後にrdtscll命令を入れて処理クロック数から時間を求めた。
Intel Corei7 3.4GHzのマシン。

rdtscll(start)
printk(KERN_DEBUG "get_printk_overhead %d %d %d %s\n", a, b, c, s);
rdtscll(end)

計測50回分をざっと見た感じで、平均は3500clocks前後、最大で17696clocksだった。
つまり、平均1us、最大5usの処理時間がかかっていることになる。
ただし、カーネルのプリエンプトはOFFになっているけど、ここ以外の箇所でprintkを実行しているところがあるので、その排他制御とかの影響も若干入っている気がする。

HelloWorldソースコード解説 | Linuxデバイスドライバ開発入門
http://www.linux-dvr.biz/archives/64

＠IT：システム管理の基礎 syslogdの設定をマスターしよう（2/3）
http://www.atmarkit.co.jp/flinux/rensai/root03/root03b.html


--- 2013/06/21 追記 ---
カーネル・ロギング: API と実装
http://www.ibm.com/developerworks/jp/linux/library/l-kernel-logging-apis/