Printk與sched_clock_init的一點分析

在分析Linu內核啓動的過程當中，發現一段「不日常」的日誌，感受產生這段日誌的代碼確定是「難以想象」的。所以就大體分析了一下：

日誌以下：

[ 0.000000] console [ttyMT0] enabled

[ 2.157770] Calibrating delay loop... 1694.10 BogoMIPS (lpj=4235264)

更精細的日誌以下：

        [    0.000000] start:sched_clock_init.

        [    2.100505] end  :sched_clock_init.

與這段日誌有關的代碼是：

void sched_clock_init(void)

{

    /*printk(KERN_CRIT 「start:sched_clock_init.\n」)*/

    sched_clock_running = 1;

    /*printk(KERN_CRIT 「end  :sched_clock_init.\n」)*/

}

難道這一句簡簡單單的賦值就會花費兩秒是的時間？？那麼就分析一下相關的代碼：sched_clock_running做用和printk的實現。

 

1.      sched_clock_running的做用

分析發現，調用sched_clock_running的地方僅僅有函數sched_clock_cpu():

u64 sched_clock_cpu(int cpu)

{

    if (unlikely(!sched_clock_running))

       return 0;

 

    return sched_clock();

}

很明顯，若是sched_clock_running爲0(unlikely已經說明sched_clock_running不多爲0)，則返回0；若是不爲0，調用sched_clock返回當前的調度時鐘時間(相對系統起始的時間，單位爲納秒)。

函數sched_clock_cpu()被大約四個函數調用cpu_clock() / local_clock / update_rq_clock() / ttwu_queue()。

 

綜上可知，執行sched_clock_init以前，獲取的調度時鐘時間都是0，執行sched_clock_init以後，取得的調度時鐘時間都是有非零值的。

 

2.      Printk()的實現

Printk的實現都在文件./kernel/printk.c中。Printk() ->  vprintk()，而在vprintk()會經過cpu_clock()獲取時間。而有上可知，可否打印時間是和sched_clock_init有沒有被執行是有直接關係的。

 

3.      結論

經過分析，能夠知道，日誌中顯示的兩秒的差距不是由於執行語句花費了兩秒，而是由於在該語句以前，沒有獲取到有效的調度時鐘時間。