Modul 93_Log2Syslog - FHEM Logs an Syslog-Server leiten und Syslogs empfangen

[DS_Starter]

Inspiriert vom Modul 92_rsyslog (aus contrib) von betateilchen (herzlichen Dank dafür!) habe ich dieses kleine Modul erstellt, welches das FHEM Systemlog und/oder FHEM-Events an einen remoten Syslog-Server weiterleitet. Es soll all jenen nützlich sein, die in ihrer Umgebung einen zentralen Syslog-Server bereits für das Logging von Geräten wie Router, Switsches o.ä. verwenden und gern die Meldungen von FHEM mit integrieren möchten.

Direkt nach der Definition sendet das neue Device alle neu auftretenden FHEM Systemlog Einträge und Events ohne weitere Einstellungen an den Zielhost, Port=514/UDP Format:IETF, wenn reguläre Ausdrücke für Events/FHEM angegeben wurden.
Wurde kein Regex gesetzt, erfolgt keine Weiterleitung von Events oder FHEM Systemlogs.

Alle Messages werden mit Severity "notice" weitergeleitet wenn nicht der Event oder FHEM-Log Eintrag das Suchwort "Warning" oder "Error" enthält. In diesen Fällen wird auch die Severity entsprechend gesetzt. Die Verbose-Level im FHEM-Log werden entsprechend ihrer Wertigkeit umgesetzt.

Getestet habe ich es mit dem Synology On-Board Syslog-Server (Protokoll-Center) und der Enterprise-Lösung Splunk (kann bis 500 MB
tägliches Datenvolumen kostenfrei genutzt werden) -> https://www.splunk.com/en_us/products/splunk-enterprise.html.


Voraussetzungen:

    1. das Modul muss aus ./contrib nach ./FHEM gebracht werden, entweder als Kopie oder als symlink.
    2. Es wird das Perl Modul "IO::Socket::INET" benötigt und muss installiert sein. Das Modul kann über CPAN oder mit   apt-get install libio-socket-multicast-perl (auf Debian Linux Systemen) installiert werden.
   
Definition:

    define <name> Log2Syslog <Zielhost> [ident:<ident>] [event:<regexp>] [fhem:<regexp>] 
   
    <destination host> = Zielhost auf dem der Syslog-Server läuft
    [ident:<ident>] = optinaler Programm Identifier. Wenn nicht gesetzt wird per default der Devicename benutzt.
    [event:<regexp>] = optionaler regulärer Ausdruck zur Filterung von Events zur Weiterleitung
    [fhem:<regexp>] = optionaler regulärer Ausdruck zur Filterung von FHEM Logs zur Weiterleitung

    Beispiel um alles zu loggen:

    define splunklog Log2Syslog splunk.mydomain.dom event:.*  fhem:.*
   

Attribute:

   Siehe Hilfe mit "help Log2Syslog".
      
Das Modul ist eingecheckt und ab dem 29.08.2017 per Update verfügbar.

Wie immer sind Feedback / Hinweise gewünscht.
Eine aktuelle Entwicklungsversion (Weiterentwicklung) stelle ich weiterhin unter ./contrib zum Test zur Verfügung sofern es eine Version zum Test gibt.

Grüße,
Heiko

[rudolfkoenig]

Alle Messages werden mit Severity "information" weitergeleitet wenn nicht der Event oder FHEM-Log Eintrag das Suchwort "Warning" oder "Error" enthält. In diesen Fällen wird auch die Severity entsprechend gesetzt.

Eigentlich ist verbose anders definiert: https://fhem.de/commandref.html#verbose
Ich meine folgende Zuordnung waere sinnvoll:
0: Critical
1: Error
2: Warning
3: Notice
4: Informational
5: Debug

[PatrickR]

Tolle Sache!
Schließe mich Rudis Hinweis zu Logleveln an. Nur für Events müsste man sich was überlegen...


Von unterwegs gesendet.

[DS_Starter]

Guten Morgen zusammen,

die Idee hinter der Severity-Level bezog sich tatsächlich weniger auf die verbose-Level, sondern auf das Vorhandensein von bestimmten Signalwörtern im Meldungstext selbst. Eben aus dem Grund weil ich in den Events sonst nichts ableiten kann.

Rudi hat natürlich Recht und ich stelle das mal auf meine Weiterentwicklungsagenda den Schweregrad zu vereinheitlichen.
Es würde für mich so aussehen, dass alle Meldungen (vorrangig Events) mit Severity "Notice" rausgehen, es sei denn es finden sich die entsprechenden Signalwörter.
Bei den FHEM Logs würde ich den verbose-Level direkt auf die Severity mappen (je nachdem was  Sys::Syslog hergibt). Sollte sich im Logtext wieder ein Signalwort finden, kann dieses die Severity übersteuern.

Denke das würde dann passen.

[rudolfkoenig]

Die Weiterleitung der Events bremst bei meinen Tests das System merklich (apptime)...

Wuerde mich interessieren wieso: soweit ich es in diesem RFC sehe, gibt es keine Antwort vom Server, und damit sollten die Meldungen in den UDP/TCP Puffer des Client-Kernels verschwinden, und damit "gefuehlt" asynchron sein.
Vielleicht ist das ein Grund das Syslog Protokoll selbst zu implementieren

[DS_Starter]

Vielleicht ist das ein Grund das Syslog Protokoll selbst zu implementieren

Ja das ist auch nochmal eine Idee. Ich schau mal ob ich das hinbringe ... 

[betateilchen]

Hallo Heiko,

kannst Du das Modul bis zu seiner Fertigstellung nicht einfach in ./contrib bereitstellen? Das würde die Einbindung auf Testsystemen, die i.d.R. ohnehin per SVN verwaltet werden, erheblich erleichtern. Man muss dann das Modul nicht dauernd neu aus dem Forum-Thread laden und auf irgendeinen eigenen Server kopieren, sondern kann einfach mit einem symlink arbeiten.

[DS_Starter]

Hallo Udo,

ja klar, kann ich machen. Bin grad am schrauben. Wenn ich die nächste Version fertig habe passe ich das alles an.

[betateilchen]

was ich mir an dem Modul grundsätzlich anders wünschen würde:

Die Angabe der regexp dafür, was geloggt werden soll, sollte sich eher an der "Logik" von FileLog und DbLog orientieren, als Angabe von regexp bereits im define, anstatt zusätzlich mit Attributen zu arbeiten.

Code Auswählen Erweitern


define   <name>   Log2Syslog  <ident> <destination host> [event:<regexp>] [fhem:<regexp>]


Ausserdem würde ich das Defaultverhalten bei nicht angegebenen regexp umkehren: Nichts loggen. Auch damit würde man sich am bisher bekannten Verhalten von FileLog und DbLog orientieren. Per default alles zu loggen ist jedenfalls nichts, was ich als Anwender unbedingt haben möchte.

Damit erübrigen sich dann auch die Attribute logmode, FhemlogFilter, EventlogFilter.

Meine derzeitige Befürchtung ist, dass da gerade wieder ein Attribute-Moloch geschaffen wird, den ausser dem Entwickler selbst niemand mehr versteht und beherrscht, weil er sich an nichts hält, das man bisher aus FHEM kennt.

[DS_Starter]

Hallo Udo,

die beiden RegEx im Def finde ich eine gute Idee. Werde ich bei der kommenden Version gleich mit vorsehen.
Die Idee per Default alles weiterzuleiten kam aus dem Gedankengang dass wir ja im eigentlichen Sinn nichts loggen wollen, sondern all das was der User im FHEM sehen würde an den zentralen Server weiterzuleiten.
Aber das geht natürlich auch wenn man im Define für beide RegEx ".*" setzt.

Komme ganz gut mit der eigenen Implementierung des syslog Protokolls voran. Performance ist Klasse wie es sein soll. Stoße aber immer wieder darauf dass der syslog-server meine Message nicht so versteht wie ich es erwarte.
Baue Mal weiter (heute Abend).

Grüße
Heiko

[DS_Starter]

Jetzt habe ich die Verbesserungsvorschläge umgesetzt und und das syslog Protokoll nachgbildet (IETF, BSD).
Den Eingangsbeitrag habe ich angepasst weil sich sowohl die Definition als auch die Attribute verändert haben.

Der Ident-String ist im Def entfernt, aber wird im Modul aus dem Devicenamen und dem Logtyp, also entweder event oder fhem, zusammengesetzt und an den Server übertragen. So kann man im Syslog Server die Übersichtlichkeit erhöhen und Filter setzen etc.

Die Performance ist auch jetzt so wie ich sie haben möchte -> ca. 6 ms mit apptime gemessen bei Freischaltung aller Events und logs (also 2 x ".*").

Ach ja ... im contrib ist es nun auch 

Grüße
Heiko

[rudolfkoenig]

Gratuliere!
Hast du eine Idee, warum die alte Implementierung nicht so effizient war?

[DS_Starter]

Hallo Rudi,

in die Ursachenforschung hatte ich nicht wirklich viel Energie reingesteckt weil ich von der Idee es selbst zu implementieren gleich begeistert war und mich darauf konzentriert habe.
Aber ich vermute !  das es es mit Systemaufrufen zu Unix syslog(3) zu tun hat da SYS::SYSLOG sich dessen bedient.
Erschwerend kam sicherlich dazu dass ich als Ziel ein DNS Namen benutzt habe statt einer IP. Das war wahrscheinlich keine so gute Idee.
Möglicherweise wären andere Tester zu einem anderen Ergebnis gekommen.
Wenn daran Interesse besteht kann ich die alte Version gerne nochmal zur Verfügung stellen. Vielleicht schau ich mit der alten V auch nochmal.

Bin gespannt was die ersten Tests bei anderen Usern ergeben 

Grüße,
Heiko

[SusisStrolch]

Du wolltest es so 

Ich habe Version 2.0.0 und ein Device definiert

Code Auswählen Erweitern

defmod syslog Log2Syslog 192.168.254.20 event:.* fhem:.*
attr syslog room DbLog
attr syslog verbose 3

setstate syslog active
setstate syslog 2017-08-17 16:28:19 state active



a) Beim Anlegen des Device wird folgende Meldung ausgegeben:

Code Auswählen Erweitern

2017.08.17 16:20:01.332 1: PERL WARNING: "my" variable $sock masks earlier declaration in same scope at ./FHEM/93_Log2Syslog.pm line 176.
2017.08.17 16:20:01.333 1: PERL WARNING: "my" variable $sock masks earlier declaration in same scope at ./FHEM/93_Log2Syslog.pm line 220.


b) ein Event ":Garten.LCG.Environment -> error: 0" wird als Severity "error" geloggt

c) 93_Log2Syslog übernimmt (logisch) ab "Server started with 138 defined entities", allerdings laufen nur/noch einige Log-Mitteilungen ins fhem.log

Code Auswählen Erweitern

2017.08.17 16:28:19.852 0: Server started with 138 defined entities (fhem.pl:14854/2017-08-06 perl:5.020002 os:linux user:fhem pid:31485)
2017.08.17 16:28:20.172 1: 192.168.254.25:9090 reappeared (CuBoxI4Pro)
2017.08.17 16:28:20.181 1: 192.168.254.27:9090 reappeared (Cubox_i4)
2017.08.17 16:28:20.189 1: 192.168.254.26:9090 reappeared (Hummingboard)
2017.08.17 16:28:22.595 3: Can't connect to 192.168.254.40:23: connect to http://192.168.254.40:23 timed out
2017.08.17 16:28:22.596 3: SIGNALduino sduino: connect to http://192.168.254.40:23 timed out
2017.08.17 16:28:24.004 3: DbRep db5.rep - connected
2017.08.17 16:28:24.008 3: DbRep Rep.Agent - connected
2017.08.17 16:28:24.013 3: DbRep db10.rep - connected
2017.08.17 16:28:25.675 4: ESPEasy ESPEasy_D1pro_01_Env: set statusRequest
2017.08.17 16:28:25.676 5: ESPEasy ESPEasy_D1pro_01_Env: Start internalTimer +300 => 2017-08-17 16:33:26
2017.08.17 16:28:26.328 3: UWZ Unwetterzentrale: Run.1000 Done fetching data
2017.08.17 16:29:22.440 4: HttpUtils url=http://192.168.254.40:23/
2017.08.17 16:30:19.784 1: miniCUL433: answer: Please define miniCUL433 first
2017.08.17 16:30:25.922 4: HttpUtils url=http://192.168.254.40:23/


Auf dem Syslog-Server finde ich jedoch nur einen einzelnen "syslog_fhem" Eintrag, nämlich den:

Code Auswählen Erweitern

Server started with 138 defined entities (fhem.pl:14854/2017-08-06 perl:5.020002 os:linux user:fhem pid:31485
Alles andere wandert munter ins fhem.log

[DS_Starter]

Ja, wollte ich 

a) Entwickler Fehler, mache ich heute Abend weg

b) das ist so designed ... Signalwort "error"

c) Also fhem.log wird natürlich weiterhin bedient wenn nicht ausgeschaltet. Das nur eine Message ankommt und dann nicht mehr ist sicher ungewöhnlich und ist bei auch nicht so. Rollt alles schön rein. Nun ist UDP nicht das zuverlässigste Protokoll. Mach das Ganze Mal mit TCP.  Musst auf Empfänger Seite auch einrichten natürlich.