作者：Younger Liu，
本作品采用知识共享署名-非商业性使用-相同方式共享 3.0 未本地化版本许可协议进行许可。
在分析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. ”)*/
sched_clock_running = 1;
/*printk(KERN_CRIT “end :sched_clock_init. ”)*/
}
难道这一句简简单单的赋值就会花费两秒是的时间？？那么就分析一下相关的代码：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. 结论
通过分析，可以知道，日志中显示的两秒的差距不是因为执行语句花费了两秒，而是因为在该语句之前，没有获取到有效的调度时钟时间。
作者：Younger Liu，
本作品采用知识共享署名-非商业性使用-相同方式共享 3.0 未本地化版本许可协议进行许可。