INSTAR 9008 / MQTT2_Server: Error: addToWritebuffer for MQTT_Server_* without FD

Begonnen von fhemxperte, 13 Dezember 2021, 17:56:02

Vorheriges Thema - Nächstes Thema

fhemxperte

Hi zusammen,

ich habe ein Problem mit meiner INSTAR 9008 Kamera (aktuelle Firmware 4.1.2.48 und WebUI 3.2) und dem MQTT2_Server auf FHEM (allerneueste Version). Sobald ich die Kamera mit den korrekten Verbindungsdaten (Copy / Paste) gegen den Server verbinden lasse, bekomme ich viele der folgenden Fehlermeldungen im Fhem Log (4 andere Geräte sind bereits verbunden - 2xValetudo und 2xTasmota). Der Fehler tritt auch auf, wenn ich einen blank Server auf bspw. Port 2883 starte und die Kamera gegen diesen verbinden lasse.

Gesucht habe ich bereits eine Menge im Internet, aber meistens waren die Fehlermeldungen immer ein wenig anders als meine:


Fehlermeldungen:
2021.12.13 17:46:47 1: FD closed in  TcpServer_Close:116 MQTT2_SERVER_Undef:3895 CallFn:2300 CommandDelete:809
2021.12.13 17:46:47 1: ERROR: addToWritebuffer for MQTT_Server_Test_192.168.80.67_45879 without FD
2021.12.13 17:46:47 1: callstack: addToWritebuffer:243 MQTT2_SERVER_out:412 MQTT2_SERVER_Read:463 __ANON__:3427 HandleTimeout:695
2021.12.13 17:46:47 1: FD closed in  TcpServer_Close:116 MQTT2_SERVER_Undef:3895 CallFn:2300 CommandDelete:809
2021.12.13 17:46:47 1: ERROR: addToWritebuffer for MQTT_Server_Test_192.168.80.67_45879 without FD
2021.12.13 17:46:47 1: callstack: addToWritebuffer:243 MQTT2_SERVER_out:412 MQTT2_SERVER_Read:463 __ANON__:3427 HandleTimeout:695
2021.12.13 17:46:47 1: FD closed in  TcpServer_Close:116 MQTT2_SERVER_Undef:3895 CallFn:2300 CommandDelete:809
2021.12.13 17:46:53 1: ERROR: addToWritebuffer for MQTT_Server_Test_192.168.80.67_45880 without FD
2021.12.13 17:46:53 1: callstack: addToWritebuffer:243 MQTT2_SERVER_out:412 MQTT2_SERVER_Read:463 __ANON__:3427 HandleTimeout:695
2021.12.13 17:46:53 1: FD closed in  TcpServer_Close:116 MQTT2_SERVER_Undef:3895 CallFn:2300 CommandDelete:809
2021.12.13 17:46:53 1: ERROR: addToWritebuffer for MQTT_Server_Test_192.168.80.67_45880 without FD
2021.12.13 17:46:53 1: callstack: addToWritebuffer:243 MQTT2_SERVER_out:412 MQTT2_SERVER_Read:463 __ANON__:3427 HandleTimeout:695
2021.12.13 17:46:53 1: FD closed in  TcpServer_Close:116 MQTT2_SERVER_Undef:3895 CallFn:2300 CommandDelete:809



Meine Definition des Gerätes sieht folgermaßen aus (ohne den verbose Eintrag - da wieder zurückgedreht):
defmod MQTT_Server MQTT2_SERVER 1883 global
attr MQTT_Server DbLogExclude .*
attr MQTT_Server autocreate no
attr MQTT_Server group Server
attr MQTT_Server icon mqtt
attr MQTT_Server room 7_X_Hardware->7_5_MQTT



Ich habe den Server einmal auf verbose 5 gestellt und das Log angehangen  (user und password habe ich replaced). Eventuell weiß hier jemand mehr. Den Source Code habe ich mir auch angeguckt, aber da ich mich mit dem Modul kein bisschen auskenne, dachte ich, dass ich euch einfach mal frage.


Viel Grüße,
Micha

rudolfkoenig

Die Kamera abonniert (SUBSCRIBE) als erstes knapp 1700 MQTT Topics, vmtl. sind das die moeglichen Konfigurationsparameter. Ich finde diese Anzahl etwas uebertrieben, immerhin kann man daraus ableiten, was man alles setzen koennte, wenn man den Wertebereich kennt.

Danach meldet sie die Netzwerkkonfiguration (ca 20-mal PUBLISH), und dann schliesst sie die Verbindung.
Offensichtlich wartet sie die PUBACKs auf die PUBLISH nicht ab (sehr unhoeflich), so dass diese auf taube Ohren fallen, vulgo die gezeigten Fehlermeldungen generieren. Ich habe den Server geaendert, um die Fehlermeldungen zu vermeiden, das duerfte aber an dem eigentlichen Problem nichts aendern.

Moegliche Ursachen:
- die Kamera erwartet irgendwelche Anweisungen via MQTT, wenn sie nicht kommen, dann wird die Verbindung geschlossen.
- die Kamera ist beleidigt, weil der MQTT2_SERVER kein QOS2 anbietet. Etwas merkwuerdig, dass sie erst nach 1700 Antworten beleidigt wird.

Funktioniert die Kamera mit mosquitto?

fhemxperte

Anhand der Logdaten dachte ich mir schon, dass da einiges abgeht. Leider lässt sich bei der Kamera nichts weiteres bzgl. MQTT einstellen.


Ob Mosquitto mit der Kamera klar kommt, werde ich gleich testen und gebe dann Feedback (laut offizieller Website sollte sie es https://wiki.instar.com/de/Web_User_Interface/1080p_Serie/Netzwerk/MQTT/).


Ich konnte noch etwas MQTT Log von der Kamera extrahieren:
2021-12-13 17:46:40: [Error] Missing 'set' obj, topic: features/nightvision/currentbrightness
2021-12-13 17:46:40: [Info] Config: Version 2
2021-12-13 17:46:40: [Info] Config: Units loaded: 282
2021-12-13 17:46:40: [Info] Config: Memory required: 40749
2021-12-13 17:46:40: [Warning] A file at /mnt/mtd/ipc/tmpfs/restricted/mqttfifi already exists and will be deleted.
2021-12-13 17:46:40: [Info] Authenticate with Mqtt-Broker
2021-12-13 17:46:40: [Info] Connect to Mqtt-Broker 192.168.80.44 on port 1883...
2021-12-13 17:46:40: [Info] Synchronize Cgi-Server with Mqtt-Broker
2021-12-13 17:46:40: [Info] Mqtt listen thread has been started.
2021-12-13 17:46:40: [Info] Synchronize Cgi-Server with Mqtt-Broker
2021-12-13 17:46:40: [Error] Broker was disconnected unexpectedly!
2021-12-13 17:46:40: [Error] Session::listen: Protocol error
2021-12-13 17:46:41: [Info] Adapter connected!
2021-12-13 17:46:46: [Error] Broker was disconnected unexpectedly!
2021-12-13 17:46:46: [Error] Session::listen: Protocol error
2021-12-13 17:46:46: [Error] Failed to subscribe to topics: Session::subscribe: no connection.
2021-12-13 17:46:51: [Info] Retry...
2021-12-13 17:46:51: [Error] Failed to subscribe to topics: Session::subscribe: no connection.
2021-12-13 17:46:52: [Error] Broker was disconnected unexpectedly!
2021-12-13 17:46:52: [Error] Session::listen: Protocol error
2021-12-13 17:46:52: [Error] Failed to subscribe to topics: Session::subscribe: no connection.

fhemxperte

Die Connection mit Mosquitto funktioniert einwandfrei (einziger Unterschied ist: zwecks Testing habe ich keine Authentifizierung eingerichtet).

Wäre natürlich ein Workaround, da ich gerne den MQTT2_SERVER nutzen wollen würde.

Log der Kamera mit Mosquitto:
2021-12-13 19:34:7: [Error] Missing 'set' obj, topic: features/nightvision/currentbrightness
2021-12-13 19:34:7: [Info] Config: Version 2
2021-12-13 19:34:7: [Info] Config: Units loaded: 282
2021-12-13 19:34:7: [Info] Config: Memory required: 40749
2021-12-13 19:34:7: [Warning] A file at /mnt/mtd/ipc/tmpfs/restricted/mqttfifi already exists and will be deleted.
2021-12-13 19:34:7: [Info] Connect to Mqtt-Broker 192.168.80.44 on port 1884...
2021-12-13 19:34:7: [Info] Synchronize Cgi-Server with Mqtt-Broker
2021-12-13 19:34:7: [Info] Mqtt listen thread has been started.
2021-12-13 19:34:7: [Info] Synchronize Cgi-Server with Mqtt-Broker
2021-12-13 19:34:8: [Info] Adapter connected!


Log von Mosquitto (verbose) ist im Anhang.

rudolfkoenig

Womoeglich kann man den Instar Support fragen, ob sie eine detailliertere Begruendung des Verbindungabbaus liefern koennten.
Lustigerweise sagen z.Zt. beide Seiten, dass die andere Seite angefangen hat :)

INSTAR

> Womoeglich kann man den Instar Support fragen

Falls ich hier gepingt wurde ist die Benachrichtigung leider nicht durchgekommen  ;)

Wir sind gerade ein ähnliches Problem angegangen - der MQTT Client der Kamera bricht nach kurzer Zeit die Verbindung zum MQTT Broker in ioBroker ab. Dort war das Problem - die Kamera lief, wenn man den MQTT Client nutzte, im QoS2 Modus. Das mochte der dortige Broker nicht.


Ich habe gerade einen Blick in die Docs des MQTT2_SERVER geworfen - hier steht ja auch, dass nur QoS0 und 1 unterstützt werden. Ich denke daher - das wird das gleiche Problem sein.


Ich bin gerade dabei eine neue Firmware zu testen in der man den Client Modus von 0-2 frei einstellen kann. Bei ioBroker läuft das jetzt schon seit 2 Tagen stabil mit QoS1.
INSTAR Deutschland GmbH
IP Kameras und Netzwerktechnik