Конвертировать метку времени dmesg в пользовательский формат даты

Я пытаюсь понять метку времени dmesg и мне трудно преобразовать ее, чтобы изменить ее на формат даты / даты / Java.

Буду признателен за любую оказанную помощь.

Пример журнала dmesg:

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

Спасибо!

12 ответов

Решение

Понимание dmesg Отметка времени довольно проста: время в секундах с момента запуска ядра. Итак, имея время запуска (uptime), вы можете сложить секунды и показать их в любом формате, который вам нравится.

Или лучше, вы могли бы использовать -T вариант и разобрать удобочитаемый формат.

Со страницы руководства:

-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.

С помощью ответа Aliaksei Ramanau я написал обходной путь, который делает преобразование в ваш.bashrc. Это ничего не сломает, если у вас нет метки времени или уже правильные метки времени.

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

Кроме того, хорошее прочтение о логике преобразования меток времени dmesg и о том, как включить метки времени, когда их нет: https://supportcenter.checkpoint.com/supportcenter/portal?eventSubmit_doGoviewsolutiondetails=&solutionid=sk92677

Для систем без "dmesg -T", таких как RHEL/CentOS 6, мне понравилась функция "dmesg_with_human_timestamps", предоставленная ранее Lucas Cimon. Это имеет некоторые проблемы с некоторыми из наших коробок с большим временем безотказной работы. Оказывается, что временные метки ядра в dmesg получены из значения времени безотказной работы, сохраняемого отдельными процессорами. Со временем это не синхронизируется с часами реального времени. В результате наиболее точное преобразование для последних записей dmesg будет основано на тактовой частоте процессора, а не на / proc / uptime. Например, на конкретном поле CentOS 6.6 здесь:

# 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

Если учесть время работы процессора в миллисекундах, то здесь смещение составляет почти 5 с половиной часов. Поэтому я пересмотрел скрипт и преобразовал его в нативный bash:

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

Поэтому KevZero запросил менее хитрое решение, поэтому я придумал следующее:

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

Вот пример:

$ 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

Если вы хотите, чтобы он работал немного лучше, вместо этого поместите отметку времени из proc в переменную:)

dmesg -Tможет показывать неправильное время, отличное от dateвывод команды.

Обходной путь — logctl с параметрами -k, --dmesg. Я использую -k, так как он короче:

      journalctl -k

Он покажет только сообщения ядра и правильное время.

Чтобы показать только строки ядра, соответствующие фразе:

      journalctl -kg phrase

Если у вас нет -T вариант для dmesg как например на Andoid, вы можете использовать busybox версия. Следующее решает также некоторые другие проблемы:

  1. [0.0000] формату предшествует нечто, похожее на неуместную информацию о цвете, такие префиксы, как <6>,
  2. Делать целые числа из чисел с плавающей точкой.

Это вдохновлено этим сообщением в блоге.

#!/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                                                                                                                      

Обратите внимание, однако, что эта реализация довольно медленная.

В последних версиях dmesg вы можете просто позвонить dmesg -T,

Вам нужно будет сослаться на "btime" в /proc/stat, который является временем эпохи Unix, когда система загружалась в последний раз. Затем вы могли бы основываться на времени загрузки этой системы, а затем добавить прошедшие секунды, указанные в dmes g, чтобы вычислить метку времени для каждого события.

Команда ниже дает вам лучший результат

      dmesg | awk -F ] '{"cat /proc/uptime | cut -d \" \" -f 1" | getline st;a=substr( $1,2, length($1) - 1);print strftime("%F %H:%M:%S %Z",systime()-st+a)" -> "$0}'

В старых дистрибутивах Linux еще одним вариантом является использование сценария упаковки, например, в Perl или Python.

Смотрите решения здесь:

http://linuxaria.com/article/how-to-make-dmesg-timestamp-human-readable?lang=en http://jmorano.moretrix.com/2012/03/dmesg-human-readable-timestamps/

Предостережение, о котором, похоже, не упоминают другие ответы, заключается в том, что время, отображаемое dmesg не учитывает время сна / приостановки. Итак, есть случаи, когда обычный ответ использования dmesg -T не работает и показывает совершенно неправильное время.

Обходной путь для таких ситуаций - записать что-то в журнал ядра в известное время, а затем использовать эту запись в качестве ссылки для вычисления других времен. Очевидно, это будет работать только после последнего приостановления.

Итак, чтобы отобразить правильное время для последних записей на машинах, которые могли быть приостановлены с момента их последней загрузки, используйте что-то вроде этого из моего другого ответа здесь:

# write current time to kernel ring buffer so it appears in dmesg output
echo "timecheck: $(date +%s) = $(date +%F_%T)" | sudo tee /dev/kmsg

# use our "timecheck" entry to get the difference
# between the dmesg timestamp and real time
offset=$(dmesg | grep timecheck | tail -1 \
| perl -nle '($t1,$t2)=/^.(\d+)\S+ timecheck: (\d+)/; print $t2-$t1')

# pipe dmesg output through a Perl snippet to
# convert it's timestamp to correct readable times
dmesg | tail \
| perl -pe 'BEGIN{$offset=shift} s/^\[(\d+)\S+/localtime($1+$offset)/e' $offset

Мне нужно было просмотреть журнал кольцевого буфера на старом встроенном устройстве Linux. На устройстве не было новой опции -T для dmesg, не было bc или даже версии sed или bash, которая работала бы с приведенными выше примерами. Я закончил создание сценария с использованием AWK для форматирования дат журнала на основе сценария sed runejuhl. Вот скрипт, вдруг кому пригодится.

          #!/bin/sh
    
    # print kernel ring buffer (dmesg log) with readable times if (dmsg -T not available)
    
    # boot time in seconds
    boottime=$(echo $(grep -m1 "btime" /proc/stat) | grep -Eo "[0-9]*$")
    
    lines=$1
    if [ -z $lines ]; then
        lines=10
    fi
    
    #dislpay last x lines of kernel log using awk script instead of sed / bc
    dmesg | tail -n $lines | awk 'match($0, /^\[ *([0-9]+\.[0-9]+)\]/) \
    { print strftime("[%a %d/%m/%Y %H:%M:%S]",sprintf("%.0f", ('$boottime' + substr($0, RSTART+1, RLENGTH-2)))) substr($0, RLENGTH+1) }'

Он считывает время загрузки системы и сохраняет его в переменной, затем анализирует журнал, извлекая метку времени каждой строки, добавляя ее ко времени загрузки, форматируя ее в строку даты и времени и записывая ее вместе с остальной частью строки.

Строка времени загрузки (btime) считывается из /proc/stat и извлекается время.
boottime=$(echo $(grep -m1 "btime" /proc/stat) | grep -Eo "[0-9]*$")

команда сопоставления AWK используется для поиска отметки времени в формате [0.0]
match($0, /^\[ *([0-9]+\.[0-9]+)\]/)

После совпадения регулярного выражения переменные RSTART и RLENGTH содержат начало и длину совпадающих символов. Метка времени извлекается с помощью команды подстроки, игнорируя [ ]substr($0, RSTART+1, RLENGTH-2)

Затем временная метка добавляется к значению времени загрузки и округляется обратно до целого числа, используяsprintf("%.0f", timestamp + boottime)

Наконец, время форматируется до читаемого значения с помощьюа остальная часть строки журнала будет напечатана с помощью другой команды substr, берущей остальную часть строки после исходной отметки времени.substr($0, RLENGTH+1)

Другие вопросы по тегам