/var/log/messages
, /var/log/syslog
Und einige andere Protokolldateien verwenden , um einen Zeitstempel , die eine absolute Zeit enthält, wie Jan 13 14:13:10
.
/var/log/Xorg.0.log
und /var/log/dmesg
, sowie die Ausgabe von $ dmesg
, verwenden Sie ein Format, das aussieht
[50595.991610] malkovich: malkovich malkovich malkovich malkovich
Ich vermute, dass die Zahlen Sekunden und Mikrosekunden seit dem Start darstellen.
Mein Versuch, diese beiden Zeitstempelsätze (unter Verwendung der Ausgabe von uptime
) zu korrelieren, ergab jedoch eine Diskrepanz von etwa 5000 Sekunden.
Dies ist ungefähr die Zeit, für die mein Computer angehalten wurde.
Gibt es eine bequeme Möglichkeit, die von dmesg und Xorg verwendeten numerischen Zeitstempel in absolute Zeitstempel umzuwandeln?
aktualisieren
Als ersten Schritt, um dies herauszufinden, und um meine Frage hoffentlich etwas klarer zu machen, habe ich ein Python-Skript geschrieben, um den Zeitversatz zu analysieren /var/log/syslog
und auszugeben. Auf meinem Computer, auf dem Ubuntu 10.10 ausgeführt wird, enthält diese Datei zahlreiche vom Kernel stammende Zeilen, die sowohl mit dem Zeitstempel dmesg als auch mit dem Zeitstempel syslog versehen sind. Das Skript gibt für jede Zeile in dieser Datei eine Zeile aus, die einen Kernel-Zeitstempel enthält.
Verwendung:
python syslogdriver.py /var/log/syslog | column -nts $'\t'
Freigegebene Ausgabe (siehe unten für Spaltendefinitionen):
abs abs_since_boot rel_time rel_offset message
Jan 13 07:49:15 32842.1276569 32842.301498 0 malkovich malkovich
... rel_offset
ist 0 für alle dazwischenliegenden Zeilen ...
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
ist -5280 für alle verbleibenden Zeilen ...
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
... Die letzten Zeilen kommen etwas weiter unten, immer noch weit über dem Ende der Ausgabe. Einige von ihnen wurden vermutlich dmesg
vor dem Suspend in den Ringpuffer geschrieben und erst syslog
danach weitergegeben. Dies erklärt, warum alle den gleichen Syslog-Zeitstempel haben.
Spaltendefinitionen:
abs
ist die von syslog protokollierte Zeit.
abs_since_boot
ist dieselbe Zeit in Sekunden seit dem Systemstart, basierend auf dem Inhalt von /proc/uptime
und dem Wert von time.time()
.
rel_time
ist der Kernel-Zeitstempel.
rel_offset
ist der Unterschied zwischen abs_since_boot
und rel_time
. Ich runde dies auf zehn Sekunden, um einmalige Fehler zu vermeiden, da die absoluten (dh syslog
generierten) Zeitstempel nur eine Sekundengenauigkeit haben. Das ist eigentlich nicht der richtige Weg, da es (glaube ich) nur zu einer geringeren Wahrscheinlichkeit eines Off-by-10-Fehlers führt. Wenn jemand eine bessere Idee hat, lass es mich wissen.
Ich habe auch einige Fragen zum Datumsformat von Syslog. Insbesondere frage ich mich, ob jemals ein Jahr darin auftaucht. Ich vermute nein, und auf jeden Fall könnte ich mir höchstwahrscheinlich diese Informationen in TFM zu Nutze machen, aber wenn jemand es zufällig weiß, wäre es nützlich. Vorausgesetzt natürlich, dass jemand dieses Skript irgendwann in der Zukunft verwendet, anstatt nur ein paar Zeilen Perl-Code herauszuschleudern.
Nächster:
Wenn mir also keiner von Ihnen eine willkommene Offenbarung gibt, besteht mein nächster Schritt darin, eine Funktion hinzuzufügen, um den Zeitversatz für einen bestimmten Kernel-Zeitstempel zu ermitteln. Ich sollte in der Lage sein, dem Skript einen oder mehrere Syslogs zusammen mit einem Kernel-Zeitstempel zuzuweisen, um einen absoluten Zeitstempel zu erhalten. Dann kann ich wieder meine Xorg-Probleme beheben, die mir im Moment entgehen.
quelle
sort
, die Jahr, Zeitzone usw. + 1 für das Python-Skript haben.Freezing user space processes
was eindeutig vor dem Schlafengehen erfolgt.[12345.6789]..
) lediglich den absoluten Zeitstempel hinzu , damit die Dinge korrekt ausgeführt werden , vorbehaltlich der in meinem letzten Kommentar behandelten Fragen. Ich bin mir nicht sicher, was der Kernel hier wirklich tun soll. Dies hängt davon ab, was diese startrelativen Zeitstempel anzeigen sollen. Die Laufzeit (im Gegensatz zur Zeit seit dem Start) kann in manchen Zusammenhängen von Bedeutung sein. Idealerweise würde es eine zuverlässige Aufzeichnung dieser beiden Werte geben.Antworten:
Interessantes Problem, Ich bin mir nicht sicher, ob ich es jemals versucht habe. Aber ich habe den Zeitstempel bemerkt, von dem Sie sprechen, und ich habe immer geglaubt, dass er Sekunden nach dem Hochfahren ist.
In meinem Syslog, das ich auf meinem Server habe, habe ich:
Ich würde mir vorstellen, dass dies bei den meisten Linux-Distributionen ziemlich konsistent ist, da dies der Kernel ist, der das Zeug ausspuckt.
Und hier habe ich das Datum zusammen mit dem Zeitstempel.
quelle
Sie können dies ausprobieren:
Holen Sie sich zuerst den Zeitstempel der dmesg-Datei (ich gehe davon aus, dass dies die Zeit 0 von dmesg ist). Du wirst verwenden
Mit können Sie die Sekunden in ein lesbares Datum umwandeln
Um eine lesbare Ereigniszeit anzuzeigen, fügen Sie in dmesg die Sekunden des Ereignisses hinzu. Wenn das dmesg-Ereignis 55,290387 Sekunden lang war, fügen Sie 55 oder 55,290387 hinzu:
Eine andere Möglichkeit, Sekunden mit epochaler Wurzel in lesbare Zeit umzuwandeln, ist die vorgeschlagene Verwendung von Datum -d. Wenn Sie 'date' anweisen, eine mit -d gelieferte Zeit darzustellen, können Sie mit @ angeben, dass die zu konvertierende Zeit in Sekunden seit der Epoche angegeben werden soll.
Dies gibt Ihnen so etwas wie "Do Jan 13 15:26:18 CST 2011" als Ausgabe.
druckt die aktuelle Zeit im Format "Sekunden seit Epoche".Ich kann mich nicht erinnern, wie man Shell-Mathe macht, deshalb benutze ich normalerweise die Perl-Methode wie oben. :)
quelle
date -d @$((1294953978 + 55))
zumindest unter Druck setzen. Einige Kernel-Zeitstempel sind jedoch verzerrt, was bedeutet, dass die durch diese Methode erzeugten Zeiten früher sind als die entsprechenden Zeitstempel in/var/log/syslog
. Es sieht so aus, als ob dies auf Ereignisse im Zusammenhang mit dem Suspend-to-RAM zurückzuführen ist, vermutlich zusätzlich zum Ruhezustand und möglicherweise auf andere Ereignisse, da die Kernel-Zeit in diesen Zeiträumen nicht inkrementiert wird. Weitere Informationen finden Sie im Fragen-Update.Der einfachste Weg, die Nummer von dmesg auf ein Datum abzubilden, ist die Verwendung des
date
Programms.Dieser Befehl zeigt das Datum für die aktuelle Zeit minus 50595 Sekunden an.
Von
man date
:Die Zahl entspricht der Einschaltzeit und nicht der seit dem Start verstrichenen Zeit.
quelle
Da Sie festgestellt haben, dass sich die Zeitverschiebung während der Unterbrechung / Wiederaufnahme geändert hat, wird dies an mindestens einer Stelle dokumentiert. Die Manpage von dmesg (1) sagt:
Ich habe keine Möglichkeit gefunden, den Kernel dazu zu bringen, diese Zeitstempel mit der Wandzeit synchron zu halten.
quelle
Schnell, dreckig, funktioniert.
Inhalt dieses Skripts:
Die Beispielausgabe lautet wie folgt:
quelle