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.