I know the time in dmesg is the time since boot. But my specific question is this time is calculated at the start or end of the process mentioned in the line?

Why this is important?
take this example:

[    4.352025] floppy0: no floppy controllers found
[    5.718270] random: nonblocking pool is initialized
[   94.134265] Adding 2094076k swap on /dev/sda5.  Priority:-1 extents:1 across:2094076k FS**
[   96.988453] init: bootchart main process (274) terminated with status 127

If the time, is calculated after finishing the process, the process in the 3rd line should be taken responsible for slow boot.
But if time is calculated from the beginning of the process, the 2nd line should be taken responsible for it.

But it become more complicated when we check dmesg long after boot.
Take this for example:

[28047.749604] wlp3s0: associated
[28941.112855] [drm:intel_pipe_update_end [i915]] *ERROR* Atomic update failure on pipe A (start=757985 end=757986)
[31407.938694] cfg80211: World regulatory domain updated:
[31407.938699] cfg80211:  DFS Master region: unset

This 2466s gap shouldn't have any useful meaning.

I see many times there is confusion about which line in dmesg should be hold responsible for a slow boot.

How can we make sense of time in dmesg?

  • 1
    Have you considered the fact that there are activities that don't show up on dmesg? Mar 23, 2016 at 18:29
  • That is I think the reason for big gaps when running dmesg long after boot. The reason I am asking this question is to find how reliable is the result of dmesg for debugging. I have used it many times. but I mostly get different sets of numbers which all ends in about one minute boot. I see others are not clear about which line should be taken responsible for the gap. Can you help me to understand it better? Mar 23, 2016 at 18:33

2 Answers 2


dmesg is not a suitable way to analyse or investigate the performance of the boot process. You should use bootchart or in younger distributions the already in systemd integrated version of bootchart systemd-analyse.

Because these are complex processes I will not copy the tutorials to this answer.

How to install bootchart is explained here.

How to use systemd-analyse is explained here.


Each log entry shows the time at which the log entry was printed. No more, no less. If the log entry describes a process that is not instantaneous, there's no rule that the log entry must come before or after that process is carried out, it's up to what the developer chose to do. Grammar is a clue: “did this” indicates that the action is complete, “will do this” indicates that it hasn't been done yet; but “doing this” is ambiguous.

As cmks explains, dmesg only shows kernel logs, it doesn't paint a useful picture of what happens on the system once the initramfs or the init program has started. None of the lines that you show describe events that take more than a fraction of a second, so none of them are responsible for a long boot time. It's something else, which isn't happening in the kernel.

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .