Paho MQTT - Log says message published but nothing sent out

Question

I'm really struggling to get this basic concept to work, I've probably spent 15 hours on this one problem, the time spent searching for answers was full of useless contradictory information.

I've got a client-side process subscribed to MQTT topic, it reacts according to the type of message received. I'm then wanting to send back data to the shore-side process.

I've tried looping forever, start loop, no loop, on and on and ****ing on but the data is NOT appearing in MQTT Explorer (local port forward on 1883 to inspect live feed)

Code

Main

import os
import paho.mqtt.client as mqtt
import logging
import time
import lib.mqtt.mqtt_actions as mqtt_act
logging.basicConfig(level=logging.INFO, filename='/data/client.log', filemode='a+',format='%(asctime)s - %(name)s : %(levelname)s - %(message)s')

def main():
    client = mqtt.Client()
    client.tls_set(-setup tls certs-)
    client.on_connect = mqtt_act.on_connect
    client.on_message = mqtt_act.on_message
    client.on_log = mqtt_act.on_log
    client.connect(-connect to broker-)
    client.loop_forever()
    try:
     while True:
      time.sleep(1)
    except KeyboardInterrupt:
        client.loop_stop()

if __name__ == "__main__":
    main()

MQTT actions

import json
import logging
import time
import subprocess 
logger = logging.getLogger()
logger.setLevel(logging.INFO)    

def send_ack(client, _id):
    client.publish('a/topic/state_change', payload='{"id": "'+str(_id)+'","status": "START", "code": "003", "timestamp": "'+str(datetime.datetime.now())+'"}')
    logging.info("send ack")
    client.loop()

def on_log(client,userdata,level,buff):
    print(buff)

def on_connect(client, userdata, flags, rc):
        logging.info("Connected with return code: "+str(rc))
        # get some sort of identifier
        _id = get_id()
        client.subscribe('a/topic/'+_id+'/#')
def on_message(client, userdata, msg):
        _ = json.loads(msg.payload.decode())
        logging.info("Received message from master")
        if _['action'] == "test123":
            _id = _['id']
            logging.info("ID: "+str(_id))
            send_ack(client, _id)
            outcome = get_data()
            outcome['id'] = str(_id)
            try:
             client.publish("a/topic/endpoint/"+str(_id), str(outcome))
             client.loop()
            except Exception as e:
                logging.info(str(e))

Output

host:~$:/tmp/client_test# python3 listen.py 
Sending CONNECT (u0, p0, wr0, wq0, wf0, c1, k60) client_id=b''
Received CONNACK (0, 0)
Sending SUBSCRIBE (d0, m1) [(b'a/topic/222/#', 0)]
Received SUBACK
Received PUBLISH (d0, q0, r0, m0), 'a/topic/222/test123', ...  (89 bytes)
Sending PUBLISH (d0, q0, r0, m2), 'b'a/topic/endpoint/state_change'', ... (122 bytes)
Sending PUBLISH (d0, q0, r0, m3), 'b'a/topic/endpoint/64cb76fa-791b-11eb-bde4-005056ae7e22'', ... (2596 bytes)
Received PUBLISH (d0, q0, r0, m0), 'a/topic/222/test123', ...  (89 bytes)

What appears in MQTT Explorer

state_change
test123

You shouldn't be calling `client.loop()` anywhere if you've started `client.loop_forever()` or `client.loop_start()` — hardillb, Feb 27 '21 at 17:12
@hardillb - I believe I tried that earlier today and it hung on trying to send_ack(), will retry and confirm — Danny Watson, Feb 27 '21 at 17:25
@hardillb - yes, just tried removing all `client.loop()`, and it's hung on publishing the state change in `send_ack()` — Danny Watson, Feb 27 '21 at 17:27
@hardillb - this is what I mean about the contradictory information on the web, I don't want to have to wait for `on_message()` to finish otherwise the `send_ack()` is useless as it tells the shoreside that the client has received and is acting on an action, I therefore have to manually use `client.loop()` - what do you recommend ? — Danny Watson, Feb 27 '21 at 17:37
You should **NOT** be running long running tasks in the callbacks. I'd you have a long running task that should be handed off to a separate thread — hardillb, Feb 27 '21 at 19:02

Danny Watson · Answer 1 · 2021-02-28T16:20:58.380

So I took the advice given and set up threads, I also changed the loop_forever() to loop_start()

Main

import os
import paho.mqtt.client as mqtt
import logging
import time
import lib.mqtt.mqtt_actions as mqtt_act
logging.basicConfig(level=logging.INFO, filename='/data/client.log', filemode='a+',format='%(asctime)s - %(name)s : %(levelname)s - %(message)s')

def main():
    client = mqtt.Client()
    client.tls_set(-setup tls certs-)
    client.on_connect = mqtt_act.on_connect
    client.on_message = mqtt_act.on_message
    client.on_log = mqtt_act.on_log
    client.connect(-connect to broker-)
    client.loop_start()
    try:
     while True:
      time.sleep(1)
    except KeyboardInterrupt:
        client.loop_stop()

if __name__ == "__main__":
    main()

MQTT

import json
import logging
import time
import threading
import subprocess 
logger = logging.getLogger()
logger.setLevel(logging.INFO)    

def send_ack(client, _id):
    client.publish('a/topic/state_change', payload='{"id": "'+str(_id)+'","status": "START", "code": "003", "timestamp": "'+str(datetime.datetime.now())+'"}')
    logging.info("send ack")

def on_log(client,userdata,level,buff):
    print(buff)

def on_connect(client, userdata, flags, rc):
        logging.info("Connected with return code: "+str(rc))
        # get some sort of identifier
        _id = get_id()
        client.subscribe('a/topic/'+_id+'/#')
def on_message(client, userdata, msg):
        _ = json.loads(msg.payload.decode())
        logging.info("Received message from master")
        if _['action'] == "test123":
            _id = _['id']
            logging.info("ID: "+str(_id))
            send_ack(client, _id)
            t1 = threading.Thread(target=start_test, args=(_id, 5,client,), name='test_thread')
            t1.start()

def start_test(ID, int_a, client):
    outcome = get_data()
    outcome['id'] = ID
    data = json.dumps(outcome)
    try:
        client.publish("a/test/endpoint/"+str(outcome['id']), data)
    except Exception as e:
        logging.info(str(e))

Not if you use loop_start() as that will handle the keep alive messages on a background thread — hardillb, Feb 27 '21 at 19:00
@hardillb - OK, if you know the solution, provide a proper response and I'll review and mark as the answer otherwise I'll mark my own in a few days — Danny Watson, Feb 28 '21 at 15:00
@hardillb - I've updated this answer to fulfil your recommendations, can you review and confirm or advise? — Danny Watson, Feb 28 '21 at 15:29
You are still calling `get_data()` in the `on_message()` callback and calling the `client.loop()` in `send_ack()` — hardillb, Feb 28 '21 at 15:56
@hardillb - sorry I realised I had an error in this, I've removed the call to `get_data()` and moved the call into the thead func — Danny Watson, Feb 28 '21 at 16:21
@hardlib - any feedback would be appreciated, if you think the answer is sufficient, could you upvote it and I'll mark it as the answer — Danny Watson, Mar 09 '21 at 15:17

Paho MQTT - Log says message published but nothing sent out

1 Answers1