FBAHAHTTP Problem - Modul deaktiviert sich von selbst

Begonnen von P.A.Trick, 08 November 2021, 06:54:15

Vorheriges Thema - Nächstes Thema

P.A.Trick

Ich nutze 3 DECT Steckdosen an meiner Fritzbox 7390 seit Jahren ohne Probleme. Am WE habe ich die Fritte gegen
eine 7590AX getauscht. Nach einem fhem restart disabled sich das Modul selbstständig und steht im Status "Defined".

Die einzige Möglichkeit die ich gefunden habe das Modul wieder zu aktivieren, ist das disable Attibut zu löschen und das Passwort neu zu setzen :-/

Any ideas?

Fritz OS 7.29
FHEM: 6.1 (up2date)
Cubietruck,RPI,QNAP Ts-419p+, FS20, FRITZ!DECT200, 7 MAX! Thermostate, 3 MAX! Fensterkontakte, Kodi, CUL V3.3, EM1000S, LW12, LD382, HUE, HM-CFG-USB-2, 1x HM-LC-SW1-FM, 2x HM-LC-SW2-FM, 2x HM-LC-Sw1PBU-FM, 3xHM-LC-Bl1PBU-FM,HM-SEC-RHS, 2xHM-SEC-SD,HM-WDS30-T-O, 3x HM-LC-Dim1TPBU-FM, RPI+AddOn

rudolfkoenig

Wenn ich mich mit dem Problem beschaeftigen soll, dann braeuchte ich sowas wie Logs, Definition, etc.

P.A.Trick

Hi Rudi, ja sorry ich wollte erst einmal so anfragen ob jemand noch Probleme hat, oder ich der einzige bin.



Modul Def:

Internals:
   Clients    :FBDECT:
   DEF        192.168.1.1
   FUUID      5c445b5b-f33f-cbb9-a0c2-c010ef91b1e6188b
   FVERSION   00_FBAHAHTTP.pm:0.233270/2020-12-11
   NAME       fb2
   NR         1537
   STATE      connected
   TYPE       FBAHAHTTP
   CmdStack:
   MatchList:
     1:FBDECT   .*
   READINGS:
     2021-11-07 21:48:37   templateList   
Attributes:
   devStateIcon connected:10px-kreis-gruen Initialized:10px-kreis-gelb disconnected:10px-kreis-rot
   dummy      0
   fbTimeout  4
   fritzbox-user murdoc
   genericDeviceType ignore
   group      _FRITZBOX
   icon       it_router@grey
   polltime   62
   room       System->Dienste
   verbose    5


Exemplarisch eine DECT Steckdose:

Internals:
   Clients    :FBDECT:
   DEF        192.168.1.1
   FUUID      5c445b5b-f33f-cbb9-a0c2-c010ef91b1e6188b
   FVERSION   00_FBAHAHTTP.pm:0.233270/2020-12-11
   NAME       fb2
   NR         1537
   STATE      connected
   TYPE       FBAHAHTTP
   CmdStack:
   MatchList:
     1:FBDECT   .*
   READINGS:
     2021-11-07 21:48:37   templateList   
Attributes:
   devStateIcon connected:10px-kreis-gruen Initialized:10px-kreis-gelb disconnected:10px-kreis-rot
   dummy      0
   fbTimeout  4
   fritzbox-user murdoc
   genericDeviceType ignore
   group      _FRITZBOX
   icon       it_router@grey
   polltime   62
   room       System->Dienste
   verbose    0


Log fb2 verbose 5 ohne Fehler

2021.11.08 18:44:29.928 5: fb2: dispatch <device identifier="08761 0078388" id="19" functionbitmask="35712" fwversion="04.16" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>UG.AZ.PC</name><switch><state>1</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>1</state></simpleonoff><powermeter><voltage>236021</voltage><power>100990</power><energy>4131437</energy></powermeter><temperature><celsius>220</celsius><offset>0</offset></temperature></device>
2021.11.08 18:44:29.902 5: fb2: dispatch <device identifier="08761 0145037" id="18" functionbitmask="35712" fwversion="04.16" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>UG.WK.Serversteckdose</name><switch><state>1</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>1</state></simpleonoff><powermeter><voltage>234783</voltage><power>25960</power><energy>2341464</energy></powermeter><temperature><celsius>205</celsius><offset>0</offset></temperature></device>
2021.11.08 18:44:29.833 5: fb2: dispatch <device identifier="08761 0033992" id="16" functionbitmask="35712" fwversion="04.16" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>OG.FZ.SchalterSolaranlage</name><switch><state>0</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>0</state></simpleonoff><powermeter><voltage>233957</voltage><power>0</power><energy>1193061</energy></powermeter><temperature><celsius>215</celsius><offset>0</offset></temperature></device>


Ich versuche noch einmal beim Fehler das Log anzuhängen. Folgt sobald ich den Fehler im Log habe. Dankeschön im Voraus.
Cubietruck,RPI,QNAP Ts-419p+, FS20, FRITZ!DECT200, 7 MAX! Thermostate, 3 MAX! Fensterkontakte, Kodi, CUL V3.3, EM1000S, LW12, LD382, HUE, HM-CFG-USB-2, 1x HM-LC-SW1-FM, 2x HM-LC-SW2-FM, 2x HM-LC-Sw1PBU-FM, 3xHM-LC-Bl1PBU-FM,HM-SEC-RHS, 2xHM-SEC-SD,HM-WDS30-T-O, 3x HM-LC-Dim1TPBU-FM, RPI+AddOn

P.A.Trick

#3
2021.11.08 18:56:32.698 1: Perfmon: possible freeze starting at 18:56:30, delay is 2.698
2021.11.08 18:56:32.689 3: [sendmsg] - [MSG] 18:56:31: [warning] Keine Verbindung mehr zur Steckdose UG.AZ.PC !
2021.11.08 18:56:32.575 1: sendemail returned: Nov 08 18:56:32 66517e831d67 sendemail[876]: Email was sent successfully!
2021.11.08 18:56:31.829 3: [sendmsg] - [MSG] 18:56:30: [warning] Keine Verbindung mehr zur Steckdose UG.WK.Serversteckdose  !
2021.11.08 18:56:31.711 1: sendemail returned: Nov 08 18:56:31 66517e831d67 sendemail[852]: Email was sent successfully!
2021.11.08 18:56:30.782 3: [sendmsg] - [MSG] 18:56:29: [warning] Keine Verbindung mehr zur Steckdose OG.FZ.SchalterSolaranlage!
2021.11.08 18:56:30.669 1: sendemail returned: Nov 08 18:56:30 66517e831d67 sendemail[828]: Email was sent successfully!
2021.11.08 18:54:42.990 3: [sendmsg] - [MSG] 18:54:42: [info] Jolians PS3 ist nicht verbunden!


Fehler ist aufgetreten, keine Einträge im Log nur meine Überwachung hat es mitbekommen (Heartbeat).
BTW: Die Ausgabe des Logs im voherigen Post ist nur einmal erschienen!

Das Device ist unverändert:


Historie löschen
Internals:
   Clients    :FBDECT:
   CmdStack   
   DEF        192.168.1.1
   FUUID      5c445b5b-f33f-cbb9-a0c2-c010ef91b1e6188b
   FVERSION   00_FBAHAHTTP.pm:0.233270/2020-12-11
   NAME       fb2
   NR         1537
   STATE      connected
   TYPE       FBAHAHTTP
   MatchList:
     1:FBDECT   .*
   READINGS:
     2021-11-07 21:48:37   templateList   
Attributes:
   devStateIcon connected:10px-kreis-gruen Initialized:10px-kreis-gelb disconnected:10px-kreis-rot
   disable    1
   dummy      0
   fbTimeout  4
   fritzbox-user murdoc
   genericDeviceType ignore
   group      _FRITZBOX
   icon       it_router@grey
   polltime   62
   room       System->Dienste
   verbose    5


Update: Ich habe jetzt versucht mit einem Druck auf edit Def und modify das Gerät wieder zum laufen zu bewegen. fb2 springt auf Defined, aber das Modul arbeitet nicht. Keine Logeinträge! Ein set refreshstate und ein set password "<mypass>" bringt auch keine Lösung.
Cubietruck,RPI,QNAP Ts-419p+, FS20, FRITZ!DECT200, 7 MAX! Thermostate, 3 MAX! Fensterkontakte, Kodi, CUL V3.3, EM1000S, LW12, LD382, HUE, HM-CFG-USB-2, 1x HM-LC-SW1-FM, 2x HM-LC-SW2-FM, 2x HM-LC-Sw1PBU-FM, 3xHM-LC-Bl1PBU-FM,HM-SEC-RHS, 2xHM-SEC-SD,HM-WDS30-T-O, 3x HM-LC-Dim1TPBU-FM, RPI+AddOn

rudolfkoenig

Versuch bitte im Problemfall ein "set refreshstate" bei  "attr verbose 5".

P.A.Trick

Zitat von: rudolfkoenig am 08 November 2021, 19:33:29
Versuch bitte im Problemfall ein "set refreshstate" bei  "attr verbose 5".

2021.11.08 19:40:37.131 5: End notify loop for fb2
2021.11.08 19:40:37.121 5: Starting notify loop for fb2, 1 event(s), first is refreshstate
2021.11.08 19:40:37.121 5: Cmd: >set fb2 refreshstate<
2021.11.08 19:40:37.120 4: Connection accepted from telnetPort_127.0.0.1_59906


Wirklich viel steht da nicht :-/
Cubietruck,RPI,QNAP Ts-419p+, FS20, FRITZ!DECT200, 7 MAX! Thermostate, 3 MAX! Fensterkontakte, Kodi, CUL V3.3, EM1000S, LW12, LD382, HUE, HM-CFG-USB-2, 1x HM-LC-SW1-FM, 2x HM-LC-SW2-FM, 2x HM-LC-Sw1PBU-FM, 3xHM-LC-Bl1PBU-FM,HM-SEC-RHS, 2xHM-SEC-SD,HM-WDS30-T-O, 3x HM-LC-Dim1TPBU-FM, RPI+AddOn

P.A.Trick

2021.11.08 19:44:09.523 4: <hidden>: HTTP response code 204
+     1 2021.11.08 19:44:09.524 5: HttpUtils <hidden>: Got data, length: 0
+     2 2021.11.08 19:44:09.524 5: HttpUtils response header:
+     3 HTTP/1.0 204 No Content^M
+     4 Content-Type: application/json^M
+     5 Request-Id: dbfbdefc-40c3-11ec-a816-0242ac130003^M
+     6 X-Influxdb-Build: OSS^M
+     7 X-Influxdb-Version: 1.8.10^M
+     8 X-Request-Id: dbfbdefc-40c3-11ec-a816-0242ac130003^M
+     9 Date: Mon, 08 Nov 2021 18:44:09 GMT
+    10 2021.11.08 19:44:10.034 4: Connection accepted from WEB_172.18.0.4_58016
+    11 2021.11.08 19:44:10.041 5: POST /fhem?cmd.modifyfb2%3Dmodify%20fb2%20192.168.1.1&XHR=1&fwcsrf=csrf_116183244222037&fw_id=4493 HTTP/1.1^M
+    12 Connection: close^M
+    13 Host: raspberrypi4^M
+    14 X-Real-IP: 192.168.1.54^M
+    15 X-Forwarded-For: 192.168.1.54^M
+    16 Connection: close^M
+    17 Content-Length: 0^M
+    18 Authorization: Basic YWRtaW46Z2VvbWV0cmll^M
+    19 Accept: text/plain, */*; q=0.01^M
+    20 cache-control: no-cache^M
+    21 X-Requested-With: XMLHttpRequest^M
+    22 User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.69 Safari/537.36^M
+    23 Sec-GPC: 1^M
+    24 Origin: http://raspberrypi4^M
+    25 Referer: http://raspberrypi4/fhem?detail=fb2^M
+    26 Accept-Encoding: gzip, deflate^M
+    27 Accept-Language: de-DE,de;q=0.9,en-US;q=0.8,en;q=0.7^M
+    28 Cookie: adminer_sid=f28b01f8a61195ce65e4d445593a675a; adminer_key=21145a79f48f5deadf1e4f2495bedae8; grafana_session=688ef22842ffa574a88635b41e95f771
+    29 2021.11.08 19:44:10.042 4: WEB_172.18.0.4_58016 POST /fhem?cmd.modifyfb2%3Dmodify%20fb2%20192.168.1.1&XHR=1&fwcsrf=csrf_116183244222037&fw_id=4493; BU
        FLEN:0
+    30 2021.11.08 19:44:10.042 5: Cmd: >modify fb2 192.168.1.1<


Hier noch das log wenn ich DEF und modify drücke. Sollte das HttpUtils nichts zurück liefern?
Cubietruck,RPI,QNAP Ts-419p+, FS20, FRITZ!DECT200, 7 MAX! Thermostate, 3 MAX! Fensterkontakte, Kodi, CUL V3.3, EM1000S, LW12, LD382, HUE, HM-CFG-USB-2, 1x HM-LC-SW1-FM, 2x HM-LC-SW2-FM, 2x HM-LC-Sw1PBU-FM, 3xHM-LC-Bl1PBU-FM,HM-SEC-RHS, 2xHM-SEC-SD,HM-WDS30-T-O, 3x HM-LC-Dim1TPBU-FM, RPI+AddOn

P.A.Trick

#7
Sorry ganz vergessen! Das Attribut 

attr fb2 disable 1

hatte sich wieder von selbst gesetzt.

2021.11.08 20:04:24.005 5: End notify loop for global

        ];
          'DELETEATTR fb2 disable'
2021.11.08 20:04:24.001 5: npmjs (fhemServerNpm) - Notify: $VAR1 = [

        ];
          'DELETEATTR fb2 disable'
2021.11.08 20:04:24.000 5: Installer (fhemInstaller) - Notify: $VAR1 = [
2021.11.08 20:04:23.980 5: Starting notify loop for global, 1 event(s), first is DELETEATTR fb2 disable
2021.11.08 20:04:23.979 5: Cmd: >deleteattr fb2 disable<


Danach rennt er wieder los und der Status wird auch gesetzt:

2021.11.08 20:04:45.738 4: Connection closed for WEB_172.18.0.4_60710: EOF
2021.11.08 20:04:45.706 5: End notify loop for fb2
2021.11.08 20:04:45.697 5: Starting notify loop for fb2, 1 event(s), first is refreshstate
2021.11.08 20:04:45.696 5: IP: 192.168.1.1 -> 192.168.1.1
2021.11.08 20:04:45.696 4: FBAHAHTTP_connect fb2: got SID d6fce853845e03ed
Content-Security-Policy: default-src 'none'; connect-src 'self'; font-src 'self'; frame-src https://service.avm.de https://help.avm.de https://www.avm.de https://avm.de https://assets.avm.de https://clickonce.avm.de http://clickonce.avm.de http://download.avm.de https://download.avm.de 'self'; img-src 'self' https://tv.avm.de https://help.avm.de/images/ http://help.avm.de/images/ data:; script-src 'self' 'unsafe-inline'; style-src 'self' 'unsafe-inline'; frame-ancestors 'self'; media-src 'self'
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
X-Frame-Options: SAMEORIGIN
Pragma: no-cache
Expires: -1
Date: Mon, 08 Nov 2021 19:04:45 GMT
Content-Type: text/xml
Connection: close
Cache-Control: no-cache
HTTP/1.0 200 OK
2021.11.08 20:04:45.695 5: HttpUtils response header:
2021.11.08 20:04:45.695 5: HttpUtils http://192.168.1.1/login_sid.lua?username=murdoc: Got data, length: 443
2021.11.08 20:04:45.695 4: http://192.168.1.1/login_sid.lua?username=murdoc: HTTP response code 200


Und danach kommen auch die Daten wieder:

2021.11.08 20:04:46.199 5: fb2: dispatch <device identifier="08761 0033992" id="16" functionbitmask="35712" fwversion="04.16" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>OG.FZ.SchalterSolaranlage</name><switch><state>0</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>0</state></simpleonoff><powermeter><voltage>237229</voltage><power>0</power><energy>1193061</energy></powermeter><temperature><celsius>210</celsius><offset>0</offset></temperature></device>

2021.11.08 20:04:46.199 5: <devicelist version="1" fwversion="7.29"><device identifier="08761 0033992" id="16" functionbitmask="35712" fwversion="04.16" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>OG.FZ.SchalterSolaranlage</name><switch><state>0</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>0</state></simpleonoff><powermeter><voltage>237229</voltage><power>0</power><energy>1193061</energy></powermeter><temperature><celsius>210</celsius><offset>0</offset></temperature></device><device identifier="08761 0145037" id="18" functionbitmask="35712" fwversion="04.16" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>UG.WK.Serversteckdose</name><switch><state>1</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>1</state></simpleonoff><powermeter><voltage>236454</voltage><power>25960</power><energy>2341501</energy></powermeter><temperature><celsius>210</celsius><offset>0</offset></temperature></device><device identifier="08761 0078388" id="19" functionbitmask="35712" fwversion="04.16" manufacturer="AVM" productname="FRITZ!DECT 200"><present>1</present><txbusy>0</txbusy><name>UG.AZ.PC</name><switch><state>1</state><mode>manuell</mode><lock>0</lock><devicelock>0</devicelock></switch><simpleonoff><state>1</state></simpleonoff><powermeter><voltage>234407</voltage><power>164580</power><energy>4131628</energy></powermeter><temperature><celsius>215</celsius><offset>0</offset></temperature></device></devicelist>
2021.11.08 20:04:46.198 5: http://192.168.1.1/webservices/homeautoswitch.lua?sid=d6fce853845e03ed&switchcmd=getdevicelistinfos: HTTP response code 200
2021.11.08 20:04:46.197 4: Connection closed for WEB_172.18.0.4_60728: EOF
2021.11.08 20:04:46.169 4: Connection closed for WEB_172.18.0.4_60726: EOF

/ Cache-Control: no-cache, no-store, must-revalidate
2021.11.08 20:04:46.142 4: WEB: /fhem?cmd=%7BAttrVal(%22fb2%22%2C%22room%22%2C%22%22)%7D&XHR=1&fwcsrf=csrf_116183244222037 / RL:34 / text/plain; charset=UTF-8 / Content-Encoding: gzip
2021.11.08 20:04:46.141 5: Cmd: >{AttrVal("fb2","room","")}<
Cubietruck,RPI,QNAP Ts-419p+, FS20, FRITZ!DECT200, 7 MAX! Thermostate, 3 MAX! Fensterkontakte, Kodi, CUL V3.3, EM1000S, LW12, LD382, HUE, HM-CFG-USB-2, 1x HM-LC-SW1-FM, 2x HM-LC-SW2-FM, 2x HM-LC-Sw1PBU-FM, 3xHM-LC-Bl1PBU-FM,HM-SEC-RHS, 2xHM-SEC-SD,HM-WDS30-T-O, 3x HM-LC-Dim1TPBU-FM, RPI+AddOn

rudolfkoenig

ZitatUnd danach kommen auch die Daten wieder:
Das ist zwar toll, aber wenn ich helfen soll, brauche ich den anderen Fall, wo es nicht geht.

Und bitte, wenn moeglich, keine Reverse-Logs, ich habe Schwierigkeiten rueckwaerts zu lesen.

P.A.Trick

Ich glaube ich habe es gefunden. Sorry ich habe mir selbst einen Bock geschossen.
Bedingt durch Probleme mit fhem wenn das Internet weg ist, habe ich einige Module, u.a. auch das fb2 mit einem attr fb2 disable 1 ausgestattet.
Durch den Wechsel der Fritzbox hat sich die mac geändert und das DOIF hat nicht mehr die Module aktualisiert nach einem Neustart.
Meine Demenz führte dazu, dass ich mich daran nicht mehr erinnern konnte (ist Jahre her :-/).

Sorry für das Layer 8 Problem.
Cubietruck,RPI,QNAP Ts-419p+, FS20, FRITZ!DECT200, 7 MAX! Thermostate, 3 MAX! Fensterkontakte, Kodi, CUL V3.3, EM1000S, LW12, LD382, HUE, HM-CFG-USB-2, 1x HM-LC-SW1-FM, 2x HM-LC-SW2-FM, 2x HM-LC-Sw1PBU-FM, 3xHM-LC-Bl1PBU-FM,HM-SEC-RHS, 2xHM-SEC-SD,HM-WDS30-T-O, 3x HM-LC-Dim1TPBU-FM, RPI+AddOn