Converter data e hora dmesg em formato de data personalizado

112

Estou tentando entender o carimbo de data / hora dmesg e acho difícil convertê-lo para alterá-lo para o formato de data / data java customizado.

Qualquer ajuda é muito apreciada.

Amostra de log dmesg:

[14614.647880] airo(eth1): link lost (missed beacons)

Obrigado!

ukanth
fonte

Respostas:

180

Entender o dmesgtimestamp é muito simples: é o tempo em segundos desde que o kernel foi iniciado. Então, tendo tempo de inicialização (uptime ), você pode somar os segundos e mostrá-los no formato que desejar.

Ou melhor, você pode usar a -Topção de linha de comando dmesge analisar o formato legível por humanos.

Na página de manual :

-T, --ctime
    Print human readable timestamps. The timestamp could be inaccurate!

    The time source used for the logs is not updated after system SUSPEND/RESUME.
Drescherjm
fonte
10
Qual comando aceita -T? Meu dmesg não diz, nem a página de manual diz isso. (Linux Mint Debian Edition).
gyorgyabraham
1
O meu faz ( dmesgde util-linux 2.20.1no Ubuntu 13.04)
2
Não disponível no redhat e / ou oracle linux 5.6, rpm -qf /bin/dmesg => util-linux-2.13-0.56.0.2.el5
michael
7
Esta opção apareceu em util-linux 2.20, de acordo com as Notas de Lançamento: ftp.kernel.org/pub/linux/utils/util-linux/v2.20/…
ks1322
1
@xealits obrigado pelo acompanhamento, isso é legal da sua parte :) Em relação à pergunta, acho que a parte do entendimento é menor e o "converta para alterá-lo para o formato de data / data java customizado." foi a parte principal, mas sua opinião pode ser diferente. Tenha um bom dia;)
32

Com a ajuda de dr answer, escrevi uma solução alternativa que faz a conversão para colocar em seu .bashrc. Não vai quebrar nada se você não tiver nenhum carimbo de data / hora ou já estiver correto.

dmesg_with_human_timestamps () {
    $(type -P dmesg) "$@" | perl -w -e 'use strict;
        my ($uptime) = do { local @ARGV="/proc/uptime";<>}; ($uptime) = ($uptime =~ /^(\d+)\./);
        foreach my $line (<>) {
            printf( ($line=~/^\[\s*(\d+)\.\d+\](.+)/) ? ( "[%s]%s\n", scalar localtime(time - $uptime + $1), $2 ) : $line )
        }'
}
alias dmesg=dmesg_with_human_timestamps

Além disso, uma boa leitura sobre a lógica de conversão de carimbo de data / hora dmesg e como habilitar carimbos de data / hora quando não houver nenhum: https://supportcenter.checkpoint.com/supportcenter/portal?eventSubmit_doGoviewsolutiondetails=&solutionid=sk92677

Lucas cimon
fonte
pequena melhoria: você pode remover 'tail -1' no pipeline e apenas deixar o awk comer as linhas e imprimir da linha final em seu buffer. local dmesg_bin=$(type -a dmesg | awk 'END { print $NF }')
Brian Onn
@Lucas: você pode explicar usando 'type -a dmesg | ...' em vez de $ (which dmesg)? Existe uma vantagem em um tubo de 3 estágios para obter esse caminho?
Stabledog
@Stabledog: boa pergunta. Para obter uma explicação sobre por que usar typeover which, consulte esta pergunta . Eu editei minha resposta para evitar o tubo triplo inútil.
Lucas Cimon
este snippet bash / perl funcionou para mim, eu tenho uma máquina RHEL5.7 antiga que preciso cuidar e o dmesg não tem a opção de imprimir o carimbo de data / hora em tempo humano.
Paul M
17

Para sistemas sem "dmesg -T", como RHEL / CentOS 6, gostei da função "dmesg_with_human_timestamps" fornecida por lucas-cimon anteriormente. Ele tem alguns problemas com algumas de nossas caixas com grande tempo de atividade. Acontece que os timestamps do kernel em dmesg são derivados de um valor de tempo de atividade mantido por CPUs individuais. Com o tempo, isso fica fora de sincronia com o relógio em tempo real. Como resultado, a conversão mais precisa para entradas dmesg recentes será baseada no clock da CPU em vez de / proc / uptime. Por exemplo, em uma caixa CentOS 6.6 particular aqui:

# grep "\.clock" /proc/sched_debug  | head -1
  .clock                         : 32103895072.444568
# uptime
 15:54:05 up 371 days, 19:09,  4 users,  load average: 3.41, 3.62, 3.57
# cat /proc/uptime
32123362.57 638648955.00

Considerando o tempo de atividade da CPU em milissegundos, há um deslocamento de quase 5 horas e meia aqui. Então, revisei o script e o converti em bash nativo no processo:

dmesg_with_human_timestamps () {
    FORMAT="%a %b %d %H:%M:%S %Y"

    now=$(date +%s)
    cputime_line=$(grep -m1 "\.clock" /proc/sched_debug)

    if [[ $cputime_line =~ [^0-9]*([0-9]*).* ]]; then
        cputime=$((BASH_REMATCH[1] / 1000))
    fi

    dmesg | while IFS= read -r line; do
        if [[ $line =~ ^\[\ *([0-9]+)\.[0-9]+\]\ (.*) ]]; then
            stamp=$((now-cputime+BASH_REMATCH[1]))
            echo "[$(date +"${FORMAT}" --date=@${stamp})] ${BASH_REMATCH[2]}"
        else
            echo "$line"
        fi
    done
}

alias dmesgt=dmesg_with_human_timestamps
Allen Belletti
fonte
A função não funcionou no zsh. Tinha que fazer isso no bash adequado. Dito isso, em uma caixa com 221 dias de tempo de atividade, essa solução tinha o carimbo de hora até o minuto real. Outras soluções mostraram que o evento de causa raiz acontecia 2 horas ou mais no início do dia. Obrigado, Allen. Você salvou minha tarde.
Trenton
As máquinas RHEL5.x não parecem ter / proc / sched_debug :-(
Paul M
14

Então, KevZero solicitou uma solução menos confusa, então eu vim com o seguinte:

sed -r 's#^\[([0-9]+\.[0-9]+)\](.*)#echo -n "[";echo -n $(date --date="@$(echo "$(grep btime /proc/stat|cut -d " " -f 2)+\1" | bc)" +"%c");echo -n "]";echo -n "\2"#e'

Aqui está um exemplo:

$ dmesg|tail | sed -r 's#^\[([0-9]+\.[0-9]+)\](.*)#echo -n "[";echo -n $(date --date="@$(echo "$(grep btime /proc/stat|cut -d " " -f 2)+\1" | bc)" +"%c");echo -n "]";echo -n "\2"#e'
[2015-12-09T04:29:20 COT] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)
[2015-12-09T04:29:23 COT] wlp3s0: authenticate with dc:9f:db:92:d3:07
[2015-12-09T04:29:23 COT] wlp3s0: send auth to dc:9f:db:92:d3:07 (try 1/3)
[2015-12-09T04:29:23 COT] wlp3s0: authenticated
[2015-12-09T04:29:23 COT] wlp3s0: associate with dc:9f:db:92:d3:07 (try 1/3)
[2015-12-09T04:29:23 COT] wlp3s0: RX AssocResp from dc:9f:db:92:d3:07 (capab=0x431 status=0 aid=6)
[2015-12-09T04:29:23 COT] wlp3s0: associated
[2015-12-09T04:29:56 COT] thinkpad_acpi: EC reports that Thermal Table has changed
[2015-12-09T04:29:59 COT] i915 0000:00:02.0: BAR 6: [??? 0x00000000 flags 0x2] has bogus alignment
[2015-12-09T05:00:52 COT] thinkpad_acpi: EC reports that Thermal Table has changed

Se você quiser que ele tenha um desempenho um pouco melhor, coloque o carimbo de data / hora de proc em uma variável ao invés :)

Runejuhl
fonte
4

Nas versões recentes do dmesg, você pode simplesmente ligar dmesg -T.

Steffen Heil
fonte
3
A mesma resposta já foi dada por RC dois anos antes da sua.
Josch
4

Se você não tem a -Topção de dmesgcomo por exemplo no Andoid, você pode usar a busyboxversão. O seguinte resolve também alguns outros problemas:

  1. O [0.0000]formato é precedido por algo que parece informações de cores perdidas, prefixos como<6> .
  2. Faça inteiros de flutuantes.

É inspirado nesta postagem do blog .

#!/bin/sh                                                                                                               
# Translate dmesg timestamps to human readable format                                                                   

# uptime in seconds                                                                                                     
uptime=$(cut -d " " -f 1 /proc/uptime)                                                                                  

# remove fraction                                                                                                       
uptime=$(echo $uptime | cut -d "." -f1)                                                                                 

# run only if timestamps are enabled                                                                                    
if [ "Y" = "$(cat /sys/module/printk/parameters/time)" ]; then                                                          
  dmesg | sed "s/[^\[]*\[/\[/" | sed "s/^\[[ ]*\?\([0-9.]*\)\] \(.*\)/\\1 \\2/" | while read timestamp message; do      
    timestamp=$(echo $timestamp | cut -d "." -f1)                                                                       
    ts1=$(( $(busybox date +%s) - $uptime + $timestamp ))                                                               
    ts2=$(busybox date -d "@${ts1}")                                                                                    
    printf "[%s] %s\n" "$ts2" "$message"                                                                                
  done                                                                                                                  
else                                                                                                                    
  echo "Timestamps are disabled (/sys/module/printk/parameters/time)"                                                   
fi                                                                                                                      

Observe, no entanto, que essa implementação é bastante lenta.

Anne van Rossum
fonte
3

você precisará fazer referência ao "btime" em / proc / stat, que é o tempo de época do Unix em que o sistema foi inicializado pela última vez. Em seguida, você pode basear-se no tempo de inicialização do sistema e adicionar os segundos decorridos fornecidos em dmesg para calcular a data e hora de cada evento.

imcom
fonte