HttpUtils.pm vom 19.04.2021 "defekt"?

Begonnen von Sascha_F, 20 April 2021, 12:19:06

Vorheriges Thema - Nächstes Thema

rudolfkoenig

Ja, die CPU Auslastung waere wichtig.

Hab dein strace Log irgendwie uebersehen.

Von hinten betrachtet:
- es wird ueber FD 39 mit einem Rechner im cloud (layla.amazon.de) verschluesselt kommuniziert (lesen/schreiben), und danach exklusiv von diesem Rechner auf Daten gewartet, mit 10s timeout. Keine Ahnung, wo das passiert, ich vermute im SSL Bibliothek. Sollte nicht fuer dein Lockup verantwortlich sein, da es nie mit timeout zurueckkommt (das exklusive Warten kommt oefters vor).

- light_light_dim_00.svg wird ein paar Dutzend-mal gelesen, ohne damit was zu machen. Das ist mehr als komisch (=> Bug), ist aber auch nicht fuer das Problem verantwortlich, da nach 0.25s wieder im globalen select gelandet sind. Wuesste gerne, wie man das ausloest.

- 0.2s vor dem Schluss wird noch mit einem CUL_HM via CUL Protokoll kommuniziert (wenn ich mich nicht irre), scheint also alles ok zu sein.

Laut strace war das Programm zum Zeitpunkt des Abbruchs im Kernel (via _newselect), d.h. es darf keine Endlosschleife sein:
eine Endlosschleife produziert im strace keine Ausgabe, da strace nur Systemcalls (Kommunikation mit dem Kernel) verzeichnet.

Bin ratlos.

Sascha_F

Mit der HttpUtils aus dem Beitrag hier liegt die CPU-Last (RPi 4) zwischen 3 % und 28 % - nach Start von FHEM über sytemctl beginnend bei 28 % und dann abfallend. (HttpUtils hier aus dem Beitrag). Unterschied zum letzten Test ist, dass das gesamte System auf heutigem Update-Stand ist (natürlich mit Ausnahme der HttpUtils).

Aufgefallen ist mir (über das Homebride-Log), dass die Verbindung zum MQTT2-SERVER nach ca. 1 Minute (auto-retry) wieder hergestellt wird. (während WEB noch nicht wieder erreichbar ist). Einige Zeit danach stand WEB zur Verfügung und ich konnte Räume mit normaler Geschwindigkeit wechseln. Dabei ist mir aufgefallen, dass PUSHOVER und ECHODEVICE nicht connected waren. ECHODEVICE hat sich dann aber quasi sofort connected - nach Auswahl des PUSHOVER-Devices hing FHEM wieder einige Minuten. Anschließend war auch PUSHOVER connected. ECHODEVICE scheint scheint ggf. aber auch Probleme zu haben - konnte nur sehen, dass das devstateicon immer wieder mal für einen Sekundenbruchteil zwischen disconnected (o.ä.) und connected gewechselt hat.

Zwischendurch kann ich immer mal wieder mit normaler Geschwindigkeit zwischen Räumen/Devices wechseln, aber dann hängt es wieder.

Bei ECHODEVICE weiß ich, dass es eine Verbindung zu "https://layla.amazon.de" aufbaut. Ich kopiere hier mal die Blöcke aus dem FHEM-Log rein:

2021.05.01 14:18:38 3: [AlexaEchoDevice] [echodevice_SendCommand] [13] IGNORIERE Command=account Abfrage in CMD_Queue schon vorhanden!

2021.05.01 14:19:42 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=getnotifications Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:19:42 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=alarmvolume Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:19:42 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=bluetoothstate Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:19:42 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=getdnd Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:19:42 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=wakeword Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:19:42 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=listitems_task Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:19:42 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=listitems_shopping Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:19:42 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=getdevicesettings Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:19:42 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=getisonline Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:19:42 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=devices Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:19:42 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=namedListsIDs Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:19:42 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=devicesstate Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:19:42 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=account Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:19:42 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=getbehavior Abfrage in CMD_Queue schon vorhanden!

2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_SendCommand] [16] IGNORIERE Command=getnotifications Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_SendCommand] [16] IGNORIERE Command=alarmvolume Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_SendCommand] [16] IGNORIERE Command=bluetoothstate Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_SendCommand] [16] IGNORIERE Command=getdnd Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_SendCommand] [16] IGNORIERE Command=wakeword Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_SendCommand] [16] IGNORIERE Command=listitems_task Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_SendCommand] [16] IGNORIERE Command=listitems_shopping Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_SendCommand] [16] IGNORIERE Command=getdevicesettings Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_SendCommand] [16] IGNORIERE Command=getisonline Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_SendCommand] [16] IGNORIERE Command=devices Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_SendCommand] [16] IGNORIERE Command=namedListsIDs Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_SendCommand] [16] IGNORIERE Command=devicesstate Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_SendCommand] [16] IGNORIERE Command=account Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_SendCommand] [16] IGNORIERE Command=getbehavior Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_SendCommand] [16] IGNORIERE Command=getsettingstraffic Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_LostConnect] connection error = read from https://layla.amazon.de:443 timed out / set loginerror to 1
2021.05.01 14:22:03 3: [AlexaEchoDevice] [echodevice_setState] to connected but loginerror

2021.05.01 14:22:47 3: [AlexaEchoDevice] [echodevice_LostConnect] connection error = read from https://layla.amazon.de:443 timed out / set loginerror to 2

2021.05.01 14:23:39 3: [AlexaEchoDevice] [echodevice_LoginStart] connected but loginerror

2021.05.01 14:23:41 3: [AlexaEchoDevice] [echodevice_ParseAuth] reset loginerror from 2 to 0
2021.05.01 14:23:41 3: [AlexaEchoDevice] [echodevice_setState] to connected

2021.05.01 14:26:23 3: [AlexaEchoDevice] [echodevice_LostConnect] connection error = read from https://layla.amazon.de:443 timed out / set loginerror to 1
2021.05.01 14:26:23 3: [AlexaEchoDevice] [echodevice_setState] to connected but loginerror
2021.05.01 14:27:02 3: [AlexaEchoDevice] [echodevice_LoginStart] connected but loginerror
2021.05.01 14:27:02 3: [AlexaEchoDevice] [echodevice_ParseAuth] reset loginerror from 1 to 0
2021.05.01 14:27:02 3: [AlexaEchoDevice] [echodevice_setState] to connected

2021.05.01 14:30:39 3: [AlexaEchoDevice] [echodevice_SendCommand] [14] IGNORIERE Command=alarmvolume Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:30:39 3: [AlexaEchoDevice] [echodevice_SendCommand] [14] IGNORIERE Command=bluetoothstate Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:30:39 3: [AlexaEchoDevice] [echodevice_SendCommand] [14] IGNORIERE Command=getdnd Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:30:39 3: [AlexaEchoDevice] [echodevice_SendCommand] [14] IGNORIERE Command=wakeword Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:30:39 3: [AlexaEchoDevice] [echodevice_SendCommand] [14] IGNORIERE Command=listitems_task Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:30:39 3: [AlexaEchoDevice] [echodevice_SendCommand] [14] IGNORIERE Command=listitems_shopping Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:30:39 3: [AlexaEchoDevice] [echodevice_SendCommand] [14] IGNORIERE Command=getdevicesettings Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:30:39 3: [AlexaEchoDevice] [echodevice_SendCommand] [14] IGNORIERE Command=getisonline Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:30:39 3: [AlexaEchoDevice] [echodevice_SendCommand] [14] IGNORIERE Command=devices Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:30:39 3: [AlexaEchoDevice] [echodevice_SendCommand] [14] IGNORIERE Command=namedListsIDs Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:30:39 3: [AlexaEchoDevice] [echodevice_SendCommand] [14] IGNORIERE Command=devicesstate Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:30:39 3: [AlexaEchoDevice] [echodevice_SendCommand] [14] IGNORIERE Command=account Abfrage in CMD_Queue schon vorhanden!

2021.05.01 14:32:12 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=getnotifications Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:32:12 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=alarmvolume Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:32:12 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=bluetoothstate Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:32:12 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=getdnd Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:32:12 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=wakeword Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:32:12 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=listitems_task Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:32:12 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=listitems_shopping Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:32:12 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=getdevicesettings Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:32:12 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=getisonline Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:32:12 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=devices Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:32:12 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=namedListsIDs Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:32:12 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=devicesstate Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:32:12 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=account Abfrage in CMD_Queue schon vorhanden!
2021.05.01 14:32:12 3: [AlexaEchoDevice] [echodevice_SendCommand] [15] IGNORIERE Command=getbehavior Abfrage in CMD_Queue schon vorhanden!

2021.05.01 14:33:35 3: [AlexaEchoDevice] [echodevice_LostConnect] connection error = read from https://layla.amazon.de:443 timed out / set loginerror to 1
2021.05.01 14:33:35 3: [AlexaEchoDevice] [echodevice_setState] to connected but loginerror
2021.05.01 14:33:36 3: [AlexaEchoDevice] [echodevice_LoginStart] connected but loginerror

2021.05.01 14:33:38 3: [AlexaEchoDevice] [echodevice_ParseAuth] reset loginerror from 1 to 0
2021.05.01 14:33:38 3: [AlexaEchoDevice] [echodevice_setState] to connected


Geht alexa-fhem (über Connector) ggf. auch über layla? Wenn hier ein Problem bestehen würde, würde das aber sicher deutlich mehr Anwender betreffen, denke ich.

Im nächsten Step kann ich natürlich auch alle ECHODEVICE-Devices und PUSHOVER auskommentieren - komme nur leider heute nicht mehr dazu. Danach fällt mir allerdings auch nicht mehr viel ein.


Ich liste unten mal alle Module aus fheminfo auf - es sind auch welche dabei, welche nicht im FHEM-Repository enthalten sind. Ich hoffe, ich habe wirklich alle erwischt (rot). Ich habe beim Folgetest alle Devices in der fhem.cfg auskommentiert, welche Module verwenden, die nicht im offiziellen FHEM-Repository enthalten sind:


  • AptToDate
  • AutoShuttersControl
  • CUL
  • CUL_HM
  • DOIF
  • DOIFtools
  • DbLog
  • DbRep
  • ENIGMA2
  • FB_CALLLIST
  • FB_CALLMONITOR
  • FHEMWEB
  • FileLog
  • HMCCU
  • HMCCUDEV
  • HMCCURPCPROC
  • HMinfo
  • HTTPMOD (für hm-firmware-update)
  • HUEBridge
  • HUEDevice
  • HomeConnect
  • HomeConnectConnection
  • Hyperion
  • HyperionNG
  • IPCAM
  • Installer
  • KODI
  • MQTT2_DEVICE
  • MQTT2_SERVER
  • NUKIBridge
  • NUKIDevice
  • NotifyAndroidTV
  • PRESENCE (lan-ping)
  • Pushover
  • RESIDENTS
  • ROOMMATE
  • SVG
  • SoftliqCloud
  • Unifi
  • UnifiClient
  • UnifiProtect
  • UnifiSwitch
  • WifiLight
  • alexa
  • allowed
  • autocreate
  • cmdalias
  • dummy
  • echodevice
  • eventTypes
  • holiday
  • homebridge
  • homekitDevice
  • km200
  • notify
  • npmjs
  • readingsGroup
  • structure
  • telnet
  • watchdog
  • weblink

Sag Bescheid, wenn Dir noch etwas einfällt oder ich etwas tun kann - oder ggf. auch willst, dass ich aufhöre...

rudolfkoenig

Wenn Du eine Konfiguration zum Nachstellen bauen kannst, dann werde ich versuchen selbst zu debuggen, bin aber unsicher, ob sowas einfach herstellen laesst. Sonst faellt mir nichts Sinnvolles mehr zum eingrenzen des Problems ein => Ich schlage vor es erstmal zu den Akten zu legen.