Fritzbox: Wie meldet man am besten Fehler im Openhab 3.4 Binding nach Einspielen von Fritz Laborversion

Einrichtung der openHAB Umgebung und allgemeine Konfigurationsthemen.

Moderatoren: seppy, udo1toni

Scooter_0807
Beiträge: 21
Registriert: 9. Apr 2021 21:44
Wohnort: Fehmarn

Fritzbox: Wie meldet man am besten Fehler im Openhab 3.4 Binding nach Einspielen von Fritz Laborversion

Beitrag von Scooter_0807 »

Hallo zusammen,

Vorweg: Ich habe 2 Umgebungen mit OpenHAB und Fritzbox. Eine ist produktiv, mit einer teste ich herum.

Ich habe in meiner Testumgebung auf der Fritzbox 7490 die neueste Laborversion "7.51-102642 BETA-Version" eingespielt.
Jetzt meldet in OpenHAB3 das AVM Binding immer "Communication Error Fritzbox does not response" und kurz darauf "invalid request".

Die produktive Fritzbox 7490 hat das aktuelle, offizielle FritzOS 7.29. Aus OpenHAB kann ich mit dem AVM-Binding problemlos auf alles zugreifen.
Das verwendete AVM Binding / OpenHAB hat auf beiden Umgebungen die Version 3.4.1
OpenHAB läuft auf einem Raspberry Pi3.

Der verwendete User ist auf beiden Fritzboxen gleich und hat die gleichen Rechte. Das Problem ist in der Testumgebung auch erst mit dem Update auf die Laborversion aufgetreten. Im Log der Fritzbox kann ich keinen Fehler sehen.

Ich habe ein Ticket Feeback bei AVM gegeben und auf das Problem hingewiesen. Ich erhielt aber das Feedback, dass dies ein Problem von OpenHAB wäre.

Also erste Erkenntnis, die ich teilen möchte: Fritz Labor 7.51 mit Fritzbox 7490 erzeugt Kommunikationsfehler, also setzt die bitte nicht ein.

Jetzt meine Frage in die Runde:
Wie kann ich feststellen ob OpenHAB im Binding wirklich ein Problem hat?
Gibt es vom AVM-Binding eine Logdatei, sodass ich in den beiden Umgebungen prüfen kann, ob sich die Antwort der Fritzbox fehlerhaft verändert hat oder ob das OpenHAB Binding ein Problem hat?

Vielen Dank und Grüße

Benutzeravatar
udo1toni
Beiträge: 13856
Registriert: 11. Apr 2018 18:05
Answers: 222
Wohnort: Darmstadt

Re: Fritzbox: Wie meldet man am besten Fehler im Openhab 3.4 Binding nach Einspielen von Fritz Laborversion

Beitrag von udo1toni »

Also, zunächst mal: Natürlich ist AVM die falsche Adresse, um solche Fehler zu melden. AVM bestimmt, wie die Kommunikation mit FRITZ!Boxen abzulaufen hat, nicht irgendeine Popelsoftware wie openHAB oder HASS oder ioBroker. Selbst Microsoft muss die Protokolle von AVM einhalten, wenn sie auf die FRITZ!Box zugreifen wollen. ;)

Die richtige Adresse ist also erst mal die offizielle openHAB Community (das englische Forum) und wenn Fehler dort bestätigt werden ein Eintrag in den Issues auf github.
openHAB4.1.2 stable in einem Debian-Container (bookworm) (Proxmox 8.1.5, LXC), mit openHABian eingerichtet

Harka
Beiträge: 297
Registriert: 30. Apr 2021 13:13
Answers: 15

Re: Fritzbox: Wie meldet man am besten Fehler im Openhab 3.4 Binding nach Einspielen von Fritz Laborversion

Beitrag von Harka »

Hi,
die Warnung kommt für mich zu spät. Habe gerade gestern auf meiner 7490 das selbe Beta eingespielt.
Kann aber bisher kein Fehler erkennen. Weder im Protokoll noch bei den Funktionen (Anruferkennung, Fritz-Thermostat, Anrufweiterschaltung, Netzwerkbinding …). Betrifft also zumindestens nicht alle potentiellen „Opfer“.

e: Binding ist auch bei 3.4.1, Werte entsprechen den Voreinstellungen, habe http und https erfolgreich getestet, RasPi 4
Zuletzt geändert von Harka am 23. Jan 2023 19:49, insgesamt 1-mal geändert.

Benutzeravatar
udo1toni
Beiträge: 13856
Registriert: 11. Apr 2018 18:05
Answers: 222
Wohnort: Darmstadt

Re: Fritzbox: Wie meldet man am besten Fehler im Openhab 3.4 Binding nach Einspielen von Fritz Laborversion

Beitrag von udo1toni »

Das ist schon mal hochinteressant, wäre also toll, falls ihr Euch mal miteinander kurzschließt und evtl. Unterschiede in Eurer Konfiguration findet (was dann vielleicht den Fehler einzugrenzen hilft)
openHAB4.1.2 stable in einem Debian-Container (bookworm) (Proxmox 8.1.5, LXC), mit openHABian eingerichtet

Scooter_0807
Beiträge: 21
Registriert: 9. Apr 2021 21:44
Wohnort: Fehmarn

Re: Fritzbox: Wie meldet man am besten Fehler im Openhab 3.4 Binding nach Einspielen von Fritz Laborversion

Beitrag von Scooter_0807 »

Moin,

die Idee zum Austausch finde ich gut. Harka, ich würde Dir eine PN schreiben.

Frage vorweg: Gibt es im OpenHAB eine logdatei wo ich nachverfolgen kann was das AVM-Binding an die Fritzbox sendet und welche Antwort zurückkommt?
Die Logdatei in der Fritzbox hat ja wenig Inhalt.

Benutzeravatar
udo1toni
Beiträge: 13856
Registriert: 11. Apr 2018 18:05
Answers: 222
Wohnort: Darmstadt

Re: Fritzbox: Wie meldet man am besten Fehler im Openhab 3.4 Binding nach Einspielen von Fritz Laborversion

Beitrag von udo1toni »

Du kannst das Logging für das FRITZ!Box Binding aufdrehen und dann in openhab.log nachvollziehen. Wie detailliert das Binding Auskunft gibt, weiß ich aber nicht.
Grundsätzlich: Du loggst Dich in der Karaf Konsole ein (üblicherweise von der GNU/Linux Shell aus, per openhab-cli console) und gibst dort den Befehl log:set TRACE org.openhab.binding.avmfritz ein. Der Befehl wirkt unmittelbar, die Einstellung bleibt auch über einen Neustart erhalten.
Los wirst Du das Ganze wieder mit Befehl log:set DEFAULT org.openhab.binding.avmfritz. Alternativ kannst Du auch INFO, DEBUG, WARN, ERROR oder gar OFF setzen, das sollte man aber nur bei bekannten Fehlern machen, sonst kann man bei eventuellen Problemen nicht nachvollziehen, ob es mit dem betreffenden Untersystem Probleme gab. DEFAULT erbt die Einstellungen des übergeordneten Loggers. TRACE ist die höchste Stufe :)
openHAB4.1.2 stable in einem Debian-Container (bookworm) (Proxmox 8.1.5, LXC), mit openHABian eingerichtet

Harka
Beiträge: 297
Registriert: 30. Apr 2021 13:13
Answers: 15

Re: Fritzbox: Wie meldet man am besten Fehler im Openhab 3.4 Binding nach Einspielen von Fritz Laborversion

Beitrag von Harka »

Hi,
versuch doch mal die Beta wieder raus zu schmeißen. Unter System/Update gibt es die Option "Zurück zum offiziellen FRITZ!OS" und beim Download der Beta war auch noch eine Rücksetzprogramm mit in der Zip-Datei. Wenn das Binding anschließend wieder geht grenzt es den Fehler noch weiter ein.

Scooter_0807
Beiträge: 21
Registriert: 9. Apr 2021 21:44
Wohnort: Fehmarn

Re: Fritzbox: Wie meldet man am besten Fehler im Openhab 3.4 Binding nach Einspielen von Fritz Laborversion

Beitrag von Scooter_0807 »

Hallo nochmal,
Dank udo1toni, ich habe das Logging in der Openhab Console auf DEBUG hochgesetzt.
Man kann leider nur für ALLE Bindings das login hochdrehen.
Wie auch immer, ich habe alle Things disabled, Login hochgesetzt und dann das Thing für die Fritzbox von DISABLED wieder eingeschaltet.

Das habe ich mit der funktionierenden Fritzbox (offizielles FritzOS) und mit der Test-Fritzbox (Laborversion) durchgefürht.

Im Log ist das Problem erkennbar:
So sieht das Log aus, wenn OpenHab zur funktionierenden Fritzbox die Verbindung öffnen will:

Code: Alles auswählen

Queued HttpRequest[GET /status HTTP/1.1]@1a4d26a for HttpDestination[http://192.168.0.214]@1444559,queue=1,pool=DuplexConnectionPool@157503c[c=0/0/2,a=0,i=0,q=1]
write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@d96fac[p=0,l=15,c=32768,r=15]={<<<event: message\n>>>data: {"t...\x00\x00\x00\x00\x00\x00\x00}
Acquiring create=true on DuplexConnectionPool@157503c[c=0/0/2,a=0,i=0,q=1]
write(array HeapByteBuffer@fff003[p=0,l=6,c=6,r=6]={<<<data: >>>})
Try creating connection 0/2 with 0 pending
Try creating(true) connection, pending/demand/supply: 0/2/0, result=true
write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@d96fac[p=0,l=21,c=32768,r=21]={<<<event: message\ndata: >>>{"topic":...\x00\x00\x00\x00\x00\x00\x00}
Creating connection 0/2 at MultiEntry@ff5020{PENDING,usage=0,multiplex=0,pooled=null}
write(array HeapByteBuffer@16268c4[p=0,l=198,c=198,r=198]={<<<{"topic":"openhab/things/..."ThingStatusInfoEvent"}>>>})
Und so sieht es aus, wenn die Verbindung zur Fritzbox mit der Laborversion eröffnet werden soll:

Code: Alles auswählen

Queued HttpRequest[GET /login_sid.lua HTTP/1.1]@1443c57 for HttpDestination[http://192.168.1.1]@ae84c8,queue=1,pool=DuplexConnectionPool@18e3fdb[c=0/0/2,a=0,i=0,q=1]
Acquiring create=true on DuplexConnectionPool@18e3fdb[c=0/0/2,a=0,i=0,q=1]
Selector sun.nio.ch.EPollSelectorImpl@17bbf0a woken with none selected
Selector sun.nio.ch.EPollSelectorImpl@17bbf0a woken up from select, 0/0/5 selected
Try creating connection 0/2 with 0 pending
Selector sun.nio.ch.EPollSelectorImpl@17bbf0a processing 0 keys, 0 updates
updateable 0
updates 0
Selector sun.nio.ch.EPollSelectorImpl@17bbf0a waiting with 5 keys
queue org.eclipse.jetty.io.ManagedSelector$DestroyEndPoint@1240536 startThread=0
flushed 206 SocketChannelEndPoint@32ac3b{l=/192.168.1.202:8080,r=/192.168.0.202:53540,OPEN,fill=-,flush=W,to=1405/30000}{io=0/0,kio=0,kro=1}->HttpConnection@be3e12[p=HttpParser{s=CONTENT,0 of -1},g=HttpGenerator@3da39b{s=COMMITTED}]=>HttpChannelOverHttp@c82042{s=HttpChannelState@19515ce{s=WAITING rs=ASYNC os=COMMITTED is=IDLE awp=false se=false i=false al=2},r=1,c=false/false,a=WAITING,uri=//192.168.1.202:8080/rest/events?topics=openhab/items/*/*,openhab/things/*/*,openhab/channels/*/triggered,openhab/channels/*/descriptionchanged,age=188298024}
Flushed=true written=206 remaining=0 WriteFlusher@34e640{WRITING}->null
generate: DONE for SendCallback@141b01e[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@1b8fed0] (null,[p=200,l=200,c=32768,r=0],false)@COMMITTED
onWriteComplete(false,null) s=OPEN,api=BLOCKED,sc=false,e=null->s=OPEN,api=BLOCKING,sc=false,e=null c=null cb=null w=false
write(array HeapByteBuffer@2a186b[p=0,l=1,c=1,r=1]={<<<\n>>>})
Commit failed
org.eclipse.jetty.io.EofException: null
	at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:279) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:381) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:831) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.HttpConnection.send(HttpConnection.java:555) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:1014) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:1086) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.HttpOutput.channelWrite(HttpOutput.java:285) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.HttpOutput.channelWrite(HttpOutput.java:269) ~[bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.HttpOutput.flush(HttpOutput.java:751) ~[bundleFile:9.4.46.v20220331]
	at org.openhab.core.io.rest.core.internal.GsonMessageBodyWriter.writeTo(GsonMessageBodyWriter.java:91) ~[?:?]
	at org.openhab.core.io.rest.core.internal.MediaTypeExtension.writeTo(MediaTypeExtension.java:84) ~[?:?]
	at org.apache.cxf.jaxrs.sse.OutboundSseEventBodyWriter.writePayloadTo(OutboundSseEventBodyWriter.java:133) ~[bundleFile:3.4.5]
	at org.apache.cxf.jaxrs.sse.OutboundSseEventBodyWriter.writeTo(OutboundSseEventBodyWriter.java:112) ~[bundleFile:3.4.5]
	at org.apache.cxf.jaxrs.sse.OutboundSseEventBodyWriter.writeTo(OutboundSseEventBodyWriter.java:40) ~[bundleFile:3.4.5]
	at org.apache.cxf.jaxrs.sse.SseEventSinkImpl.dequeue(SseEventSinkImpl.java:238) ~[bundleFile:3.4.5]
	at org.eclipse.jetty.server.handler.ContextHandler.handle(ContextHandler.java:1525) [bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.server.AsyncContextState$1.run(AsyncContextState.java:153) [bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) [bundleFile:9.4.46.v20220331]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) [bundleFile:9.4.46.v20220331]
	at java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: java.io.IOException: Broken pipe
	at sun.nio.ch.FileDispatcherImpl.writev0(Nat
Das Binding kommt nicht einmal dazu die API aufzurufen, weil der eigentliche Verbindungsaufbau schon auf die Bretter geht.
Hinweis sind für mich 2 meldungen:
1. queue org.eclipse.jetty.io.ManagedSelector$DestroyEndPoint@1240536 startThread=0
2. onWriteComplete(false,null) s=OPEN,api=BLOCKED,sc=false,

Da scheint die API auf der Fritzbox in die Knie gegangen zu sein.

Bevor ich jetzt die Fritzbox zurücksetze würde ich nochmal einen Hinweis bei AVM aufgeben, ob ggf. die Updateprozedur ein Fehler machen kann.

Ich melde mich !

Scooter_0807
Beiträge: 21
Registriert: 9. Apr 2021 21:44
Wohnort: Fehmarn

Re: Fritzbox: Wie meldet man am besten Fehler im Openhab 3.4 Binding nach Einspielen von Fritz Laborversion

Beitrag von Scooter_0807 »

Harka hat geschrieben: 24. Jan 2023 17:31 Hi,
versuch doch mal die Beta wieder raus zu schmeißen. Unter System/Update gibt es die Option "Zurück zum offiziellen FRITZ!OS" und beim Download der Beta war auch noch eine Rücksetzprogramm mit in der Zip-Datei. Wenn das Binding anschließend wieder geht grenzt es den Fehler noch weiter ein.
Hallo Harka,
laut AVM ist ein Downgrade nicht möglich.
Hintergrund:
Mit dem Upgrade werden auch die angeschlossenen Geräte wie Fritz Fon und Heizkörperregler auf eine neue Version gehoben. Die funktionieren dann nicht mehr mit dem offiziellen "alten" OS.
Wie auch immer werde ich nach einer möglichen Antwort von AVM die Fritzbox zurücksetzen und das Lobar-Release neu aufspielen.

Benutzeravatar
udo1toni
Beiträge: 13856
Registriert: 11. Apr 2018 18:05
Answers: 222
Wohnort: Darmstadt

Re: Fritzbox: Wie meldet man am besten Fehler im Openhab 3.4 Binding nach Einspielen von Fritz Laborversion

Beitrag von udo1toni »

Scooter_0807 hat geschrieben: 24. Jan 2023 18:27 Man kann leider nur für ALLE Bindings das login hochdrehen.
Nein, das ist Quatsch. Das Logging ist feingranular, Du drehst offensichtlich an der falschen Schraube. Mach es exakt, wie ich es beschrieben habe und das Logging wird exakt für dieses eine Binding geändert.

Alles komplett auf Debug zu setzen ist auch nicht sehr hilfreich, denn Du bekommst damit massig zusätzliche Systmlast, die auch das Binding selbst beeinflussen kann.
Bitte NICHT mit start_debug.sh starten, das ist NICHT sinnvoll (zumindest in diesem Zusammenhang). Das Logging lässt sich komplett im laufenden Betrieb steuern, und nur im laufenden Betrieb (es sei denn, Du schraubst selbst an der log4j2.xml rum, das solltest Du aber nur bei guter Kenntnis von log4j2 machen).
Scooter_0807 hat geschrieben: 24. Jan 2023 18:27 2. onWriteComplete(false,null) s=OPEN,api=BLOCKED,sc=false,
Kann es sein, dass die FRITZ!Box schlicht vergessen hat, dass Du den Zugriff erlaubt hast? Versuch dazu: Sperre den Zugang in der FRITZ!Box und erlaube ihn erneut (vielleicht zwischendurch Speichern und/oder gar Neustart der Box)

Ach so... Nur zur Klarstellung... openHAB3 gibt es nicht ohne Karaf Konsole, die ist IMMER da. Wenn Du kein GNU/Linux System als Unterbau nutzt, kann der Aufruf der Konsole anders erfolgen. Dann wäre es hilfreich, Installationsart und Betriebssystem zu kennen :)
openHAB4.1.2 stable in einem Debian-Container (bookworm) (Proxmox 8.1.5, LXC), mit openHABian eingerichtet

Antworten