mqtt bug

[piwo2]

--init-file

{
    "pre_connect": {
        "tinkerforge/register/ip_connection/connected": {"register": true},
        "tinkerforge/register/ip_connection/disconnected": {"register": true},
        "tinkerforge/register/ip_connection/enumerate": {"register": true}
    },
    "post_connect": {
        "tinkerforge/request/ip_connection/enumerate": "",
        "tinkerforge/request/temperature_bricklet/siX/set_temperature_callback_period": {"period":10000},
        "tinkerforge/register/temperature_bricklet/siX/temperature": {"register": true}
    }
}

SZENARIO1 : start tinkerforge_mqtt, start mosquitto, stop mosquitto, wait, start mosquitto

!!! beim wieder-connecten zum mqtt-broker wird die enumeration NICHT durchgeführt (die befehle f.d. temperature-bricklets aber DOCH !!!

mosquitto log

[rotten@vlap ~]$ mosquitto -v 2>&1 | awk '(($3~"^PUB")||($3~"^SUB")){print;i=1;next}(i>0){i=0;print}'
1608665630: Received SUBSCRIBE from auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34
1608665630: 	tinkerforge/request/# (QoS 0)
1608665630: Sending SUBACK to auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34
1608665630: Received SUBSCRIBE from auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34
1608665630: 	tinkerforge/register/# (QoS 0)
1608665630: Sending SUBACK to auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34
1608665630: Received PUBLISH from auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34 (d0, q0, r0, m0, 'tinkerforge/callback/bindings/restart', ... (4 bytes))
1608665630: Received SUBSCRIBE from auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34
1608665630: 	tinkerforge/callback/bindings/restart (QoS 0)
1608665630: Sending SUBACK to auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34
1608665630: Received PUBLISH from auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/connected', ... (29 bytes))
1608665630: Received PUBLISH from auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/enumerate', ... (215 bytes))
1608665630: Received PUBLISH from auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/enumerate', ... (215 bytes))
1608665630: Received PUBLISH from auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/enumerate', ... (226 bytes))
1608665630: Received PUBLISH from auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/enumerate', ... (239 bytes))
1608665630: Received PUBLISH from auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/enumerate', ... (233 bytes))
1608665630: Received PUBLISH from auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/enumerate', ... (250 bytes))
1608665634: Received PUBLISH from auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34 (d0, q0, r0, m0, 'tinkerforge/callback/temperature_bricklet/siX/temperature', ... (21 bytes))
1608665655: Received PUBLISH from auto-2EDD88C3-26B4-DD9D-C98C-BEE87E941B34 (d0, q0, r0, m0, 'tinkerforge/callback/temperature_bricklet/siX/temperature', ... (21 bytes))
^C
[rotten@vlap ~]$ # ... wait some time
[rotten@vlap ~]$ 
[rotten@vlap ~]$ mosquitto -v 2>&1 | awk '(($3~"^PUB")||($3~"^SUB")){print;i=1;next}(i>0){i=0;print}'
1608665696: Received SUBSCRIBE from auto-B61BF8CE-693C-6675-FC0E-FA85790E2877
1608665696: 	tinkerforge/request/# (QoS 0)
1608665696: Sending SUBACK to auto-B61BF8CE-693C-6675-FC0E-FA85790E2877
1608665696: Received SUBSCRIBE from auto-B61BF8CE-693C-6675-FC0E-FA85790E2877
1608665696: 	tinkerforge/register/# (QoS 0)
1608665696: Sending SUBACK to auto-B61BF8CE-693C-6675-FC0E-FA85790E2877
1608665696: Received SUBSCRIBE from auto-B61BF8CE-693C-6675-FC0E-FA85790E2877
1608665696: 	tinkerforge/callback/bindings/restart (QoS 0)
1608665696: Sending SUBACK to auto-B61BF8CE-693C-6675-FC0E-FA85790E2877
1608665709: Received PUBLISH from auto-B61BF8CE-693C-6675-FC0E-FA85790E2877 (d0, q0, r0, m0, 'tinkerforge/callback/temperature_bricklet/siX/temperature', ... (21 bytes))
1608665718: Received PUBLISH from auto-B61BF8CE-693C-6675-FC0E-FA85790E2877 (d0, q0, r0, m0, 'tinkerforge/callback/temperature_bricklet/siX/temperature', ... (21 bytes))
1608665732: Received PUBLISH from auto-B61BF8CE-693C-6675-FC0E-FA85790E2877 (d0, q0, r0, m0, 'tinkerforge/callback/temperature_bricklet/siX/temperature', ... (21 bytes))
1608665733: Received PUBLISH from auto-B61BF8CE-693C-6675-FC0E-FA85790E2877 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/disconnected', ... (32 bytes))
1608665733: Received PUBLISH from auto-B61BF8CE-693C-6675-FC0E-FA85790E2877 (d0, q0, r0, m0, 'tinkerforge/callback/bindings/shutdown', ... (4 bytes))
1608665733: Received DISCONNECT from auto-B61BF8CE-693C-6675-FC0E-FA85790E2877
^C
[rotten@vlap ~]$ 

tinkerforge_mqtt log

[rotten@vlap-wp tf]$ tinkerforge_mqtt --init-file tf-std.json --ipcon-port 44445 --debug
2020-12-22 20:33:35,015 <INFO> MQTT bindings: Starting Tinkerforge MQTT bindings 2.0.12
2020-12-22 20:33:35,015 <DEBUG> MQTT bindings: Configuring connection to MQTT broker at localhost:1883
2020-12-22 20:33:35,015 <DEBUG> MQTT bindings: Connected to MQTT broker at localhost:1883
2020-12-22 20:33:35,017 <INFO> MQTT bindings: Could not connect to MQTT Broker. Will retry.
2020-12-22 20:33:35,018 <DEBUG> paho.mqtt.client: Connection failed, retrying
2020-12-22 20:33:38,022 <INFO> MQTT bindings: Could not connect to MQTT Broker. Will retry.
2020-12-22 20:33:38,023 <DEBUG> paho.mqtt.client: Connection failed, retrying
2020-12-22 20:33:42,026 <INFO> MQTT bindings: Could not connect to MQTT Broker. Will retry.
2020-12-22 20:33:42,026 <DEBUG> paho.mqtt.client: Connection failed, retrying
2020-12-22 20:33:50,029 <DEBUG> paho.mqtt.client: Sending CONNECT (u0, p0, wr0, wq0, wf1, c1, k60) client_id=b''
2020-12-22 20:33:50,029 <DEBUG> paho.mqtt.client: Received CONNACK (0, 0)
2020-12-22 20:33:50,029 <DEBUG> MQTT bindings: Connected to mqtt broker.
2020-12-22 20:33:50,029 <DEBUG> paho.mqtt.client: Sending SUBSCRIBE (d0, m1) [(b'tinkerforge/request/#', 0)]
2020-12-22 20:33:50,030 <DEBUG> paho.mqtt.client: Sending SUBSCRIBE (d0, m2) [(b'tinkerforge/register/#', 0)]
2020-12-22 20:33:50,030 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m3), 'b'tinkerforge/callback/bindings/restart'', ... (4 bytes)
2020-12-22 20:33:50,030 <DEBUG> paho.mqtt.client: Sending SUBSCRIBE (d0, m4) [(b'tinkerforge/callback/bindings/restart', 0)]
2020-12-22 20:33:50,030 <DEBUG> MQTT bindings: 

2020-12-22 20:33:50,031 <DEBUG> MQTT bindings: Registered ip connection callback 0 under topic tinkerforge/callback/ip_connection/connected.
2020-12-22 20:33:50,031 <DEBUG> MQTT bindings: 

2020-12-22 20:33:50,031 <DEBUG> MQTT bindings: Registered ip connection callback 1 under topic tinkerforge/callback/ip_connection/disconnected.
2020-12-22 20:33:50,031 <DEBUG> MQTT bindings: 

2020-12-22 20:33:50,031 <DEBUG> paho.mqtt.client: Received SUBACK
2020-12-22 20:33:50,031 <DEBUG> MQTT bindings: Registered ip connection callback 253 under topic tinkerforge/callback/ip_connection/enumerate.
2020-12-22 20:33:50,032 <DEBUG> paho.mqtt.client: Received SUBACK
2020-12-22 20:33:50,032 <DEBUG> MQTT bindings: Connecting to brickd at localhost:44445
2020-12-22 20:33:50,032 <DEBUG> paho.mqtt.client: Received SUBACK
2020-12-22 20:33:50,034 <DEBUG> MQTT bindings: Connected to Brick Daemon: Connection established after request from user.
2020-12-22 20:33:50,034 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m5), 'b'tinkerforge/callback/ip_connection/connected'', ... (29 bytes)
2020-12-22 20:33:50,034 <DEBUG> MQTT bindings: Connected to brickd at localhost:44445
2020-12-22 20:33:50,035 <DEBUG> MQTT bindings: 

2020-12-22 20:33:50,035 <DEBUG> MQTT bindings: Enumerating devices.
2020-12-22 20:33:50,035 <DEBUG> MQTT bindings: 

2020-12-22 20:33:50,035 <DEBUG> MQTT bindings: Calling function set_temperature_callback_period for device siX of type temperature_bricklet.
2020-12-22 20:33:50,113 <DEBUG> MQTT bindings: Device connected: 2GYM6W at 0 (Pos 0), Hardware: 1.0.0, Firmware: 2.0.3, Dev ID: 17
2020-12-22 20:33:50,113 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m6), 'b'tinkerforge/callback/ip_connection/enumerate'', ... (215 bytes)
2020-12-22 20:33:50,197 <DEBUG> MQTT bindings: Device available: 2GYM6W at 0 (Pos 0), Hardware: 1.0.0, Firmware: 2.0.3, Dev ID: 17
2020-12-22 20:33:50,198 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m7), 'b'tinkerforge/callback/ip_connection/enumerate'', ... (215 bytes)
2020-12-22 20:33:50,199 <DEBUG> MQTT bindings: Device available: 6CPXd6 at 2GYM6W (Pos 1), Hardware: 1.0.0, Firmware: 2.4.9, Dev ID: 13
2020-12-22 20:33:50,200 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m8), 'b'tinkerforge/callback/ip_connection/enumerate'', ... (226 bytes)
2020-12-22 20:33:50,200 <DEBUG> MQTT bindings: Device available: siX at 6CPXd6 (Pos b), Hardware: 1.1.0, Firmware: 2.0.4, Dev ID: 216
2020-12-22 20:33:50,201 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m9), 'b'tinkerforge/callback/ip_connection/enumerate'', ... (239 bytes)
2020-12-22 20:33:50,202 <DEBUG> MQTT bindings: Device available: qRa at 6CPXd6 (Pos d), Hardware: 1.1.0, Firmware: 2.0.2, Dev ID: 27
2020-12-22 20:33:50,202 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m10), 'b'tinkerforge/callback/ip_connection/enumerate'', ... (233 bytes)
2020-12-22 20:33:50,203 <DEBUG> MQTT bindings: Device available: EBH at 6CPXd6 (Pos a), Hardware: 1.0.0, Firmware: 2.0.3, Dev ID: 289
2020-12-22 20:33:50,203 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m11), 'b'tinkerforge/callback/ip_connection/enumerate'', ... (250 bytes)
2020-12-22 20:33:50,235 <DEBUG> MQTT bindings: Calling function set_temperature_callback_period for device siX of type temperature_bricklet succedded.
2020-12-22 20:33:50,235 <DEBUG> MQTT bindings: 

2020-12-22 20:33:50,235 <DEBUG> MQTT bindings: Registered callback temperature for device siX of type temperature_bricklet. Will publish messages to tinkerforge/callback/temperature_bricklet/siX/temperature.
2020-12-22 20:33:54,045 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m12), 'b'tinkerforge/callback/temperature_bricklet/siX/temperature'', ... (21 bytes)
2020-12-22 20:34:15,549 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m13), 'b'tinkerforge/callback/temperature_bricklet/siX/temperature'', ... (21 bytes)
2020-12-22 20:34:26,069 <INFO> MQTT bindings: Could not connect to MQTT Broker. Will retry.
2020-12-22 20:34:26,069 <DEBUG> paho.mqtt.client: Connection failed, retrying
2020-12-22 20:34:28,073 <INFO> MQTT bindings: Could not connect to MQTT Broker. Will retry.
2020-12-22 20:34:28,074 <DEBUG> paho.mqtt.client: Connection failed, retrying
2020-12-22 20:34:32,077 <INFO> MQTT bindings: Could not connect to MQTT Broker. Will retry.
2020-12-22 20:34:32,078 <DEBUG> paho.mqtt.client: Connection failed, retrying
2020-12-22 20:34:40,081 <INFO> MQTT bindings: Could not connect to MQTT Broker. Will retry.
2020-12-22 20:34:40,082 <DEBUG> paho.mqtt.client: Connection failed, retrying
2020-12-22 20:34:56,086 <DEBUG> paho.mqtt.client: Sending CONNECT (u0, p0, wr0, wq0, wf1, c1, k60) client_id=b''
2020-12-22 20:34:56,087 <DEBUG> paho.mqtt.client: Received CONNACK (0, 0)
2020-12-22 20:34:56,087 <DEBUG> MQTT bindings: Connected to mqtt broker.
2020-12-22 20:34:56,087 <DEBUG> paho.mqtt.client: Sending SUBSCRIBE (d0, m17) [(b'tinkerforge/request/#', 0)]
2020-12-22 20:34:56,088 <DEBUG> paho.mqtt.client: Sending SUBSCRIBE (d0, m18) [(b'tinkerforge/register/#', 0)]
2020-12-22 20:34:56,088 <DEBUG> paho.mqtt.client: Sending SUBSCRIBE (d0, m19) [(b'tinkerforge/callback/bindings/restart', 0)]
2020-12-22 20:34:56,089 <DEBUG> paho.mqtt.client: Received SUBACK
2020-12-22 20:34:56,090 <DEBUG> paho.mqtt.client: Received SUBACK
2020-12-22 20:34:56,090 <DEBUG> paho.mqtt.client: Received SUBACK
2020-12-22 20:35:09,105 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m20), 'b'tinkerforge/callback/temperature_bricklet/siX/temperature'', ... (21 bytes)
2020-12-22 20:35:18,973 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m21), 'b'tinkerforge/callback/temperature_bricklet/siX/temperature'', ... (21 bytes)
2020-12-22 20:35:32,555 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m22), 'b'tinkerforge/callback/temperature_bricklet/siX/temperature'', ... (21 bytes)
^C2020-12-22 20:35:33,687 <DEBUG> MQTT bindings: Disconnecting from brickd and mqtt broker.
2020-12-22 20:35:33,788 <DEBUG> MQTT bindings: Disconnected from Brick Daemon: Disconnect was requested by user.
2020-12-22 20:35:33,789 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m23), 'b'tinkerforge/callback/ip_connection/disconnected'', ... (32 bytes)
2020-12-22 20:35:33,790 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m24), 'b'tinkerforge/callback/bindings/shutdown'', ... (4 bytes)
2020-12-22 20:35:33,791 <DEBUG> paho.mqtt.client: Sending DISCONNECT
[rotten@vlap-wp tf]$ 

 

SZENARIO2 start mosquitto, start tinkerforge_mqtt, connection zu brickd unterbrechen/wiederherstellen : 1. mal "kurz", 2.mal "lang"

beim wieder-connecten zum brickd wird die enumeration NICHT durchgeführt (die befehle f.d. temperature-bricklets aber DOCH !!!

mosquitto log

[rotten@vlap ~]$ mosquitto -v 2>&1 | awk '(($3~"^PUB")||($3~"^SUB")){print;i=1;next}(i>0){i=0;print}'
1608668265: Received SUBSCRIBE from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838
1608668265: 	tinkerforge/request/# (QoS 0)
1608668265: Sending SUBACK to auto-5B1E6410-87AF-0E4C-3787-DF2D85582838
1608668265: Received SUBSCRIBE from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838
1608668265: 	tinkerforge/register/# (QoS 0)
1608668265: Sending SUBACK to auto-5B1E6410-87AF-0E4C-3787-DF2D85582838
1608668265: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/bindings/restart', ... (4 bytes))
1608668265: Received SUBSCRIBE from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838
1608668265: 	tinkerforge/callback/bindings/restart (QoS 0)
1608668265: Sending SUBACK to auto-5B1E6410-87AF-0E4C-3787-DF2D85582838
1608668265: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/connected', ... (29 bytes))
1608668265: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/enumerate', ... (215 bytes))
1608668265: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/enumerate', ... (215 bytes))
1608668265: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/enumerate', ... (226 bytes))
1608668265: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/enumerate', ... (239 bytes))
1608668265: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/enumerate', ... (233 bytes))
1608668265: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/enumerate', ... (250 bytes))
1608668273: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/temperature_bricklet/siX/temperature', ... (21 bytes))
1608668283: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/temperature_bricklet/siX/temperature', ... (21 bytes))
1608668312: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/temperature_bricklet/siX/temperature', ... (21 bytes))
1608668315: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/disconnected', ... (33 bytes))
1608668326: Received PINGREQ from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838
1608668415: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/connected', ... (36 bytes))
1608668415: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/enumerate', ... (215 bytes))
1608668420: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/temperature_bricklet/siX/temperature', ... (21 bytes))
1608668446: Received PINGREQ from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838
1608668473: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/temperature_bricklet/siX/temperature', ... (21 bytes))
1608668483: Received PUBLISH from auto-5B1E6410-87AF-0E4C-3787-DF2D85582838 (d0, q0, r0, m0, 'tinkerforge/callback/temperature_bricklet/siX/temperature', ... (21 bytes))
^C^
[rotten@vlap ~]$ mosquitto -v 2>&1 | awk '(($3~"^PUB")||($3~"^SUB")){print;i=1;next}(i>0){i=0;print}'
1608668528: Received SUBSCRIBE from auto-789C9A36-55FE-8919-8859-89627A21EBCC
1608668528: 	tinkerforge/request/# (QoS 0)
1608668528: Sending SUBACK to auto-789C9A36-55FE-8919-8859-89627A21EBCC
1608668528: Received SUBSCRIBE from auto-789C9A36-55FE-8919-8859-89627A21EBCC
1608668528: 	tinkerforge/register/# (QoS 0)
1608668528: Sending SUBACK to auto-789C9A36-55FE-8919-8859-89627A21EBCC
1608668528: Received SUBSCRIBE from auto-789C9A36-55FE-8919-8859-89627A21EBCC
1608668528: 	tinkerforge/callback/bindings/restart (QoS 0)
1608668528: Sending SUBACK to auto-789C9A36-55FE-8919-8859-89627A21EBCC
1608668534: Received PUBLISH from auto-789C9A36-55FE-8919-8859-89627A21EBCC (d0, q0, r0, m0, 'tinkerforge/callback/temperature_bricklet/siX/temperature', ... (21 bytes))
1608668544: Received PUBLISH from auto-789C9A36-55FE-8919-8859-89627A21EBCC (d0, q0, r0, m0, 'tinkerforge/callback/temperature_bricklet/siX/temperature', ... (21 bytes))
1608668561: Received PUBLISH from auto-789C9A36-55FE-8919-8859-89627A21EBCC (d0, q0, r0, m0, 'tinkerforge/callback/ip_connection/disconnected', ... (32 bytes))
1608668561: Received PUBLISH from auto-789C9A36-55FE-8919-8859-89627A21EBCC (d0, q0, r0, m0, 'tinkerforge/callback/bindings/shutdown', ... (4 bytes))
1608668561: Received DISCONNECT from auto-789C9A36-55FE-8919-8859-89627A21EBCC
^C
[rotten@vlap ~]$ 

tinkerforge_mqtt log

[rotten@vlap-wp tf]$ tinkerforge_mqtt --init-file tf-std.json --ipcon-port 44445 --debug
2020-12-22 21:17:45,851 <INFO> MQTT bindings: Starting Tinkerforge MQTT bindings 2.0.12
2020-12-22 21:17:45,851 <DEBUG> MQTT bindings: Configuring connection to MQTT broker at localhost:1883
2020-12-22 21:17:45,851 <DEBUG> MQTT bindings: Connected to MQTT broker at localhost:1883
2020-12-22 21:17:45,854 <DEBUG> paho.mqtt.client: Sending CONNECT (u0, p0, wr0, wq0, wf1, c1, k60) client_id=b''
2020-12-22 21:17:45,854 <DEBUG> paho.mqtt.client: Received CONNACK (0, 0)
2020-12-22 21:17:45,854 <DEBUG> MQTT bindings: Connected to mqtt broker.
2020-12-22 21:17:45,854 <DEBUG> paho.mqtt.client: Sending SUBSCRIBE (d0, m1) [(b'tinkerforge/request/#', 0)]
2020-12-22 21:17:45,854 <DEBUG> paho.mqtt.client: Sending SUBSCRIBE (d0, m2) [(b'tinkerforge/register/#', 0)]
2020-12-22 21:17:45,855 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m3), 'b'tinkerforge/callback/bindings/restart'', ... (4 bytes)
2020-12-22 21:17:45,855 <DEBUG> paho.mqtt.client: Sending SUBSCRIBE (d0, m4) [(b'tinkerforge/callback/bindings/restart', 0)]
2020-12-22 21:17:45,855 <DEBUG> MQTT bindings: 

2020-12-22 21:17:45,855 <DEBUG> MQTT bindings: Registered ip connection callback 0 under topic tinkerforge/callback/ip_connection/connected.
2020-12-22 21:17:45,855 <DEBUG> MQTT bindings: 

2020-12-22 21:17:45,855 <DEBUG> paho.mqtt.client: Received SUBACK
2020-12-22 21:17:45,855 <DEBUG> MQTT bindings: Registered ip connection callback 1 under topic tinkerforge/callback/ip_connection/disconnected.
2020-12-22 21:17:45,855 <DEBUG> paho.mqtt.client: Received SUBACK
2020-12-22 21:17:45,855 <DEBUG> MQTT bindings: 

2020-12-22 21:17:45,856 <DEBUG> paho.mqtt.client: Received SUBACK
2020-12-22 21:17:45,856 <DEBUG> MQTT bindings: Registered ip connection callback 253 under topic tinkerforge/callback/ip_connection/enumerate.
2020-12-22 21:17:45,856 <DEBUG> MQTT bindings: Connecting to brickd at localhost:44445
2020-12-22 21:17:45,857 <DEBUG> MQTT bindings: Connected to Brick Daemon: Connection established after request from user.
2020-12-22 21:17:45,857 <DEBUG> MQTT bindings: Connected to brickd at localhost:44445
2020-12-22 21:17:45,857 <DEBUG> MQTT bindings: 

2020-12-22 21:17:45,857 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m5), 'b'tinkerforge/callback/ip_connection/connected'', ... (29 bytes)
2020-12-22 21:17:45,857 <DEBUG> MQTT bindings: Enumerating devices.
2020-12-22 21:17:45,857 <DEBUG> MQTT bindings: 

2020-12-22 21:17:45,857 <DEBUG> MQTT bindings: Calling function set_temperature_callback_period for device siX of type temperature_bricklet.
2020-12-22 21:17:45,937 <DEBUG> MQTT bindings: Device connected: 2GYM6W at 0 (Pos 0), Hardware: 1.0.0, Firmware: 2.0.3, Dev ID: 17
2020-12-22 21:17:45,938 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m6), 'b'tinkerforge/callback/ip_connection/enumerate'', ... (215 bytes)
2020-12-22 21:17:45,970 <DEBUG> MQTT bindings: Device available: 2GYM6W at 0 (Pos 0), Hardware: 1.0.0, Firmware: 2.0.3, Dev ID: 17
2020-12-22 21:17:45,971 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m7), 'b'tinkerforge/callback/ip_connection/enumerate'', ... (215 bytes)
2020-12-22 21:17:45,972 <DEBUG> MQTT bindings: Device available: 6CPXd6 at 2GYM6W (Pos 1), Hardware: 1.0.0, Firmware: 2.4.9, Dev ID: 13
2020-12-22 21:17:45,972 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m8), 'b'tinkerforge/callback/ip_connection/enumerate'', ... (226 bytes)
2020-12-22 21:17:45,974 <DEBUG> MQTT bindings: Device available: siX at 6CPXd6 (Pos b), Hardware: 1.1.0, Firmware: 2.0.4, Dev ID: 216
2020-12-22 21:17:45,974 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m9), 'b'tinkerforge/callback/ip_connection/enumerate'', ... (239 bytes)
2020-12-22 21:17:45,975 <DEBUG> MQTT bindings: Device available: qRa at 6CPXd6 (Pos d), Hardware: 1.1.0, Firmware: 2.0.2, Dev ID: 27
2020-12-22 21:17:45,975 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m10), 'b'tinkerforge/callback/ip_connection/enumerate'', ... (233 bytes)
2020-12-22 21:17:45,976 <DEBUG> MQTT bindings: Device available: EBH at 6CPXd6 (Pos a), Hardware: 1.0.0, Firmware: 2.0.3, Dev ID: 289
2020-12-22 21:17:45,976 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m11), 'b'tinkerforge/callback/ip_connection/enumerate'', ... (250 bytes)
2020-12-22 21:17:46,011 <DEBUG> MQTT bindings: Calling function set_temperature_callback_period for device siX of type temperature_bricklet succedded.
2020-12-22 21:17:46,012 <DEBUG> MQTT bindings: 

2020-12-22 21:17:46,012 <DEBUG> MQTT bindings: Registered callback temperature for device siX of type temperature_bricklet. Will publish messages to tinkerforge/callback/temperature_bricklet/siX/temperature.
2020-12-22 21:17:53,550 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m12), 'b'tinkerforge/callback/temperature_bricklet/siX/temperature'', ... (21 bytes)
2020-12-22 21:18:03,483 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m13), 'b'tinkerforge/callback/temperature_bricklet/siX/temperature'', ... (21 bytes)
2020-12-22 21:18:32,770 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m14), 'b'tinkerforge/callback/temperature_bricklet/siX/temperature'', ... (21 bytes)
2020-12-22 21:18:35,085 <DEBUG> MQTT bindings: Disconnected from Brick Daemon: Disconnect initiated by Brick Daemon or WIFI/Ethernet Extension.
2020-12-22 21:18:35,085 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m15), 'b'tinkerforge/callback/ip_connection/disconnected'', ... (33 bytes)
2020-12-22 21:18:46,098 <DEBUG> paho.mqtt.client: Sending PINGREQ
2020-12-22 21:18:46,099 <DEBUG> paho.mqtt.client: Received PINGRESP
2020-12-22 21:19:46,157 <DEBUG> paho.mqtt.client: Sending PINGREQ
2020-12-22 21:19:46,158 <DEBUG> paho.mqtt.client: Received PINGRESP
2020-12-22 21:20:15,063 <DEBUG> MQTT bindings: Connected to Brick Daemon: Connection after auto-reconnect.
2020-12-22 21:20:15,063 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m16), 'b'tinkerforge/callback/ip_connection/connected'', ... (36 bytes)
2020-12-22 21:20:15,230 <DEBUG> MQTT bindings: Device connected: 2GYM6W at 0 (Pos 0), Hardware: 1.0.0, Firmware: 2.0.3, Dev ID: 17
2020-12-22 21:20:15,230 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m17), 'b'tinkerforge/callback/ip_connection/enumerate'', ... (215 bytes)
2020-12-22 21:20:20,599 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m18), 'b'tinkerforge/callback/temperature_bricklet/siX/temperature'', ... (21 bytes)
2020-12-22 21:20:46,626 <DEBUG> paho.mqtt.client: Sending PINGREQ
2020-12-22 21:20:46,627 <DEBUG> paho.mqtt.client: Received PINGRESP
2020-12-22 21:21:13,540 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m19), 'b'tinkerforge/callback/temperature_bricklet/siX/temperature'', ... (21 bytes)
2020-12-22 21:21:23,475 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m20), 'b'tinkerforge/callback/temperature_bricklet/siX/temperature'', ... (21 bytes)
2020-12-22 21:21:38,205 <INFO> MQTT bindings: Could not connect to MQTT Broker. Will retry.
2020-12-22 21:21:38,205 <DEBUG> paho.mqtt.client: Connection failed, retrying
2020-12-22 21:21:40,208 <INFO> MQTT bindings: Could not connect to MQTT Broker. Will retry.
2020-12-22 21:21:40,209 <DEBUG> paho.mqtt.client: Connection failed, retrying
2020-12-22 21:21:44,211 <INFO> MQTT bindings: Could not connect to MQTT Broker. Will retry.
2020-12-22 21:21:44,211 <DEBUG> paho.mqtt.client: Connection failed, retrying
2020-12-22 21:21:52,214 <INFO> MQTT bindings: Could not connect to MQTT Broker. Will retry.
2020-12-22 21:21:52,215 <DEBUG> paho.mqtt.client: Connection failed, retrying
2020-12-22 21:22:08,219 <DEBUG> paho.mqtt.client: Sending CONNECT (u0, p0, wr0, wq0, wf1, c1, k60) client_id=b''
2020-12-22 21:22:08,220 <DEBUG> paho.mqtt.client: Received CONNACK (0, 0)
2020-12-22 21:22:08,220 <DEBUG> MQTT bindings: Connected to mqtt broker.
2020-12-22 21:22:08,220 <DEBUG> paho.mqtt.client: Sending SUBSCRIBE (d0, m21) [(b'tinkerforge/request/#', 0)]
2020-12-22 21:22:08,221 <DEBUG> paho.mqtt.client: Sending SUBSCRIBE (d0, m22) [(b'tinkerforge/register/#', 0)]
2020-12-22 21:22:08,221 <DEBUG> paho.mqtt.client: Sending SUBSCRIBE (d0, m23) [(b'tinkerforge/callback/bindings/restart', 0)]
2020-12-22 21:22:08,222 <DEBUG> paho.mqtt.client: Received SUBACK
2020-12-22 21:22:08,223 <DEBUG> paho.mqtt.client: Received SUBACK
2020-12-22 21:22:08,223 <DEBUG> paho.mqtt.client: Received SUBACK
2020-12-22 21:22:14,267 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m24), 'b'tinkerforge/callback/temperature_bricklet/siX/temperature'', ... (21 bytes)
2020-12-22 21:22:24,404 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m25), 'b'tinkerforge/callback/temperature_bricklet/siX/temperature'', ... (21 bytes)
^C2020-12-22 21:22:41,761 <DEBUG> MQTT bindings: Disconnecting from brickd and mqtt broker.
2020-12-22 21:22:41,863 <DEBUG> MQTT bindings: Disconnected from Brick Daemon: Disconnect was requested by user.
2020-12-22 21:22:41,863 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m26), 'b'tinkerforge/callback/ip_connection/disconnected'', ... (32 bytes)
2020-12-22 21:22:41,864 <DEBUG> paho.mqtt.client: Sending PUBLISH (d0, q0, r0, m27), 'b'tinkerforge/callback/bindings/shutdown'', ... (4 bytes)
2020-12-22 21:22:41,865 <DEBUG> paho.mqtt.client: Sending DISCONNECT
[rotten@vlap-wp tf]$

 

ALLGREMEIN :

die funktionelle differenzierung im inti-file (pre_connect, post_connect) ist wirklich eine gute sache !!!

1) ich würde mir hier noch "verbesserungen" bzw sinnvolle "features" wünschen wie pre_reconnect, post_reconnect, post_disconnect,  ...

das würde manche sachen erheblich vereinfachen, da man damit die zustansmaschine für ein
 -> mqtt-topic-translation-gateway (an dem ich gerade arbeite) <-
recht nett über message_callback_add() umsetzen könnte

lg wp

[piwo2]

bumpup

kein bug ? feature ?

lg wp

[rtrbt]

Moin,

Sorry für die späte Antwort, Weihnachtsurlaub und so.

Das ist tatsächlich kein Bug im eigentlichen Sinne: post_connect wird nur einmal ausgeführt und zwar nachdem die Verbindung zum Brick Daemon steht (die wird nach der Verbindung zum Broker aufgebaut). Auf meiner "Nice-to-have"-Liste steht tatsächlich noch "configure" o.Ä. einzuführen, was dann nach jeder Neuverbindung zum Broker oder Brick Daemon ausgeführt werden würde, für genau solche Fälle. Das kann aber noch etwas dauern, bis ich dazu komme.

Du kannst Mosquitto-Neustarts aber mitbekommen, indem du dich auf "$SYS/broker/version" registrierst, da gibt Mosquitto beim (Neu)Start die Versionsnummer aus.
 

[piwo2]

ok.

kleine frage :

warum wird dann der request des callbacks des bricklets honoriert (d.h. callback-responses treten erneut auf) ?

"Überlebt" der callback des temperature bricklets (und die bricklet-callbacks antworten wieder weil noch aktiv oder wieder aktiviert oder noch nicht deaktiviert) oder wird nur der enumerate-callback quasi "vergessen" ?

(edit:)
ok. es wurde nur der enumerate-request nicht erneut abgesetzt, und ein erneutes enumerate beim start der bindings fehlt dann .... aber soweit ich gesehen habe erfolgt doch ein enumerate beim start der bindings ...

(edit2:)
ich habe auch die these, dass die callbacks ja in den bricks ablaufen und nur die mqtt-bridge das vermittelt.
d.h. wenn es kein disconnect gibt, läuft alles wie gehabt beim reconnect zum mqtt-broker ... ein RESET topic ist also KEIN echtes reset.
was wäre dann ein echtes RESET-topic ? mqtt-disconnect UND ipconn.disconnect ?
fragen über fragen. und wie wäre das in eine einheitliche status-maschine zu bringen ?

(edit3:)

ich habe ein problem, eine definitve entscheigungsgrundlage zu haben, wann die bricks/bricklets WIRKLICH neu konfiguriert werden müsen :
wenn es nicht im int-file erfolgt.
szenarien:
mqtt-disconnect, ipconn-disconnect -> konfiguration verloren, aber keine entscheidungsgrundlage weil nicht in den topics erkennbar
nur mqtt-disconnect : gab es einen ipconn-disconnect ? -> siehe oben
nur ipconn-disconnect : ist der brickd wohin connected wurde noch intakt ? -> siehe oben

warum : es gibt ja auch stateless bricklets wo man intern den "status" behalten muss bzw. wiederherstellen wie das remote switch bricklet, weil man da gar keinen status abfragen kann ... oder NC-digital-outs die bei reinitialisierungen mal ein bisschen lang offen sein könnten ...
die sind dann besonders kritisch, vor allem wenn ein impliziter state-change umd sie zu initialisieren recht unangenehm werden kann (sierenen heulen, lichter blinken, womöglich gibts einen disconnect bei der initialen herstellung .... ohgott ...)

d.h. die reinitialisierung des brickd hat absoluten vorrang, am besten von der mqtt-bridge aus bei disconnects ! den einzigen gau, den ich akzeptiere ist der stromverlust auf den bricks/bricklets bzw. tod des brickd, denn "kritische" NC sind sowieso mit 2 NO ausgängen & beschaltung auch im stromlosen zustand  gewährleistet ;-)
aber wie soll das automatisiert wiederherstellbar bzw. konsistent erkennbar sein ??? stromversorgung über spezielle bricklets aus/ein (habe ich auch schon für notfälle über parallen/unabhängigen brickd *ggg*) ???

bitte um kurze erklärung ;-) bzw. best-practice und ausblick, worauf ich mich gefasst machen sollte ;-)

 

bearbeitet January 6, 2021 at 06:04 von piwo2

[rtrbt]

4 hours ago, piwo2 said:

ich habe ein problem, eine definitve entscheigungsgrundlage zu haben, wann die bricks/bricklets WIRKLICH neu konfiguriert werden müsen

Das kommt ganz auf deine Paranoia an ;) Ich habe bei den openHAB-Bindings das gleiche Problem und bin da relativ aggressiv, lies ich konfiguriere immer alles neu, wenn ich mir nicht 100%ig sicher bin, dass alles passt.

Ich versuche mal alle Komponenten aufzulisten, bei denen was schief gehen kann, frag nochmal wenn da irgendwelche Lücken sind. Es gibt:

• Einzelne Bricks/Bricklets: Die schicken beim Neustart ein Enumerate mit Connected. Das passiert z.b. wenn du die Firmware aktualisierst, oder aus anderen Gründen ein Brick(let) resettest.
• Den Stack, der neustartet wenn du USB abziehst und wieder dransteckst. Wenn alles andere noch läuft, solltest du im Moment des Stecker-ziehens ein Enumerate mit Disconnected für alle Bricks/Bricklets bekommen, auf jeden Fall bekommst du aber ein Enumerate mit Connected, wenn der Stack angeschlossen wird.
• Der Brick Daemon. Wenn der neustartet oder du aus anderen Gründen die Verbindung verlierst, kannst du das über das connected btw. disconnected Callback mitbekommen.
• Der MQTT-Broker. Das hängt etwas vom Broker ab, was passiert wenn du den neustartest. Bei mosquitto kannst du dich wie oben beschrieben auf $SYS/broker/version subscriben. (Achtung: In der Shell brauchst du Anführungszeichen oder musst das $ escapen, sonst wirds nichts)
• Die MQTT-Bindings. Wenn die Bindings sich sauber beenden siehst du das unter "tinkerforge/callback/bindings/shutdown", falls sie crashen (und deshalb diesen Publish nicht schaffen würden) siehst du stattdessen "tinkerforge/callback/bindings/last_will". Wenn die Bindings (neu)starten bekommst du "tinkerforge/callback/bindings/restart", auf allen diesen Topics ist der Payload einfach null, da geht es ja nur um das Signal selbst. Den last_will bekommst du übrigens auch wenn der Broker (sauber) beendet wird.

Wenn jetzt irgendeine Komponente neustartet, musst du im worst-Case alle Callbacks neu registrieren und aktivieren und alle Konfiguration der Bricks/Bricklets neusetzen. Es kann dir nämlich passieren, das z.b. der MQTT-Broker abschmiert, während der weg ist, aber der Stack neustartet, weil jemand ungünstig ans USB-Kabel gekommen ist oder so. Das bekommst du jetzt aber nicht mehr mit, d.h. wenn der Broker wieder kommt weißt du nicht was in der Zwischenzeit passiert ist.

Andererseits kannst du natürlich Glück haben und der Broker-Neustart hat sonst nichts beeinflusst, dann kommen deine Daten weiterhin durch. WIe gesagt, das hängt von der Paranoia/den Robustheitsansprüchen hab.

Ich würde folgendes machen: Baue dir in einem z.b. Pythonscript eine Initialisierungsfunktion pro Brick/Bricklet, die die Callbacks registriert und aktiviert und alles konfiguriert. und "glaube" den Daten nur, wenn die erfolgreich durchgelaufen ist. Wenn du jetzt in der Kette irgendeinen Crash/Neustart detektierst, führst du die Funktionen alle neu aus. Du kannst dann natürlich optimieren und wenn du einen einzelnen Brick(let) neustart siehst nur das eine Gerät neu initialisieren.