Startlog analysieren

Superposchi · 07 Januar 2021, 14:37:10

Hallo, ich habe leider immer wieder Zeilen im Startlog die ich nicht verstehe bzw. dessen Ursprung mir nicht geläufig sind.

Kann mir jemand helfen das Startprotokoll zu analysieren, so dass ich die Fehler auflösen und beseitigen kann?
Anbei das Startprotokoll:

Code Auswählen

Starting FHEM ...                                                                                                                                                                                                                                                                                                                  
2021.01.07 14:13:16 1: PERL WARNING: Subroutine myUtils_Initialize redefined at ./FHEM/99_myUtilsTemplate.pm line 15.                                                                                                                                                                                                              
2021.01.07 14:13:16.870 1: Including fhem.cfg                                                                                                                                                                                                                                                                                      
2021.01.07 14:13:16.911 1: PERL WARNING: Subroutine myUtils_Initialize redefined at ./FHEM/99_myUtilsTemplate.pm line 15, <$fh> line 11.                                                                                                                                                                                           
2021.01.07 14:13:17.446 2: eventTypes: loaded 5332 lines from ./log/eventTypes.txt                                                                                                                                                                                                                                                 
2021.01.07 14:13:29.477 1: Including ./log/fhem.save                                                                                                                                                                                                                                                                               
2021.01.07 14:13:30.060 1: Messages collected while initializing FHEM:SecurityCheck:                                                                                                                                                                                                                                               
  telnetPort is not password protected                                                                                                                                                                                                                                                                                             
  WEB is not password protected                                                                                                                                                                                                                                                                                                    
  MQTT2_Server is not password protected                                                                                                                                                                                                                                                                                           
                                                                                                                                                                                                                                                                                                                                   
Protect this FHEM installation by configuring the allowed device allowedWEBhook                                                                                                                                                                                                                                                    
You can disable this message with attr global motd none                                                                                                                                                                                                                                                                            
                                                                                                                                                                                                                                                                                                                                   
sh: 1: echo: echo: I/O error                                                                                                                                                                                                                                                                                                       
2021.01.07 14:13:52.008 1: usb create starting                                                                                                                                                                                                                                                                                     
2021.01.07 14:13:52.527 1: usb create end                                                                                                                                                                                                                                                                                          
2021.01.07 14:13:52.903 2: HMinfo hm get:configCheck :-f,^(sz_smoker_rauchmelder|sz_smoker_rauchmelder)$                                                                                                                                                                                                                           
2021.01.07 14:13:53.110 0: Featurelevel: 6                                                                                                                                                                                                                                                                                         
2021.01.07 14:13:53.110 0: Server started with 197 defined entities (fhem.pl:23471/2021-01-04 perl:5.028001 os:linux user:fhem pid:10744)                                                                                                                                                                                          
2021.01.07 14:13:54.825 2: Saugroboter: connecting                                                                                                                                                                                                                                                                                 
2021.01.07 14:13:54.825 2: Saugroboter: connecting                                                                                                                                                                                                                                                                                 
2021.01.07 14:13:56.621 1: FHEMWEB SSL/HTTPS error:  SSL accept attempt failed (peer: 5.145.134.0)                                                                                                                                                                                                                                 
2021.01.07 14:13:59.312 2: Hue_Bridge: http request failed: http://192.168.178.150/api/kVLD7HZv9kDqLTUu1ahaG8sJLcpzwAKqSISo40YZ: empty answer received                                                                                                                                                                             
2021.01.07 14:14:00.507 2: http://192.168.178.1/webservices/homeautoswitch.lua?sid=06086d05153f5755&switchcmd=getdevicelistinfos: HTTP response code 200                                                                                                                                                                           
2021.01.07 14:14:11.711 1: BindingsIo: ERROR: Timeout while waiting for function to finish (id: 17749970)                                                                                                                                                                                                                          
2021.01.07 14:14:15.814 1: PERL WARNING: Argument "Jetzt live bei Magentasport!\\n\\n\\n\\n\\nAnbieter-Impr..." isn't numeric in numeric eq (==) at ./FHEM/57_CALVIEW.pm line 226.                                                                                                                                                 
2021.01.07 14:14:16.503 1: 192.168.178.156:2000 disconnected, waiting to reappear (Homematic_Gateway)                                                                                                                                                                                                                              
2021.01.07 14:14:16.514 1: FHEMWEB SSL/HTTPS error:  SSL accept attempt failed error:1408F09C:SSL routines:ssl3_get_record:http request (peer: 192.168.178.199)                                                                                                                                                                    
2021.01.07 14:14:16.517 1: 192.168.178.156:2001 disconnected, waiting to reappear (Homematic_Gateway:keepAlive)                                                                                                                                                                                                                    
2021.01.07 14:14:18.416 2: AttrTemplates: got 216 entries                                                                                                                                                                                                                                                                          
2021.01.07 14:14:19.803 1: FHEMWEB SSL/HTTPS error:  SSL accept attempt failed error:1408F09C:SSL routines:ssl3_get_record:http request (peer: 192.168.178.199)                                                                                                                                                                    
2021.01.07 14:14:19.822 1: 192.168.178.156:2000 reappeared (Homematic_Gateway)                                                                                                                                                                                                                                                     
2021.01.07 14:14:29.602 1: Calendar Kalender_Marko: retrieval failed with error message read from https://calendar.google.com:443 timed out                                                                                                                                                                                        
2021.01.07 14:14:29.604 1: Calendar Kalender_Marko: retrieved no or empty data                                                                                                                                                                                                                                                     
2021.01.07 14:14:30.519 1: Calendar Kalender_Veranstaltungen: retrieval failed with error message read from https://calendar.google.com:443 timed out                                                                                                                                                                              
2021.01.07 14:14:30.522 1: Calendar Kalender_Veranstaltungen: retrieved no or empty data                                                                                                                                                                                                                                           
2021.01.07 14:14:31.022 1: Calendar Kalender_Abfall: retrieval failed with error message read from https://calendar.google.com:443 timed out                                                                                                                                                                                       
2021.01.07 14:14:31.024 1: Calendar Kalender_Abfall: retrieved no or empty data                                                                                                                                                                                                                                                    
2021.01.07 14:18:54.206 2: IP: 192.168.178.1 -> 192.168.178.1                                                                                                                                                                                                                                                                      
2021.01.07 14:18:54.757 2: http://192.168.178.1/webservices/homeautoswitch.lua?sid=06086d05153f5755&switchcmd=getdevicelistinfos: HTTP response code 200                                                                                                                                                                           
2021.01.07 14:23:08.234 1: FHEMWEB SSL/HTTPS error: Connection reset by peer SSL accept attempt failed (peer: 162.142.125.54)                                                                                                                                                                                                      
2021.01.07 14:23:09.400 1: FHEMWEB SSL/HTTPS error:  SSL accept attempt failed error:1408F09C:SSL routines:ssl3_get_record:http request (peer: 162.142.125.54)                                                                                                                                                                     
2021.01.07 14:23:09.630 1: FHEMWEB SSL/HTTPS error: Connection reset by peer SSL accept attempt failed (peer: 162.142.125.54)                                                                                                                                                                                                      
2021.01.07 14:23:54.209 2: IP: 192.168.178.1 -> 192.168.178.1                                                                                                                                                                                                                                                                      
2021.01.07 14:23:54.840 2: http://192.168.178.1/webservices/homeautoswitch.lua?sid=06086d05153f5755&switchcmd=getdevicelistinfos: HTTP response code 200                                                                                                                                                                           
2021.01.07 14:28:54.211 2: IP: 192.168.178.1 -> 192.168.178.1                                                                                                                                                                                                                                                                      
2021.01.07 14:28:54.911 2: http://192.168.178.1/webservices/homeautoswitch.lua?sid=06086d05153f5755&switchcmd=getdevicelistinfos: HTTP response code 200

Die meisten Fehler sagen mir nichts bzw. kann ich mir ihren Ursprung nicht erklären und bräuchte bei der Analyse und Fehlerbeseitigung allgemeine Hilfe.

Beta-User · 07 Januar 2021, 17:06:04

Mal die ersten paar:
- Die "redefined"-Meldungen sind Perl-Warnings die daher rühren, dass du zwar irgendwo eine eigene myUtils erstellt hast, aber die Initialize nicht so benannt hast wie die Datei heißt. Warum das 2x kommt, ist mir allerdings unklar.
Lösung: Suchen und "richtig" benennen.
- Die usb create- Meldungen kommen von initialUsbCheck.
Lösung: Den kannst du deaktivieren (attr initialUsbCheck disable 1);

- Die Timeouts nach google kommen vermutlich entweder dadurch, das FHEM vor dem Netzwerk oben ist und/oder keine korrekte Uhrzeit hat.
Lösungsansätze:
-- Hardwareuhr nachrüsten
-- systemd so einstellen, dass FHEM erst gestartet wird, wenn das Netzwerk verfügbar ist (ist aber auch nicht unproblematisch).
-- ggf. mal nachsehen, ob sich das Laden des Kalenders verzögern läßt (calendar kann das).
-- Abfall ist sowieso in den meisten Fällen statisch; würde ich runterladen und als lokale ics verwenden (in jedem Fall das Intervall hochsetzen!)

Für den Rest musst du jeweils eigentlich individuell auf die Suche gehen, das ist teilweise auch kaum zu beantworten, ohne z.B. zu wissen, was sich hinter den genannten IP-Adressen verbirgt.

Das mit den Passworthinweisen für Telnet&Co. ist selbsterklärend, oder?

betateilchen · 07 Januar 2021, 17:11:32

Zitat von: Beta-User am 07 Januar 2021, 17:06:04
- Die "redefined"-Meldungen sind Perl-Warnings die daher rühren, dass du zwar irgendwo eine eigene myUtils erstellt hast, aber die Initialize nicht so benannt hast wie die Datei heißt. Warum das 2x kommt, ist mir allerdings unklar.

Der Anwender hat das template File bearbeitet, dort die _Initialize() Funktion umbenannt und die Datei mit dem Zusatz template abgespeichert. Vermutlich wurde beim Editieren der Button "Save <fileName>" verwendet anstatt "Save as"

Inzwischen wurde der Fehler offenbar bemerkt und die 99_myUtils.pm korrekt abgespeichert, aber in der Template Datei ist immer noch die Initialize Funktion falsch benannt.

Superposchi · 08 Januar 2021, 08:48:06

Ok, werde ich durchgehen und soweit ich kann ändern. Das mit dem Inizialized ist mir zwar noch nicht klar, aber mal schauen was ich dazu finde. Habe nur ein Script für die Anwesenheitserkennung in meine 99_myutils über die Edit Funktion in der Fhem-Weboberfläche vorgenommen.

Code Auswählen

2021.01.07 14:23:54.209 2: IP: 192.168.178.1 -> 192.168.178.1                                                                                                                                                                                                                                                                     
2021.01.07 14:23:54.840 2: http://192.168.178.1/webservices/homeautoswitch.lua?sid=06086d05153f5755&switchcmd=getdevicelistinfos: HTTP response code 200

Diese beiden Zeilen kommen kontinuierlich wieder, den ganzen Tag über. Kann einer dazu was sagen?

Beta-User · 08 Januar 2021, 09:44:49

Zu diesen Zeilen liefert mir meine Suchmaschine u.a. diesen Link: https://en.wikipedia.org/wiki/List_of_HTTP_status_codes#2xx_success
Was sich hinter der IP 192.168.178.1 bzw. der Weiterleitung (?) nach /webservices/homeautoswitch.lua verbirgt kann aber nur jemand sagen, der die betreffenden Adressen aufrufen kann (=> Du!).

Meine Glaskugel verdächtigt irgendwas, was mit Fritzbox zu tun hat.

betateilchen · 08 Januar 2021, 10:29:34

HTTP Code 200 ist eher positiv zu betrachten, das bedeutet, dass der letzte http-Request erfolgreich war und Daten zurückgeliefert wurden. Die Meldung ist somit keine Fehler- sondern eine Ergebnismeldung. Alles gut.

192.168.178.1 ist die IP Adresse der Fritzbox bei unbekümmerten Internetanwendern, die sich meist wenig bis gar keine Gedanken darüber machen, ob es wirklich sinnvoll ist, einen Internet-Router in der Standardkonfiguration zu betreiben.

homeautoswitch.lua gehört zum HTTP Interface zur AVM Home Automation und ist vollständig dokumentiert

https://avm.de/fileadmin/user_upload/Global/Service/Schnittstellen/AHA-HTTP-Interface.pdf

Vermutlich werden in der FHEM Installation AVM Geräte benutzt und es wird regelmäßig geprüft, welche Geräte vorhanden sind. Ich würde das als ein normales Verhalten betrachten. Ob man sowas im Level 2 loggen muss, ist eine andere Frage.

Superposchi · 08 Januar 2021, 11:30:32

Ok, danke für die Ausführungen. Ja es gibt AVM-aktoren, die entsprechend gepollt werden.
Kann ich diese Logeinträge denn irgendwie unterdrücken ohne den Verbose runterzusetzen oder kann das nur der Modulautor?

Es macht das Log halt total unübersichtlich wenn jede 3-4 Zeile diese Info enthält, die ja nach deinen Ausführungen eigentlich eher gut sind.
Wenn ich es nur über ein Verbose regeln kann, bei welchem Device muss ich dann das Verbose runtersetzen, habe einmal die Fritzbox sebst als Device und ein Fritzbox_actors-Device.

betateilchen · 08 Januar 2021, 12:35:28

Du brauchst doch nur auszuprobieren, bei welchem der beiden genannten devices Du das Attribut verbose auf 0 setzen musst.
Ein überschaubarer Aufwand

Beta-User · 08 Januar 2021, 12:38:41

...und wenn das dann geklärt ist die Frage nach der Sinnfälligkeit des 2-er loglevels mal im richtigen Forumsbereich lt. MAINTAINER.txt zu stellen (ist wohl für alle Module derselbe

) kann eventuell auch nicht schaden....

betateilchen · 08 Januar 2021, 12:49:24

Ich glaube nicht, dass der loglevel 2 tatsächlich im Modul steht.

Die Meldungen kommen vermutlich aus HttpUtils.pm und dort werden bei nonblocking calls die Loglevel aus dem aufrufenden device verwendet.

Superposchi · 08 Januar 2021, 13:01:24

Das Loglevel 2 hatte ich mal pauschal für alle Devices auf 2 gesetzt um etwas mehr Übersicht im Log zu bekommen.

ZitatDu brauchst doch nur auszuprobieren, bei welchem der beiden genannten devices Du das Attribut verbose auf 0 setzen musst.
Ein überschaubarer Aufwand

Wenn ich das nicht schon mal irgendwann ausprobiert hätte würde ich nicht fragen.

ZitatDie "redefined"-Meldungen sind Perl-Warnings die daher rühren, dass du zwar irgendwo eine eigene myUtils erstellt hast, aber die Initialize nicht so benannt hast wie die Datei heißt.

Ich komme mit dieser Inizialize noch nicht zurecht, was genau ist das bzw. wo finde ich das? Ist das eine eigenständige Datei?

Beta-User · 08 Januar 2021, 13:18:37

Das "Initialize" ist jeweils eine Funktion, die ziemlich zu Beginn jeder myUtils-file steht (und auch einer Muster-file, eben jener "template").
betateilchen hatte hier ja bereits was dazu geschrieben:

Zitat von: betateilchen am 07 Januar 2021, 17:11:32
[...], aber in der Template Datei ist immer noch die Initialize Funktion falsch benannt.

Weitere Details wären im Wiki hier zu finden: https://wiki.fhem.de/wiki/99_myUtils_anlegen

Zitat von: betateilchen am 08 Januar 2021, 12:49:24
Ich glaube nicht, dass der loglevel 2 tatsächlich im Modul steht.

Die Meldungen kommen vermutlich aus HttpUtils.pm und dort werden bei nonblocking calls die Loglevel aus dem aufrufenden device verwendet.

Witzig, dann erreicht Superposchi also mit dem Versuch, das loszuwerden also genau das Gegenteil

. Oder deute ich das jetzt wieder falsch (sorry, so tief liege ich leider nicht unter diesem Teil des Autos...)...?

betateilchen · 08 Januar 2021, 13:19:36

Zitat von: Superposchi am 08 Januar 2021, 13:01:24
Ich komme mit dieser Inizialize noch nicht zurecht, was genau ist das bzw. wo finde ich das? Ist das eine eigenständige Datei?

Das ist keine Datei, sondern eine Funktion IN einer Datei.

Bei Dir existiert eine Datei mit dem Namen ./FHEM/99_myUtilsTemplate.pm die es mit diesem Namen eigentlich nicht geben soll/darf.

Außerdem gibt es bei Dir (höchstwahrscheinlich) auch noch die Datei ./FHEM/99_myUtils.pm was korrekt wäre.

In beiden Dateien gibt es eine Funktion mit dem Namen myUtils_Initialize(). Diese Funktion darf es nur in einer Datei geben, die 99_myUtils.pm heißt.

Lösung: Übernehme Deine eigenen Funktionen (und nur diese!) aus der 99_myUtilsTemplate.pm in die 99_myUtils.pm und lösche danach die Datei 99_myUtilsTemplate.pm.

Superposchi · 08 Januar 2021, 19:40:51

Ja, es gibt sowohl die 99_myutilsTamplate.pm, als auch die 99_myutils.pm.
Erstere war mit der Installation von Fhem da und dientwie der NAme Template schon sagt als vorlage für die zweite, welche die eigenen Scripte beinhaltet.
So weit zumindest mein Verständnis von dem was ich gelesen habe.

Hier der Inhalt der 99_myutilsTemplate.pm:

Code Auswählen

##############################################
# $Id: myUtilsTemplate.pm 7570 2015-01-14 18:31:44Z rudolfkoenig $
#
# Save this file as 99_myUtils.pm, and create your own functions in the new
# file. They are then available in every Perl expression.

package main;

use strict;
use warnings;
use POSIX;

sub
myUtils_Initialize($$)
{
  my ($hash) = @_;
}

# Enter you functions below _this_ line.

##############################################

1;

Hier der Inhalt der 99_myutils.pm:

Code Auswählen

##############################################
# $Id: myUtilsTemplate.pm 7570 2015-01-14 18:31:44Z rudolfkoenig $
#
# Save this file as 99_myUtils.pm, and create your own functions in the new
# file. They are then available in every Perl expression.

package main;

use strict;
use warnings;
use POSIX;

sub
myUtils_Initialize($$)
{
  my ($hash) = @_;
}

# Enter you functions below _this_ line.

##############################################
# angemeldete MAC-Adresse in Fritzbox suchen
#

    sub checkAllFritzMACpresent($) {
    # Benötigt: nur die zu suchende MAC ($MAC),
    # Es werden alle Instanzen vom Type FRITZBOX abgefragt
    #
    # Rückgabe: 1 = Gerät gefunden
    # 0 = Gerät nicht gefunden
    my ($MAC) = @_;
    # Wird in keiner Instanz die MAC Adresse gefunden bleibt der Status 0
    my $Status = 0;
    $MAC =~ tr/:/_/;
    $MAC = "mac_".uc($MAC);
    my @FBS = devspec2array("TYPE=FRITZBOX");
    foreach( @FBS ) {
    my $StatusFritz = ReadingsVal($_, $MAC, "weg");
    if ($StatusFritz eq "weg") {
    } elsif ($StatusFritz eq "inactive") {
    } else {
    # Reading existiert, Rückgabewert ist nicht "inactive", also ist das Gerät am Netzwerk angemeldet.
    $Status = 1;
    }
    }
    return $Status
    }

1;

Wenn ich das richtig verstehe müsste ich also aus der Templates-Datei folgendes Löschen:

Code Auswählen

sub
myUtils_Initialize($$)
{
  my ($hash) = @_;
}

betateilchen · 08 Januar 2021, 19:47:50

Zitat von: Superposchi am 08 Januar 2021, 19:40:51
Wenn ich das richtig verstehe müsste ich also aus der Templates-Datei folgendes Löschen:
Code Auswählen Erweitern
sub myUtils_Initialize($$) { my ($hash) = @_; }

Nein.

Zitat von: Superposchi am 08 Januar 2021, 19:40:51
Ja, es gibt sowohl die 99_myutilsTamplate.pm, als auch die 99_myutils.pm.
Erstere war mit der Installation von Fhem da

Nein. Die Vorlage heißt bei der Auslieferung "myUtilsTemplate.pm" ohne "99_" am Anfang.

Du hast die Datei vermutlich bei der Bearbeitung in 99_myUtilsTemplate.pm (falsch) umbenannt.
Also benenne die Datei jetzt wieder in ihren Original-Namen um, dann verschwindet die Meldung beim FHEM Start.