Edited at
LinuxDay 8

カーネルコードリーディングのすヽめ ~ カーネルバッファ ~


はじめに

Linux Advent Calendar 2018、8日目の記事になります。

タイトルにもある通りカーネルコードリーディングのすヽめです。

自身は今年の夏頃からカーネルに興味を持ち、関連書籍を読み漁ったり実際にコードリーディングを行ったり、カーネルモジュールを書いてみたりしているのですが、常に新たな発見と驚きを与えてくれます。

カーネルは巨大且つブラックボックスになりがちで深いところに潜るのは最初少し敷居が高いようにも思えますが、とても身近な存在であるが故にその中身が見えてくるとコマンド1つ打つにしても見方が変わってきますし、またLinuxを触るのがより楽しくなります。

そんなこんなでマイペースにやっているのですが、身近に「カーネルが好きです」という人はあまりおらず日々一人黙々とやっていることの方が多いので、ぜひ皆さんにもその楽しさを知ってもらおうと今回カレンダーに参加しました。


概要

今回は比較的簡単に読めるカーネルバッファを取り上げようと思います。カーネルのバージョンは最新のものではなく「詳解 Linux Kernel」で取り上げられている2.6.11を見ていこうと思います。

余談ですがコードリーディングする上では決して最新の物である必要はないように思います。古いバーションの方が比較的コード量も少なく読みやすいことが多いです。※物によっては実装が全く異なるため注意が必要ですが。

普段コードリーディングする際はMacでvscodeを使っています。Cmd+Shift+Fで関数名や変数名を指定しプロジェクト全体で文字列検索を行ったり、実際に読んでいて気になったものがあればF12のショートカットでその定義に飛んだりと言った感じです。


printk()

カーネルコンソールにメッセージを出力するための関数であるprintk()からその実装を紐解いて見ていこうと思います。起動メッセージの出力やカーネルモジュール内で文字列を出力する際に用いられます。

当該関数は以下のような使い方をします。

printk(KERN_INFO "Linux Advent Calendar %d\n", 2018);

第一引数は以下のように定義されておりメッセージの重要度を表しています。


include/linux/kernel.h

#define KERN_EMERG  "<0>"   /* system is unusable           */

#define KERN_ALERT "<1>"
/* action must be taken immediately */
#define KERN_CRIT "<2>"
/* critical conditions */
#define KERN_ERR "<3>"
/* error conditions */
#define KERN_WARNING "<4>"
/* warning conditions */
#define KERN_NOTICE "<5>"
/* normal but significant condition */
#define KERN_INFO "<6>"
/* informational */
#define KERN_DEBUG "<7>"
/* debug-level messages */

関数の実装は以下のように定義されています。


kernel/printk.c

asmlinkage int printk(const char *fmt, ...)

{
va_list args;
int r;

va_start(args, fmt);
r = vprintk(fmt, args);
va_end(args);

return r;
}


内部を見るとvprintk()を呼び出しているのがわかります。(va_listva_startなどは可変長引数を処理するためのものですが今回は割愛します。カーネルはどの機能を追っても割と"沼"であることが多いので目的のもの以外は気にせず進むのも大切になってきます。)


vprintk()

当該関数の定義は以下のようになっています。(ログバッファへの書き込みに直接関係のありそうな部分のみを抜粋しました。)


kernel/printk.c

asmlinkage int vprintk(const char *fmt, va_list args)

{
unsigned long flags;
int printed_len;
char *p;
static char printk_buf[1024];
static int log_level_unknown = 1;

/*
*(省略)
*/

/* Emit the output into the temporary buffer */
printed_len = vscnprintf(printk_buf, sizeof(printk_buf), fmt, args);

/*
* Copy the output into log_buf. If the caller didn't provide
* appropriate log level tags, we insert them here
*/

for (p = printk_buf; *p; p++) {
if (log_level_unknown) {
if (p[0] != '<' || p[1] < '0' || p[1] > '7' || p[2] != '>') {
emit_log_char('<');
emit_log_char(default_message_loglevel + '0');
emit_log_char('>');
}
log_level_unknown = 0;
}
emit_log_char(*p);
if (*p == '\n')
log_level_unknown = 1;
}

/*
*(省略)
*/

out:
return printed_len;
}


まず上記のコード内の以下の部分です。

static char printk_buf[1024];

/*
(省略)
*/

/* Emit the output into the temporary buffer */
printed_len = vscnprintf(printk_buf, sizeof(printk_buf), fmt, args);

vscnprintf()は書式文字列と引数をパースし、第一引数であるバッファに書き込むような処理を行なっています(パース処理ということもあってコード量が多いので割愛します)。

次に以下の部分です。

char *p;

static int log_level_unknown = 1;
/*
(省略)
*/

for (p = printk_buf; *p; p++) {
if (log_level_unknown) {
if (p[0] != '<' || p[1] < '0' || p[1] > '7' || p[2] != '>') {
emit_log_char('<');
emit_log_char(default_message_loglevel + '0');
emit_log_char('>');
}
log_level_unknown = 0;
}
emit_log_char(*p);
if (*p == '\n')
log_level_unknown = 1;
}

ポインタを用いて先ほどのバッファを走査しています。

最初の条件分岐は先ほど見たログレベルの処理です。ログレベルが指定されていない場合にはデフォルトのログレベルでemit_log_char()を用いてログバッファに書き込んでいます。

それ以外はシンプルに一文字ずつemit_log_char()で文字を書き込んでいます。行の末尾(改行)だった場合には次の行で再度ログレベルを表示する必要があるため最初の条件分岐で参照されていたlog_level_unknown1を代入します。


emit_log_char()

先ほど実際に一文字ずつ書き込んでいる処理で使用されていたemit_log_char()を見ていきます。当該関数の実際の定義は以下です。


kernel/printk.c

static void emit_log_char(char c)

{
LOG_BUF(log_end) = c;
log_end++;
if (log_end - log_start > log_buf_len)
log_start = log_end - log_buf_len;
if (log_end - con_start > log_buf_len)
con_start = log_end - log_buf_len;
if (logged_chars < log_buf_len)
logged_chars++;
}

LOG_BUFというマクロにlog_endというインデックスのような物を指定して引数の文字を代入しているのがわかります。

条件分岐は何やら難しそうなことをしていそうですが用いられている変数は以下のように定義されています。

:kernel/printk.c

static unsigned long log_start; /* Index into log_buf: next char to be read by syslog() */
static unsigned long con_start; /* Index into log_buf: next char to be sent to consoles */
static unsigned long log_end; /* Index into log_buf: most-recently-written-char + 1 */
static unsigned long logged_chars; /* Number of chars produced since last read+clear operation */

log_startsyslog()が読み込みの際に用いるインデックスで、con_startはコンソールにバッファから文字列を送る際に用いられるようです。

要するに先ほどの条件分岐はバッファに文字が書き込まれlog_endがインクリメントされた際にバッファのサイズを超えるようであれば、そのスタート位置(log_startcon_start)を後ろにずらしてバッファのサイズを維持するという処理のようです。(syslog()のコードは読んでいないので定かではないですが・・・)


LOG_BUF

先ほど文字を代入していたLOG_BUFマクロを見ていきます。定義は以下です。


kernel/printk.c

#define __LOG_BUF_LEN (1 << CONFIG_LOG_BUF_SHIFT)


static char __log_buf[__LOG_BUF_LEN];
static char *log_buf = __log_buf;
static int log_buf_len = __LOG_BUF_LEN;

#define LOG_BUF_MASK (log_buf_len - 1)
#define LOG_BUF(idx) (log_buf[(idx)&LOG_BUF_MASK])


ついにバッファらしき物にたどり着きました!

まず先ほど使用されていたLOG_BUF(log_buf[(idx)&LOG_BUF_MASK])と定義されており、引数のインデックス(idx)をマスク(LOG_BUF_MASK)でAND演算した物を添字としlog_bufferの要素を指していることがわかります。

log_bufferの定義は上記から抜粋すると以下の部分になります。

static char __log_buf[__LOG_BUF_LEN];

static char *log_buf = __log_buf;

実際には__LOG_BUF_LENの長さを持ったchar型配列だということがわかります。

次にマスク値(LOG_BUF_MASK)ですが抜粋すると以下が定義部分になります。

static int log_buf_len = __LOG_BUF_LEN;

#define LOG_BUF_MASK (log_buf_len - 1)

先ほどの配列変数の定義にも使用されていた__LOG_BUF_LENから-1した数値だということがわかりました。

そしてchar型配列(__log_buf)及びマスク(LOG_BUF_MASK)で使用されていた__LOG_BUF_LENですが、定義は以下のようにされています。

#define __LOG_BUF_LEN (1 << CONFIG_LOG_BUF_SHIFT)

CONFIG_LOG_BUF_SHIFTはカーネルコンフィグレーション項目の1つです。getconfコマンドを用いることでその値が取得できます。

自身の環境では以下のような結果になりました。

$ sudo grep CONFIG_LOG_BUF_SHIFT /boot/config-`uname -r`

CONFIG_LOG_BUF_SHIFT=18

要するに、CONFIG_LOG_BUF_SHIFTの数だけ"1"を左シフトした数値がログバッファのサイズ(__LOG_BUF_LEN)になります。自身の環境でだと256KB(0x40000)です。

マスク(LOG_BUF_MASK)はこの__LOG_BUF_LENから-1した数値だったので自身の環境では0x3FFFF(下位18bitが1)になることがわかります。

感の良い人はもう気づいているかもしれませんが、カーネルバッファはリングバッファになっています。先ほど見たemit_log_char()をもう一度見てみます。


kernel/printk.c

static void emit_log_char(char c)

{
LOG_BUF(log_end) = c;
log_end++;
/*
*(省略)
*/

}

インデックスとなっているlog_endはインクリメントされているだけで、インデックスがある値以上になると先頭に戻るような気配はありません。ここで先ほどのマスクが登場します。

自身の環境で考えるとマスクは下位18bitなのでインデックスが19bit目に桁上がりした際には、下位18bitのみがマスクされ残ります。よって19bit目以降が削ぎ落とされ、またインデックスが0からということになります。

これがカーネルバッファの正体です。


最後に

いかがだったでしょう、思っていたよりも簡単だったな〜と思っていただけたなら嬉しいです。今回処理を追ったカーネルバッファはもちろん氷山の一角です(ですらない!?)。まだまだため息が出るほど面白い処理が沢山あるのでぜひ皆さんも自分の気になる処理を追ってみてください!

余談ですが自身のブログでもコードリーディングした物をつらつら書いているので良かったら見てみてください。

https://k-onishi.hatenablog.jp/

最後までお付き合い頂きありがとうございました。

(もし間違いや不明な点などがあれば、ご指摘いただけると幸いですm(_ _)m)