Doppeltes Fehlerlogging mit Systemd

  • Hallo,

    aktuell beschäftigt mich das Problem, dass auftretende Fehler in Python Skripte doppelt geloggt werden mit systemd.


    Skript (verkürzte darstellung, deshalb Zeilennr. später unstimmig):

    Fehler natürlich bewusst herbeigeführt


    Code
    def main():
        a = 1 + "a"
    
    if __name__ == "__main__":
        try:
            main()
        finally:
            LOGGER.exeption("Schwerwiegender Fehler aufgetreten")

    LOGGER ist eine Instanz von dem Modul from systemd import journal


    Mein Problem:

    Das in rot ist auch im Terminal wirklich rot, und die gewollte Ausgabe durch das Skript. Es hat den anschein, dass aber auch der Python Interpreter selbst nochmals die Fehlermeldungen an systemd weiterleitet. (Die Codeformatierung hatte was gegen meine Farbe, rot ist der Teil nach picoffee[7577]:

    bis Ende des Codeblockes

    Entweder, wie bringe ich dem Pythoninterpreter bei dass er die Fehlermeldungen nicht weiterreichen soll? Eventuell eine Ausgabeumleitung, aber ob die in einer System Unit funktioniert hab ich noch nicht getest und würde ich auch nicht "schön" finden

    oder aber, kann ich systemd es lernen die doppelte Ausgabe zu ignorieren?

  • Hallo,


    kannst du auch noch einfacher im Terminal nachstellen:


    Python
    >>> try:
    ...     a = 0 + 'b'
    ... finally:
    ...     print('Fehler')
    ... 
    Fehler
    Traceback (most recent call last):
      File "<stdin>", line 2, in <module>
    TypeError: unsupported operand type(s) for +: 'int' and 'str'
    >>> 

    Hingegen:

    Python
    >>> try:
    ...     a = 0 + 'b'
    ... except TypeError:
    ...     pass
    ... finally:
    ...     print('fehler')
    ... 
    fehler
    >>>

    liefert das von dir gewünschte Verhalten.


    Gruß, noisefloor

  • Beziehungsweise noch näher an deinem aktuellen Code:

    Erst wird die letzte Exception durch den Logger ausgegeben, dann das selbe Traceback nochmal, weil die Exception nicht abgefangen wurde. Die nicht abgefangene(n) Exception(s) wird/werden immer ganz am Ende des try/except/finally ausgegeben:


  • Skript (verkürzte darstellung, deshalb Zeilennr. später unstimmig):


    Ok ich hab es wohl etwas zu sehr verkürzt, die Struktur sieht viel mehr so aus:


    Code den Fehler abfangen (macht finally nach meinem Verständnis nicht)

    finally = Code, der immer ausgeführt wird, egal ob im try-Block eine Exception geworfen (und nicht abgefangen) wurde oder nicht

    finally eigentlich deshalb, ich will ja auf nicht abgefangene Fehler aufmerksam werden (siehe nachgereichten Code im Kommentar) Aber ja, es könnte die gewünschte Lösung sein, dass ich es im journal die Fehlermeldungen nicht doppelt stehen habe, wenn ich ein blankes! :evil: except vor dem finally setze.

    Da der try/except Block außerhalb der Endlosschleife plaziert ist, beendet sich danach sowieso das Skript.



    kannst du auch noch einfacher im Terminal nachstellen:

    Ja, kommt in meinem Eingangspost schlecht rüber, logging.exception speichert ja die auftretende Fehlermeldung, nur ich will es eben nicht doppelt haben.



    EDIT (Nachtrag):

    Hier nochmals gestaffelt dargestellt:

    Lila der Block wie es sich verhält mit dem Code von oben und von mir nicht gewünscht ist, da doppelte Fehlerausgabe. Wie aber schon an der Farbe zu erkennen, die Ausgabe welche der Pythoninterpreter selbst macht ist keine error Meldung sondern eine Info.

    Somit sind unbekannte Fehler mittels journalctl -u exception_test -p err nicht mehr filterbar, da -p auf info gestellt werden müsste -> unbrauchbar

    Somit muss ein "manuelles" Loggen erfolgen.


    Der Blaue Block kommt wie folgt zustande:

    Python
    try:
        main()
    except:
        pass
    finally:
        LOGGER.exception("Schwerwiegender Fehler aufgetreten")

    Somit ebenfalls nicht brauchbar, da keine passende Fehlerausgabe mehr zustanden kommt.


    Jetzt der grüne Block - so wie ich es mir auch vorstelle :)

    Realisiert habe ich es aktuell mit 2 Wegen


    1. Weg:

    Python
    try:
        main()
    except:
        LOGGER.exception("Schwerwiegender Fehler aufgetreten")

    Da hier ein blankes except verwendet wird, habe ich, danke eines Tipps von Linus noch einen 2. Weg gefunden, um das blanke except zu vermeiden:



    Für Interessenten die es auch ausprobieren möchten noch das setup_logging Modul und die Service Unit:


  • Hallo,


    also technisch gesehen ist es so, dass der Code wegen des fehlenden `except` den Fehler nach stderr schreibt, was bei einem von systemd gestartetem Programm, was im Hintergrund läuft, wohl in den Log von journald umgeleitet wird.


    Du kannst natürlich auch so was machen:

    !!! Achtung, Hack! Nicht nachmachen, wenn ihr nicht genau wisst, was ihr tut!!!

    Python
    >>> import sys
    >>> with open('/dev/null', 'w') as f:
    ...     sys.stderr = f
    ...     try:
    ...         a = 1 + 'b'
    ...     finally:
    ...         print('Fehler')
    ... 
    Fehler
    >>>

    Aber sinnvoll ist das in dem Kontext hier nicht.


    Gruß, noisefloor

  • Hallo,


    eben nicht gesehen: Der Code von Hofei mit dem `sys.excepthook = unbekannter_fehler` macht ja im Prinzip das gleiche. Sinnvoll ist das aber IMHO nicht, weil das, genau wie das Umleiten von stdout, die eigentliche Fehlermeldung "weg bügelt", was bei der Fehlersuche nicht hilfreich ist. Wenn einen der Traceback wirklich nicht interessiert, kann man das IMHO machen.


    Gruß, noisefloor

  • finally eigentlich deshalb, ich will ja auf nicht abgefangene Fehler aufmerksam werden

    Mit finally wirst Du aber auch auf einen Fehler aufmerksam gemacht, wenn gar keiner auftritt:

    Code
    $ python << EOF
    > try:
    >   a = 1+1
    > finally:
    >   print "Schwerer Fehler!"
    > EOF
    Schwerer Fehler!
    $ 

    Da hier ein blankes except verwendet wird, habe ich, danke eines Tipps von Linus noch einen 2. Weg gefunden, um das blanke except zu vermeiden:

    Wozu soll das gut sein? Der Effekt ist der gleiche wie der eines blanken excepts, nur etwas versteckter.