システムログ2
Rev.1を表示中。最新版はこちら。
cat /proc/kmsgはproc_kmsg_operationsのreadコールバック関数を呼び出します。（openコールバック関数は何もしません。）kmsg_read()はdo_syslog()を呼び出すことで、シスログを取得しています。まずcat /proc/kmsgでの処理です。最初のif文は非ブロッキングでの読み出し時、シスログバッファにメッセージが入ってないならAGAINで復帰しています。なおstraceでcatを見ると、ファイルオープンはO_RDONLY|O_LARGFILEでオープンしています。で、do_syslog()の引数を2としてコールしています。
const struct file_operations proc_kmsg_operations = {
.read = kmsg_read,
.poll = kmsg_poll,
.open = kmsg_open,
.release = kmsg_release,
};
static ssize_t kmsg_read(struct file *file, char __user *buf,
size_t count, loff_t *ppos)
{
if ((file->f_flags & O_NONBLOCK) && !do_syslog(9, NULL, 0))
return -EAGAIN;
return do_syslog(2, buf, count);
}
do_syslog()引数のtypeにより、以下のような処理を行っています。0 -- ログのクローズ。現在は未処理.
1 -- ログのオープン。現在は未処理.
2 -- ログの読み込み。(/proc/kmsgをreadした時).
3 -- 指定されたサイズのログを読み込んだ後、残りのログをクリアしない。
4 -- 指定されたサイズのログを読み込んだ後、残りのログをクリアする
5 -- シスログバッファをクリアする
6 -- コンソールログレベルをミニマムレベルに設定
7 -- コンソールログレベルをデフォルトに設定
8 -- コンソールの表示するログレベルの設定
9 -- ログバッファのまだ読み込まれていないサイズ
10-- ログバッファのサイズ
int do_syslog(int type, char __user *buf, int len)
{
unsigned i, j, limit, count;
int do_clear = 0;
char c;
int error = 0;
error = security_syslog(type);
if (error)
return error;
switch (type) {
case 0: /* Close log */
break;
case 1: /* Open log */
break;
case 2: /* Read from log */
error = -EINVAL;
if (!buf || len < 0)
goto out;
error = 0;
if (!len)
goto out;
if (!access_ok(VERIFY_WRITE, buf, len)) {
error = -EFAULT;
goto out;
}
error = wait_event_interruptible(log_wait,
(log_start - log_end));
if (error)
goto out;
i = 0;
spin_lock_irq(&logbuf_lock);
while (!error && (log_start != log_end) && i < len) {
c = LOG_BUF(log_start);
log_start++;
spin_unlock_irq(&logbuf_lock);
error = __put_user(c,buf);
buf++;
i++;
cond_resched();
spin_lock_irq(&logbuf_lock);
}
spin_unlock_irq(&logbuf_lock);
if (!error)
error = i;
break;
case 4: /* Read/clear last kernel messages */
do_clear = 1;
/* FALL THRU */
case 3: /* Read last kernel messages */
error = -EINVAL;
if (!buf || len < 0)
goto out;
error = 0;
if (!len)
goto out;
if (!access_ok(VERIFY_WRITE, buf, len)) {
error = -EFAULT;
goto out;
}
count = len;
if (count > log_buf_len)
count = log_buf_len;
spin_lock_irq(&logbuf_lock);
if (count > logged_chars)
count = logged_chars;
if (do_clear)
logged_chars = 0;
limit = log_end;
for (i = 0; i < count && !error; i++) {
j = limit-1-i;
if (j + log_buf_len < log_end)
break;
c = LOG_BUF(j);
spin_unlock_irq(&logbuf_lock);
error = __put_user(c,&buf[count-1-i]);
cond_resched();
spin_lock_irq(&logbuf_lock);
}
spin_unlock_irq(&logbuf_lock);
if (error)
break;
error = i;
if (i != count) {
int offset = count-error;
/* buffer overflow during copy, correct user buffer. */
for (i = 0; i < error; i++) {
if (__get_user(c,&buf[i+offset]) ||
__put_user(c,&buf[i])) {
error = -EFAULT;
break;
}
cond_resched();
}
}
break;
case 5: /* Clear ring buffer */
logged_chars = 0;
break;
case 6: /* Disable logging to console */
console_loglevel = minimum_console_loglevel;
break;
case 7: /* Enable logging to console */
console_loglevel = default_console_loglevel;
break;
case 8: /* Set level of messages printed to console */
error = -EINVAL;
if (len < 1 || len > 8)
goto out;
if (len < minimum_console_loglevel)
len = minimum_console_loglevel;
console_loglevel = len;
error = 0;
break;
case 9: /* Number of chars in the log buffer */
error = log_end - log_start;
break;
case 10: /* Size of the log buffer */
error = log_buf_len;
break;
default:
error = -EINVAL;
break;
}
out:
return error;
}
catで読み出した場合のtype=2の処理です。ユーザバッファは未指定、ないし読み出しサイズが0/マイナスの場合そのまま復帰です。読み出しサイズがシスログバッファサイズを越えていた場合、読み出しサイズをシスログバッファサイズに設定します。
wait_event_interruptible()はlog_start - log_endが0なら、ログバッファにログが溜まるまでウエイトします。（これがcatで表示した場合にコマンドプロンプトに戻らない理由のようです。）
ログがあるならwhileループでユーザバッファにログを設定します。この時ユーザバッファに設定するまいにlog_startをインクリメントしながら、log_endないし指定したサイズまで取得していることです。最終的ににlog_start=log_endとなり、再度catで/proc/kmsgを読み出しても、ログが表示されないわけです。
dmesgコマンドは/proc/kmsgを参照しません。（参照したら毎回ログが表示できなくなります。）straceによるとsyslog()をtype=10でバッファサイズを取得した後、そのサイズでsyslog()をtype=3で呼び出しています。なおこれは全シスログを表示するということですが、その処理は少々トリッキーです。
リストを見ると2段構えのforループで処理をしています。しかもバッファの設定は頭から出なく、尻から設定しています。なぜこのような処理をと・・・。forループの処理で cond_resched()を呼び出しています。本処理中にタスク切り替えが発生しうる。ということです。そうなるの切り替わったプロセスでprintk()すなわち、シスログを追加設定することがありうるわけです。シスログはリングバッファです。場合によっては先頭のログを上書きする恐れがあります。このようなケースを想定しての処理です。
処理の概要として、最初のforループでエンドからユーザバッファにセットしていきます。そしてタスク切り替えで、シスログの先頭を上書きするようなシスログをprintkした場合、それがユーザバッファに設定中のポジションだったといたします。この場合上段のforループを抜けます。そして下段のforループでこれまで設定したユーザバッファを、インデックスが0の位置に移動させることで、シスログ上書きによるケースを回避しています。
シスログが上書きされたかどうのかチェックはif (j + log_buf_len < log_end)です。 j = limit-1-i;のlimitは上書きされる前のlog_endで、jは設定しているポジションです。log_endは更新されたものです。（注：log_endはlog_buf_len超えてインクリメントされていきます。）この条件式の意味するところは、なかなか理解しがたいですが、よ〜く考えるとなるほどです。とにかくこの条件式が真なら、今設定しているポジションjは、シスログ更新で上書きされたということでforループを抜けます。そうでないならユーザバッファに設定していきます。
if (i != count)でシスログ上書きで、全サイズを設定できなかったことを意味します。 error = iは設定できなかったポジションで、それでもっとそのインデックスのデータをインデックス0からにセットしなおしています。だらだら書きましたがソースを見てもらった方がいいかと思います。なお、先のtypeを2でdo_syslog()の処理では、log_start++を更新していましたが、この処理ではかかるインデックス変数を更新していません。従って何回dmesgコマンドを実行しても、全ログを表示することが可能なわけです。
で、本記事をアップした動機でもあった、cat /proc/kmsgでコマンドプロンプトに戻らない。と言うことですが、その処理で wait_event_interruptible()をコールしていました。conditionはlog_start - log_endです。従ってログが内場合ウエイトするようになっています。
#define wait_event_interruptible(wq, condition) \
({ \
int __ret = 0; \
if (!(condition)) \
__wait_event_interruptible(wq, condition, __ret); \
__ret; \
})
しかしシスログがあるならプロンプトに戻ってくるはずです。結論はcatの実装にあるようです。catは指定されたファイルをopenし、fstatでファイルサイズを取得した後、かかるサイズでreadします。そして再度readして読み込みサイズが0なら処理終了としています。すなわち少なくとも2回はreadすることになっているようです。従って一回目のreadでlog_startがlog_endとなってしまい、2回目のreadではシスログが無いと言うことでウエイト状態に入ってしまうと言う事のようです。補足
普通にファイルをオープンして、シスログバッファサイズでもって1回のみのreadで処理すると無事プロセスは終了します。ただしシスログを有している場合ですが。
