linux打印信息,linux打印中时间信息

使能 CONFIG_PRINTK_TIME之后，内核每行打印前面有时间信息，本文探讨一下相关代码以及时间信息的含义。

| CONFIG_PRINTK_TIME:

|

| Selecting this option causes timing information to be

| included in printk output.  This allows you to measure

| the interval between kernel operations, including bootup

| operations.  This is useful for identifying long delays

| in kernel startup.

|

| Symbol: PRINTK_TIME [=y]

| Prompt: Show timing information on printks

|   Defined at lib/Kconfig.debug:2

|   Depends on: PRINTK [=y]

|   Location:

|     -> Kernel hacking

在kernel/printk.c中：

#if defined(CONFIG_PRINTK_TIME)

static int printk_time = 1;

#else

static int printk_time = 0;

#endif

module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);

if (printk_time) {

/* Follow the token with the 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);

可以看到打印时间“.”号之前是s，之后是us。

其中的cpu_clock可参考下面代码(kernel/sched_clock.c)，

void sched_clock_init(void)

{

sched_clock_running = 1;

}

u64 sched_clock_cpu(int cpu)

{

if (unlikely(!sched_clock_running))

return 0;

return sched_clock();

}

unsigned long long cpu_clock(int cpu)

{

return sched_clock_cpu(cpu);

}

其中的sched_clock定义也在在kernel/sched_clock.c中

/*

* Scheduler clock - returns current time in nanosec units.

* This is default implementation.

* Architectures and sub-architectures can override this.

*/

unsigned long long __attribute__((weak)) sched_clock(void)

{

return (unsigned long long)(jiffies - INITIAL_JIFFIES)

* (NSEC_PER_SEC / HZ);

}

EXPORT_SYMBOL_GPL(sched_clock);

这里的时间精度是jiffies，并非很高精度。

但在一些地方override了该weak函数，例如在arch/mips/kernel/csrc-r4k.c中有：

/*

* Override the global weak sched_clock symbol(defined in sched_clock.c)

* with this local implementation which uses the clocksource to get some

* better resolution when scheduling the kernel. We accept that this wraps

*  around for now, since it is just a relative time stamp.

*/

unsigned long long notrace sched_clock(void)

{

return clocksource_cyc2ns(clocksource_mips.read(&clocksource_mips),

clocksource_mips.mult, clocksource_mips.shift);

}

这个精度就上去了。

另外宏do_div的定义见inclue/asm-generic/div64.h

#if BITS_PER_LONG == 64

# define do_div(n,base) ({     \

uint32_t __base = (base);    \

uint32_t __rem;      \

__rem = ((uint64_t)(n)) % __base;   \

(n) = ((uint64_t)(n)) / __base;    \

__rem;       \

})

#elif BITS_PER_LONG == 32

extern uint32_t __div64_32(uint64_t *dividend, uint32_t divisor);

/* The unnecessary pointer compare is there

* to check for type safety (n must be 64bit)

*/

# define do_div(n,base) ({    \

uint32_t __base = (base);   \

uint32_t __rem;     \

(void)(((typeof((n)) *)0) == ((uint64_t *)0)); \

if (likely(((n) >> 32) == 0)) {   \

__rem = (uint32_t)(n) % __base;  \

(n) = (uint32_t)(n) / __base;  \

} else       \

__rem = __div64_32(&(n), __base); \

__rem;      \

})

#else /* BITS_PER_LONG == ?? */

# error do_div() does not yet support the C64

#endif /* BITS_PER_LONG */