linux的核心日志系統

<a>今天有同僚問我在應用程式中怎麼列印資訊，在核心中有printk，使用者空間用什麼？我感到這個問題很奇怪，用printf不就可以了嗎？他說他的代碼在一個so中，我都無語了！他原來是做windows的，在windows中很多都是win32程式，帶界面的，不是控制台程式，他大多數通過單步跟蹤和斷點來了解程式運作時的資訊，其實吧，我倒是挺不喜歡單步或者斷點的，除了特殊的調試需要，一般我都是通過列印日志來擷取資訊，linux有強大的日志記錄系統，可以給程式一個安心的多的執行環境，日志僅僅是一個旁路的作用，起到記錄個審計的作用而不會影響程式的執行，單步和斷點就不同了，很多的問題你僅僅通過單步是無法發現的，特别是并發問題，不過在windows上寫代碼的哥們總是喜歡單步，就像他們總喜歡反彙編一樣，這裡面的原因就是，第一，windows程式大多數不是控制台，它實際上沒有地方列印資訊，第二，windows擁有強大的可視化IDE，這就給單步和斷點提供了友善。</a>

<a>在linux中，syslogd是使用者空間的一個守護程序，所有的需要記錄日志的别的程序可以和這個守護程序通信，可以委托這個守護程序幫助記錄日志，為何不自己記錄呢，那是因為syslogd非常的專業，可以将日志記錄到很細的地步，可以看etc/下面的配置檔案，既然所有的程序都可以委托syslogd記錄日志，那麼就涉及到了程序間通信，這就是linux中另外一大塊的内容了，這裡就不談了，linux善于使用小的程式組合成大的機制，linux善于分布式的思想而不是集中的，但是為何将日志都委托給一個守護程序呢，這不就集中了嗎？其實這難道不是各司其職嗎？是以這還是一個邊界的問題。syslogd之外還有一個klogd，這兩個其實不是一個層次的，syslogd是個總的日志記錄器，而klogd僅僅是一個syslogd的用戶端罷了，和很多需要記錄日志的程序的級别一樣，在需要記錄日志的程序裡，可以調用syslog函數将日志發送給syslogd守護程序，可是核心并不是一個程序，那麼它的日志就有必要專門設定一個使用者程序負責傳給syslogd，這個程序就是klogd，至于klogd如何從核心得到核心日志資訊，這就是它自己的事情了，其實核心專門留下了兩個日志接口，一個是sys_syslog系統調用（注意不要和syslog函數混淆，syslog系統調用是和核心通信的，而syslog函數是和syslogd通信的），另一個是/proc/kmsg檔案，klogd使用的是後者，當然也可以直接使用ksyslog系統調用。這裡首先看一下核心日志的一些結構，首先核心日志大多數由printk産生，你也可以認為完全由printk産生，但是我們知道，printk将資訊列印到了螢幕，并沒有别的什麼副作用，實際上并不是僅僅發生了我們看到的事情，實際上printk并不是将資訊直接寫入了标準輸出檔案，而僅僅将資訊塞入了一個環形緩沖區，，然後至于這個緩沖區的内容什麼時候顯示到标準輸出，那就是另外一個事情了，而核心日志就是存在于這個環形緩沖區，列印到螢幕的僅僅是一個緩沖區副本，真正的資料還在緩沖區保留，隻有到了klogd或者别的什麼調用syslog系統調用将資訊讀出時或者緩沖區滿了（環形緩沖區首尾相接）的時候才會清除部分資料或者全部資料，剛才說了有兩種方式來得到核心日志，一個是/proc/kmsg。一個是系統調用，幸運的是，這兩個都是調用了do_syslog核心函數：</a>

<a>int do_syslog(int type, char __user * buf, int len)</a>

<a>{</a>

<a>unsigned long i, j, limit, count;</a>

<a>int do_clear = 0;</a>

<a>char c;</a>

<a>int error = 0;</a>

<a>error = security_syslog(type);</a>

<a>if (error)</a>

<a>return error;</a>

<a>switch (type) {</a>

<a>...</a>

<a>case 2:</a>

<a>goto out;</a>

<a>i = 0;</a>

<a>spin_unlock_irq(&amp;logbuf_lock);</a>

<a>error = __put_user(c,buf);</a>

<a>buf++;</a>

<a>i++;</a>

<a>spin_lock_irq(&amp;logbuf_lock);</a>

<a>}</a>

<a>我們看一下printk調用的vprintk核心函數：</a>

<a>asmlinkage int vprintk(const char *fmt, va_list args)</a>

<a>unsigned long flags;</a>

<a>int printed_len;</a>

<a>char *p;</a>

<a>static char printk_buf[1024];</a>

<a>static int log_level_unknown = 1;</a>

<a>printed_len = vscnprintf(printk_buf, sizeof(printk_buf), fmt, args);</a>

<a>for (p = printk_buf; *p; p++) {</a>

<a>if (log_level_unknown) {</a>

<a>if (p[0] != '&lt;' || p[1] &lt; '' || p[1] &gt; '7' || p[2] != '&gt;') {</a>

<a>emit_log_char('&lt;');</a>

<a>emit_log_char(default_message_loglevel + '');</a>

<a>emit_log_char('&gt;');</a>

<a>log_level_unknown = 0;</a>

<a>emit_log_char(*p);</a>

<a>if (*p == '/n')</a>

<a>log_level_unknown = 1;</a>

<a>if (!cpu_online(smp_processor_id()) &amp;&amp; system_state != SYSTEM_RUNNING) {</a>

<a>spin_unlock_irqrestore(&amp;logbuf_lock, flags);</a>

<a>console_locked = 1;</a>

<a>console_may_schedule = 0;</a>

<a>} else {</a>

<a>out:</a>

<a>return printed_len;</a>

<a>核心的環形緩沖有兩個用途，一個是直接列印在螢幕上，還有一個就是可能使用者空間的核心日志程式正在運作，是以這個函數完成了兩個作用：</a>

<a>void release_console_sem(void)</a>

<a>unsigned long _con_start, _log_end;</a>

<a>unsigned long wake_klogd = 0;</a>

<a>spin_lock_irqsave(&amp;logbuf_lock, flags);</a>

<a>if (con_start == log_end)</a>

<a>break; /* Nothing to print */</a>

<a>_con_start = con_start;</a>

<a>_log_end = log_end;</a>

<a>call_console_drivers(_con_start, _log_end);</a>

<a>console_locked = 0;</a>

<a>up(&amp;console_sem);</a>

<a>wake_up_interruptible(&amp;log_wait);</a>

<a>最後我們看一下procfs導出的kmsg接口的read函數，其實也是調用了do_syslog函數：</a>

<a>static ssize_t kmsg_read(struct file *file, char __user *buf, size_t count, loff_t *ppos)</a>

<a>if ((file-&gt;f_flags &amp; O_NONBLOCK) &amp;&amp; !do_syslog(9, NULL, 0))</a>

<a>return -EAGAIN;</a>

<a>return do_syslog(2, buf, count);</a>

<a>這裡我覺得有一個問題，就是在printk的時候，如果我們恰好可以得到裝置的信号量，那麼就必須等到資訊完全顯示到裝置上時調用棧才可以傳回，也就是說，最好不要在核心大量調用printk函數，另外，在多處理器上這也是很不利的，以前的處理器少，是以問題不大，現在都是多處理器了，性能就可能受printk的影響了，我覺得可以為每一個cpu準備一個環形緩沖區，然後在拼接這些緩沖區的時候進行控制，比如在使用者空間讀每個cpu的緩沖區，隻不過将它們作為一個整體去了解，這個我感覺可以用檔案系統實作。在任何程式中頻繁調用列印都是不妙的，因為列印涉及裝置操作，想想看，外設相比cpu多麼慢，而且對于機器中的唯一裝置，而且是每個程序幾乎都在用的裝置，我們花在打架上的時間又是何等的長。</a>

<a>回歸同僚問我的那個問題，在linux上怎麼列印資訊，其實，隻要你不關閉，每個程式都會預設打開0，1，2三個檔案描述符，這三個描述符在start_kernel中調用的kernel_init程序（最終成為/sbin/init）中被初始化，也就是在下面的代碼：</a>

<a>if (sys_open((const char __user *) "/dev/console", O_RDWR, 0) &lt; 0)</a>

<a>printk(KERN_WARNING "Warning: unable to open an initial console./n");</a>

<a>(void) sys_dup(0);</a>

在這裡，sys_open打開了/dev/console，将其作為标準輸出，其實也就是我們的終端，目前終端，在sys_open中會自動将檔案描述符0配置設定給這個終端檔案，然後緊接着的sys_dup相當于複制了這個終端檔案描述符代表的檔案給了新的描述符1和2，這樣的話實際上0，1，2代表的是同一個東西，都是指目前的終端，這也就是為什麼你往标準錯誤裡面寫東西也不會錯的道理，實際上标準輸入，輸出，錯誤都是給使用者程序用的，對于核心，它們是一個東西。因為linux程序都是fork出來的，根源就是這個kernel_init程序，于是每個程序都會預設複制父程序的0，1，2檔案描述符（如果父程序沒有關閉它們的話）。

 本文轉自 dog250 51CTO部落格，原文連結:http://blog.51cto.com/dog250/1274024