FritzBox Log auswerten und Meldungen für bestimmte Einträge verschicken

[RalfRog]

Hinweis vom 4. April 2023: ab Modulversion 07.50.12 ist ausser  FritzOS 7.50 auch < 7.50 möglich (bis 6.8 )

Trotz VPN ist es manchmal vielleicht erforderlich für einige Zeit den Externen Zugang per HTTPS zu FritzBox zu aktivieren.
Nicht immer kommt infrage sich eine eMail Notifikation schicken zu lassen, weil z.B. eventuell zu viele erfolgreiche Anmeldeversuche ein Mailflut auslösen.

Das Ziel war nur gescheiterte Anmeldeversuche gemeldet zu bekommen. Das Log also zeitnah zu durchsuchen, um zu reagieren bzw. fremde externe IP-Adressen ab FritzOS 7.50 eventuell in die Blacklist einzutragen.

Die Methode kann natürlich für jeden beliebigen von der FritzBox geloggten Eintrag erfolgen.

Die FritzBox wird über das Modul 72_FRITZBOX.pm überwacht und bietet darin per Kommando "get fritzbox luaData xhr 1 lang de page log xhrId log filter all useajax 1 no_sidrenew nop" die Möglichkeit das Logfile abzufragen.
Der Modulautor hat auf Basis der Idee https://forum.fhem.de/index.php?topic=132790.0 zur einfachen Handhabung ab Modulversion 07.50.10 das Logfile
als hash in der 99_myUtils.pm per "sub myUtilsFritzLogExPost" bereit gestellt.
Ab 07.50.12 ist der Aufruf in zwei Varianten möglich (non)Blocking myUtilsFritzLogExPostnb / myUtilsFritzLogExPost


Folgender Code erzeugt einen Logeintrag und schickt per msg (Wiki https://wiki.fhem.de/wiki/Msg) eine Mail^*1 für gescheiterte Logins mit der Meldungs-ID 501, 503, 505 oder 510.
^*1 Eine Push Nachricht per TelegramBot scheitert aktuell noch daran, dass er schlicht nicht ausgeführt wird ist ab Modulversion 07.50.12 möglich wenn der Aufruf statt nonBlocking (Standard) Blocking ausgeführt wird. Wird per Parameter off im Kommando get <name> fritzLog <hash> ausgewählt.

Vorbemerkung

• CommandRef lesen !
• Modulversion: ab 07.50.12 für Fritz!OS 7.50 mit Erweiterung auf 7.29/21 und 6.8
• 99_myUtils.pm ergänzen:
  "use Data::Dumper;" (wird von der sub aufgerufen)
  Sub einfügen Beispiel siehe weiter unten
  "sub myUtilsFritzLogExPostnb" und "sub myUtilsFritzLogExPost"

• ein at, notify, doif einrichten um ein "get <name> fritzLog <hash | table> <all | sys | wlan | usb | net | fon>[on|off]" des Moduls aufzurufen

Hinweis1
Der Aufruf des Log "get <name> fritzLog hash..." kann wahlweise mit dem zusätzlichen Parameter "off" am Ende der Zeile aufgerufen werden.
Dann wird das Logfile modulintern blocking (statt nonblocking) aufgerufen und verzweigt in 99_myUtils in die Sub "myUtilsFritzLogExPost" (ohne nb). Damit können Probleme umgangen werden, die z.B. beim Aufruf des TelgramBot aus der Sub heraus auftreten. Ursache ist, dass aus nonBlocking nicht erneut nonBlocking aufgerufen werden kann.
Muss man ausprobieren, ob der eigene Code davon betroffen ist (siehe https://forum.fhem.de/index.php?msg=1270723)

Hinweis2
Die Datenstruktur in Fritz!OS 7.50 / 7.29 / 6.8 ist etwas unterschiedlich (ID = Fehlernummer, Group = System, WLAN etc.).
Die Codezeile "Log3 $name, 3, "INFO: fritzLogInfo: \n" . Dumper $result" hilft bei der Analyse der Daten des Logs.

• In 7.50 ist der Logeintrag ein hash (keys: 'id', 'date', 'time', 'group' als Text, 'msg', 'helplink', 'nohelp')
• In 7.29 ein array in dem die Daten sortiert vorliegen (Datum, Zeit, Meldung, ID, Group als Zahl, Helplink)
• In 6.8 fehlt mir eine Referenz

Code mit Kommentar und leicht abgewandelt gegenüber Idee und Vorschlag https://forum.fhem.de/index.php?msg=1269178  für Fritz!OS 07.50 mit hash

Code Auswählen Erweitern

############
## Fritzbox-Log auswerten  nonblocking     ######
### fester Name der Sub "myUtilsFritzLogExPost" fuer Modul FritzBox
### mit der Funtion get <name> fritzLog <hash | table> <all | sys | wlan | usb | net | fon>
###
sub myUtilsFritzLogExPostnb($$$) {
  my ($hash, $filter, $result) = @_;
  my $name = $hash->{NAME};

  if(defined $result->{Error}) {
    Log3 $name, 2, "ERROR: fritzLogInfo: " . $result->{Error};                       # fuer Fehler LogLevel 2
    return $result->{Error};
  }

### zur Ueberprüfung wird hier per Funktion Dumper mal das ganze Ergebnis ausgegeben ###
### wenn nicht mehr nötig auskommentieren, oder ich setzt es mir auf LogLevel 4      ###
  Log3 $name, 4, "INFO: fritzLogInfo: \n" . Dumper $result;

### hier wird - ist sinnvoll!- geloggt welche Loginfo abgefragt wurde                ###
### eingefügt: return "keine Auswertung auf diesen Filter"                           ###
###        für Filter die weiter unten nicht ausgewertet werden                      ###
###        hier zunächst nur sys, wlan                                               ###
  if ($filter eq "all") {
    Log3 $name, 2, "INFO: fritzLogInfo: all";
    return "keine Auswertung auf diesen Filter";                                     # Sub Ende da keine Auswerung

  } elsif ($filter eq "sys") {
    Log3 $name, 2, "INFO: fritzLogInfo: sys";

  } elsif ($filter eq "wlan") {
    Log3 $name, 2, "INFO: fritzLogInfo: wlan";

  } elsif ($filter eq "usb") {
    Log3 $name, 2, "INFO: fritzLogInfo: usb";
    return "keine Auswertung auf diesen Filter";                                     # Sub Ende da keine Auswerung

  } elsif ($filter eq "net") {
    Log3 $name, 2, "INFO: fritzLogInfo: net";
    return "keine Auswertung auf diesen Filter";                                     # Sub Ende da keine Auswerung

  } elsif ($filter eq "fon") {
    Log3 $name, 2, "INFO: fritzLogInfo: fon";
    return "keine Auswertung auf diesen Filter";                                     # Sub Ende da keine Auswerung

  } else {
    Log3 $name, 2, "INFO: fritzLogInfo: wrong filter";
    return "keine Auswertung auf diesen Filter";                                     # Sub Ende da keine Auswerung
  }


# so gehts! mit dem Referenzieren auf die Arrays und Hashes
# my $logidx = $result->{data}->{log};   #Referenz auf das ARRAY log in foreach (@{ $result -> {data} -> {log} })
# direkter Wert $wert = $result->{data}->{log}->[Array 0 bis N]->{msg}; entsprechend der n Zeilen im Fritzbox-Log

### Ab hier Auswertung auf bestimmte Einträge                                        ###
#     Debug $filter;
my $boxread = "box_sys_LogNewest"  if ($filter eq "sys");                            # if Filter = sys  OldReading box_sys_LogNewest  auslesen
   $boxread = "box_wlan_LogNewest" if ($filter eq "wlan");                           # if Filter = wlan OldReading box_wlan_LogNewest auslesen
my ($readId,$readDate,$readTime) =  split(' ',OldReadingsVal($name,$boxread,""));    # Zeit des vorherigen -OldLogeintrages = readTime
#     Debug $readTime;

     foreach my $logidx (@{$result->{data}->{log}}) {                               # alle Elemente im Array log durchgehen
#     Debug $logidx;

         if ($logidx->{time} ne $readTime){                                         # Element im Array untersuchen wenn Eintrag neuer als OldReading-Time
#     Debug $logidx->{time};

             if ($logidx->{id} eq 501||$logidx->{id} eq 503||$logidx->{id} eq 505||$logidx->{id} eq 510) {      # 505 User und falsches Kennwort oder 501, 503, 510
                 Log3 $name, 2, "$name Anmeldefehler 5xx: $logidx->{msg}";
                 fhem("msg mail  $name Anmeldefehler 5xx: $logidx->{msg}",1);        # Alternative, da msg push hängt       
#                 fhem("msg push $name Anmeldefehler 5xx: $logidx->{msg}",1);        # Meldung per masg ueber TelegramBot
#                 fhem("set teleBot message @#UserName Anmeldefehler 5xx: $logidx->{id}  $logidx->{msg}",1);   # Meldung direkt ueber TelegramBot

                 return "5xx gefunden";
             }                                      # ende 2. if und -Schluss da id gefunden
#           elsif {}                             # weitere id prüfen
 
         }                                          # ende 1. nächstes Array Element

         else { return "done no match in timewindow";}    # else des 1. if: alte Zeit erreicht, daher bis hierher bereits gesucht also Schluss

                                                    # nächstes Element im Array
     } # ende foreach

  return "done no match in Log";    ### und Schluss

}                   ### Ende Sub
ToDo's

• Push Message über TelegramBot läuffähig bekommen  erledigt durch blocking Aufruf von get <name> fritzLog hash
• kritische Systemmeldungen heraussuchen und melden  erledigt, im Webinterface in der Hilfe zum modul hat der Modulautor interessante Systemmeldungen aufgelistet
• Code für WLAN-Meldungen ergänzen

[RalfRog]

Aufbau eines Log: (in Fritz!OS 7.50) hier mit Filter "fon"

Der interessante Teil fängt im Abschnitt "'log' => [.........]," an. Das sind die einzelnen Logeinträge wie sie zeilenweise in der Fritzbox zu sehen sind.
Datum -> date  |  Uhrzeit -> time  |  Meldung -> msg  |  Fehlernummer -> id  |  Filter -> group  |  Link zur Hilfe -> helplink

Die Variable $VAR1 unten im Logauszug (im Codeschnipsel = $result) ist ein:

• hash mit den "key's" der Wertepaare 'hide', 'data', 'sid', 'time', 'pid', 'timeTillLogout'
• 'data' ist darin ein weiterer hash mit den "key's" der Wertepaare 'show', 'wlan', 'log', 'filter', 'wlanGuestPushmail'
• 'log' ist darin ein arrray mit mehreren hashes 1-n die die Loginfos enthalten. Diese wieder als key der Wertepaare 'id', 'date', 'time', 'group', 'msg', 'helplink', 'nohelp'
• Die Inhalte von 'id', 'date', 'time', 'msg' sind die eigentlich interessanten Daten

Es hat mich einiges an Lesen und Kopfzerbrechen gekostet wie auf die verschiedenen Variablen ($scalar, @array, %hash) zugegriffen wird. Für Perl-Kenner ist das geläufig 
Eins noch: array's sind sortiert (daher ist die Reihenfolge nach Datum absteigend), hash'es sind unsortiert (daher ist die Reihenfolge von 'date', 'time', 'msg' in jedem Eintrag anders).

Beispiel
Der Zugriff auf den 3. Logeintrag unten aus dem Logauszug mit "Internetverbindung (Telefonie) wurde erfolgreich hergestellt" erfolgt im Perl-Code über:
$Meldung = {$result}->{data}->{log}->[2]->{msg}

Code Auswählen Erweitern

$VAR1 = {
          'hide' => {
                      'ssoSet' => bless( do{\(my $o = 1)}, 'JSON::PP::Boolean' ),
                      'rss' => $VAR1->{'hide'}{'ssoSet'},
                      'liveImg' => $VAR1->{'hide'}{'ssoSet'},
                      'provServ' => $VAR1->{'hide'}{'ssoSet'},
                      'rrd' => $VAR1->{'hide'}{'ssoSet'},
                      'liveTv' => $VAR1->{'hide'}{'ssoSet'},
                      'dectRdio' => $VAR1->{'hide'}{'ssoSet'},
                      'mobile' => $VAR1->{'hide'}{'ssoSet'},
                      'dectMail' => $VAR1->{'hide'}{'ssoSet'}
                    },
          'data' => {
                      'show' => {
                                  'all' => $VAR1->{'hide'}{'ssoSet'},
                                  'fon' => $VAR1->{'hide'}{'ssoSet'},
                                  'net' => $VAR1->{'hide'}{'ssoSet'},
                                  'sys' => $VAR1->{'hide'}{'ssoSet'},
                                  'wlan' => {
                                              'has_wpa2_support' => $VAR1->{'hide'}{'ssoSet'},
                                              'has_wpa3_support' => bless( do{\(my $o = 0)}, 'JSON::PP::Boolean' )
                                            },
                                  'usb' => $VAR1->{'hide'}{'ssoSet'}
                                },
                      'wlan' => $VAR1->{'data'}{'show'}{'wlan'}{'has_wpa3_support'},
                      'log' => [
                                 {
                                   'time' => '00:01:38',
                                   'group' => 'fon',
                                   'date' => '26.03.23',
                                   'nohelp' => 0,
                                   'id' => 72,
                                   'helplink' => '/help/help.lua?sid=ac643567284b964a&helppage=hilfe_syslog_72.html',
                                   'msg' => 'Anmeldung der Internetrufnummer sip1 war nicht erfolgreich. Gegenstelle meldet Ursache 401'
                                 },
                                 {
                                   'group' => 'fon',
                                   'date' => '24.03.23',
                                   'nohelp' => 0,
                                   'time' => '08:56:20',
                                   'msg' => "Internettelefonie mit 0123987654321 \x{c3}\x{bc}ber sip.provider.de war nicht erfolgreich. Ursache: Not Found (404)",
                                   'id' => 78,
                                   'helplink' => '/help/help.lua?sid=ac643567284b964a&helppage=hilfe_syslog_78.html'
                                 },
                                 {
                                   'msg' => 'Internetverbindung (Telefonie) wurde erfolgreich hergestellt. IP-Adresse: 11.12.13.14, DNS-Server: 1.2.3.11 und 1.2.3.99 Gateway: 11.12.13.1',
                                   'id' => 180,
                                   'helplink' => '/help/help.lua?sid=ac643567284b964a&helppage=hilfe_syslog_180.html',
                                   'nohelp' => 0,
                                   'group' => 'fon',
                                   'date' => '18.03.23',
                                   'time' => '11:44:19'
                                 },
                                 {
                                   'group' => 'fon',
                                   'date' => '18.03.23',
                                   'nohelp' => 0,
                                   'time' => '11:39:10',
                                   'msg' => 'Internetverbindung (Telefonie) wurde getrennt.',
                                   'id' => 181,
                                   'helplink' => '/help/help.lua?sid=ac643567284b964a&helppage=hilfe_syslog_181.html'
                                 },
                                 {
                                   'nohelp' => 0,
                                   'date' => '25.02.23',
                                   'group' => 'fon',
                                   'time' => '18:22:40',
                                   'msg' => "Internettelefonie mit SIP2 \x{c3}\x{bc}ber 11.12.13.55 war nicht erfolgreich. Ursache:  (408) [2 Meldungen seit 25.02.23 18:22:05]",
                                   'helplink' => '/help/help.lua?sid=ac643567284b964a&helppage=hilfe_syslog_78.html',
                                   'id' => 78
                                 },
                                 {
                                   'msg' => "Internettelefonie mit 01239876543 \x{c3}\x{bc}ber sip.provider.de war nicht erfolgreich. Ursache: Not Found (404)",
                                   'helplink' => '/help/help.lua?sid=ac643567284b964a&helppage=hilfe_syslog_78.html',
                                   'id' => 78,
                                   'date' => '11.02.23',
                                   'group' => 'fon',
                                   'nohelp' => 0,
                                   'time' => '19:39:59'
                                 },
                                 {
                                   'group' => 'fon',
                                   'date' => '11.02.23',
                                   'nohelp' => 0,
                                   'time' => '19:39:44',
                                   'msg' => "Internettelefonie mit 0123987654 \x{c3}\x{bc}ber sip.provider.de:5060 war nicht erfolgreich. Ursache: Decline (603)",
                                   'id' => 78,
                                   'helplink' => '/help/help.lua?sid=ac643567284b964a&helppage=hilfe_syslog_78.html'
                                 },
                                 {
                                   'msg' => "Internettelefonie mit 0123987654 \x{c3}\x{bc}ber sip.provider.de:5060 war nicht erfolgreich. Ursache: Decline (603)",
                                   'helplink' => '/help/help.lua?sid=ac643567284b964a&helppage=hilfe_syslog_78.html',
                                   'id' => 78,
                                   'date' => '08.02.23',
                                   'group' => 'fon',
                                   'nohelp' => 0,
                                   'time' => '19:05:07'
                                 },
                                 {
                                   'helplink' => '/help/help.lua?sid=ac643567284b964a&helppage=hilfe_syslog_180.html',
                                   'id' => 180,
                                   'msg' => 'Internetverbindung (Telefonie) wurde erfolgreich hergestellt. IP-Adresse: 11.12.13.14, DNS-Server: 1.2.3.11 und 1.2.3.99 Gateway: 11.12.13.1',
                                   'time' => '18:35:50',
                                   'nohelp' => 0,
                                   'date' => '08.02.23',
                                   'group' => 'fon'
                                 },
                                 {
                                   'msg' => 'Internetverbindung (Telefonie) wurde getrennt.',
                                   'helplink' => '/help/help.lua?sid=ac643567284b964a&helppage=hilfe_syslog_181.html',
                                   'id' => 181,
                                   'nohelp' => 0,
                                   'date' => '08.02.23',
                                   'group' => 'fon',
                                   'time' => '18:35:42'
                                 }
                               ],
                      'filter' => 'fon',
                      'wlanGuestPushmail' => $VAR1->{'hide'}{'ssoSet'}
                    },
          'sid' => 'ac643567284b964a',
          'time' => [],
          'pid' => 'log',
          'timeTillLogout' => '1153'
        };


[KölnSolar]

Hi Ralf,
sehr interessant !

Das Ziel war nur gescheiterte Anmeldeversuche gemeldet zu bekommen. Das Log also zeitnah zu durchsuchen, um zu reagieren bzw. fremde externe IP-Adressen ab FritzOS 7.50 eventuell in die Blacklist einzutragen.

Werde ich ausprobieren. Wenn Jörg das Update eingecheckt hat.
Zum schnelleren Verständnis für andere zitiere ich Dich mal. 

gescheiterte Logins mit der Meldungs-ID 501, 503, 505 oder 510

Prio 1
Der Grund für die Logauswertung, kommt bei fehlerhafter Anmeldung wenn externer HTTPS Zugang offen ist.
505    Anmeldung des Benutzers xx an der FRITZ!Box-Benutzeroberfläche von IP-Adresse yy gescheitert (falsches Kennwort)

Prio 2
501 Anmeldung an der FRITZ!Box-Benutzeroberfläche von IP-Adresse yy gescheitert (falsches Kennwort)
503 Anmeldung an der FRITZ!Box-Benutzeroberfläche von IP-Adresse yy gescheitert (ungültige Sitzungskennung). Zur Sicherheit werden
510 Anmeldung einer App mit unbekanntem Anmeldenamen von IP-Adresse yy gescheitert.

Eintrag 505 hab ich öfter.    Und nun zum Anlass genommen mir meine Einstellung

kommt bei fehlerhafter Anmeldung wenn externer HTTPS Zugang offen ist

anzusehen. Sakra, ich könnt schwören, dass das bei mir abgeschaltet war(Edit: oder hab ich vielleicht den Menüpunkt Internet:Freigaben:FRITZ!Box-Dienste: Internetzugriff missinterpretiert und gedacht: ohne Internet:Freigaben:Portfreigaben:meinHTTPSPort , wäre der externe Zugriff ausgeschlossen ?  ) Jetzt aber wieder....
Danke&Grüße Markus

[RalfRog]

• Edit
  Das Problem ist seit Modulversion 07.50.12 gelöst. Möglicher Blocking Aufruf der Funktion in der 99_myUtils (statt default NonBlocking).

Hi KölnSolar

Hast Du ne Idee zum Problem mit dem TelegramBot in dem Kontext hier? Schau mal:

Edit 28.3 uups falschen Link kopiert
forum.fhem.de /index.php?msg=126962                https://forum.fhem.de/index.php?msg=1269628

Zumindest Mails bekomme ich  . Insoweit positiv und funktionabel:

Code Auswählen Erweitern

2023.03.27 13:08:31.372 2: INFO: fritzLogInfo: sys
2023.03.27 13:08:31.394 2: Fritzbox IntruderCheck: Anmeldung des Benutzers Admin an der FRITZ!Box-Benutzeroberfläche von IP-Adresse 80.187.73.194 gescheitert (falsches Kennwort).
2023.03.27 13:08:32.671 3: sendEmail Subroutine returned: Mar 27 13:08:32 raspberry sendEmail[16217]: Email was sent successfully!
2023.03.27 13:08:32.673 3: msg globalMsg: ID=1679915311.39784.1 TYPE=mail ROUTE=mich@provider.de STATUS=OK PRIORITY=0 TITLE='System Message' MSG='Fritzbox 505 IntruderCheck: Anmeldung des Benutzers Admin an der FRITZ!Box-Benutzeroberfläche von IP-Adresse 80.187.73.194 gescheitert (falsches Kennwort).'

Edit 3. April 2023
Antwort in kurz:
es sieht so aus, als wenn non Blocking in non Blocking nicht funktioniert. ...
Bearbeitet hier: https://forum.fhem.de/index.php?msg=1270863

[KölnSolar]

Hi Ralf,

leider nicht. Ich bin ein Freund alter Technik und nutze nur eMail, also nix Telegram, WattsÄpp....

Grüße Markus

[RalfRog]

Neben der Möglichkeit das Logfile per Kommando vom Modul auszulesen:

Code Auswählen Erweitern

  get <name> fritzLog <table> <all | sys | wlan | usb | net | fon>
  get <name> fritzLog <hash> <all | sys | wlan | usb | net | fon> [on|off]und in 99_myUtil im Detail auszuwerten

werden auch drei Readings bereitgestellt:

Code Auswählen Erweitern

  box_sys_LogNewest
  box_wlan_LogNewest
  box_fon_LogNewest
Sie enthalten jeweils den letzten Eintrag aus dem Ereignislog der Fritzbox gefiltert auf System, WLAN und Telefonie.
Mit den Readings kann auf die EreignisID reagiert werden ohne den Rückgabehash im Detail mit eigenem Code auszuwerten.
In der Hilfe zum Modul sind eine Reihe wichtiger IDs aufgeführt.