Von MQTT2_SERVER verschickte Nachrichten mit type "reserved"

Begonnen von krikan, 21 Oktober 2019, 21:19:21

Vorheriges Thema - Nächstes Thema

krikan

Hallo!

Habe einen gerooteten Staubsauger mit dem aktuellen https://github.com/Hypfer/Valetudo 0.4 bestückt und MQTT auf dem Sauger aktiviert. Die vom MQTT2_SERVER verschickten MQTT-Nachrichten lassen Valetudo mit MQTT auf dem Sauger reproduzierbar abstürzen. Nach https://github.com/Hypfer/Valetudo/issues/134#issuecomment-511531783 werden die Abstürze auf die Nachrichten von FHEM mit "reserved"-Flags zurückgeführt. Für Valetudo gibt es mittlerweile einen Patch, der das Problem beheben soll.

Obwohl ich aus der Diskussion bei Valetudo interpretiere, dass FHEM "falsche" Nachrichten verschickt, kann ich das anhand des obigen Github-Issuses und den dortigen Infos nicht nachvollziehen. Für mich sehen alle FHEM-MQTT-Nachrichten korrekt aus.

Blöderweise kann ich anhand der Valetudo-Logs nicht erkennen, welche FHEM-MQTT-Nachrichten das Problem auslösen. Tippe auf SUBSCRIBE, da es 11 Fehler in Valetudo bis zum Absturz gibt.

Kann mir jemand erklären, wo das Problem bei den FHEM-MQTT-Nachrichten ist? Da das Problem durch Valetudo durch Patch behobem wurde, ist das hier ein eher akademisches Thema; aber ich würde gerne das MQTT-Protokoll verstehen und wissen, auf welcher Seite (FHEM oder Valetudo) die Ursache liegt.  :)

Gruß, Christian

verbose 5-Log von FHEM bis zum Absturz von Valetudo:
2019.10.21 20:27:05.782 4: Connection accepted from fhemMqtt_192.168.188.46_54219
2019.10.21 20:27:05.801 5: CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_6eba03a8
2019.10.21 20:27:05.802 4: fhemMqtt_192.168.188.46_54219 mqttjs_6eba03a8 CONNECT V:4 keepAlive:60
2019.10.21 20:27:05.849 5: SUBSCRIBE: (130)c(154)^(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.21 20:27:05.849 4: fhemMqtt_192.168.188.46_54219 mqttjs_6eba03a8 SUBSCRIBE
2019.10.21 20:27:05.850 4:   topic:valetudo/rockrobo/command qos:0
2019.10.21 20:27:05.850 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.21 20:27:05.850 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.21 20:27:05.893 4: Connection closed for fhemMqtt_192.168.188.46_54219: EOF
2019.10.21 20:27:08.709 4: Connection accepted from fhemMqtt_192.168.188.46_54221
2019.10.21 20:27:08.745 5: CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_847aa466
2019.10.21 20:27:08.746 4: fhemMqtt_192.168.188.46_54221 mqttjs_847aa466 CONNECT V:4 keepAlive:60
2019.10.21 20:27:08.787 5: SUBSCRIBE: (130)c(9)&(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.21 20:27:08.788 4: fhemMqtt_192.168.188.46_54221 mqttjs_847aa466 SUBSCRIBE
2019.10.21 20:27:08.788 4:   topic:valetudo/rockrobo/command qos:0
2019.10.21 20:27:08.788 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.21 20:27:08.788 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.21 20:27:08.836 4: Connection closed for fhemMqtt_192.168.188.46_54221: EOF
2019.10.21 20:27:11.770 4: Connection accepted from fhemMqtt_192.168.188.46_54233
2019.10.21 20:27:11.790 5: CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_ea895da2
2019.10.21 20:27:11.790 4: fhemMqtt_192.168.188.46_54233 mqttjs_ea895da2 CONNECT V:4 keepAlive:60
2019.10.21 20:27:11.838 5: SUBSCRIBE: (130)c_g(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.21 20:27:11.838 4: fhemMqtt_192.168.188.46_54233 mqttjs_ea895da2 SUBSCRIBE
2019.10.21 20:27:11.838 4:   topic:valetudo/rockrobo/command qos:0
2019.10.21 20:27:11.839 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.21 20:27:11.839 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.21 20:27:11.882 4: Connection closed for fhemMqtt_192.168.188.46_54233: EOF
2019.10.21 20:27:14.716 4: Connection accepted from fhemMqtt_192.168.188.46_54235
2019.10.21 20:27:14.752 5: CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_e9ff2f91
2019.10.21 20:27:14.753 4: fhemMqtt_192.168.188.46_54235 mqttjs_e9ff2f91 CONNECT V:4 keepAlive:60
2019.10.21 20:27:14.799 5: SUBSCRIBE: (130)c(202)(241)(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.21 20:27:14.799 4: fhemMqtt_192.168.188.46_54235 mqttjs_e9ff2f91 SUBSCRIBE
2019.10.21 20:27:14.800 4:   topic:valetudo/rockrobo/command qos:0
2019.10.21 20:27:14.800 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.21 20:27:14.800 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.21 20:27:14.869 4: Connection closed for fhemMqtt_192.168.188.46_54235: EOF
2019.10.21 20:27:17.691 4: Connection accepted from fhemMqtt_192.168.188.46_54236
2019.10.21 20:27:17.710 5: CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_df6285f1
2019.10.21 20:27:17.711 4: fhemMqtt_192.168.188.46_54236 mqttjs_df6285f1 CONNECT V:4 keepAlive:60
2019.10.21 20:27:17.749 5: SUBSCRIBE: (130)c(231)f(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.21 20:27:17.749 4: fhemMqtt_192.168.188.46_54236 mqttjs_df6285f1 SUBSCRIBE
2019.10.21 20:27:17.749 4:   topic:valetudo/rockrobo/command qos:0
2019.10.21 20:27:17.749 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.21 20:27:17.750 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.21 20:27:17.792 4: Connection closed for fhemMqtt_192.168.188.46_54236: EOF
2019.10.21 20:27:20.590 4: Connection accepted from fhemMqtt_192.168.188.46_54237
2019.10.21 20:27:20.609 5: CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_c1cb4628
2019.10.21 20:27:20.610 4: fhemMqtt_192.168.188.46_54237 mqttjs_c1cb4628 CONNECT V:4 keepAlive:60
2019.10.21 20:27:20.647 5: SUBSCRIBE: (130)c(229)=(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.21 20:27:20.648 4: fhemMqtt_192.168.188.46_54237 mqttjs_c1cb4628 SUBSCRIBE
2019.10.21 20:27:20.648 4:   topic:valetudo/rockrobo/command qos:0
2019.10.21 20:27:20.648 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.21 20:27:20.648 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.21 20:27:20.691 4: Connection closed for fhemMqtt_192.168.188.46_54237: EOF
2019.10.21 20:27:23.487 4: Connection accepted from fhemMqtt_192.168.188.46_54238
2019.10.21 20:27:23.524 5: CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_243d2d09
2019.10.21 20:27:23.525 4: fhemMqtt_192.168.188.46_54238 mqttjs_243d2d09 CONNECT V:4 keepAlive:60
2019.10.21 20:27:23.566 5: SUBSCRIBE: (130)c(144)i(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.21 20:27:23.566 4: fhemMqtt_192.168.188.46_54238 mqttjs_243d2d09 SUBSCRIBE
2019.10.21 20:27:23.566 4:   topic:valetudo/rockrobo/command qos:0
2019.10.21 20:27:23.566 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.21 20:27:23.567 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.21 20:27:23.610 4: Connection closed for fhemMqtt_192.168.188.46_54238: EOF
2019.10.21 20:27:26.395 4: Connection accepted from fhemMqtt_192.168.188.46_54239
2019.10.21 20:27:26.432 5: CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_2d44c263
2019.10.21 20:27:26.433 4: fhemMqtt_192.168.188.46_54239 mqttjs_2d44c263 CONNECT V:4 keepAlive:60
2019.10.21 20:27:26.474 5: SUBSCRIBE: (130)c(131)(226)(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.21 20:27:26.475 4: fhemMqtt_192.168.188.46_54239 mqttjs_2d44c263 SUBSCRIBE
2019.10.21 20:27:26.475 4:   topic:valetudo/rockrobo/command qos:0
2019.10.21 20:27:26.475 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.21 20:27:26.476 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.21 20:27:26.522 4: Connection closed for fhemMqtt_192.168.188.46_54239: EOF
2019.10.21 20:27:28.094 3: TRX_WEATHER: Unknown device TFATS34C_9, please define it
2019.10.21 20:27:29.352 4: Connection accepted from fhemMqtt_192.168.188.46_54240
2019.10.21 20:27:29.371 5: CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_1aaaa765
2019.10.21 20:27:29.371 4: fhemMqtt_192.168.188.46_54240 mqttjs_1aaaa765 CONNECT V:4 keepAlive:60
2019.10.21 20:27:29.409 5: SUBSCRIBE: (130)c(233)(213)(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.21 20:27:29.410 4: fhemMqtt_192.168.188.46_54240 mqttjs_1aaaa765 SUBSCRIBE
2019.10.21 20:27:29.410 4:   topic:valetudo/rockrobo/command qos:0
2019.10.21 20:27:29.410 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.21 20:27:29.410 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.21 20:27:29.453 4: Connection closed for fhemMqtt_192.168.188.46_54240: EOF
2019.10.21 20:27:32.220 4: Connection accepted from fhemMqtt_192.168.188.46_54241
2019.10.21 20:27:32.239 5: CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_787a6590
2019.10.21 20:27:32.240 4: fhemMqtt_192.168.188.46_54241 mqttjs_787a6590 CONNECT V:4 keepAlive:60
2019.10.21 20:27:32.278 5: SUBSCRIBE: (130)c(253)(185)(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.21 20:27:32.278 4: fhemMqtt_192.168.188.46_54241 mqttjs_787a6590 SUBSCRIBE
2019.10.21 20:27:32.278 4:   topic:valetudo/rockrobo/command qos:0
2019.10.21 20:27:32.278 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.21 20:27:32.278 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.21 20:27:32.321 4: Connection closed for fhemMqtt_192.168.188.46_54241: EOF
2019.10.21 20:27:35.135 4: Connection accepted from fhemMqtt_192.168.188.46_54242
2019.10.21 20:27:35.215 5: CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_333ea0b7
2019.10.21 20:27:35.216 4: fhemMqtt_192.168.188.46_54242 mqttjs_333ea0b7 CONNECT V:4 keepAlive:60
2019.10.21 20:27:35.256 5: SUBSCRIBE: (130)c(159)o(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.21 20:27:35.256 4: fhemMqtt_192.168.188.46_54242 mqttjs_333ea0b7 SUBSCRIBE
2019.10.21 20:27:35.256 4:   topic:valetudo/rockrobo/command qos:0
2019.10.21 20:27:35.256 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.21 20:27:35.256 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.21 20:27:35.300 4: Connection closed for fhemMqtt_192.168.188.46_54242: EOF

rudolfkoenig

Leider protokolliert MQTT2_SERVER nur die Eingangsseite sehr detailliert, nicht die Antworten.

Soweit ich sehe, verschickt MQTT2_SERVER "nur" Nachrichten der Sorte  CONNACK, PUBACK, SUBACK, UNSUBACK, PINGRESP, PUBLISH.
Der verlinkte Beitrag verweist auf die Tabelle 2.2 im RFC, die wiederum besagt, dass im Kommandobyte das zweite Nibble bis auf PUBLISH 0 sein muss (== reserviert), bei PUBLISH 0 sein darf.
MQTT2_SERVER versendet alle Nachrichten mit 0 im zweiten Nibble des Kommandobytes, siehe die addToWritebuffer Zeilen in MQTT2_SERVER.

Ich vermute eher ein Laengenkodierungsproblem, entweder in MQTT2_SERVER oder in Valudo.

Da ich an einem Fix interessiert bin, habe ich gerade eine Version eingecheckt, was auch die Ausgangsseite detailliert protokolliert.
Wenn das Problem noch reproduzierbar ist, bin ich an einem erneuten Dump interessiert.

krikan

Log mit geänderter Modulversion:
2019.10.22 01:28:56.734 4: Connection accepted from fhemMqtt_192.168.188.46_55680
2019.10.22 01:28:56.772 5: in:  CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_e0418ba5
2019.10.22 01:28:56.773 4:   fhemMqtt_192.168.188.46_55680 mqttjs_e0418ba5 CONNECT V:4 keepAlive:60
2019.10.22 01:28:56.773 5: out: CONNACK:  (2)(0)(0)
2019.10.22 01:28:56.815 5: in:  SUBSCRIBE: (130)c(132)(198)(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.22 01:28:56.815 4:   fhemMqtt_192.168.188.46_55680 mqttjs_e0418ba5 SUBSCRIBE
2019.10.22 01:28:56.815 4:   topic:valetudo/rockrobo/command qos:0
2019.10.22 01:28:56.816 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.22 01:28:56.816 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.22 01:28:56.816 5: out: SUBACK: (144)(3)(132)(198)(0)(0)(0)
2019.10.22 01:28:56.862 4: Connection closed for fhemMqtt_192.168.188.46_55680: EOF
2019.10.22 01:28:59.629 4: Connection accepted from fhemMqtt_192.168.188.46_55682
2019.10.22 01:28:59.678 5: in:  CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_20e93af4
2019.10.22 01:28:59.679 4:   fhemMqtt_192.168.188.46_55682 mqttjs_20e93af4 CONNECT V:4 keepAlive:60
2019.10.22 01:28:59.679 5: out: CONNACK:  (2)(0)(0)
2019.10.22 01:28:59.721 5: in:  SUBSCRIBE: (130)c(245)z(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.22 01:28:59.721 4:   fhemMqtt_192.168.188.46_55682 mqttjs_20e93af4 SUBSCRIBE
2019.10.22 01:28:59.721 4:   topic:valetudo/rockrobo/command qos:0
2019.10.22 01:28:59.722 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.22 01:28:59.722 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.22 01:28:59.722 5: out: SUBACK: (144)(3)(245)z(0)(0)(0)
2019.10.22 01:28:59.770 4: Connection closed for fhemMqtt_192.168.188.46_55682: EOF
2019.10.22 01:29:02.652 4: Connection accepted from fhemMqtt_192.168.188.46_55683
2019.10.22 01:29:02.699 5: in:  CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_8bd699c7
2019.10.22 01:29:02.700 4:   fhemMqtt_192.168.188.46_55683 mqttjs_8bd699c7 CONNECT V:4 keepAlive:60
2019.10.22 01:29:02.700 5: out: CONNACK:  (2)(0)(0)
2019.10.22 01:29:02.745 5: in:  SUBSCRIBE: (130)czK(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.22 01:29:02.745 4:   fhemMqtt_192.168.188.46_55683 mqttjs_8bd699c7 SUBSCRIBE
2019.10.22 01:29:02.746 4:   topic:valetudo/rockrobo/command qos:0
2019.10.22 01:29:02.746 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.22 01:29:02.746 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.22 01:29:02.747 5: out: SUBACK: (144)(3)zK(0)(0)(0)
2019.10.22 01:29:02.801 4: Connection closed for fhemMqtt_192.168.188.46_55683: EOF
2019.10.22 01:29:05.582 4: Connection accepted from fhemMqtt_192.168.188.46_55684
2019.10.22 01:29:05.628 5: in:  CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_82f1f5d4
2019.10.22 01:29:05.629 4:   fhemMqtt_192.168.188.46_55684 mqttjs_82f1f5d4 CONNECT V:4 keepAlive:60
2019.10.22 01:29:05.629 5: out: CONNACK:  (2)(0)(0)
2019.10.22 01:29:05.669 5: in:  SUBSCRIBE: (130)c(188)(179)(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.22 01:29:05.669 4:   fhemMqtt_192.168.188.46_55684 mqttjs_82f1f5d4 SUBSCRIBE
2019.10.22 01:29:05.669 4:   topic:valetudo/rockrobo/command qos:0
2019.10.22 01:29:05.669 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.22 01:29:05.670 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.22 01:29:05.670 5: out: SUBACK: (144)(3)(188)(179)(0)(0)(0)
2019.10.22 01:29:05.716 4: Connection closed for fhemMqtt_192.168.188.46_55684: EOF
2019.10.22 01:29:08.631 4: Connection accepted from fhemMqtt_192.168.188.46_55685
2019.10.22 01:29:08.679 5: in:  CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_21d5fdf3
2019.10.22 01:29:08.680 4:   fhemMqtt_192.168.188.46_55685 mqttjs_21d5fdf3 CONNECT V:4 keepAlive:60
2019.10.22 01:29:08.680 5: out: CONNACK:  (2)(0)(0)
2019.10.22 01:29:08.725 5: in:  SUBSCRIBE: (130)c(8))(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.22 01:29:08.725 4:   fhemMqtt_192.168.188.46_55685 mqttjs_21d5fdf3 SUBSCRIBE
2019.10.22 01:29:08.726 4:   topic:valetudo/rockrobo/command qos:0
2019.10.22 01:29:08.726 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.22 01:29:08.726 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.22 01:29:08.727 5: out: SUBACK: (144)(3)(8))(0)(0)(0)
2019.10.22 01:29:08.775 4: Connection closed for fhemMqtt_192.168.188.46_55685: EOF
2019.10.22 01:29:11.107 3: TRX_WEATHER: Unknown device TFATS34C_9, please define it
2019.10.22 01:29:11.636 4: Connection accepted from fhemMqtt_192.168.188.46_55686
2019.10.22 01:29:11.656 5: in:  CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_0d85bfbd
2019.10.22 01:29:11.657 4:   fhemMqtt_192.168.188.46_55686 mqttjs_0d85bfbd CONNECT V:4 keepAlive:60
2019.10.22 01:29:11.657 5: out: CONNACK:  (2)(0)(0)
2019.10.22 01:29:11.694 5: in:  SUBSCRIBE: (130)c(221)%(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.22 01:29:11.694 4:   fhemMqtt_192.168.188.46_55686 mqttjs_0d85bfbd SUBSCRIBE
2019.10.22 01:29:11.694 4:   topic:valetudo/rockrobo/command qos:0
2019.10.22 01:29:11.694 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.22 01:29:11.695 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.22 01:29:11.695 5: out: SUBACK: (144)(3)(221)%(0)(0)(0)
2019.10.22 01:29:11.740 4: Connection closed for fhemMqtt_192.168.188.46_55686: EOF
2019.10.22 01:29:14.550 4: Connection accepted from fhemMqtt_192.168.188.46_55687
2019.10.22 01:29:14.598 5: in:  CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_a01e9d8f
2019.10.22 01:29:14.599 4:   fhemMqtt_192.168.188.46_55687 mqttjs_a01e9d8f CONNECT V:4 keepAlive:60
2019.10.22 01:29:14.599 5: out: CONNACK:  (2)(0)(0)
2019.10.22 01:29:14.640 5: in:  SUBSCRIBE: (130)c(138)(144)(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.22 01:29:14.640 4:   fhemMqtt_192.168.188.46_55687 mqttjs_a01e9d8f SUBSCRIBE
2019.10.22 01:29:14.641 4:   topic:valetudo/rockrobo/command qos:0
2019.10.22 01:29:14.641 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.22 01:29:14.641 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.22 01:29:14.641 5: out: SUBACK: (144)(3)(138)(144)(0)(0)(0)
2019.10.22 01:29:14.687 4: Connection closed for fhemMqtt_192.168.188.46_55687: EOF
2019.10.22 01:29:17.484 4: Connection accepted from fhemMqtt_192.168.188.46_55688
2019.10.22 01:29:17.530 5: in:  CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_9c3db279
2019.10.22 01:29:17.531 4:   fhemMqtt_192.168.188.46_55688 mqttjs_9c3db279 CONNECT V:4 keepAlive:60
2019.10.22 01:29:17.531 5: out: CONNACK:  (2)(0)(0)
2019.10.22 01:29:17.572 5: in:  SUBSCRIBE: (130)c(255)(210)(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.22 01:29:17.572 4:   fhemMqtt_192.168.188.46_55688 mqttjs_9c3db279 SUBSCRIBE
2019.10.22 01:29:17.572 4:   topic:valetudo/rockrobo/command qos:0
2019.10.22 01:29:17.573 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.22 01:29:17.573 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.22 01:29:17.573 5: out: SUBACK: (144)(3)(255)(210)(0)(0)(0)
2019.10.22 01:29:17.619 4: Connection closed for fhemMqtt_192.168.188.46_55688: EOF
2019.10.22 01:29:20.518 4: Connection accepted from fhemMqtt_192.168.188.46_55689
2019.10.22 01:29:20.568 5: in:  CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_a71d7042
2019.10.22 01:29:20.569 4:   fhemMqtt_192.168.188.46_55689 mqttjs_a71d7042 CONNECT V:4 keepAlive:60
2019.10.22 01:29:20.569 5: out: CONNACK:  (2)(0)(0)
2019.10.22 01:29:20.613 5: in:  SUBSCRIBE: (130)c(211)7(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.22 01:29:20.613 4:   fhemMqtt_192.168.188.46_55689 mqttjs_a71d7042 SUBSCRIBE
2019.10.22 01:29:20.613 4:   topic:valetudo/rockrobo/command qos:0
2019.10.22 01:29:20.614 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.22 01:29:20.614 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.22 01:29:20.614 5: out: SUBACK: (144)(3)(211)7(0)(0)(0)
2019.10.22 01:29:20.661 4: Connection closed for fhemMqtt_192.168.188.46_55689: EOF
2019.10.22 01:29:23.562 4: Connection accepted from fhemMqtt_192.168.188.46_55690
2019.10.22 01:29:23.609 5: in:  CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_aaaa007d
2019.10.22 01:29:23.609 4:   fhemMqtt_192.168.188.46_55690 mqttjs_aaaa007d CONNECT V:4 keepAlive:60
2019.10.22 01:29:23.610 5: out: CONNACK:  (2)(0)(0)
2019.10.22 01:29:23.655 5: in:  SUBSCRIBE: (130)cY(183)(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.22 01:29:23.656 4:   fhemMqtt_192.168.188.46_55690 mqttjs_aaaa007d SUBSCRIBE
2019.10.22 01:29:23.656 4:   topic:valetudo/rockrobo/command qos:0
2019.10.22 01:29:23.656 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.22 01:29:23.656 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.22 01:29:23.656 5: out: SUBACK: (144)(3)Y(183)(0)(0)(0)
2019.10.22 01:29:23.705 4: Connection closed for fhemMqtt_192.168.188.46_55690: EOF
2019.10.22 01:29:26.455 4: Connection accepted from fhemMqtt_192.168.188.46_55692
2019.10.22 01:29:26.502 5: in:  CONNECT: (16)(27)(0)(4)MQTT(4)(2)(0)<(0)(15)mqttjs_f26c8022
2019.10.22 01:29:26.503 4:   fhemMqtt_192.168.188.46_55692 mqttjs_f26c8022 CONNECT V:4 keepAlive:60
2019.10.22 01:29:26.504 5: out: CONNACK:  (2)(0)(0)
2019.10.22 01:29:26.546 5: in:  SUBSCRIBE: (130)cIL(0)(25)valetudo/rockrobo/command(0)(0)(31)valetudo/rockrobo/set_fan_speed(0)(0) valetudo/rockrobo/custom_command(0)
2019.10.22 01:29:26.547 4:   fhemMqtt_192.168.188.46_55692 mqttjs_f26c8022 SUBSCRIBE
2019.10.22 01:29:26.547 4:   topic:valetudo/rockrobo/command qos:0
2019.10.22 01:29:26.547 4:   topic:valetudo/rockrobo/set_fan_speed qos:0
2019.10.22 01:29:26.548 4:   topic:valetudo/rockrobo/custom_command qos:0
2019.10.22 01:29:26.548 5: out: SUBACK: (144)(3)IL(0)(0)(0)
2019.10.22 01:29:26.594 4: Connection closed for fhemMqtt_192.168.188.46_55692: EOF

krikan

Brauche wohl einen Grundlagenkurs in MQTT-Nachrichten. Wenn ich die FHEM-Nachrichten nach http://docs.oasis-open.org/mqtt/mqtt/v3.1.1/os/mqtt-v3.1.1-os.html betrachte, dann habe ich Verständnisprobleme.

2019.10.22 01:28:56.773 5: out: CONNACK:  (2)(0)(0)
Nach http://docs.oasis-open.org/mqtt/mqtt/v3.1.1/os/mqtt-v3.1.1-os.html#_Toc398718033 fehlt im Log das 1. Byte des Fixed Header (32).
Ich hätte die Nachricht zusammengebaut:
(32) (2) (0) (0)

2019.10.22 01:28:56.816 5: out: SUBACK: (144)(3)(132)(198)(0)(0)(0)
Nach http://docs.oasis-open.org/mqtt/mqtt/v3.1.1/os/mqtt-v3.1.1-os.html#_Toc398718068 ist das 2. Byte des Fixed Header die "Remaining Length". Bei einer "Remaining Length" von (3) verstehe ich die letzten beiden Bytes (0) (0) im Log nicht. Wofür stehen die bzw. sind die zuviel?
Hier hätte ich folgende Nachricht gebildet:
(144) (3) (132) (198) (0)

Ist eventuell das von mir gewählte Dokument http://docs.oasis-open.org/mqtt/mqtt/v3.1.1/os/mqtt-v3.1.1-os.html falsch? Muss ich woanders nachschauen?

rudolfkoenig

ZitatNach http://docs.oasis-open.org/mqtt/mqtt/v3.1.1/os/mqtt-v3.1.1-os.html#_Toc398718033 fehlt im Log das 1. Byte des Fixed Header (32).
Fehlt nicht, ist aber druckbar (Leerzeichen), deswegen tarnt es sich gut.
Habe eine Weile ueberlegt, bin aber immer noch dafuer, es dabei zu belassen.

ZitatBei einer "Remaining Length" von (3) verstehe ich die letzten beiden Bytes (0) (0) im Log nicht.
Vielen Dank fuer die hoefliche Formulierung :), das ist wohl auch die Ursache des Problems: (0)(0) Als Nachricht ist nicht erlaubt.
Ich habe den Fehler behoben, kann es aber nicht testen, da ich keinen Client kenne, der mehrere topics in eine Subscribe Nachricht zusammenfasst.


krikan

Zitat von: rudolfkoenig am 22 Oktober 2019, 11:00:24
Fehlt nicht, ist aber druckbar (Leerzeichen), deswegen tarnt es sich gut.
Bedeutet das, dass ich nur das Log nicht richtig lese/verstehe: statt (32) ist eben ein "gedrucktes" Leerzeichen im Log!?

ZitatHabe eine Weile ueberlegt, bin aber immer noch dafuer, es dabei zu belassen.
Kein Problem. Wenn man es kennt, dann ist es ok.

ZitatVielen Dank fuer die hoefliche Formulierung :)
Ich beschäftige mich genau seit gestern mit MQTT, darum bin ich froh, wenn ich nicht total falsch interpretiere.

ZitatIch habe den Fehler behoben, kann es aber nicht testen, da ich keinen Client kenne, der mehrere topics in eine Subscribe Nachricht zusammenfasst.
Tests mache ich; will MQTT ja für den Sauger nutzen. (Bisher wurden noch keine MQTT2_DEVICES -Devices per autocreate erzeugt; das muss ich noch verstehen.)

rudolfkoenig

Zitatstatt (32) ist eben ein "gedrucktes" Leerzeichen im Log!?
Ja, zwei Leerzeichen zwischen : und ( bei CONNACK. Man muesste Header und Topic/Message anders behandeln, die debug Routine weiss aber nicht, was Header ist => Umbau waere zu aufwendig.

ZitatBisher wurden noch keine MQTT2_DEVICES -Devices per autocreate erzeugt; das muss ich noch verstehen.
Wird erst beim Eintreffen von MQTT-Nachrichten erzeugt, es muss ein autocreate Device existieren, und das autocreate Attribut fuer MQTT2_SERVER sollte nicht auf no stehen.

Otto123

Zitat von: krikan am 22 Oktober 2019, 11:43:29
Ich beschäftige mich genau seit gestern mit MQTT, darum bin ich froh, wenn ich nicht total falsch interpretiere.
Tests mache ich; will MQTT ja für den Sauger nutzen. (Bisher wurden noch keine MQTT2_DEVICES -Devices per autocreate erzeugt; das muss ich noch verstehen.)
Mir geht es wie Dir, ok seit 14 Tagen aber nur lückenhaft. Deswegen lese ich interessiert mit :)

Zusätzlich zu Rudis Aussage:

Das autocreate hängt nach meiner Erkenntnis an der CID, in einer  pub Message
mosquitto_pub -h raspib2 -i COMPUTER -t /pi/CPU/raspib/temperature -m 22
erzeugt ein Device.
Lässt Du - i COMPUTER weg passiert es nicht ;)

Gruß Otto
Viele Grüße aus Leipzig  ⇉  nächster Stammtisch an der Lindennaundorfer Mühle
RaspberryPi B B+ B2 B3 B3+ ZeroW,HMLAN,HMUART,Homematic,Fritz!Box 7590,WRT3200ACS-OpenWrt,Sonos,VU+,Arduino nano,ESP8266,MQTT,Zigbee,deconz

rudolfkoenig

ZitatLässt Du - i COMPUTER weg passiert es nicht
Ja, weil MQTT2_DEVICE extra Code fuer mosquitto_pub hat, der ohne -i immer andere ClientIDs schickt.

krikan

Mit der geänderten MQTT2-SERVER gibt es keinen Absturz von Valetudo auf dem Sauger mehr. Das (knappe) Valetudo-Log ist bisher ebenfalls ohne Fehlermeldungen. Aus meiner Sicht alles Bestens.

Zitat von: rudolfkoenig am 22 Oktober 2019, 11:59:20
Wird erst beim Eintreffen von MQTT-Nachrichten erzeugt, es muss ein autocreate Device existieren, und das autocreate Attribut fuer MQTT2_SERVER sollte nicht auf no stehen.
Funktioniert jetzt. Rahmenbedingungen waren vorher auch erfüllt, aber der Absturz war wohl zu früh!?

Ansonsten muss ich jetzt erst mal lesen...

krikan

#10
Jetzt verursacht zwar FHEM keinen Absturz von Valetuo mehr, aber Valetudo bringt -mit zugegeben etwas längeren MQTT-Nachrichten- fhem.pl zum "erliegen". fhem.pl zieht nach diesen Nachrichten laut "top" 100% der CPU-Leistung. Fängt sich aber auch nach bis zu einer halben Stunde nicht. Das habe ich jetzt mehrmals erlebt; meistens habe ich nur bis zu 5 Minuten gewartet und fhem.pl dann "gekillt".

Letzte Zeilen im Log eines Beispiels habe ich angehängt, da es für code-Tags zu lang ist. Es gibt auch noch längere Nachrichten wie "data_length":28718.

rudolfkoenig

#11
- die Nachricht aus dem Log ist 283776 Bytes lang und beinhaltet vmtl. ein Bitmap
- ich kriege es mit mosquitto_pub weder unter Linux, noch unter OSX verschickt (Argument list too long)
- als mosquitto_pub Ersatz habe ich jetzt eine minimalistische FHEM Konfiguration gebaut, mit MQTT2_CLIENT
- das MQTT autocreate, in speziellen json2nameValue ist nicht fuer Bilder im JSON-Format optimiert: auch wenn es (vmtl.?) in einigen Minuten durch ist, werden ca 60.000 Readings, und entsprechend viele Events generiert (pro gesetzten Pixel 2, fuer X und fuer Y).
- ich habe MQTT2_DEVICE gerade angepasst: ab sofort muss fuer das automatisch angelegte json2nameValue die Nachricht kleiner als 10k sein.
- als Workaround kann man mit der "alten" Code readingList mit "mqttjs_b3bf0259:valetudo/rockrobo/map_data:.* map_data" ergaenzen und/oder "attr mqttjs_b3bf0259 autocreate 0" setzen.
- idealerweise baut jemand eine valetudo2png() Funktion :)

krikan

Zitat von: Otto123 am 22 Oktober 2019, 12:02:03
Mir geht es wie Dir, ok seit 14 Tagen aber nur lückenhaft. Deswegen lese ich interessiert mit :)
Meine Frustrationsgrenze ist bald erreicht. Habe mir wohl nicht das ideale Einstiegsobjekt ausgesucht, da Valetudo-MQTT-Doku recht verstreut lliegt bzw. sich nur aus .js-Code im Detail erschließt. (Oder ich finde es nur nicht). Aber ihr könnt mich am 2.11. in Hambug ja aufbauen.

Zitat von: rudolfkoenig am 22 Oktober 2019, 21:03:45
die Nachricht aus dem Log[...] beinhaltet vmtl. ein Bitmap
Ja, Bitmap

Zitat
- ich kriege es mit mosquitto_pub weder unter Linux, noch unter OSX verschickt (Argument list too long)
Hätte erwartet, dass bei mosquitto_pub "-f file" das Längenproblem löst.

Zitat- das MQTT autocreate, in speziellen json2nameValue ist nicht fuer Bilder im JSON-Format optimiert: auch wenn es (vmtl.?) in einigen Minuten durch ist, werden ca 60.000 Readings, und entsprechend viele Events generiert (pro gesetzten Pixel 2, fuer X und fuer Y).
- ich habe MQTT2_DEVICE gerade angepasst: ab sofort muss fuer das automatisch angelegte json2nameValue die Nachricht kleiner als 10k sein.
- als Workaround kann man mit der "alten" Code readingList mit "mqttjs_b3bf0259:valetudo/rockrobo/map_data:.* map_data" ergaenzen und/oder "attr mqttjs_b3bf0259 autocreate 0" setzen.
Danke im Nachhinein betrachtet, hätte ich auch selbst darauf kommen können. Ist wohl zuviel Unbekanntes auf eine Haufen.
"In einigen Minuten durch.." -> habe einmal tatsächlich ein halbe Stunde gewartet und es war noch nicht durch. Aber ich nutze auch nur einen (sonst ausreichenden Raspi 1 zum Experimentieren und keine Workstation.  ;)

Zitat- idealerweise baut jemand eine valetudo2png() Funktion :)
Dann warten wir mal ab...

Otto123

Hast Du wegen Valetudo auch den Staubsauger Thread verfolgt? Ich meine dort mit gelesen zu haben, dass die Karte nur über einen Link verwendet wird. Und irgendwo anders ging es hier auch schon mal um die Verschickung von png Bildern über mqtt... Hilft Dir jetzt auch nicht :)
Viele Grüße aus Leipzig  ⇉  nächster Stammtisch an der Lindennaundorfer Mühle
RaspberryPi B B+ B2 B3 B3+ ZeroW,HMLAN,HMUART,Homematic,Fritz!Box 7590,WRT3200ACS-OpenWrt,Sonos,VU+,Arduino nano,ESP8266,MQTT,Zigbee,deconz

herrmannj

Aufbau: sehr gern! Bin auch erst vor 2-3 Wochen tiefer in mqtt eingestiegen und mache ganz andere Erfahrungen. Bin sehr begeistert, auch von Rudi s Implementierung. Ich denke der Staubsauger ist einfach ein blöder Einstieg ...

Vg joerg