コンソールログレベル
Rev.2を表示中。最新版はこちら。
カーネルログはprink()毎に、リングバッファのlog_buf[]に書き出され、同時にstatic struct console *consoleにリストされているドライバのwriteコールバック関数で出力されます。この時コンソールログで、ログの先頭の<数値>がコンソールログレベルです。ドライバ毎に初期化で、register_console()をコールすることで、該当するドライバがコンソールドライバとして、consoleに登録されます。登録されたドライバからカーネルログが書き出されることになります。
struct console {
char name[16];
void (*write)(struct console *, const char *, unsigned);
int (*read)(struct console *, char *, unsigned);
struct tty_driver *(*device)(struct console *, int *);
void (*unblank)(void);
int (*setup)(struct console *, char *);
int (*early_setup)(void);
short flags;
short index;
int cflag;
void *data;
struct console *next;
};
static struct console *console;
printk()からvprintk()とコールされます。default_message_loglevelはログにコンソールログレベルがない時のログレベルです。log_prefix()でログレベルを取得し、emit_log_char()でログをlog_buf[]に設定し、console_unlock()でコンソールに書き出します。
asmlinkage int vprintk(const char *fmt, va_list args)
{
int printed_len = 0;
int current_log_level = default_message_loglevel;
unsigned long flags;
int this_cpu;
char *p;
size_t plen;
char special;
boot_delay_msec();
printk_delay();
local_irq_save(flags);
this_cpu = smp_processor_id();
if (unlikely(printk_cpu == this_cpu)) {
if (!oops_in_progress && !lockdep_recursing(current)) {
recursion_bug = 1;
goto out_restore_irqs;
}
zap_locks();
}
lockdep_off();
raw_spin_lock(&logbuf_lock);
printk_cpu = this_cpu;
if (recursion_bug) {
recursion_bug = 0;
strcpy(printk_buf, recursion_bug_msg);
printed_len = strlen(recursion_bug_msg);
}
printed_len += vscnprintf(printk_buf + printed_len,
sizeof(printk_buf) - printed_len, fmt, args);
p = printk_buf;
plen = log_prefix(p, ¤t_log_level, &special);
if (plen) {
p += plen;
switch (special) {
case 'c': /* Strip <c> KERN_CONT, continue line */
plen = 0;
break;
case 'd': /* Strip <d> KERN_DEFAULT, start new line */
plen = 0;
default:
if (!new_text_line) {
emit_log_char('\n');
new_text_line = 1;
}
}
}
for (; *p; p++) {
if (new_text_line) {
new_text_line = 0;
if (plen) {
int i;
for (i = 0; i < plen; i++)
emit_log_char(printk_buf[i]);
printed_len += plen;
} else {
emit_log_char('<');
emit_log_char(current_log_level + '0');
emit_log_char('>');
printed_len += 3;
}
if (printk_time) {
char tbuf[50], *tp;
unsigned tlen;
unsigned long long t;
unsigned long nanosec_rem;
t = cpu_clock(printk_cpu);
nanosec_rem = do_div(t, 1000000000);
tlen = sprintf(tbuf, "[%5lu.%06lu] ",
(unsigned long) t,
nanosec_rem / 1000);
for (tp = tbuf; tp < tbuf + tlen; tp++)
emit_log_char(*tp);
printed_len += tlen;
}
if (!*p)
break;
}
emit_log_char(*p);
if (*p == '\n')
new_text_line = 1;
}
if (console_trylock_for_printk(this_cpu))
console_unlock();
lockdep_on();
out_restore_irqs:
local_irq_restore(flags);
return printed_len;
}
ログレベルは0から7までで、２桁以上の数値が設定されていても下位3ビットをログレベルとします。上位の値はファシリティで、syslogd等で使われます。
static size_t log_prefix(const char *p, unsigned int *level, char *special)
{
unsigned int lev = 0;
char sp = '\0';
size_t len;
if (p[0] != '<' || !p[1])
return 0;
if (p[2] == '>') {
/* usual single digit level number or special char */
switch (p[1]) {
case '0' ... '7':
lev = p[1] - '0';
break;
case 'c': /* KERN_CONT */
case 'd': /* KERN_DEFAULT */
sp = p[1];
break;
default:
return 0;
}
len = 3;
} else {
char *endp = NULL;
lev = (simple_strtoul(&p[1], &endp, 10) & 7);
if (endp == NULL || endp[0] != '>')
return 0;
len = (endp + 1) - p;
}
if (sp && !special)
return 0;
if (special) {
*special = sp;
/* return special char, do not touch level */
if (sp)
return len;
}
if (level)
*level = lev;
return len;
}
console_unlock()でロック取得し、リングバッファのオーバラップを考慮しながらcall_console_drivers()をコールします。
void console_unlock(void)
{
unsigned long flags;
unsigned _con_start, _log_end;
unsigned wake_klogd = 0, retry = 0;
if (console_suspended) {
up(&console_sem);
return;
}
console_may_schedule = 0;
again:
for ( ; ; ) {
raw_spin_lock_irqsave(&logbuf_lock, flags);
wake_klogd |= log_start - log_end;
if (con_start == log_end)
break; /* Nothing to print */
_con_start = con_start;
_log_end = log_end;
con_start = log_end; /* Flush */
raw_spin_unlock(&logbuf_lock);
stop_critical_timings(); /* don't trace print latency */
call_console_drivers(_con_start, _log_end);
start_critical_timings();
local_irq_restore(flags);
}
console_locked = 0;
if (unlikely(exclusive_console))
exclusive_console = NULL;
raw_spin_unlock(&logbuf_lock);
up(&console_sem);
raw_spin_lock(&logbuf_lock);
if (con_start != log_end)
retry = 1;
raw_spin_unlock_irqrestore(&logbuf_lock, flags);
if (retry && console_trylock())
goto again;
if (wake_klogd)
wake_up_klogd();
}
call_console_drivers()から__call_console_drivers()とコールされます。ログレベルがconsole_loglevelより小さい時、またはログレベルを無視する時、__call_console_drivers()とコールされ、struct console *console->write()でログを書き出します。
static void _call_console_drivers(unsigned start,
unsigned end, int msg_log_level)
{
if ((msg_log_level < console_loglevel || ignore_loglevel) &&
console_drivers && start != end) {
if ((start & LOG_BUF_MASK) > (end & LOG_BUF_MASK)) {
/* wrapped write */
__call_console_drivers(start & LOG_BUF_MASK,
log_buf_len);
__call_console_drivers(0, end & LOG_BUF_MASK);
} else {
__call_console_drivers(start, end);
}
}
}
static void __call_console_drivers(unsigned start, unsigned end)
{
struct console *con;
for_each_console(con) {
if (exclusive_console && con != exclusive_console)
continue;
if ((con->flags & CON_ENABLED) && con->write &&
(cpu_online(smp_processor_id()) ||
(con->flags & CON_ANYTIME)))
con->write(con, &LOG_BUF(start), end - start);
}
}
補足
ログ値は以下のようにマクロ定義されています。端末ドライバ実装で、<0>はKERN_EMERGで全ての端末に出力させる事は理にかなっているわけです。#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 */
検証サンプル
#include <linux/init.h>
#include <linux/module.h>
#include <linux/kernel.h>
#include <linux/console.h>
#include <linux/printk.h>
MODULE_LICENSE("GPL");
MODULE_AUTHOR("y.kitamura");
static int mod_init(void)
{
int i;
struct console *con;
for_each_console(con) {
printk("<0>%s\n", con->name);
}
for (i = 0; i < 10; i++) {
printk("<%d>log level:%d\n", i, i);
}
return -1;
}
module_init(mod_init);
コンソール画面からinsmodした結果です。ssh等の端末からinsmodすると、/dev/ptsがregister_console()されていないので、ログレベル0のみ表示されます。(コンソールには表示)ログレベル0の表示は、カーネルとして実装されていなく、ドライバのwriteコール内での実装のようです。
<8><9>は単にログとなっています。
[root@localhost lkm]# cat /proc/sys/kernel/printk 4 4 1 7 [root@localhost lkm]# tty /dev/tty1 [root@localhost lkm]# insmod consoledrv.ko [ 3610.934390] tty [ 3610.934729] log level:0 [ 3610.934926] log level:1 [ 3610.935067] log level:2 [ 3610.935475] log level:3 [root@localhost lkm]# dmesg : [ 3610.934390] tty [ 3610.934729] log level:0 [ 3610.934926] log level:1 [ 3610.935067] log level:2 [ 3610.935475] log level:3 [ 3610.937111] log level:4 [ 3610.937118] log level:5 [ 3610.937122] log level:6 [ 3610.937126] log level:7 [ 3610.937131] <8>log level:8 [ 3610.937135] <9>log level:9
