[20200317]dmesg與時間戳3.txt
--//dmesg的輸出顯示的時間戳不是很精確的,網上許多鏈接計算使用/proc/uptime會隨著uptime的延長,誤差越來越大.
--//隨手寫的腳本如下:
# cat $(which tdmesg )
#! /bin/bash
FORMAT="%Y-%m-%d %T:"
now=$(date +%s)
cputime=$(grep -m1 "sched_clk" /proc/sched_debug | cut -f2 -d: )
uptime=$(grep -m1 "ktime" /proc/sched_debug | cut -f2 -d: )
# echo $now $cputime $uptime
if [ "$1" == "uptime" ] ; then
cputime=$uptime
else
cputime=$cputime
fi
dispnum=${2:-50}
#echo $dispnum
dmesg| tail -${dispnum} | while read -r line; do
offset=$( echo $line | cut -d"]" -f1 | tr -d "[")
stamp=$( echo $now - $cputime / 1000 + $offset | bc -l )
#echo "$(date -d "1970-01-01 00:00:00 UTC $stamp seconds" +"${FORMAT}") $line"
echo "$(date -d "@${stamp}" +"${FORMAT}") $line"
done
--//晚上想如果我能定時插入1個時間戳,獲得比較準確的時間對于分析問題有一定的幫助.至少可以參考一下，
--//如何插入呢?我使用strace跟蹤很容易發現dmesg實際上是讀取/dev/kmsg.但是我測驗rhel 5.9 與centos 7.0不同.
--//如果直接使用cat /dev/kmsg看centos 7.0可以直接看到里面的內容.
--//而rhel 5.9不行報 Invalid argument.似乎兩個版本對這個快取處理方式不同.
# cat /dev/kmsg
cat: /dev/kmsg: Invalid argument
--//我直接執行 zdate >> /dev/kmsg,再使用dmesg觀察,可以正常顯示寫入的時間戳的.
--//以下是我執行zdate >> /dev/kmsg后今天看到的情況：
--//zdate 我定義的別名，
# alias zdate
alias zdate='date +'\''%Y/%m/%d %T'\'''
$ tdmesg '' 8
2020-03-16 09:47:57: [7219393.671149] device eth0 left promiscuous mode
2020-03-16 09:47:59: [7219395.849048] device eth0 entered promiscuous mode
2020-03-16 09:48:00: [7219396.305863] device eth0 left promiscuous mode
2020-03-16 10:58:25: [7223621.108505] 2020/03/16 10:55:34
2020-03-16 10:58:36: [7223632.716785] 2020/03/16 10:55:46
2020-03-16 11:11:45: [7224421.260769] 2020/03/16 11:08:56
2020-03-16 11:11:49: [7224425.731058] 2020/03/16 11:09:00
2020-03-16 11:11:50: [7224426.450256] 2020/03/16 11:09:01
--//你可以發現實際出現很大偏差，
# zdate >> /dev/kmsg
$ tdmesg '' 9
2020-03-16 09:47:58: [7219393.671149] device eth0 left promiscuous mode
2020-03-16 09:48:00: [7219395.849048] device eth0 entered promiscuous mode
2020-03-16 09:48:01: [7219396.305863] device eth0 left promiscuous mode
2020-03-16 10:58:25: [7223621.108505] 2020/03/16 10:55:34
2020-03-16 10:58:37: [7223632.716785] 2020/03/16 10:55:46
2020-03-16 11:11:46: [7224421.260769] 2020/03/16 11:08:56
2020-03-16 11:11:50: [7224425.731058] 2020/03/16 11:09:00
2020-03-16 11:11:51: [7224426.450256] 2020/03/16 11:09:01
2020-03-17 10:16:51: [7307526.307652] 2020/03/17 10:16:51
--//馬上插入對照看時間基本一致，明天再看就出現誤差了，這樣只能定時插入時間戳，對照分析就能相對獲得比較正確的時間點，
--//實際上centos 7的dmesg看也是誤差很大的，
# cat /etc/redhat-release
CentOS Linux release 7.7.1908 (Core)
# dmesg -T -L | tail -3
[Tue Mar 17 10:29:37 2020] 2020/03/17 10:19:12
[Tue Mar 17 10:30:34 2020] 2020/03/17 10:20:08
[Tue Mar 17 10:30:37 2020] 2020/03/17 10:20:12
--//對比時間相差 10分鐘+25秒， 大約625秒
--//使用我寫的腳本測驗：
# tdmesg '' 3
2020-03-17 10:19:11: [1295232.409194] 2020/03/17 10:19:12
2020-03-17 10:20:08: [1295289.078426] 2020/03/17 10:20:08
2020-03-17 10:20:11: [1295292.485899] 2020/03/17 10:20:12
--//基本接近，
# egrep "sched_clk|ktime|cpu_clk" /proc/sched_debug
ktime : 1294875872.314080
sched_clk : 1295502651.262182
cpu_clk : 1295502651.262218
--//(1295502651.262182-1294875872.314080)/1000 = 626.778948102
--//基本接近，也就是dmesg -T也是使用 類似 /proc/uptime作為基準的，這樣開機運行時間越長誤差越大，
--//這樣就很簡單了,利用crond定時執行，每小時執行1次，注意百分號前面的\不然不能正確執行，
--//在crontab中%字符被認為是換行，所以你的命令中有%時，在crontab中要加\轉義
$ man 5 crontab
The "sixth" field (the rest of the line) specifies the command to be run. The entire command portion of the line, up to
a newline or % character, will be executed by /bin/sh or by the shell specified in the SHELL variable of the cronfile.
Percent-signs (%) in the command, unless escaped with backslash (\), will be changed into newline characters, and all
data after the first % will be sent to the command as standard input.
# cat /etc/cron.d/dmesg
0 * * * * root /bin/date +"\%Y/\%m/\%d \%T" >> /dev/kmsg
--//這樣寫入這個時間戳是準確的,這樣再結合前面的腳本,分析誤差就不會太大.當然誤差還是存在的.
--//不知道這樣武斷的寫法有什么問題不妥,有待在測驗環境觀察.
轉載請註明出處，本文鏈接：https://www.uj5u.com/caozuo/127005.html
標籤：Linux
上一篇：git工具-系列目錄