Can't connect to 127.0.0.1:43199: IO::Socket::INET:

[Burny4600]

Grundsätzlich sind es https Verbindungen für FHEMWEB.
FHEM2FHEM ist das Gleiche.

Bei den mir aufgefallenen Error Meldungen sind es nur http Verbindungen.
Wie folgt.

list PV_Anlage_1

Code Auswählen Erweitern

Internals:
   BUSY       0
   CFGFN      /media/hdd/fhem/mycfg/pv_anlagen/pv_anlagen_rasp01.cfg
   DEF        http://192.168.17.177/solar_api/GetInverterRealtimeData.cgi?Scope=System 15
   FUUID      5c45b04b-f33f-f4d2-74e9-653c34bd30828590
   Interval   15
   MainURL    http://192.168.17.177/solar_api/GetInverterRealtimeData.cgi?Scope=System
   ModuleVersion 4.1.12 - 19.4.2022
   NAME       PV_Anlage_1
   NOTIFYDEV  global
   NR         7283
   NTFY_ORDER 50-PV_Anlage_1
   STATE      Aktuell: 59 Watt | Heute: 11 kWh | Dieses Jahr: 721 kWh
   TYPE       HTTPMOD
   value     
   HttpUtils:
     NAME       
     addr       http://192.168.17.177:80
     auth       0
     code       200
     compress   1
     conn       
     data       
     displayurl http://192.168.17.177/solar_api/GetInverterRealtimeData.cgi?Scope=System
     header     
     host       192.168.17.177
     httpheader HTTP/1.0 200 OK
Content-Type: text/javascript
     httpversion 1.0
     hu_blocking 0
     hu_filecount 1
     hu_port    80
     hu_portSfx
     ignoreredirects 1
     loglevel   4
     path       /solar_api/GetInverterRealtimeData.cgi?Scope=System
     protocol   http
     redirects  0
     timeout    2
     url        http://192.168.17.177/solar_api/GetInverterRealtimeData.cgi?Scope=System
     sslargs:
   QUEUE:
   READINGS:
     2022-05-10 18:47:21   Body_Data_DAY_ENERGY_Unit Wh
     2022-05-10 18:47:21   Body_Data_DAY_ENERGY_Values_1 11000
     2022-05-10 18:47:21   Body_Data_PAC_Unit W
     2022-05-10 18:47:21   Body_Data_PAC_Values_1 59
     2022-05-10 18:47:21   Body_Data_TOTAL_ENERGY_Unit Wh
     2022-05-10 18:47:21   Body_Data_TOTAL_ENERGY_Values_1 32168000
     2022-05-10 18:47:21   Body_Data_YEAR_ENERGY_Unit Wh
     2022-05-10 18:47:21   Body_Data_YEAR_ENERGY_Values_1 721000
     2022-05-10 18:47:21   DDE             11
     2022-05-10 18:47:21   DTE             32168
     2022-05-10 18:47:21   DYE             721
     2022-05-10 18:47:21   Head_RequestArguments_Scope System
     2022-05-10 18:47:21   Head_Status_Code 0
     2022-05-10 18:47:21   Head_Status_Reason
     2022-05-10 18:47:21   Head_Status_UserMessage
     2022-05-10 18:47:21   Head_Timestamp  2022-05-10T18:47:22+02:00
     2022-05-10 18:47:21   PAC             59
   REQUEST:
     context    reading
     data       
     header     
     ignoreredirects 0
     num        unknown
     retryCount 0
     type       update
     url        http://192.168.17.177/solar_api/GetInverterRealtimeData.cgi?Scope=System
   defptr:
     readingBase:
       Body_Data_DAY_ENERGY_Unit reading
       Body_Data_DAY_ENERGY_Values_1 reading
       Body_Data_PAC_Unit reading
       Body_Data_PAC_Values_1 reading
       Body_Data_TOTAL_ENERGY_Unit reading
       Body_Data_TOTAL_ENERGY_Values_1 reading
       Body_Data_YEAR_ENERGY_Unit reading
       Body_Data_YEAR_ENERGY_Values_1 reading
       Head_RequestArguments_Scope reading
       Head_Status_Code reading
       Head_Status_Reason reading
       Head_Status_UserMessage reading
       Head_Timestamp reading
     readingNum:
       Body_Data_DAY_ENERGY_Unit unknown
       Body_Data_DAY_ENERGY_Values_1 unknown
       Body_Data_PAC_Unit unknown
       Body_Data_PAC_Values_1 unknown
       Body_Data_TOTAL_ENERGY_Unit unknown
       Body_Data_TOTAL_ENERGY_Values_1 unknown
       Body_Data_YEAR_ENERGY_Unit unknown
       Body_Data_YEAR_ENERGY_Values_1 unknown
       Head_RequestArguments_Scope unknown
       Head_Status_Code unknown
       Head_Status_Reason unknown
       Head_Status_UserMessage unknown
       Head_Timestamp unknown
     readingOutdated:
     requestReadings:
       update:
         Body_Data_DAY_ENERGY_Unit reading unknown
         Body_Data_DAY_ENERGY_Values_1 reading unknown
         Body_Data_PAC_Unit reading unknown
         Body_Data_PAC_Values_1 reading unknown
         Body_Data_TOTAL_ENERGY_Unit reading unknown
         Body_Data_TOTAL_ENERGY_Values_1 reading unknown
         Body_Data_YEAR_ENERGY_Unit reading unknown
         Body_Data_YEAR_ENERGY_Values_1 reading unknown
         Head_RequestArguments_Scope reading unknown
         Head_Status_Code reading unknown
         Head_Status_Reason reading unknown
         Head_Status_UserMessage reading unknown
         Head_Timestamp reading unknown
Attributes:
   alias      Energieertrag
   devStateStyle style="text-align:right;;font-weight:bold;;"
   event-min-interval .*:60
   event-on-change-reading .*
   extractAllJSON 1
   group      PV-Anlage 1
   icon       measure_photovoltaic_inst
   room       PV-Anlagen
   sortby     01.01
   stateFormat {sprintf("Aktuell: %s Watt | Heute: %s kWh | Dieses Jahr: %s kWh",
(ReadingsNum("$name","PAC",0)),
(ReadingsNum("$name","DDE",0)),
(ReadingsNum("$name","DYE",0)))}
   userReadings PAC:Body_Data_PAC_Values_1.* {ReadingsNum("$name","Body_Data_PAC_Values_1",0)},
DDE:Body_Data_DAY_ENERGY_Values_1.* {ReadingsNum("$name","Body_Data_DAY_ENERGY_Values_1",0)/1000},
DYE:Body_Data_YEAR_ENERGY_Values_1.* {ReadingsNum("$name","Body_Data_YEAR_ENERGY_Values_1",0)/1000},
DTE:Body_Data_TOTAL_ENERGY_Values_1.* {ReadingsNum("$name","Body_Data_TOTAL_ENERGY_Values_1",0)/1000}

LOG Error Meldung

Code Auswählen Erweitern

2022.05.09 07:48:59.631 3: PV_Anlage_1: Read callback: Error: read from http://192.168.17.177:80 timed out

list SDS011

Code Auswählen Erweitern

Internals:
   ADDRESS    192.168.17.160
   CFGFN      /media/hdd/fhem/mycfg/wetter/sds011_rasp01.cfg
   DEF        local 192.168.17.160
   FUUID      5e736c9a-f33f-21bc-6371-c3fd9ac6f7bb5531
   INTERVAL   150
   MODE       local
   NAME       SDS011
   NR         8641
   STATE      PM 10: 3.8 µg/m³  <br> PM 2.5: 3.5 µg/m³  <br> Temperatur: 32.1 °C  <br> Feuchte: 19.9 % <br> Luftdruck Wels: 982.4 hPa <br> Luftdruck Meereshöhe: 1019.8 hPa <br> WLAN Signal: -75.0 dBm
   TIMEOUT    5
   TYPE       LuftdatenInfo
   READINGS:
     2022-05-10 18:48:12   GPS_timestamp   2022-05-10T16:47:59.000
     2022-05-10 18:48:12   PM10            3.77
     2022-05-10 18:48:12   PM2.5           3.47
     2022-05-10 18:48:12   altitude        329.90
     2022-05-10 18:48:12   humidity        19.95
     2022-05-10 18:48:12   interval        145000
     2022-05-10 18:48:12   latitude        48.150955
     2022-05-10 18:48:12   longitude       14.003261
     2022-05-10 18:48:12   max_micro       51414
     2022-05-10 18:48:12   min_micro       33
     2022-05-10 18:48:12   pressure        981.3628
     2022-05-10 18:48:12   relpressure     1018.7628
     2022-05-10 18:48:12   samples         4145006
     2022-05-10 18:48:12   signal          -75
     2022-03-31 19:26:09   softwareVersion NRZ-2020-133
     2022-05-10 18:48:12   state           active
     2022-05-10 18:48:12   temperature     32.06
Attributes:
   alias      AB Wetterstation - Feinstaub Sensor
   devStateStyle style="text-align:left;;font-weight:bold;;"
   event-on-change-reading PM10,PM2.5,humidity,temperature,max_micro,min_micro,pressure,relpressure,samples
   group      Feinstaub Monitoring
   icon       time_graph
   interval   150
   rawReading 1
   room       AB-Wetterstation
   sortby     01
   stateFormat {sprintf("PM 10: %.1f µg/m³  <br> ",ReadingsVal("$name","PM10",0))
.sprintf("PM 2.5: %.1f µg/m³  <br> ",ReadingsVal("$name","PM2.5",0))
.sprintf("Temperatur: %.1f °C  <br> ",ReadingsVal("$name","temperature",0))
.sprintf("Feuchte: %.1f %% <br> ",ReadingsVal("$name","humidity",0)-0.0)
.sprintf("Luftdruck Wels: %.1f hPa <br> ",ReadingsVal("$name","pressure",0)+1.0)
.sprintf("Luftdruck Meereshöhe: %.1f hPa <br> ",ReadingsVal("$name","relpressure",0)+1.0)
.sprintf("WLAN Signal: %.1f dBm ",ReadingsVal("$name","signal",0))}
   timeout    5
   userReadings relpressure { ReadingsVal("$name","pressure",0)+37.4; }

LOG Error Meldung

Code Auswählen Erweitern

2022.05.09 12:24:41.918 2: LuftdatenInfo (SDS011) - error while request: read from http://192.168.17.160:80 timed out

Ich versuche nur alles einzugrenzen.

Sobald wieder Antw:Can't connect to 127.0.0.1:43199: IO::Socket::INET: Meldungen auftauchen, werde ich versuchen mit verbose 5 ein wenig mehr herauszufinden.

[Burny4600]

Neuerlicher  IO::Socket::INET: Logeintrag.

sudo kill -USR1 15853

[rudolfkoenig]

Leider finde ich im Log nach dem USR1 kein "Can't connect" mehr.
"timed out" gibts zwar, aber die Ursache kann ich nicht sagen.

In den 74 Sekunden mit verbose 5 gab es 1710 Events, also durchschnittlich 23/sec, was relativ viel ist, insb. fuer diese Menge an DOIF/FileLog/etc auf einem RPi. Davon 470-mal irgendwas mit cmd_nr (DOIF, ALH_...),  229-mal "UNKNOWNCODE" (hauptsaechlich sduino_og2 ), und 210-mal DMSG (sduino_og2). Wenn moeglich, sollten diese vermieden werden.

Ich habe die im Event-Loop verbrachten Zeiten berechnet (mit dem neu eingecheckten contrib/sumUpNotifyTimes.pl), siehe Anhang #1, und das Ergebnis visualisiert, siehe Anhang #2. Der Durchschnitt liegt bei etwa 40%, mit 100%-Ausreisser fuer jeweils 3 Sekunden, dafuer ist Etwas mit dem Namen BMP180 verantwortlich. Letzteres ist definitiv ungesund, und sollte vermieden werden.

[Burny4600]

sduino_og2
Ich habe die whitelist_IDs auf die aktuell im Einsatz befindlichen Sensoren reduziert. Damit müsste schon ein Großteil der sduino_og2 Meldungen verschwinden. Beim sduino_ab habe ich das Gleiche vorgenommen.

Starting notify loop for ALH_****
Da muss ich die Enigma2 Meldungen ein wenig umbauen. Ein Trigger auf BMP180 ist hier nicht notwendig.

Ich werde das mit den Änderungen beobachten.
Danke für die Tipps.

[Burny4600]

Irgendwo übersehe ich anscheinend einen Fehler in meiner Konfiguration.
Gestern ging es wieder mit den Can't connect to 127.0.0.1 an.

Heute machte ich einen Neustart mit verbose 5 um vielleicht ein wenig Klarheit zu schaffen.

[Beta-User]

Schalte mal das hier (überall) ab:

2022.05.17 11:56:01.917 5: Starting notify loop for EG_SL_HZG_TC_Climate, 1 event(s), first is commState: CMDs_pending

[Burny4600]

Was soll ich da abschalten?

[rudolfkoenig]

Das verbose 5 Log zeigt nur, dass die Startup-Zeit  260 Sekunden lang dauert, und deswegen zu Verbindungsproblemen kommt. Die "reine" define/attr/setstate Zeit ist 138 Sekunden, der Rest geht fuer  Abarbeitung des "global:INITIALIZED" Triggers.
Etwas irritierend fuer mich ist, dass ich die ersten drei Zeilen des Logs nicht zuordnen kann.

Ich meine immer noch, dass der Rechner fuer diese Menge und Art von Definitionen unterdimensioniert ist.

[MadMax-FHEM]

Was soll ich da abschalten?

Ich denke das ist gemeint:

https://forum.fhem.de/index.php/topic,127619.msg1221390.html#msg1221390

https://forum.fhem.de/index.php/topic,120240.msg1169707.html#msg1169707

Gruß, Joachim

[Burny4600]

Sowie die Raspberry 4 wieder erhältlich sind, habe ich ohnehin einen Wechsel vom Raspberry 3 auf dem Raspberry 4 bei diesem Gerät durchzuführen.
Dennoch versuche ich noch Verbesserungen der Performance zu finden, oder grundsätzliche Änderungen zu ermitteln.

@MadMax-FHEM

Ich denke das ist gemeint:

Ich werde mir das ansehen, was damit gemeint ist.

Wie ist der aktuelle Status betreffend den commState Attribut?
Muss die Datei 10_CUL_HM.pm noch exclude werden?

[Beta-User]

Ich meine immer noch, dass der Rechner fuer diese Menge und Art von Definitionen unterdimensioniert ist.

+1

Ggf. würde es helfen, einen Teil auf ein zweites FHEM zu verlagern. Dann nutzt du ggf. wenigstens zwei Kerne und Netzwerk-Wartereien können gemütlich warten...

Trotzdem ist ein Teil des Problems wohl auch, dass vieles nicht optimiert gelöst ist, z.B. betr. CUL_HM (in Teilen doppelt, aber schon fertig):

geht mit einem Befehl

Code Auswählen Erweitern

attr TYPE=CUL_HM:FILTER=DEF=[0-9a-fA-F]{6}:FILTER=DEF!=[0]{6} commStInCh off

Oder auch

Wer das als CUL_HM-Nutzer testen will, kann z.B. folgende Basis nehmen:

Code Auswählen Erweitern

defmod archHM1 archetype TYPE=CUL_HM:FILTER=DEF=.{6}
attr archHM1 attributes commStInCh IOgrp

Dann eines der im setter "import" aufgeführten Devices nehmen (das die beiden Attribute gesetzt hat) und loslegen .

Bei mir nach dem import:

Code Auswählen Erweitern

attr archHM1 IOgrp undef:VCCU
attr archHM1 commStInCh undef:off
(Das initiale notify "initNotify" um alle möglichen Dinge in einen definierten Ausgangszustand zu versetzen ist mir auch zutiefst suspekt).

[Burny4600]

attr TYPE=CUL_HM:FILTER=DEF=[0-9a-fA-F]{6}:FILTER=DEF!=[0]{6} commStInCh off
Habe ich jetzt ausgeführt.
Wird hier auf Burst Funktionen Einfluss genommen oder nicht?

Einiges bin ich dabei auch auf andere PIs zu verschieben. Damit sollte sich diese Instanz auch leichter tun.

Jedenfalls sehe ich aus euren Informationen noch einiges an Potenzial, was ich bei mir verbessern kann.

[Beta-User]

Wird hier auf Burst Funktionen Einfluss genommen oder nicht?

Nein. Das ändert nur das Verhalten der Kanal-Devices dahingehend, dass ein bestimmtes Reading nicht (mehr) gesetzt wird, das man tendenziell als User auch nicht vermisst... Mit "burst" hat das nichts zu tun.

[rudolfkoenig]

Bei der Initialisierung der 12 CULs (alle V 1.26.08 a-culfw Build: 323) gibt es jeweils ein Timeout von 3 Sekunden, weil die Antwort auf die Versionsabfrage (V) erst beim zweiten Versuch kommt, unabhaengig davon, ob es direkt per USB oder indirekt via TCP/IP angesprochen wird.
Macht in der Summe 12*3 = 36 Sekunden, was auch mit schnelleren Hardware nicht behoben wird.
Ich habe gerade mit einem "original" CUL/culfw getestet, und sehe dieses Problem nicht.

Womoeglich hilft in FHEM/00_CUL.pm, Zeile 549 die sehr grosszuegig bemessene 3 Sekunden auf 1 oder gar 0.5 zu aendern. Die bessere Loesung waere das Firmware zu fixen.

[Beta-User]

@Rudi: Das Problem mit dem Nano dürfte sein, dass der jeweils die eigentliche MCU neu startet, wenn die Baudrate am USB-Seriell-Wandler geändert wird (das ist auch das eigentliche Problem beim initialUsbCheck). Vermutlich wäre es kein Problem, die Wartezeit für den ersten Wiederholungsversuch deutlich zu verkürzen.

Muss die Datei 10_CUL_HM.pm noch exclude werden?

Jein. Die aktuelle svn-Version ist (fast) sauber, es gibt aber eine verbesserte Variante von frank (bitte selber suchen). Wenn du die installiert hast, solltest du warten, ob martinp876 das dann wieder übernimmt...