关联 /var/log/* 时间戳

Question

/var/log/messages、/var/log/syslog和其他一些日志文件使用包含绝对时间的时间戳，例如Jan 13 14:13:10.

/var/log/Xorg.0.log和/var/log/dmesg，以及 的输出$ dmesg，使用看起来像

[50595.991610] malkovich: malkovich malkovich malkovich malkovich

我猜测/收集这些数字代表自启动以来的秒和微秒。

但是，我尝试将这两组时间戳相关联（使用 的输出uptime）给出了大约 5000 秒的差异。

这大约是我的计算机被挂起的时间。

有没有一种方便的方法可以将 dmesg 和 Xorg 使用的数字时间戳映射到绝对时间戳？

更新

作为解决这个问题的初步步骤，也希望让我的问题更清楚一点，我编写了一个Python 脚本来解析/var/log/syslog和输出时间偏差。在我运行 ubuntu 10.10 的机器上，该文件包含许多源自内核的行，这些行都标有 dmesg 时间戳和 syslog 时间戳。该脚本为该文件中的每一行输出一行，其中包含内核时间戳。

用法：

python syslogdriver.py /var/log/syslog | column -nts $'\t'

清除输出（列定义见下文）：

abs              abs_since_boot  rel_time      rel_offset  message
Jan 13 07:49:15  32842.1276569   32842.301498  0           malkovich malkovich

...rel_offset对于所有中间行都是 0 ...

Jan 13 09:55:14  40401.1276569   40401.306386  0           PM: Syncing filesystems ... done.
Jan 13 09:55:14  40401.1276569   40401.347469  0           PM: Preparing system for mem sleep
Jan 13 11:23:21  45688.1276569   40402.128198  -5280       Skipping EDID probe due to cached edid
Jan 13 11:23:21  45688.1276569   40402.729152  -5280       Freezing user space processes ... (elapsed 0.03 seconds) done.
Jan 13 11:23:21  45688.1276569   40402.760110  -5280       Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
Jan 13 11:23:21  45688.1276569   40402.776102  -5280       PM: Entering mem sleep

...rel_offset对于所有剩余的行是 -5280 ...

Jan 13 11:23:21  45688.1276569   40403.149074  -5280       ACPI: Preparing to enter system sleep state S3
Jan 13 11:23:21  45688.1276569   40403.149477  -5280       PM: Saving platform NVS memory
Jan 13 11:23:21  45688.1276569   40403.149495  -5280       Disabling non-boot CPUs ...
Jan 13 11:23:21  45688.1276569   40403.149495  -5280       Back to C!
Jan 13 11:23:21  45688.1276569   40403.149495  -5280       PM: Restoring platform NVS memory
Jan 13 11:23:21  45688.1276569   40403.151034  -5280       ACPI: Waking up from system sleep state S3

......最后几行从更远的地方开始，仍然远高于输出的结尾。 其中一些可能dmesg在挂起发生之前被写入的循环缓冲区，并且仅在syslog之后传播到。这解释了为什么它们都具有相同的系统日志时间戳。

列定义：

abs 是 syslog 记录的时间。

abs_since_boot是系统启动后的相同时间（以秒为单位），基于 的内容/proc/uptime和 的值time.time()。

rel_time 是内核时间戳。

rel_offset之间的差别abs_since_boot和rel_time。我将其四舍五入到几十秒，以避免由于绝对（即syslog生成的）时间戳只有秒精度而导致的一次性错误。这实际上不是正确的方法，因为它确实（我认为..）只会导致出现 10 次错误的可能性较小。如果有人有更好的主意，请告诉我。

我也有一些关于 syslog 的日期格式的问题；特别是，我想知道是否有一年出现在其中。我猜不会，无论如何都可以帮助自己获得 TFM 中的信息，但如果有人碰巧知道它会很有用。..当然，假设有人在未来的某个时候使用这个脚本，而不是仅仅破坏几行 Perl 代码。

下一个：

因此，除非你们中的一个人给了我一些受欢迎的启示，否则我的下一步将是添加一个函数来获取给定内核时间戳的时间偏差。我应该能够为脚本提供一个或一组系统日志以及内核时间戳，以获得绝对时间戳。然后我可以重新调试我的 Xorg 问题，目前我无法解决这些问题。

Answer 1

有趣的问题，不确定我是否尝试过这样做。但我注意到你所说的时间戳，我一直相信它是自启动以来的秒数。

在我的服务器上的系统日志中，我有：

Jan 10 19:58:55 wdgitial kernel: [    0.000000] Initializing cgroup subsys cpuset
Jan 10 19:58:55 wdgitial kernel: [    0.000000] Initializing cgroup subsys cpu
Jan 10 19:58:55 wdgitial kernel: [    0.000000] Linux version 2.6.32-21-server (buildd@yellow) (gcc version 4.4.3 (Ubuntu 4.4.3-4ubuntu5) ) #32-Ubuntu SMP Fri Apr 16     09:17:34 UTC 2010 (Ubuntu 2.6.32-21.32-server 2.6.32.11+drm33.2)
Jan 10 19:58:55 wdgitial kernel: [    0.000000] Command line:  root=/dev/xvda1 ro quiet splash

我想这在大多数 Linux 发行版中是相当一致的，因为这是内核吐出它的东西。

这里我有日期和时间戳。