Neues MQTT Plugin

[gklein]

Danke für die Erläuterung, ich stelle mal das Logging entsprechend ein und schaue was beim nächsten Disconnect so auftaucht

Schönen Abend
Gunnar

[gklein]

Hallo zusammen,

mein Fehler ist wieder aufgetaucht. Hier mal das Log dazu:

23-07-15 12:21:20 CEST DEBUG    __init__          modules.mqtt.paho_client _get_caller_type: inspect.stack()[2][1] = '/usr/local/smarthome/lib/model/mqttplugin.py', split = ['', 'usr', 'local', 'smarthome', 'lib', 'model', 'mqttplugin.py']  --  (__init__.py:_get_caller_type:743)
2023-07-15 12:21:20 CEST INFO     __init__          modules.mqtt.paho_client 'publish_topic()' - called from Plugin by 'publish_topic()'  --  (__init__.py:publish_topic:773)
2023-07-15 12:21:20 CEST INFO     __init__          modules.mqtt.paho_client Plugin 'tasmota' is publishing topic 'cmnd/gosund7/teleperiod' with payload '15' (qos=1, retain=False)  --  (__init__.py:publish_topic:781)
2023-07-15 12:21:20 CEST DEBUG    __init__          modules.mqtt.paho_client cast_to_mqtt: data = '15', type(data) = '<class 'int'>', bool_values ='None'  --  (__init__.py:cast_to_mqtt:870)
2023-07-15 12:21:20 CEST DEBUG    __init__          modules.mqtt.paho_client _on_log: Sending PUBLISH (d0, q1, r0, m20032), 'b'cmnd/gosund7/teleperiod'', ... (2 bytes)  --  (__init__.py:_on_mqtt_log:597)
2023-07-15 12:21:20 CEST INFO     __init__          modules.mqtt.paho_client Plugin 'tasmota' has published topic 'cmnd/gosund7/teleperiod' with payload '15'  --  (__init__.py:publish_topic:785)
2023-07-15 12:21:20 CEST DEBUG    __init__          modules.mqtt.paho_client _on_log: Received PUBACK (Mid: 20032)  --  (__init__.py:_on_mqtt_log:597)
2023-07-15 12:21:20 CEST DEBUG    __init__          modules.mqtt.paho_client _on_log: Received PUBLISH (d0, q0, r0, m0), 'tele/gosund7/STATE', ...  (318 bytes)  --  (__init__.py:_on_mqtt_log:597)
2023-07-15 12:21:20 CEST DEBUG    __init__          modules.mqtt.paho_client _on_mqtt_message: RECEIVED topic 'tele/gosund7/STATE', payload 'b'{"Time":"2023-07-15T11:21:19","Uptime":"55T02:10:11","UptimeSec":4759811,"Vcc":3.405,"Heap":28,"SleepMode":"Dynamic","Sleep":50\xfe\x01\x00\x13tele/gosund7/SENSOR{"Time":"2023-07-15T11:21:19","ENERGY":{"TotalStartTime":"2022-02-25T21:34:59","Total":219.881,"Yesterday":0.581,"Today":0.038,"Period": 0,"Power":94,"ApparentPower":94', QoS '0', retain '0'  --  (__init__.py:_on_mqtt_message:533)
2023-07-15 12:21:20 CEST DEBUG    __init__          modules.mqtt.paho_client _on_mqtt_message: subscription 'tasmota-5': {'subscriber_type': 'plugin', 'callback': <bound method Tasmota.on_mqtt_message of <plugins.tasmota.Tasmota object at 0x7fa8f423d880>>, 'payload_type': 'dict', 'bool_values': None}  --  (__init__.py:_on_mqtt_message:560)
2023-07-15 12:21:20 CEST ERROR    __init__          modules.mqtt.paho_client _on_log: Caught exception in on_message: 'utf-8' codec can't decode byte 0xfe in position 127: invalid start byte  --  (__init__.py:_on_mqtt_log:595)
​

Danach kommt kein einziger Log-Eintrag vom paho_client mehr. Sieht für mich also mausetot aus.

Viele Grüße
Gunnar

[bmx]

Naja das hier

"Sleep":50\xfe\x01\x00\x13tele/gosund7/SENSOR{"Time":"2023-07-15T11:21:19","ENERGY":

sieht für mich nicht wirklich wohlgeformt aus. Die Frage wäre wo das herkommt. Im Client könnte man vermutlich an der Stelle einfach alles verwerfen was empfangen wurde und dann weitermachen...

[gklein]

die Nachricht kommt von einer Gosund-Steckdose, geflasht mit Tasmota - Warum auch immer

Ich habe mal versucht den Code im Plugin zu verstehen und hätte sonst testweise mal ein zusätzliches "try / catch" drumrum gebaut, scheitere aber daran die richtige Stelle zu finden. Vermutung wäre in df_on_mqtt_messager ab Zeile 524 in _init_.py

def _on_mqtt_message(self, client, userdata, message):
        """
        Callback function to handle received messages for items and logics

Viele Grüße
Gunnar

[Msinn]

Da wirst Du im Plugin nichts finden. Die Exception wird (wie Du am Namen des Loggers 'modules.mqtt.paho_client' bereits sehen kannst) bereits im paho_client ausgelöst und gefangen. Im Plugin kommt deshalb nichts an, was Du mit try/except (es gibt in Python kein 'catch') abfangen könntest.

Wie hast Du das Item denn definiert, in das die Daten eingelesen werden sollen?

[gklein]

Hi,

mqtt wird implizit über das tasmota-Plugin genutzt. Die Steckdose selbst ist über Tasmota-Atrribute konfiguriert.
Ich kann damit leben wenn die Nachricht verworfen wird, der mqtt-Connect sollte halt nicht komplett auf die Bretter gehen.

Danke und VG

  Gosund5:
            type: bool
            tasmota_topic: gosund5
            tasmota_attr: online

            Schalter:
                type: bool
                tasmota_topic: ..:.
                tasmota_attr: relay
                enforce_updates: true
                ## mqtt_topic_out ??

                uzsu:
                    type: dict
                    uzsu_item: Haus.Zentral.Gosund5.Schalter
                    cache: 'true'

            Leistung:
                tasmota_topic: ..:.
                tasmota_attr: power
                type: num

            Spannung:
                tasmota_topic: ..:.
                type: num
                tasmota_attr: voltage

​
             Strom:
                tasmota_topic: ..:.
                type: num
                tasmota_attr: current

            Energy_total:
                type: num
                tasmota_topic: ..:.
                tasmota_attr: power_total

            Energy_yesterday:
                type: num
                tasmota_topic: ..:.
                tasmota_attr: power_yesterday

            Energy_today:
                type: num
                tasmota_topic: ..:.
                tasmota_attr: power_today
                database: true
                database_maxage: 730

​

[Msinn]

Das MQTT Protokoll sieht eigentlich vor (zumindest in Protokollversion 3.x), dass die Payload ein Array of Byte ist. Das Tasmota Plugin liest (soweit isch das sehe) die Daten in ein dict ein und erwartet daher, dass die Payload im JSON Format vorliegt. Bei der Rückgabe an das tasmota Plugin findet eine JSON Wandlung in ein dict statt. Wo und wie die erfolgt, kann ich im Moment nicht sagen. Dazu kenne ich das tasmota Plugin zu wenig und das Logging des paho_clients verhindert, dass ich an die Daten der Exception komme, die mir sonst den Aufruf Stack des Python Codes loggen kann.

Ich muss mal sehen, wie wir an zusätzliche Informationen zu Deinem Problem kommen können.

Ich verstehe das aber richtig, dass das Problem "nur" der Error-Log Eintrag ist und die Message verworfen wird. Später folgende Messages werden dann aber weiter korrekt verarbeitet, oder?

[Msinn]

Da Dein Problem nichts mit dem MQTT Plugin zu tun hat, sollten wir die Diskussion evtl. in den Support Thread fom Tasmota Plugin verschieben. Was meinst Du?

[gklein]

Hallo @Msinn,

ja, wir können das gerne dahin verlagern.
Wenn ich es momentan aus den Logs richtig sehe:
Tasmota/MQTT läuft normal, bis die fehlerhafte Payload kommt. Die Nachricht führt aus meiner derzeitigen Sicht dazu, dass der MQTT-Stack von SmarthomeNG vermutlich selber abbricht. SHNG versucht auch noch MQTT-Message zu erzeugen, die gehen aber nicht mehr raus (dewesgen hab ich das überhaupt bemerkt).

Hier wäre mal das Log kurz nach dem aufgetreteten Fehler oben (SMLX -> MQTT)

2023-07-15 12:21:22 CEST INFO     __init__          Haus.Zentral.Strom_Haushalt.Bezug.Total-eval 'publish_topic()' - called from Plugin by 'publish_topic()'  --  (__init__.py:publish_topic:773)
2023-07-15 12:21:22 CEST INFO     __init__          Haus.Zentral.Strom_Haushalt.Bezug.Total-eval Plugin 'mqtt' is publishing topic 'sgm-c8/energy' with payload '5073.73' (qos=1, retain=True)  --  (__init__.py:publish_topic:781)
2023-07-15 12:21:22 CEST DEBUG    __init__          Haus.Zentral.Strom_Haushalt.Bezug.Total-eval cast_to_mqtt: data = '5073.73', type(data) = '<class 'float'>', bool_values ='None'  --  (__init__.py:cast_to_mqtt:870)
2023-07-15 12:21:22 CEST DEBUG    __init__          Haus.Zentral.Strom_Haushalt.Bezug.Total-eval _on_log: Sending PUBLISH (d0, q1, r1, m20033), 'b'sgm-c8/energy'', ... (7 bytes)  --  (__init__.py:_on_mqtt_log:597)
2023-07-15 12:21:22 CEST INFO     __init__          [B]Haus.Zentral.Strom_Haushalt.Bezug.Total-eval Plugin 'mqtt' has published topic 'sgm-c8/energy' with payload '5073.73'  --  (__init__.py:publish_topic:785)
--> kommt nicht mehr im MQTT-Broker an[/B]

2023-07-15 12:21:22 CEST DEBUG    __init__          plugins.smlx.Smlx _get_caller_type: inspect.stack()[2][1] = '/usr/local/smarthome/lib/model/mqttplugin.py', split = ['', 'usr', 'local', 'smarthome', 'lib', 'model', 'mqttplugin.py']  --  (__init__.py:_get_caller_type:743)
2023-07-15 12:21:22 CEST INFO     __init__          plugins.smlx.Smlx 'publish_topic()' - called from Plugin by 'publish_topic()'  --  (__init__.py:publish_topic:773)
2023-07-15 12:21:22 CEST INFO     __init__          plugins.smlx.Smlx Plugin 'mqtt' is publishing topic 'sgm-c8/power' with payload '-5927' (qos=1, retain=True)  --  (__init__.py:publish_topic:781)
2023-07-15 12:21:22 CEST DEBUG    __init__          plugins.smlx.Smlx cast_to_mqtt: data = '-5927', type(data) = '<class 'int'>', bool_values ='None'  --  (__init__.py:cast_to_mqtt:870)
​

Ob noch was empfangen wird, kann ich nicht 100%-ig sagen, würde aber sagen nein, da im Log bis zum Restart keine Messages von Gosund mehr auftauchen. Passt soweit auch zusammen, da ja entweder Verbindung oder Module weg sind.

Viele Grüße

PS: Ich bin ab morgen für 2 Wochen offline. Falls noch mehr Logs/Infos notwendig sein sollten.

[Sisamiwe]

gklein
Kannst du den Fehler erzwingen?

Wenn ja, starte mal shNG im Debug Mode aus der Konsole und schau dort mal nach einer entsprechenden Fehlermeldung.

[gklein]

Hallo Sisamiwe,

ich habe heute mal ein wenig experimentiert, bisher leider erfolglos. Ich kann die Nachricht zwar in den Broker schicken, aber vom paho_client wird sie dann mit Fehler abgefangen - was ja erstmal gut ist:

023-08-06 17:14:20 CEST ERROR    __init__          modules.mqtt.paho_client cast_from_mqtt: datatype 'dict', error 'Expecting ',' delimiter: line 1 column 128 (char 127)', data = ‘{"Time":"2023-08-06T15:48:22","Uptime":"28T00:40:46","UptimeSec":2421646,"Vcc":3.472,"Heap":29,"SleepMode":"Dynamic","[B]Sleep":50\xfe\x01\x00[/B]\x13tele/gosund7/SENSOR{"Time":"2023-07-15T11:21:19","ENERGY":{"TotalStartTime":"2022-02-25T21:34:59","Total":219.881,"Yesterday":0.581,"Today":0.038,"Period": 0,"Power":94,"ApparentPower":94, QoS '0', retain '0'

Was mir dabei aber aufgefallen ist - die fehlerhafte Meldung scheint abgeschnitten zu sein und hat dann direkt die Folgemessage angehängt.

altes Log:
ECEIVED topic 'tele/gosund7/STATE', payload 'b'{"Time":"2023-07-15T11:21:19","Uptime":"55T02:10:11","UptimeSec":4759811,"Vcc":3.405,"Heap":28,"SleepMode":"Dynamic","Sleep":50\xfe\x01\x00\x13

--> hier fehlt eigentlich was, stattdessen geht es direkt hiermit weiter

tele/gosund7/SENSOR{"Time":"2023-07-15T11:21:19","ENERGY":{"TotalStartTime":"2022-02-25T21:34:59","Total":219.881,"Yesterday":0.581,"Today":0.038,"Period": 0,"Power":94,"ApparentPower":94', QoS '0', retain '0'  --  (__init__.py:_on_mqtt_message:533)​

so muss es eigentlich aussehen

tele/gosund7/STATE {"Time":"2023-08-06T15:39:13","Uptime":"77T06:28:05","UptimeSec":6676085,"Vcc":3.402,"Heap":30,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":405,"POWER":"ON","Wifi":{"AP":1,"SSId":"unify","BSSId":"xxxxxxxxxx","Channel":13,"Mode":"11n","RSSI":58,"Signal":-71,"LinkCount":391,"Downtime":"0T06:27:40"}}

tele/gosund7/SENSOR {"Time":"2023-08-06T15:39:13","ENERGY":{"TotalStartTime":"2022-02-25T21:34:59","Total":227.404,"Yesterday":0.000,"Today":0.404,"Period": 0,"Power":115,"ApparentPower":134,"ReactivePower":69,"Factor":0.86,"Voltage":226,"Current":0.594}}
​

Lässt sich sowas ggf. abfangen?

Viele Grüße
Gunnar

[lexxmm]

Hallo

Umstellung von 1.4.6 auf 2.0.5 funktioniert meine zweite mqtt instanze nicht mehr.

mqtt:
    plugin_name: mqtt

mqttwb:
    plugin_name: mqtt
    instance: mqttwb
    host: 192.168.10.110

​

mqtt empfängt nur und mqttwb schickt nur raus (topic out). Das hat bisher immer funktioniert. Leider gibt es auch keine Fehlermeldung...nur:

2023-09-26  11:26:39 INFO     plugins.mqtt        mqttwb@: publish_topic: Item 'Wirkleistung.openWB' -> topic 'openWB/set/evu/W', payload '9', QoS 'None', retain 'False'

Jemand eine Idee?

EDIT: Problem jetzt doch allein gefunden (Wechsel von Plugin auf Modul)...Lösung bzgl. openWB im openWB Forum gefunden. mqtt bridge erforderlich

[lexxmm]

Leider doch noch ein Problem mit mqtt nach Umstellung auf 2.0.5 gefunden...

          
name: jk1_soc
            type: num
            database@mysqldb: init
            mqtt_topic_in: jk1/Data/Percent_Remain
            mqtt_topic_out: 'openWB/set/houseBattery/%Soc'
​

setze ich den das item manuell auf einen Wert, so geht die mqtt message (mqtt_topic_out) korrekt raus. kommt es über mqtt_topic_in rein, geht es jedoch nicht raus...sollte das nicht in einem item so funktionieren?

[lexxmm]

Kann da niemand etwas zu sagen? Geht mqtt_topic_in und mqtt_topic_out gleichzeitig nicht in einem Item?

[Onkelandy]

Probier es mal mit nem Hilfsitem und on_change/update