seahawk1986
Anmeldungsdatum: 27. Oktober 2006
Beiträge: 11179
Wohnort: München
|
frank-w schrieb: trotzdem unpraktisch, um mal fix die Logs durchzuschauen
Unix-Timestamps kann man ja leicht automatisiert umwandeln lassen - einfach die Ausgabe des Programms reinpipen oder die Logdatei dem Skript als Argument übergeben:
1
2
3
4
5
6
7
8
9
10
11
12 | #!/usr/bin/env python3
from datetime import datetime
import fileinput
for line in fileinput.input():
ts, sep, logmessage = line.partition(':')
try:
iso_ts = datetime.fromtimestamp(float(ts)).isoformat(timespec='microseconds')
except (ValueError, OverflowError, OSError):
print(line, end='')
else:
print(f"{iso_ts}{sep}{logmessage}", end='')
|
$ ./decode_ts.py << EOF
> 1531821530.517610: ap0: Setup of interface done.
> 1531821530.517633: ctrl_iface not configured!
> 1531821530.517708: RTM_NEWLINK: ifi_index=10 ifname=ap0 operstate=2 linkmode=0 i
> fi_family=0 ifi_flags=0x11003 ([UP][LOWER_UP])
> 1531821530.517738: nl80211: Set IF_OPER_UP again based on ifi_flags and expected
> operstate
> 1531821530.517758: netlink: Operstate: ifindex=10 linkmode=-1 (no change), opers
> tate=6 (IF_OPER_UP)
> 1531821530.517846: RTM_NEWLINK: ifi_index=10 ifname=ap0 operstate=6 linkmode=0 i
> fi_family=0 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
> EOF
2018-07-17T11:58:50.517610: ap0: Setup of interface done.
2018-07-17T11:58:50.517633: ctrl_iface not configured!
2018-07-17T11:58:50.517708: RTM_NEWLINK: ifi_index=10 ifname=ap0 operstate=2 linkmode=0 i
fi_family=0 ifi_flags=0x11003 ([UP][LOWER_UP])
2018-07-17T11:58:50.517738: nl80211: Set IF_OPER_UP again based on ifi_flags and expected
operstate
2018-07-17T11:58:50.517758: netlink: Operstate: ifindex=10 linkmode=-1 (no change), opers
tate=6 (IF_OPER_UP)
2018-07-17T11:58:50.517846: RTM_NEWLINK: ifi_index=10 ifname=ap0 operstate=6 linkmode=0 i
fi_family=0 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP]) Timestamps durch externes Logging sind für die allermeisten Anwendungsfälle gut genug, aber wenn man möglichst nahe an den Zeitpunkt des eigentlichen Events kommen will, statt den Zeitpunkt zu speichern zu dem ein zweites Programm die Logmeldung liest, lohnt es sich den Timestamp im Programm selbst möglichst frühzeitig generieren und mit auszugeben. journald arbeitet intern mit µs Auflösung (journalctl zeigt mit Standard-Einstellungen aber nur Sekunden an), wenn man eine bessere zeitliche Auflösung wollte, müsste man das auf jeden Fall im Programm regeln.
|
seahawk1986
Anmeldungsdatum: 27. Oktober 2006
Beiträge: 11179
Wohnort: München
|
frank-w schrieb: mit | hostapd -dd /etc/hostapd/hostapd_ap0.conf | systemd-cat -t "hostapd_ap0"
|
landen die meldungen schonmal mit zeitstempel in der syslog...aber ich sehe noch keine Unterscheidung zwischen stdin und stderr...
Das kann journald/journalctl noch nicht unterscheiden (vgl. z.B. https://github.com/systemd/systemd/pull/6599) - wenn die Meldung von stdout oder stderr von systemd-cat gelesen wird, wird im journal _TRANSPORT=stdout gesetzt:
$ cat test.sh
#!/bin/bash
echo "msg on stdout"
echo "msg on stderr" >&2
$ systemd-cat -t test ./test.sh
$ journalctl --since=-1m --output=verbose
-- Logs begin at Sat 2013-05-25 19:23:07 CEST, end at Tue 2018-07-17 15:05:46 CEST. --
Tue 2018-07-17 15:05:46.534991 CEST [s=10bc3034a309485fbb040a67cf053eb6;i=a721;b=d986f9d27fa84d80ad82ce63d98369fb;m=5fe22e052;t=571319ab6684f;x=9deead1a97acbfed]
_UID=1000
_GID=100
_CAP_EFFECTIVE=0
_SYSTEMD_OWNER_UID=1000
_SYSTEMD_SLICE=user-1000.slice
_SYSTEMD_USER_SLICE=-.slice
_MACHINE_ID=8d85275275a34713886055925c957312
_HOSTNAME=archii
PRIORITY=6
_TRANSPORT=stdout
_SYSTEMD_CGROUP=/user.slice/user-1000.slice/session-c1.scope
_SYSTEMD_SESSION=c1
_SYSTEMD_UNIT=session-c1.scope
_BOOT_ID=d986f9d27fa84d80ad82ce63d98369fb
_SYSTEMD_INVOCATION_ID=388a2d24224542b9b16a0dd13173157c
SYSLOG_IDENTIFIER=test
_COMM=test.sh
_EXE=/usr/bin/bash
_CMDLINE=/bin/bash ./test.sh
MESSAGE=msg on stdout
_STREAM_ID=91defd0b3acb4159b4e70aad039155c7
_PID=4558
Tue 2018-07-17 15:05:46.535431 CEST [s=10bc3034a309485fbb040a67cf053eb6;i=a722;b=d986f9d27fa84d80ad82ce63d98369fb;m=5fe22e20b;t=571319ab66a07;x=a0616d083edf77c5]
_UID=1000
_GID=100
_CAP_EFFECTIVE=0
_SYSTEMD_OWNER_UID=1000
_SYSTEMD_SLICE=user-1000.slice
_SYSTEMD_USER_SLICE=-.slice
_MACHINE_ID=8d85275275a34713886055925c957312
_HOSTNAME=archii
PRIORITY=6
_TRANSPORT=stdout
_SYSTEMD_CGROUP=/user.slice/user-1000.slice/session-c1.scope
_SYSTEMD_SESSION=c1
_SYSTEMD_UNIT=session-c1.scope
_BOOT_ID=d986f9d27fa84d80ad82ce63d98369fb
_SYSTEMD_INVOCATION_ID=388a2d24224542b9b16a0dd13173157c
SYSLOG_IDENTIFIER=test
_COMM=test.sh
_EXE=/usr/bin/bash
_CMDLINE=/bin/bash ./test.sh
MESSAGE=msg on stderr
_STREAM_ID=91defd0b3acb4159b4e70aad039155c7
_PID=4558
|
frank-w
(Themenstarter)
Anmeldungsdatum: 30. September 2008
Beiträge: 408
|
mit der pipe landet stderr nicht in systemd-cat sondern auf der console...bisher habe ich noch keine Möglichkeit gefunden, dass systemd-cat beide streams getrennt bekommt... Edit sehe grade du rufst erst systemd-cat auf und gibst das script mit...ist halt wie du sagst beides die gleiche prio
|
seahawk1986
Anmeldungsdatum: 27. Oktober 2006
Beiträge: 11179
Wohnort: München
|
frank-w schrieb: mit der pipe landet stderr nicht in systemd-cat sondern auf der console...bisher habe ich noch keine Möglichkeit gefunden, dass systemd-cat beide streams getrennt bekommt
Aktuell wirft es die einfach zusammen, wenn man wie in der Manpage beschrieben auf die Pipe verzichtet:
systemd-cat -t "hostapd_ap0" hostapd -dd /etc/hostapd/hostapd_ap0.conf
|