コンソールログレベル
カーネルログの先頭は<ログレベル>ログのフォーマットで、コンソールログレベルのconsole_printk[0]以下のカーネルログをコンソール画面に表示します。
カーネルログのログレベルをスキップしたカーネルログをemit_log_char()で一文字づつstatic char __log_buf[__LOG_BUF_LEN];に設定し、console_unlock()から_call_console_drivers()でconsole_loglevel以下のカーネルログをコンソールに表示します。
console_loglevelとdefault_console_loglevelはカーネル初期値では7の同じですが、カーネル起動オプションによりdebugなら10,quietなら4となります。
default_console_loglevelは、console_loglevelが変更される故を考慮しての初期レベルを確認する物で、default_console_loglevelの運用上の参照はなく、故にdefault_console_loglevelが更新されるのは運用上問題であり、従ってsyslogシステムコールでは更新の実装されておりません。しかし/proc/sys/kernel/printkでは更新できてしまい、これは/proc/sys/kernel/printkの運用レベルの観点から実装上の不手際でないかと・・・?
#define CONFIG_DEFAULT_MESSAGE_LOGLEVEL 4 #define DEFAULT_CONSOLE_LOGLEVEL 7 #define DEFAULT_MESSAGE_LOGLEVEL CONFIG_DEFAULT_MESSAGE_LOGLEVEL #define MINIMUM_CONSOLE_LOGLEVEL 1 int console_printk[4] = { DEFAULT_CONSOLE_LOGLEVEL, /* console_loglevel */ DEFAULT_MESSAGE_LOGLEVEL, /* default_message_loglevel */ MINIMUM_CONSOLE_LOGLEVEL, /* minimum_console_loglevel */ DEFAULT_CONSOLE_LOGLEVEL, /* default_console_loglevel */ }; #define console_loglevel (console_printk[0]) #define default_message_loglevel (console_printk[1]) #define minimum_console_loglevel (console_printk[2]) #define default_console_loglevel (console_printk[3])
[root@localhost ~]# cat /proc/sys/kernel/printk 4 4 1 7 <- console_printk[0] console_printk[1] console_printk[2] console_printk[3]カーネルログはprintk()からvprintk()でprintk_buf[]に設定し、log_prefix()でカーネルログの<ログレベル>をcurrent_log_levelに設定します。ログレベルが設定されてない場合、デフォルトはcurrent_log_level = default_message_loglevelでconsole_printk[1]となります。
カーネルログのログレベルをスキップしたカーネルログをemit_log_char()で一文字づつstatic char __log_buf[__LOG_BUF_LEN];に設定し、console_unlock()から_call_console_drivers()でconsole_loglevel以下のカーネルログをコンソールに表示します。
#if defined(CONFIG_PRINTK_TIME) static bool printk_time = 1; #else static bool printk_time = 0; #endif 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; } 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] == '>') { 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; if (sp) return len; } if (level) *level = lev; return len; }カーネルログレベルがconsole_loglevel以下ならコンソールに表示されます。ignore_loglevelはカーネル起動時のオプションのignore_loglevelでloglevel=1となり、console_loglevelに関わらず表示されます。カーネル起動オプションは/proc/cmdlineで閲覧できます。
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); } } }
early_param("ignore_loglevel", ignore_loglevel_setup); static bool __read_mostly ignore_loglevel; static int __init ignore_loglevel_setup(char *str) { ignore_loglevel = 1; printk(KERN_INFO "debug: ignoring loglevel setting.\n"); return 0; }MINIMUM_CONSOLE_LOGLEVELはsyslogシステムコールで、SYSLOG_ACTION_CONSOLE_LEVELのコンソールログレベル設定での下限、およびSYSLOG_ACTION_CONSOLE_OFFのコンソールログの非表示時に、 console_loglevelとして設定されます。
console_loglevelとdefault_console_loglevelはカーネル初期値では7の同じですが、カーネル起動オプションによりdebugなら10,quietなら4となります。
early_param("debug", debug_kernel); early_param("quiet", quiet_kernel); static int __init debug_kernel(char *str) { console_loglevel = 10; return 0; } static int __init quiet_kernel(char *str) { console_loglevel = 4; return 0; }
追記
スペシャルコンソールログとして<c>/<d>はDEFAULT_MESSAGE_LOGLEVELでprintk("log")/printk("\nlog")と概略同等ですが、コンソール表示中に他プロセスからprintkした場合で、<d>log/printk("log")は改行しますが、<c>logだと改行されません。カーネル3での実装されています。default_console_loglevelは、console_loglevelが変更される故を考慮しての初期レベルを確認する物で、default_console_loglevelの運用上の参照はなく、故にdefault_console_loglevelが更新されるのは運用上問題であり、従ってsyslogシステムコールでは更新の実装されておりません。しかし/proc/sys/kernel/printkでは更新できてしまい、これは/proc/sys/kernel/printkの運用レベルの観点から実装上の不手際でないかと・・・?