eclipse-paho / eclipse-paho/paho.mqtt.python

Roundtrips take at least 40ms or are not in the right order when publishing in subscribe

Open
#874 4 comments 0 reactions 0 assignees View on GitHub
Status: Available
Dominant language
Python
Stars
2.4k
Forks
742
Avg merge
12d 48m
Merged PRs (30d)
1

Description

# Bug Description

I need to respond to a received message by publishing another message.
I do not need QoS, but I do need to have the correct message ordering.

In when using an agent-based tool [mango-agents](https://github.com/OFFIS-DAI/mango), round trip time of MQTT connections is always at least 40ms - even when using QoS=0

An example of this is shown in https://github.com/OFFIS-DAI/mango/issues/142

I tried reproducing this with plain paho-mqtt and got that far:

This does work with QoS = 1 set, in which case it takes 40ms for each roundtrip.
(I see that QoS=1 itself has a roundtrip, though this does not explain 40ms of waiting).
With QoS=0, the messages are not received in the correct order.
Adding `wait_for_publish` deadlocks the application.
Usage of the Threadpool did not help either.

```python
# python 3.11-3.13
import logging
import random
from multiprocessing.pool import ThreadPool

import paho.mqtt.client as paho

logger = logging.getLogger(__name__)

myQOS = 1
broker = "localhost"
port = 1883
topic = "python/mqtt"
# Generate a Client ID with the publish prefix.
client_id = f"publish-{random.randint(0, 1000)}"

pool = ThreadPool(processes=4)

def connect_mqtt(topic):
def on_connect(client, userdata, flags, rc, pa):
if rc == 0:
logger.info("Connected to MQTT Broker!")
else:
logger.error("Failed to connect, return code %d\n", rc)

def thread_publish(client, topic, payload):
info = client.publish("no topic", payload, qos=myQOS)
# wait for publish does deadlock here
#info.wait_for_publish()

def on_message(client, userdata, message: paho.MQTTMessage):
logger.info("got message %s", message.payload)
# create a thread pool where we submit the publishing
# and wait for the result
pool.apply(thread_publish, args=(client, topic, message.payload))
#info = client.publish("no topic", message.payload, qos=myQOS)

client = paho.Client(paho.CallbackAPIVersion.VERSION2, client_id)
client.on_connect = on_connect
client.on_message = on_message
client.connect(broker, port)
client.subscribe(topic)

return client

def publish(client, topic, max_count=100):
msg_count = 1
while True:
msg = f"messages: {msg_count}"
result = client.publish(topic, msg, qos=myQOS)
result.wait_for_publish()
# result: [0, 1]
status = result[0]
if status == 0:
logger.info("Send `%s` to topic `%s`", msg, topic)
else:
print(f"Failed to send message to topic {topic}")
msg_count += 1
if msg_count > max_count:
break

def run():
client = connect_mqtt(topic)
client.loop_start()
#client.subscribe("no topic")

publish(client, topic)

# this helps when QoS is 0 to wait until all is received
import time
time.sleep(1)

client.loop_stop()

if __name__ == "__main__":
logging.basicConfig(format="%(asctime)s;%(levelname)s;%(message)s", level="INFO")
run()
```

# Reproduction

*Please provide detailed steps showing how to replicate the issue (it's difficult to fix an issue we cannot replicate).
If errors are output then include the full error (including any stack trace).*
*Most issues should include a [minimal example](https://stackoverflow.com/help/minimal-reproducible-example) that
demonstrates the issue (ideally one that can be run without modification, i.e. runnable code using a public broker).*

# Environment

* Python version: 3.12.6 (any of 3.11-3.13 has this issue)
* Library version: 2.1.0
* Operating system (including version): Debian 13, trixie
* MQTT server (name, version, configuration, hosting details): local mosquitto, dockerized:

```
listener 1883
allow_anonymous true

max_keepalive 3600
```

# Logs

For many issues, especially when you cannot provide code to replicate the issue, it's helpful to include logs. Please
consider including:
* library logs; see [the readme](https://github.com/eclipse/paho.mqtt.python#enable_logger) and [logger example](https://github.com/eclipse/paho.mqtt.python/blob/master/examples/client_logger.py).
* broker logs (availability will depend the server in use)

```
2024-12-01 22:37:06,386;INFO;Connected to MQTT Broker!
2024-12-01 22:37:06,386;INFO;got message b'1'
2024-12-01 22:37:06,387;INFO;got message b'messages: 1'
2024-12-01 22:37:06,387;INFO;Send `messages: 1` to topic `python/mqtt`
2024-12-01 22:37:06,430;INFO;got message b'messages: 2'
2024-12-01 22:37:06,431;INFO;Send `messages: 2` to topic `python/mqtt`
2024-12-01 22:37:06,431;INFO;got message b'messages: 3'
2024-12-01 22:37:06,432;INFO;Send `messages: 3` to topic `python/mqtt`
2024-12-01 22:37:06,478;INFO;got message b'messages: 4'
2024-12-01 22:37:06,480;INFO;Send `messages: 4` to topic `python/mqtt`
2024-12-01 22:37:06,481;INFO;got message b'messages: 5'
2024-12-01 22:37:06,482;INFO;Send `messages: 5` to topic `python/mqtt`
2024-12-01 22:37:06,530;INFO;got message b'messages: 6'
2024-12-01 22:37:06,532;INFO;Send `messages: 6` to topic `python/mqtt`
2024-12-01 22:37:06,533;INFO;got message b'messages: 7'
2024-12-01 22:37:06,535;INFO;Send `messages: 7` to topic `python/mqtt`
2024-12-01 22:37:06,578;INFO;got message b'messages: 8'
2024-12-01 22:37:06,580;INFO;Send `messages: 8` to topic `python/mqtt`
2024-12-01 22:37:06,581;INFO;got message b'messages: 9'
2024-12-01 22:37:06,582;INFO;Send `messages: 9` to topic `python/mqtt`
2024-12-01 22:37:06,626;INFO;got message b'messages: 10'
2024-12-01 22:37:06,628;INFO;Send `messages: 10` to topic `python/mqtt`
2024-12-01 22:37:06,629;INFO;got message b'messages: 11'
2024-12-01 22:37:06,631;INFO;Send `messages: 11` to topic `python/mqtt`
2024-12-01 22:37:06,674;INFO;got message b'messages: 12'
2024-12-01 22:37:06,676;INFO;Send `messages: 12` to topic `python/mqtt`
2024-12-01 22:37:06,677;INFO;got message b'messages: 13'
2024-12-01 22:37:06,679;INFO;Send `messages: 13` to topic `python/mqtt`
2024-12-01 22:37:06,722;INFO;got message b'messages: 14'
2024-12-01 22:37:06,724;INFO;Send `messages: 14` to topic `python/mqtt`
2024-12-01 22:37:06,725;INFO;got message b'messages: 15'
2024-12-01 22:37:06,727;INFO;Send `messages: 15` to topic `python/mqtt`
2024-12-01 22:37:06,770;INFO;got message b'messages: 16'
2024-12-01 22:37:06,772;INFO;Send `messages: 16` to topic `python/mqtt`
2024-12-01 22:37:06,773;INFO;got message b'messages: 17'
2024-12-01 22:37:06,775;INFO;Send `messages: 17` to topic `python/mqtt`
2024-12-01 22:37:06,822;INFO;got message b'messages: 18'
2024-12-01 22:37:06,824;INFO;Send `messages: 18` to topic `python/mqtt`
2024-12-01 22:37:06,825;INFO;got message b'messages: 19'
2024-12-01 22:37:06,827;INFO;Send `messages: 19` to topic `python/mqtt`
2024-12-01 22:37:06,870;INFO;got message b'messages: 20'
2024-12-01 22:37:06,872;INFO;Send `messages: 20` to topic `python/mqtt`
2024-12-01 22:37:06,873;INFO;got message b'messages: 21'
2024-12-01 22:37:06,874;INFO;Send `messages: 21` to topic `python/mqtt`
2024-12-01 22:37:06,918;INFO;got message b'messages: 22'
2024-12-01 22:37:06,920;INFO;Send `messages: 22` to topic `python/mqtt`
2024-12-01 22:37:06,921;INFO;got message b'messages: 23'
2024-12-01 22:37:06,922;INFO;Send `messages: 23` to topic `python/mqtt`
2024-12-01 22:37:06,966;INFO;got message b'messages: 24'
2024-12-01 22:37:06,968;INFO;Send `messages: 24` to topic `python/mqtt`
2024-12-01 22:37:06,969;INFO;got message b'messages: 25'
2024-12-01 22:37:06,970;INFO;Send `messages: 25` to topic `python/mqtt`
2024-12-01 22:37:07,014;INFO;got message b'messages: 26'
2024-12-01 22:37:07,015;INFO;Send `messages: 26` to topic `python/mqtt`
2024-12-01 22:37:07,017;INFO;got message b'messages: 27'
2024-12-01 22:37:07,018;INFO;Send `messages: 27` to topic `python/mqtt`
2024-12-01 22:37:07,062;INFO;got message b'messages: 28'
2024-12-01 22:37:07,064;INFO;Send `messages: 28` to topic `python/mqtt`
2024-12-01 22:37:07,065;INFO;got message b'messages: 29'
2024-12-01 22:37:07,067;INFO;Send `messages: 29` to topic `python/mqtt`
2024-12-01 22:37:07,110;INFO;got message b'messages: 30'
2024-12-01 22:37:07,111;INFO;Send `messages: 30` to topic `python/mqtt`
2024-12-01 22:37:07,113;INFO;got message b'messages: 31'
2024-12-01 22:37:07,114;INFO;Send `messages: 31` to topic `python/mqtt`
2024-12-01 22:37:07,158;INFO;got message b'messages: 32'
2024-12-01 22:37:07,160;INFO;Send `messages: 32` to topic `python/mqtt`
2024-12-01 22:37:07,161;INFO;got message b'messages: 33'
2024-12-01 22:37:07,162;INFO;Send `messages: 33` to topic `python/mqtt`
2024-12-01 22:37:07,210;INFO;got message b'messages: 34'
2024-12-01 22:37:07,211;INFO;Send `messages: 34` to topic `python/mqtt`
2024-12-01 22:37:07,212;INFO;got message b'messages: 35'
2024-12-01 22:37:07,214;INFO;Send `messages: 35` to topic `python/mqtt`
2024-12-01 22:37:07,258;INFO;got message b'messages: 36'
2024-12-01 22:37:07,260;INFO;Send `messages: 36` to topic `python/mqtt`
2024-12-01 22:37:07,261;INFO;got message b'messages: 37'
2024-12-01 22:37:07,262;INFO;Send `messages: 37` to topic `python/mqtt`
2024-12-01 22:37:07,310;INFO;got message b'messages: 38'
2024-12-01 22:37:07,312;INFO;Send `messages: 38` to topic `python/mqtt`
2024-12-01 22:37:07,313;INFO;got message b'messages: 39'
2024-12-01 22:37:07,315;INFO;Send `messages: 39` to topic `python/mqtt`
2024-12-01 22:37:07,358;INFO;got message b'messages: 40'
2024-12-01 22:37:07,360;INFO;Send `messages: 40` to topic `python/mqtt`
2024-12-01 22:37:07,361;INFO;got message b'messages: 41'
2024-12-01 22:37:07,362;INFO;Send `messages: 41` to topic `python/mqtt`
2024-12-01 22:37:07,406;INFO;got message b'messages: 42'
2024-12-01 22:37:07,408;INFO;Send `messages: 42` to topic `python/mqtt`
2024-12-01 22:37:07,409;INFO;got message b'messages: 43'
2024-12-01 22:37:07,410;INFO;Send `messages: 43` to topic `python/mqtt`
2024-12-01 22:37:07,454;INFO;got message b'messages: 44'
2024-12-01 22:37:07,456;INFO;Send `messages: 44` to topic `python/mqtt`
2024-12-01 22:37:07,457;INFO;got message b'messages: 45'
2024-12-01 22:37:07,458;INFO;Send `messages: 45` to topic `python/mqtt`
2024-12-01 22:37:07,502;INFO;got message b'messages: 46'
2024-12-01 22:37:07,504;INFO;Send `messages: 46` to topic `python/mqtt`
2024-12-01 22:37:07,505;INFO;got message b'messages: 47'
2024-12-01 22:37:07,507;INFO;Send `messages: 47` to topic `python/mqtt`
2024-12-01 22:37:07,554;INFO;got message b'messages: 48'
2024-12-01 22:37:07,556;INFO;Send `messages: 48` to topic `python/mqtt`
2024-12-01 22:37:07,557;INFO;got message b'messages: 49'
2024-12-01 22:37:07,558;INFO;Send `messages: 49` to topic `python/mqtt`
2024-12-01 22:37:07,602;INFO;got message b'messages: 50'
2024-12-01 22:37:07,603;INFO;Send `messages: 50` to topic `python/mqtt`
2024-12-01 22:37:07,604;INFO;got message b'messages: 51'
2024-12-01 22:37:07,606;INFO;Send `messages: 51` to topic `python/mqtt`
2024-12-01 22:37:07,650;INFO;got message b'messages: 52'
2024-12-01 22:37:07,652;INFO;Send `messages: 52` to topic `python/mqtt`
2024-12-01 22:37:07,653;INFO;got message b'messages: 53'
2024-12-01 22:37:07,654;INFO;Send `messages: 53` to topic `python/mqtt`
2024-12-01 22:37:07,698;INFO;got message b'messages: 54'
2024-12-01 22:37:07,699;INFO;Send `messages: 54` to topic `python/mqtt`
2024-12-01 22:37:07,700;INFO;got message b'messages: 55'
2024-12-01 22:37:07,702;INFO;Send `messages: 55` to topic `python/mqtt`
2024-12-01 22:37:07,746;INFO;got message b'messages: 56'
2024-12-01 22:37:07,747;INFO;Send `messages: 56` to topic `python/mqtt`
2024-12-01 22:37:07,749;INFO;got message b'messages: 57'
2024-12-01 22:37:07,750;INFO;Send `messages: 57` to topic `python/mqtt`
2024-12-01 22:37:07,794;INFO;got message b'messages: 58'
2024-12-01 22:37:07,796;INFO;Send `messages: 58` to topic `python/mqtt`
2024-12-01 22:37:07,797;INFO;got message b'messages: 59'
2024-12-01 22:37:07,799;INFO;Send `messages: 59` to topic `python/mqtt`
2024-12-01 22:37:07,842;INFO;got message b'messages: 60'
2024-12-01 22:37:07,844;INFO;Send `messages: 60` to topic `python/mqtt`
2024-12-01 22:37:07,845;INFO;got message b'messages: 61'
2024-12-01 22:37:07,846;INFO;Send `messages: 61` to topic `python/mqtt`
2024-12-01 22:37:07,894;INFO;got message b'messages: 62'
2024-12-01 22:37:07,896;INFO;Send `messages: 62` to topic `python/mqtt`
2024-12-01 22:37:07,897;INFO;got message b'messages: 63'
2024-12-01 22:37:07,898;INFO;Send `messages: 63` to topic `python/mqtt`
2024-12-01 22:37:07,942;INFO;got message b'messages: 64'
2024-12-01 22:37:07,944;INFO;Send `messages: 64` to topic `python/mqtt`
2024-12-01 22:37:07,944;INFO;got message b'messages: 65'
2024-12-01 22:37:07,946;INFO;Send `messages: 65` to topic `python/mqtt`
2024-12-01 22:37:07,990;INFO;got message b'messages: 66'
2024-12-01 22:37:07,992;INFO;Send `messages: 66` to topic `python/mqtt`
2024-12-01 22:37:07,993;INFO;got message b'messages: 67'
2024-12-01 22:37:07,994;INFO;Send `messages: 67` to topic `python/mqtt`
2024-12-01 22:37:08,038;INFO;got message b'messages: 68'
2024-12-01 22:37:08,040;INFO;Send `messages: 68` to topic `python/mqtt`
2024-12-01 22:37:08,041;INFO;got message b'messages: 69'
2024-12-01 22:37:08,042;INFO;Send `messages: 69` to topic `python/mqtt`
2024-12-01 22:37:08,086;INFO;got message b'messages: 70'
2024-12-01 22:37:08,088;INFO;Send `messages: 70` to topic `python/mqtt`
2024-12-01 22:37:08,089;INFO;got message b'messages: 71'
2024-12-01 22:37:08,091;INFO;Send `messages: 71` to topic `python/mqtt`
2024-12-01 22:37:08,134;INFO;got message b'messages: 72'
2024-12-01 22:37:08,135;INFO;Send `messages: 72` to topic `python/mqtt`
2024-12-01 22:37:08,137;INFO;got message b'messages: 73'
2024-12-01 22:37:08,138;INFO;Send `messages: 73` to topic `python/mqtt`
2024-12-01 22:37:08,182;INFO;got message b'messages: 74'
2024-12-01 22:37:08,183;INFO;Send `messages: 74` to topic `python/mqtt`
2024-12-01 22:37:08,184;INFO;got message b'messages: 75'
2024-12-01 22:37:08,186;INFO;Send `messages: 75` to topic `python/mqtt`
2024-12-01 22:37:08,234;INFO;got message b'messages: 76'
2024-12-01 22:37:08,236;INFO;Send `messages: 76` to topic `python/mqtt`
2024-12-01 22:37:08,237;INFO;got message b'messages: 77'
2024-12-01 22:37:08,238;INFO;Send `messages: 77` to topic `python/mqtt`
2024-12-01 22:37:08,282;INFO;got message b'messages: 78'
2024-12-01 22:37:08,283;INFO;Send `messages: 78` to topic `python/mqtt`
2024-12-01 22:37:08,284;INFO;got message b'messages: 79'
2024-12-01 22:37:08,286;INFO;Send `messages: 79` to topic `python/mqtt`
2024-12-01 22:37:08,334;INFO;got message b'messages: 80'
2024-12-01 22:37:08,335;INFO;Send `messages: 80` to topic `python/mqtt`
2024-12-01 22:37:08,336;INFO;got message b'messages: 81'
2024-12-01 22:37:08,338;INFO;Send `messages: 81` to topic `python/mqtt`
2024-12-01 22:37:08,386;INFO;got message b'messages: 82'
2024-12-01 22:37:08,388;INFO;Send `messages: 82` to topic `python/mqtt`
2024-12-01 22:37:08,389;INFO;got message b'messages: 83'
2024-12-01 22:37:08,390;INFO;Send `messages: 83` to topic `python/mqtt`
2024-12-01 22:37:08,434;INFO;got message b'messages: 84'
2024-12-01 22:37:08,436;INFO;Send `messages: 84` to topic `python/mqtt`
2024-12-01 22:37:08,437;INFO;got message b'messages: 85'
2024-12-01 22:37:08,438;INFO;Send `messages: 85` to topic `python/mqtt`
2024-12-01 22:37:08,482;INFO;got message b'messages: 86'
2024-12-01 22:37:08,483;INFO;Send `messages: 86` to topic `python/mqtt`
2024-12-01 22:37:08,485;INFO;got message b'messages: 87'
2024-12-01 22:37:08,486;INFO;Send `messages: 87` to topic `python/mqtt`
2024-12-01 22:37:08,534;INFO;got message b'messages: 88'
2024-12-01 22:37:08,535;INFO;Send `messages: 88` to topic `python/mqtt`
2024-12-01 22:37:08,537;INFO;got message b'messages: 89'
2024-12-01 22:37:08,539;INFO;Send `messages: 89` to topic `python/mqtt`
2024-12-01 22:37:08,582;INFO;got message b'messages: 90'
2024-12-01 22:37:08,583;INFO;Send `messages: 90` to topic `python/mqtt`
2024-12-01 22:37:08,584;INFO;got message b'messages: 91'
2024-12-01 22:37:08,586;INFO;Send `messages: 91` to topic `python/mqtt`
2024-12-01 22:37:08,630;INFO;got message b'messages: 92'
2024-12-01 22:37:08,632;INFO;Send `messages: 92` to topic `python/mqtt`
2024-12-01 22:37:08,633;INFO;got message b'messages: 93'
2024-12-01 22:37:08,634;INFO;Send `messages: 93` to topic `python/mqtt`
2024-12-01 22:37:08,678;INFO;got message b'messages: 94'
2024-12-01 22:37:08,679;INFO;Send `messages: 94` to topic `python/mqtt`
2024-12-01 22:37:08,681;INFO;got message b'messages: 95'
2024-12-01 22:37:08,682;INFO;Send `messages: 95` to topic `python/mqtt`
2024-12-01 22:37:08,726;INFO;got message b'messages: 96'
2024-12-01 22:37:08,728;INFO;Send `messages: 96` to topic `python/mqtt`
2024-12-01 22:37:08,729;INFO;got message b'messages: 97'
2024-12-01 22:37:08,730;INFO;Send `messages: 97` to topic `python/mqtt`
2024-12-01 22:37:08,778;INFO;got message b'messages: 98'
2024-12-01 22:37:08,780;INFO;Send `messages: 98` to topic `python/mqtt`
2024-12-01 22:37:08,781;INFO;got message b'messages: 99'
2024-12-01 22:37:08,783;INFO;Send `messages: 99` to topic `python/mqtt`
2024-12-01 22:37:08,826;INFO;got message b'messages: 100'
2024-12-01 22:37:08,827;INFO;Send `messages: 100` to topic `python/mqtt`
```

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.