Como entender o tempo no dmesg

Question

Eu sei que o tempo em dmesg é o tempo desde a inicialização. Mas minha pergunta específica é que esse tempo é calculado no início ou no final do processo mencionado na linha?

Por que isso é importante?
Veja este exemplo:

[    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

Se o tempo for calculado após o término do processo, o processo na terceira linha deve ser considerado responsável pela inicialização lenta.
Mas se o tempo é calculado a partir do início do processo, a segunda linha deve ser responsabilizada por isso.

Mas fica mais complicado quando verificamos dmesg long after boot.
Tome isso por exemplo:

[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

Esse intervalo de 2466s não deve ter nenhum significado útil.

Eu vejo muitas vezes que há confusão sobre qual linha em dmesg deve ser responsável por uma inicialização lenta.

Como podemos entender o tempo no dmesg?

    

Answer 1

Cada entrada de log mostra a hora em que a entrada de log foi impressa. Nem mais nem menos. Se a entrada de log descreve um processo que não é instantâneo, não há nenhuma regra em que a entrada de log deva ocorrer antes ou depois de o processo ser realizado, depende do que o desenvolvedor escolheu fazer. Gramática é uma pista: “fez isso” indica que a ação está completa, “fará isso” indica que ainda não foi feito; mas "fazer isso" é ambíguo.

Como o cmks explica , dmesg mostra apenas registros do kernel, ele não mostra uma imagem útil do que acontece no sistema uma vez que o initramfs ou o programa de inicialização foi iniciado. Nenhuma das linhas mostradas descreve eventos que levam mais de uma fração de segundo, portanto, nenhum deles é responsável por um longo tempo de inicialização. É outra coisa, o que não está acontecendo no kernel.

    

Answer 2

O dmesg não é uma maneira adequada de analisar ou investigar o desempenho do processo de inicialização. Você deve usar bootchart ou nas distribuições mais jovens a versão integrada do systemd no bootchart systemd-analyse .

Como esses são processos complexos, não vou copiar os tutoriais para essa resposta.

Como instalar o bootchart é explicado aqui.

Como usar o systemd-analysis é explicado aqui.