• Tim Bird's avatar
    [PATCH] add timing information to printk messages · abbaf4f1
    Tim Bird authored
    Here's a little patch which is useful for showing timing information for
    kernel bootup activities.
    
    This patch adds a new Kconfig option under "Kernel Hacking" and a new
    option for the kernel command line.  It also provides a script for showing
    delta information.
    
    Note that the timing data may not be correct on some platforms until after
    time_init() is called.
    
    Recently (as of about 2.6.10) I found that the message log produced by
    dmesg is truncated when I use this feature.  That is, the first few printk
    messages of the boot sequence are not in the dmesg output, although they
    are printed to console during startup.  This is a new behavior - dmesg
    output was fine as of 2.6.9.  Increasing CONFIG_LOG_BUF_SHIFT had no effect
    on the truncation.
    
    Has something changed with printk recently?
    
    For more information on this patch, see:
    http://tree.celinuxforum.org/CelfPubWiki/InstrumentedPrintk
    
    Here's some sample output:
    ...
    [4294667.296000] Kernel command line: ro root=/dev/nfs ip=dhcp hdc=ide-scsi console=vga console=ttyS0,115200
    [4294667.296000] ide_setup: hdc=ide-scsi
    [4294667.296000] Initializing CPU#0
    [4294667.296000] PID hash table entries: 512 (order: 9, 8192 bytes)
    [    0.000000] Detected 1995.620 MHz processor.
    [   21.397369] Using tsc for high-res timesource
    [   21.399820] Console: colour VGA+ 80x25
    [   21.537244] Dentry cache hash table entries: 32768 (order: 5, 131072 bytes)
    [   21.544547] Inode-cache hash table entries: 16384 (order: 4, 65536 bytes)
    [   21.555066] Memory: 125076k/130240k available (2002k kernel code, 4556k reserved, 1006k data, 140k init, 0k highmem)
    [   21.565775] Checking if this processor honours the WP bit even in supervisor mode... Ok.
    [   21.574089] Calibrating delay loop... 3940.35 BogoMIPS (lpj=1970176)
    [   21.596511] Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
    [   21.603263] CPU: After generic identify, caps: bfebfbff 00000000 00000000 00000000 00004400 00000000 00000000
    [   21.603276] CPU: After vendor identify, caps: bfebfbff 00000000 00000000 00000000 00004400 00000000 00000000
    [   21.603287] CPU: Trace cache: 12K uops, L1 D cache: 8K
    [   21.608884] CPU: L2 cache: 128K
    ...
    
    And now the patch...
    Signed-off-by: default avatarTim Bird <tim.bird@am.sony.com>
    Signed-off-by: default avatarAndrew Morton <akpm@osdl.org>
    Signed-off-by: default avatarLinus Torvalds <torvalds@osdl.org>
    abbaf4f1
printk.c 24.5 KB