Verbindungsabbruch zum MQTT Broker bei Topic

[sippldan]

Ich habe meine IN-9008-POE mit der Version [v4.1.2.48 // 3.3(372)] mit einem externen MQTT Broker verbunden. Mein externen Broker ist ein EMQX-MQTT in der MQTT-Version 5.0.
Die Verbindungseinstellung der Kamera sind:

Im Broker ist eine Auto-Subscription zur Topic [$SYS/brokers/vServerEMQX@127.0.0.1/datetime] aktiv, da diese zur Uhrzeitsynchronisation verwendet wird.
Diese Topic wird allen Clients automatisch vom Broker zugewiesen.
Sobald diese Topic mit Payload verteilt wird (publish) so beendet die Kamera die Verbindung zum Broker sofort und baut selbstständig keine Verbindung mehr auf.

2023-07-24T09:11:42.539641+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 876, peername: xxx.xxx.xxx.xxx:54715, clientid: bw3-einfahrt, packet: PUBLISH(Q0, R0, D0, **Topic=$SYS/brokers/vServerEMQX@127.0.0.1/datetime**, PacketId=undefined, **Payload=2023-07-24T09:11:42.538793659+00:00**), tag: MQTT
2023-07-24T09:11:42.563851+00:00 [info] msg: authorization_permission_allowed, mfa: emqx_authz:log_allowed/1, line: 431, peername: xxx.xxx.xxx.xxx:54715, clientid: bw3-einfahrt, topic: bw3/camera/bw3-einfahrt/status/connection, ipaddr: {172,30,32,200}, source: file, username: <<"instar">>
2023-07-24T09:11:42.564138+00:00 [debug] msg: publish_to, mfa: emqx_trace:publish/1, line: 73, peername: xxx.xxx.xxx.xxx:54715, clientid: bw3-einfahrt, topic: bw3/camera/bw3-einfahrt/status/connection, payload: {"val":"offline"}, tag: PUBLISH
2023-07-24T09:11:42.564615+00:00 [debug] msg: mqtt_packet_sent, mfa: emqx_connection:serialize_and_inc_stats_fun/1, line: 876, peername: xxx.xxx.xxx.xxx:50637, clientid: mqtt-explorer-5339aacc, packet: PUBLISH(Q0, R0, D0, Topic=bw3/camera/bw3-einfahrt/status/connection, PacketId=undefined, **Payload={"val":"offline"}**), tag: MQTT
2023-07-24T09:11:42.564747+00:00 [warning] msg: alarm_is_deactivated, mfa: emqx_alarm:do_actions/3, line: 424, name: <<"conn_congestion/bw3-einfahrt/instar">>
2023-07-24T09:11:42.564978+00:00 [debug] msg: emqx_connection_terminated, mfa: emqx_connection:terminate/2, line: 667, peername: xxx.xxx.xxx.xxx:54715, clientid: bw3-einfahrt, reason: {shutdown,tcp_closed}, tag: SOCKET
2023-07-24T09:11:42.565142+00:00 [info] msg: terminate, mfa: emqx_connection:terminate/2, line: 672, peername: xxx.xxx.xxx.xxx:54715, clientid: bw3-einfahrt, reason: {shutdown,tcp_closed}
2023-07-24T09:11:42.565389+00:00 [debug] msg: emqx_cm_clean_down, mfa: emqx_cm:clean_down/1, line: 738, client_id: <<"bw3-einfahrt">>

Im Kameralog ist zu entnehmen:

2023-7-24 13:48:47: [Error] Missing 'set' obj, topic: features/nightvision/currentbrightness
2023-7-24 13:48:47: [Info] Config: Version 2
2023-7-24 13:48:47: [Info] Config: Units loaded: 282
2023-7-24 13:48:47: [Info] Config: Memory required: 40742
2023-7-24 13:48:47: [Warning] A file at /mnt/mtd/ipc/tmpfs/restricted/mqttfifi already exists and will be deleted.
2023-7-24 13:48:47: [Info] Authenticate with Mqtt-Broker
2023-7-24 13:48:47: [Info] Connect to Mqtt-Broker xxx.xxx.xxx.xxx on port 1883...
2023-7-24 13:48:47: [Info] Synchronize Cgi-Server with Mqtt-Broker
2023-7-24 13:48:47: [Info] Mqtt listen thread has been started.
2023-7-24 13:48:47: [Info] Synchronize Cgi-Server with Mqtt-Broker
2023-7-24 13:48:48: [Info] Adapter connected!

dort ist kein Verbindungsabbruch zu erkennen.
[Bitte die Datums / Uhrzeitangaben ignorieren]

Ich habe testweise die automatische Topic-Subscription deaktiviert, danach ist dieser Verbindungsabbruch nicht mehr aufgetreten.
Ich vermute, dass in der Kamera unbekannte Topics ignoriert werden sollten.

[INSTAR]

Hallo,

@sippldan

[$SYS/brokers/vServerEMQX@127.0.0.1/datetime] aktiv, da diese zur Uhrzeitsynchronisation verwendet wird.

Ich habe gerade einmal eine Full HD und WQHD Kamera mit einem EMQX Broker verbunden.

Wenn ich genau dieses Topic mit dem entsprechenden Payload aktualisiere bleiben beide Kameras verbunden:

MQTT Explorer

Interner WS Client

Das Problem kann ich nicht nachstellen.

@sippldan

Im Kameralog ist zu entnehmen:

Das Kameralog ist nur für den internen Broker. D.h. wenn man auf den externen Broker umstellt, werden hier keine weiteren Einträge hinzukommen.

[sippldan]

Danke für die Info.
Bitte versuchen Sie das Topic mit Wildcard folgend im EMQX unter „Auto Subscribe“ für alle hinzu zu fügen.
$SYS/brokers/+/datetime

Ich habe nach dem Hinzufügen des Auto-Subscribe die Kamera über den EMQX einmal „gekickt“ um die Verbindung neu aufbauen zu lassen.
Bei der nächsten Aktualisierung des $SYS-Topics wurde die Verbindung zur Kamera sofort unterbrochen. Das Topic wird vom Server automatisch alle 30 Sekunden „published“.

Hier ein Mitschnitt aus dem Wireshark, den ich über den non-SSL Port 1883 mitgeschnitten habe.
172.30.32.5 ist der EMQX-Server
172.30.32.200 ist die Kamera

[INSTAR]

@sippldan

Bitte versuchen Sie das Topic mit Wildcard folgend im EMQX unter „Auto Subscribe“ für alle hinzu zu fügen.

Habe ich gerade mal gemacht - ich hatte kurz gesehen, dass die WQHD Kamera sich mehrfach neu verbunden hat. Zumindest laut der Klienten Übersicht im Broker. Nach dem Starten des MQTT Clients auf der Kamera sehe ich keine Verbindungsabbrüche mehr. Ich behalte das gerade im Auge. Aber läuft jetzt schon seit über einer halben Stunde stabil.

Nach dem Hinzufügen der Subscription sehe ich, dass das Topic reinkommt. Der Kamera Client gibt eine Fehlermeldung - er kann nichts mit dem Topic anfangen. Der Client bricht die Verbindung jedoch nicht ab.

Wildcard Subscription

Wildcard Subscription

Kamera Client Log

Client Liste

Keine Verbindungsabbrüche:

EDIT: Die EMQX Version ist v5.1.2 und wurde mit Docker installiert.

docker pull emqx/emqx:latest
docker run -d -v /opt/emqx/data:/opt/emqx/data --name emqx -p 1883:1883 -p 8083:8083 -p 8084:8084 -p 8883:8883 -p 18083:18083  emqx/emqx:latest

[sippldan]

Die EMQX Version ist v5.1.2 und wurde mit Docker installiert.

Ich habe den den container bei mir nochmals neu installiert, da bei mir die EMQX Version v5.1.1 installiert war.
Ich habe den Container mit den gleichen Kommandos wie bei Ihnen erstellt.

docker pull emqx/emqx:latest
docker run -d -v /opt/emqx/data:/opt/emqx/data --name emqx -p 1883:1883 -p 8083:8083 -p 8084:8084 -p 8883:8883 -p 18083:18083  emqx/emqx:latest

Aber auch mit dem EMQX v5.1.2 und jetzt neu EMQX v5.1.3 ist das Verhalten das Selbe.
Ich habe Testweise die Topic-Prefix und Klient-ID auf der Kamera wie bei Ihnen eingestellt.

Leider habe ich dennoch Verbindungsabbrüche.

Ich weiß nicht, wie ich den Fehler besser eingrenzen könnte.
Sobald ich das Topic aktiviere und die Kamera Neustarte / oder neu verbinde, bricht nach dem Publish des Topics die Verbindung ab. Die Wireshark-Aufzeichnung belegt dieses Verhalten.

-Leider kann ich nur ein Medienobjekt hochladen-

Was kann ich tun, damit Sie den Fehler bei ihnen besser eingrenzen können?
Kann ich irgendwelche Logs auf der Kamera aktivieren, die ihnen die Diagnose leichter machen?
Ich würde so gerne den Bug finden.

[INSTAR]

@sippldan

2023-07-24T09:11:42.564978+00:00 [debug] msg: emqx_connection_terminated, mfa: emqx_connection:terminate/2, line: 667, peername: xxx.xxx.xxx.xxx:54715, clientid: bw3-einfahrt, reason: {shutdown,tcp_closed}, tag: SOCKET
2023-07-24T09:11:42.565142+00:00 [info] msg: terminate, mfa: emqx_connection:terminate/2, line: 672, peername: xxx.xxx.xxx.xxx:54715, clientid: bw3-einfahrt, reason: {shutdown,tcp_closed}

Ich habe ein Problem gefunden - nach einigen rumprobieren hatte ich es geschafft, dass die verundenen Kameras die Verbindung verloren. Allerdings sehe ich eine andere Fehlermeldung im EMQX Broker Log:

2023-07-28T10:31:16.618689+00:00 [warning] msg: pubrel_packetId_not_found, mfa: emqx_channel:handle_in/2, line: 458, peername: 192.168.2.120:33324, clientid: 120, packetId: 58134
2023-07-28T10:31:19.150531+00:00 [error] supervisor: ‚esockd_connection_sup - <0.2610.0>‘, errorContext: connection_shutdown, reason: #{max => 1000,reason => message_queue_too_long,value => 2092}, offender: [{pid,<0.1610.2>},{name,connection},{mfargs,{emqx_connection,start_link,[#{enable_authn => true,limiter => undefined,listener => {tcp,default},zone => default}]}}]

Dazu pubrel_packetId_not_found hatte ich hier auf Github gefunden:

The PUBREL PacketId 3773 is not found

Dort wird leider nicht gesagt worauf man max_awaiting_rel stellen soll. Default ist 0 also unbegrenzt.

Bei den WQHD Kameras kann man den QoS Wert einstellen - nachdem ich ich von 2 auf 1 gewechselt hatte war diese pubrel_packetId_not_found Fehlermeldung verschunden.

In den Einstellungen kann man unter Management/MQTT Settings/Session/Max Awaiting PUBREL festlegen auf wieviele QoS2 Meldungen der Broker warten soll. Denke das man QoS2 damit auch für die Full HD Kameras zum laufen bekommen kann (da hier fest QoS2 verwendet wird vom MQTT Client).

Aber message_queue_too_long tauchte immer noch auf. Hierzu gibt es ein weiteres Issue:

message_queue_too_long crashes the broker

Dafür hatte ich unter Management/MQTT Settings/Session die Max Message Queue Length einmal auf 10.000 gestellt. Aber diese Fehlermeldung bleibt leider erhalten.

Denke dieses Problem tritt nur auf wenn die Kamera sich neuverbindet und alle Ihre retained Topics gleichzeitig aktualisiert. Wenn das System sich da einmal reingeschaukelt hat hilft es nur noch den MQTT Client auf der Kamera neuzustarten.

D.h. man müsste diese Max. Queue length irgendwo einstellen können. Aber dazu habe ich nicht weiteres gefunden.

Dieses Problem ist übrigens unabhängig von dem $SYS datetime Topic.

[sippldan]

Ich habe jetzt lange rumprobiert und eingestellt.

Gestern habe ich die Kamera 9408 2K auf Version 1.5.3 [+608] und WebUI: 1.5.0 [+608] aktualisiert.

Im EMQX habe ich auch die Message queue von den „Default: 1000“ auf 8000 gestellt.
Danach tauchte der Fehler immer noch auf, jedoch waren jetzt auch über 8000 Messages im queue.

Man kann im Docker über die ENV-Variablen die config beeinflussen. Dazu muss man nur die entsprechende Einstellung als env mitgeben: Also z.B.: so:

Man beachte den doppelten Unterstrich.
EMQX - Configuration from environment variable

Wie zu sehen habe ich auch den Verbindungsabbruch durch EMQX beim Überlauf der queue deaktiviert.
FORCE_SHUTDOWN.ENABLE = false
Nun wird der Fehler im EMQX-Log nicht mehr ausgegeben.

Die Verbindung zwischen Kamera und MQTT Server werden teilweise mehrmals (bis zu 8x pro Minute) neu aufgebaut. Ein stabiler Betrieb ist hier nicht möglich.

Mit ist auch aufgefallen, dass die Kamera nach dem Verbindungsaufbau Topics aktualisiert, welche keine Änderungen haben. Ich habe so in ca. 10 Minuten mehr als 5000 Aktualisierungen bei 308 Topics?!
zB:
=> /status/multimedia/image/day/blacklevel/value in 30 Sekunden 8 Messages mit selbem Payload
=> /status/multimedia/privacy/region3 in 1 Minute in 9 Topics 111 Messages mit keiner Änderung der Payload

Die Verbindung ist in 5 Minuten 10x abgebrochen.

Die Kamera subscribed auch im übergeordneten Topic jede Menge Topics.
Zum Beispiel: => all/alarm/actions/alarminmode/raw
vielleicht sollte dies irgendwo in der Dokumentation besser heraus gehoben werden.

Zur Info: Meine „alte“ Instar 9008HD hat in der selben Zeit nicht einen Verbindungsabbruch und es wurde nicht 1 weiterer Payload von der 9008HD gesendet.
Die Topic „status/connection“ ist bei der 9008HD übrigens als „Retained“ gekennzeichnet, im Gegensatz der „Last Will“ der 94082K.

[INSTAR]

@sippldan

=> /status/multimedia/image/day/blacklevel/value in 30 Sekunden 8 Messages mit selbem Payload
=> /status/multimedia/privacy/region3 in 1 Minute in 9 Topics 111 Messages mit keiner Änderung der Payload

Die Topics werden jedes mal aktualisiert, wenn das CGI Interface genutzt wird. Wenn man z.B. in einem Menü in der Weboberfläche auf Speichern drückt werden eine ganze Reihe von CGIs abgesendet was auch einiges an Updates beim MQTT zur Folge hat.

@sippldan

Mit ist auch aufgefallen, dass die Kamera nach dem Verbindungsaufbau Topics aktualisiert

Wenn der Dienst neugestartet wird fragt die Kamera intern erstmal alle ihre Zustände ab und aktualisiert danach alle MQTT Topics. D.h. wenn der Dienst aus irgendeinem Grund im Intervall neustarten sollte, bekäme man eine recht große Last durch die ständigen Updates rein. Bei einem Verbindungsabbruch zum Broker (der kamera Client läuft durch) sollte das nicht passieren. Es sei denn der Broker verwirft nach dem Abbruch alle Einträge und die Kamera muß sie entsprechend neu anlegen.

Sieht man denn anhand des LWTs, dass die Kamera wirklich offline geht - also z.B. der MQTT neugestartet wird? Wenn das LWT sofort auf offline spring wird der Client heruntergefahren. Wenn hingegen der Broker die Verbindung abbricht, oder das Netzwerk unterbrochen wird, würde das LWT erst nach einer Zeitüberschreitung von online auf offline springen.

@sippldan

Die Kamera subscribed auch im übergeordneten Topic jede Menge Topics.

INSTAR MQTT Server für INSTAR Full HD IP Kameras – INSTAR Wiki