這段時間復習了一下內核調試系統,注意看了一下printk的實現以及內核日志的相關知識,這里做一下總結。
1、問題的引出:
做DPDK項目時,調試rte_kni.ko時,發現printk並不會向我們想想的那樣把log信息顯示在我們的終端上。有人總結了三個原因:
- 原因1:printk()有一個控制日志級別的字段,如果該字段的日記級別高於console默認的日志級別那么才會打印出來(數值越小日志級別越高,分為從0-7共計8個日志級別)。有一種簡單的改變當前終端的日志級別的方法,echo 8 > /sys/kernel/printk。理論上這樣printk就能輸出到終端了。但是我的沒有。
- 原因2:syslogd守護進程的規則有問題,/etc/syslog.conf中定義了一些列規則,其中就包含數內核消息的處理規則,fedora中的syslogd守護進程叫做rsyslogd,相應它的規則配置文件叫rsyslog.conf,其中有一行”#kern.* /dev/console“它的意思是把所有日志級別的內核log都輸出到/dev/console即我們的終端。我們只需要把該行的'#'去掉,重啟,理論上那么內核log (printk()輸出也是內核log)就會輸出到終端了。但是我的還是不能。
- 原因3:系統中同時有klogd和syslogd守護進程那么不管日志級別是什么都不能輸出到終端。
如果不能在終端上看到printk的輸出,那么可以通過查看/var/log/messages文件,或運行dmesg命令查看,或查看/proc/kmsg文件獲得信息,或是通過ctrl+alt+f2~f6進入系統文本模式裝載模塊,這樣也可以看到prink()輸出的信息,當然這里就准確對應原因1中所講的規則。
最后說一下syslogd、直接通過/proc/kmsg、和dmesg讀取printk輸出緩沖區的區別:
- syslogd:讀取了緩沖區中的數據,不會刪除緩沖區中的數據。
- 直接讀取/proc/kmsg:讀取了緩沖區中的數據后,將緩沖區中的數據刪除(klogd默認就是采用這種方法)。
- dmesg:在不刷新緩沖區的情況下獲得緩沖區的內容,並將內容返回給stdout。
本文里的知識來至LDD3,和一位網友的博客(http://www.cnitblog.com/textbox/archive/2009/10/13/61785.html)。
1、printk概述:
對於做Linux內核開發的人來說,printk實在是再熟悉不過了。內核啟動時顯示的各種信息大部分都是通過她來實現的,在做內核驅動調試的時候大部分 時候使用她就足矣。她之所以用得如此廣泛,一個是由於她使用方便,還有一個重要的原因是她的健壯性。它使用范圍很廣,幾乎是內核的任何地方都能調用它。你既可以在中斷上下文、進程上下中調用她,也可以在任何持有鎖時調用她,更可以在SMP系統中調用她,且調用時連鎖都不必使用。這樣好的適應性來源於她的設計,一個由三個指針控制的簡單“ring buffer”。
注意上面說到的是:“幾乎”在內核的任何地方都可以使用。那什么地方使用會有“問題”?那就是在系統啟動過程的早期,終端初始化之前的某些地方雖然可以使用,但是在終端和控制台被初始化之前所有信息都被緩存在printk的簡單的ring buffer(環形緩沖區)中,直到終端和控制台被初始化之后,所有緩存信息都被一並輸出。
如果你要調試的是啟動過程最開始的部分(如setup_arch()),可以依靠此時能夠工作的硬件設備(如串口)與外界通信,使用printk()的變體early_printk()函數。她在啟動過程初期就具有在終端上打印的能力,功能與prink()類似,區別在於:
所以,除非要在啟動初期在終端上輸出,否則我們認為printk()在任何情況下都能工作。這點從內核的啟動代碼中就可以看出,在已進入start_kernel不久就通過printk打印內核版本信息了。
2、printk的使用:
printk()和C庫中的printf()在使用上最主要的區別就是 printk()指定了日志級別。
2.1:日志等級
內核根據日志級別來判斷是否在終端(console)上打印消息:內核把級別比某個特定值低的所有消息顯示在終端(console)上。但是所有信息都會記錄在printk的“ring buffer”中。
printk有8個loglevel,定義在中:
- #define KERN_EMERG "<0>" /* 系統不可使用 */
- #define KERN_ALERT "<1>" /* 需要立即采取行動 */
- #define KERN_CRIT "<2>" /* 嚴重情況 */
- #define KERN_ERR "<3>" /* 錯誤情況 */
- #define KERN_WARNING "<4>" /* 警告情況 */
- #define KERN_NOTICE "<5>" /* 正常情況, 但是值得注意 */
- #define KERN_INFO "<6>" /* 信息型消息 */
- #define KERN_DEBUG "<7>" /* 調試級別的信息 */
/* 使用默認內核日志級別 */
#define KERN_DEFAULT ""
/*
* 標注為一個“連續”的日志打印輸出行(只能用於一個
* 沒有用 \n封閉的行之后). 只能用於啟動初期的 core/arch 代碼
* (否則續行是非SMP的安全).
*/
#define KERN_CONT ""
/* printk's without a loglevel use this.. */
#define DEFAULT_MESSAGE_LOGLEVEL CONFIG_DEFAULT_MESSAGE_LOGLEVEL
printk(KERN_EMERG "log_level:%s\n", KERN_EMERG);
printk( "<0>" "log_level:%s\n", KERN_EMERG);
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <errno.h>
//#define __LIBRARY__ /* _syscall3 and friends are only available through this */
//#include <linux/unistd.h>
/* define the system call, to override the library function */
//_syscall3(int, syslog, int, type, char *, bufp, int, len);
int main(int argc, char **argv)
{
int level;
if (argc == 2) {
level = atoi(argv[1]); /* the chosen console */
} else {
fprintf(stderr, "%s: need a single arg\n", argv[0]);
exit(1);
}
if (klogctl(8, NULL, level) < 0) {
fprintf(stderr, "%s: syslog(setlevel): %s\n",
argv[0], strerror(errno));
exit(1);
}
exit(0);
}
2.2:相關輔助宏
#ifndef pr_fmt
#define pr_fmt(fmt) fmt
#endif
#define pr_emerg(fmt, ...) \
printk(KERN_EMERG pr_fmt(fmt), ##__VA_ARGS__)
#define pr_alert(fmt, ...) \
printk(KERN_ALERT pr_fmt(fmt), ##__VA_ARGS__)
#define pr_crit(fmt, ...) \
printk(KERN_CRIT pr_fmt(fmt), ##__VA_ARGS__)
#define pr_err(fmt, ...) \
printk(KERN_ERR pr_fmt(fmt), ##__VA_ARGS__)
#define pr_warning(fmt, ...) \
printk(KERN_WARNING pr_fmt(fmt), ##__VA_ARGS__)
#define pr_warn pr_warning
#define pr_notice(fmt, ...) \
printk(KERN_NOTICE pr_fmt(fmt), ##__VA_ARGS__)
#define pr_info(fmt, ...) \
printk(KERN_INFO pr_fmt(fmt), ##__VA_ARGS__)
#define pr_cont(fmt, ...) \
printk(KERN_CONT fmt, ##__VA_ARGS__)
/* 除非定義了DEBUG ,否則pr_devel()不產生任何代碼 */
#ifdef DEBUG
#define pr_devel(fmt, ...) \
printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#else
#define pr_devel(fmt, ...) \
no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#endif
/* 如果你在寫一個驅動,請使用dev_dbg */
#if defined(DEBUG)
#define pr_debug(fmt, ...) \
printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#elif defined(CONFIG_DYNAMIC_DEBUG)
/* dynamic_pr_debug() uses pr_fmt() internally so we don't need it here */
#define pr_debug(fmt, ...) \
dynamic_pr_debug(fmt, ##__VA_ARGS__)
#else
#define pr_debug(fmt, ...) \
no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#endif
2.3:輸出速率控制
在調試的時候,有時某些部分可能printk會產生大量輸出, 導致系統無法正常工作,並可能使系統日志ring buffer溢出(舊的信息被快速覆蓋)。特別地,當使用一個慢速控制台設備(如串口), 過量輸出也能拖慢系統。這樣反而難於發現系統出問題的地方。所以你應當非常注意:正常操作時不應當打印任何東西,打印的輸出應當是指示需要注意的異常,並 小心不要做過頭。
#define printk_ratelimit() __printk_ratelimit(__func__)
這個函數應當在你認為打印一個可能會出現大量重復的消息之前調用,如果這個函數返回非零值, 繼續打印你的消息, 否則跳過它。典型的調用如這樣:
if (printk_ratelimit())
printk(KERN_NOTICE "The printer is still on fire\n");
/proc/sys/kern/printk_ratelimit( 可以看作一個監測周期,在這個周期內只能發出下面的控制量的信息)
/proc/sys/kernel/printk_ratelimit_burst(以上周期內的最大消息數,如果超過了printk_ratelimit()返回0)
2.4:最后特別提醒:
3、printk的內核實現
static char __log_buf[__LOG_BUF_LEN];
/*
* 在指向log_buf時並沒有用log_buf_len做限制 - 所以他們
* 在作為下標使用前必須用掩碼處理(去除CONFIG_LOG_BUF_SHIFT以上的高位)
*/
static unsigned log_start; /* log_buf中的索引: 指向由syslog()讀取的下一個字符 */
static unsigned con_start; /* log_buf中的索引: 指向發送到console的下一個字符 */
static unsigned log_end; /* log_buf中的索引:最近寫入的字符地址 + 1 */