[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Re: Bash Einzeiler Zeit+Datum letzter Eintrag dmesg



Am 15.08.2011 08:39, schrieb David Haller:
> Hallo,
> 
> Am Sun, 14 Aug 2011, Rico Koerner schrieb:
>> David hat mich durch den Hinweis auf syslog bei der Fehlersuche jetzt
>> noch auf einen anderen Lösungsweg gebracht. Da die Zeile aus dmesg auch
>> in einer Zeile im Syslog auftaucht, braucht man doch gar nicht anfangen
>> zu rechnen sondern einfach nur die passende Zeile aus dem syslog
>> ziehen.
> 
> Haaalt! Konkretes Beispiel: bei mir schreibt syslog-ng z.B. firewall
> und /dev/sr0 betreffende Einträge in jew. eigene Logs (die würden mir
> sonst das eigentliche nur zumüllen). Ergo müßte ich man in mehreren
> Dateien rumgreppen ... Der letzte Eintrag in dmesg findet sich bei mir
> grad nur(!) in /v/l/firewall.

Ja, jeder Ansatz hat seine eigenen Vor- und Nachteile.
Auch die Vorgabe "ohne root" war mir nicht bewußt. Wem die Gruppe adm
noch zu großzügig ist, kann es ja auch mit ACLs auf syslog versuchen.
Wenn die Logs abweichend sind, scheitert mein Ansatz natürlich auch,
u.U. müssten dann mehrere Logs durchsucht werden.
Dafür ist das Ergebnis genauer, weil die Abweichung zwischen den Zählern
nicht verfälschen.

> dmesg ist also schon der richtige Ansatz.

Das hab ich ja nicht verworfen.

>> Dort steht die Zeit ja schon am Anfang der Zeile. Somit wird immer die
>> korrekte Zeit ausgegeben.

Nein, eben nicht. Die Abweichung wurde ja nun schon mehrfach
festgestellt. Nur deshalb hab ich den Weg verfolgt.

>> LASTENTRY=`dmesg | tail -n1`; LASTTIME=${LASTENTRY%%]*}; grep
>> ${LASTTIME#[} /var/log/syslog | cut -c-15
>>
>> Geht sogar ohne sed/awk, auf cut konnte ich zum Schluß nicht ganz
>> verzichten.
> 
> Da ich den Krams schon im Cache habe (sonst kommt noch die Ladezeit
> der Tools (und evtl. der Subshells) ins Spiel):

Wenn man die Genauigkeit nicht benötigt, kann ich grep auch weglassen
und mir trotzdem cut/sed/awk sparen.

LASTENTRY=`dmesg | tail -n1`; LASTTIME=${LASTENTRY%%.*}; BOOT=`cat
/proc/uptime`; date -d "$((${BOOT%%.*} - ${LASTTIME#[})) seconds ago";

> Und die andere Variante, die ebenfalls /proc/uptime ausliest dürfte
> noch lahmer sein.

Lassen wir mal die Vermutungen beiseite und führen das aus.
Mein Rechner ist allerdings insgesamt nicht so schnell,

Die Ausgangsvariante:
~# time { for i in {1..1000}; do let lastentry=$(dmesg|tail -n 1|cut -f1
-d"."|cut -c2-|cut -f2 -d" "); let boot=$(cut -f1 -d. /proc/uptime); let
lastdate=$boot-$lastentry; date -d "$lastdate seconds ago"; done >
/dev/null; }

real	0m17.204s
user	0m5.704s
sys	0m16.753s

AWK:
~# time { for i in {1..1000}; do date -d "$(dmesg | gawk -F'[][ ]+'
'BEGIN{getline<"/proc/uptime";u=$1;} END{printf("%i\n",u-$2);}') seconds
ago"; done > /dev/null; }

real	0m13.924s
user	0m5.468s
sys	0m9.261s

Syslog:
~# time { for i in {1..1000}; do LASTENTRY=`dmesg | tail -n1`;
LASTTIME=${LASTENTRY%%]*}; grep ${LASTTIME#[} /var/log/syslog | cut
-c-15; done > /dev/null; }

real	0m15.713s
user	0m5.204s
sys	0m11.057s

Bash only:
~# time { for i in {1..1000}; do LASTENTRY=`dmesg | tail -n1`;
LASTTIME=${LASTENTRY%%.*}; BOOT=`cat /proc/uptime`; date -d
"$((${BOOT%%.*} - ${LASTTIME#[})) seconds ago"; done > /dev/null; }

real	0m15.433s
user	0m4.112s
sys	0m11.569s

Ja, awk ist hier am schnellsten.
Erstaunlicherweise ist grep+cut nicht wesentlich schlechter als
cat+date. Suchen wir doch mal den Zeitfresser.

Ich klammer mal die einzelnen Aufrufe aus der Schleife aus:
~# time { LASTENTRY=`dmesg | tail -n1`; for i in {1..1000}; do
LASTTIME=${LASTENTRY%%.*}; BOOT=`cat /proc/uptime`; date -d
"$((${BOOT%%.*} - ${LASTTIME#[})) seconds ago"; done > /dev/null; }

real	0m4.661s
user	0m1.264s
sys	0m3.132s

dmesg|tail schluckt schon mal >10s, also schon mal 2/3 der Gesamtzeit.

~# time { for i in {1..1000}; do dmesg; done > /dev/null; }
real	0m7.649s
user	0m2.636s
sys	0m5.152s

Den größten Teil davon benötigt dmesg selbst, ist also nicht vermeidbar.
Bleiben ca. 3s für tail.

~# time { BOOT=`cat /proc/uptime`; for i in {1..1000}; do
LASTENTRY=`dmesg | tail -n1`; LASTTIME=${LASTENTRY%%.*}; date -d
"$((${BOOT%%.*} - ${LASTTIME#[})) seconds ago"; done > /dev/null; }

real	0m12.770s
user	0m3.708s
sys	0m9.517s

cat ist auch mit ca. 3s dabei


~# time { for i in {1..1000}; do LASTENTRY=`dmesg | tail -n1`;
LASTTIME=${LASTENTRY%%.*}; BOOT=`cat /proc/uptime`; done; date -d
"$((${BOOT%%.*} - ${LASTTIME#[})) seconds ago" > /dev/null; }

real	0m12.775s
user	0m3.960s
sys	0m9.365s

date ebenfalls.


> Mantra: Prozesse starten, Disk- und Console-I/O ist lahm!
Dann spar dir doch auch den seq-Aufruf, das kann die bash auch allein. ;-)

-- for i in `seq 1 1000`;
++ for i in {1..1000};

> Oh, da fällt mir ein: das 'date' kann man sich (mit GNU awk) auch noch
> sparen:
> 
> real    0m4.050s
> user    0m0.220s
> sys     0m0.452s

Nur um hier auch den Vergleichswert auf der selben Maschine zu haben:
~# time { for i in {1..1000}; do dmesg | gawk -F'[][ ]+' ' BEGIN {
getline < "/proc/uptime"; u = $1; } END { print strftime("%c", systime()
- (u - $2) ); }'; done > /dev/null; }

real	0m10.197s
user	0m2.996s
sys	0m7.248s

ca. 4s bei date gespart, also ähnlich dem Ergebnis vom ausklammern oben.

Insgesamt ist das damit auch ein schön kurzer Einzeiler, der nur 1
zusätzliches Programm (gawk) benötigt. Sehr gut. :-)

Ich bin zwar nicht der awk-Guru, aber wenn ich es mal einsetze, dann
auch möglichst ohne Verkettungen mit anderen Programmen.

Damit sollten wir dem OP jetzt genügend Anregungen für seinen
Programmierspaß gegeben haben. ;-)

Wobei mein Spaß daran auch nicht zu kurz kam. :-)


Gruß
Rico

Attachment: smime.p7s
Description: S/MIME Kryptografische Unterschrift


Reply to: