ubuntuusers.de

via DuckDuckGo

bash redirect mit stderr-modifikation

Status: Ungelöst | Ubuntu-Version: Ubuntu 18.04 (Bionic Beaver)
Antworten |

seahawk1986

Anmeldungsdatum:
27. Oktober 2006

Beiträge: 11269

Wohnort: München
Zitieren
17. Juli 2018 14:53

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: 11269

Wohnort: München
Zitieren
17. Juli 2018 15:06

frank-w schrieb:

mit

1
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: 419
Zitieren
17. Juli 2018 16:07 (zuletzt bearbeitet: 17. Juli 2018 16:35)

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: 11269

Wohnort: München
Zitieren
17. Juli 2018 16:34

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
Antworten |