Convierta la marca de tiempo dmesg a un formato de fecha personalizado

111

Estoy tratando de entender la marca de tiempo dmesg y me resulta difícil convertirla para cambiarla al formato de fecha java / fecha personalizada.

Cualquier ayuda es muy apreciada.

Ejemplo de registro dmesg:

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

¡Gracias!

ukanth
fuente

Respuestas:

179

Comprender la dmesgmarca de tiempo es bastante simple: es el tiempo en segundos desde que se inició el kernel. Entonces, teniendo tiempo de inicio ( uptime), puede sumar los segundos y mostrarlos en el formato que desee.

O mejor, puede usar la -Topción de línea de comando dmesgy analizar el formato legible por humanos.

Desde la página del 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
fuente
10
¿Qué comando acepta -T? Mi dmesg no lo hace, ni la página de manual lo dice. (Edición Debian de Linux Mint).
gyorgyabraham
1
El mío lo hace ( dmesgdesde util-linux 2.20.1Ubuntu 13.04)
2
No disponible en redhat y / o oracle linux 5.6, rpm -qf /bin/dmesg => util-linux-2.13-0.56.0.2.el5
michael
7
Esta opción apareció en util-linux 2.20, según las Notas de la versión: ftp.kernel.org/pub/linux/utils/util-linux/v2.20/…
ks1322
1
@xealits gracias por el seguimiento, eso es amable de su parte :) Con respecto a la pregunta, creo que la parte de comprensión es menor y "convertir eso para cambiarlo al formato de fecha java / fecha personalizada". fue la parte central, pero su opinión puede diferir. Que tengas un buen día;)
32

Con la ayuda de dr answer, escribí una solución alternativa que hace que la conversión se coloque en su .bashrc. No romperá nada si no tiene ninguna marca de tiempo o si ya tiene marcas de tiempo correctas.

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

Además, una buena lectura sobre la lógica de conversión de marca de tiempo dmesg y cómo habilitar marcas de tiempo cuando no hay ninguna: https://supportcenter.checkpoint.com/supportcenter/portal?eventSubmit_doGoviewsolutiondetails=&solutionid=sk92677

Lucas Cimon
fuente
mejora menor: puede eliminar 'tail -1' en la tubería y dejar que awk coma líneas e imprima desde la línea final en su búfer. local dmesg_bin=$(type -a dmesg | awk 'END { print $NF }')
Brian Onn
@Lucas: ¿puedes explicar el uso de 'type -a dmesg | ...' en lugar de $ (qué dmesg)? ¿Existe alguna ventaja en una tubería de 3 etapas para obtener ese camino?
Stabledog
@Stabledog: buena pregunta. Para obtener una explicación sobre por qué usar typeover which, consulte esta pregunta . Sin embargo, edité mi respuesta para evitar el triple tubo inútil.
Lucas Cimon
este fragmento de bash / perl funcionó para mí, tengo una vieja máquina RHEL5.7 que debo cuidar y dmesg no tiene la opción de imprimir la marca de tiempo en tiempo humano.
Paul M
17

Para sistemas sin "dmesg -T" como RHEL / CentOS 6, me gustó la función "dmesg_with_human_timestamps" proporcionada anteriormente por lucas-cimon . Sin embargo, tiene algunos problemas con algunas de nuestras cajas con un gran tiempo de actividad. Resulta que las marcas de tiempo del kernel en dmesg se derivan de un valor de tiempo de actividad mantenido por CPU individuales. Con el tiempo, esto se desincroniza con el reloj de tiempo real. Como resultado, la conversión más precisa para las entradas recientes de dmesg se basará en el reloj de la CPU en lugar de / proc / uptime. Por ejemplo, en una caja CentOS 6.6 en particular aquí:

# 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

Teniendo en cuenta que el tiempo de actividad de la CPU está en milisegundos, aquí hay una compensación de casi 5 1/2 horas. Así que revisé el script y lo convertí a bash nativo en el proceso:

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
fuente
La función no funcionó en zsh. Tenía que hacerlo en bash propiamente dicho. Dicho esto, en una caja con 221 días de tiempo de actividad, esta solución tenía la marca de tiempo hasta el minuto real. Otras soluciones mostraron que el evento de causa raíz sucedió más de 2 horas antes en el día. Gracias, Allen. Me salvaste la tarde.
Trenton
Las máquinas RHEL5.x no parecen tener / proc / sched_debug :-(
Paul M
14

Entonces KevZero solicitó una solución menos complicada, así que se me ocurrió lo siguiente:

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'

He aquí un ejemplo:

$ 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

Si desea que funcione un poco mejor, coloque la marca de tiempo de proc en una variable en su lugar :)

runejuhl
fuente
4

En versiones recientes de dmesg, puede simplemente llamar a dmesg -T.

Steffen Heil
fuente
3
La misma respuesta ya la dio RC dos años antes que la suya.
Josch
4

Si no tiene la -Topción para dmesg, por ejemplo, en Andoid, puede usar la busyboxversión. Lo siguiente también resuelve algunos otros problemas:

  1. El [0.0000]formato está precedido por algo que parece información de color fuera de lugar, prefijos como <6>.
  2. Haz números enteros a partir de flotantes.

Está inspirado en esta publicación de 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                                                                                                                      

Sin embargo, tenga en cuenta que esta implementación es bastante lenta.

Anne van Rossum
fuente
3

necesitará hacer referencia a "btime" en / proc / stat, que es la época de Unix en la que el sistema se inició por última vez. Luego, puede basarse en el tiempo de arranque del sistema y luego agregar los segundos transcurridos dados en dmesg para calcular la marca de tiempo para cada evento.

imcom
fuente