knolleary / pubsubclient

A client library for the Arduino Ethernet Shield that provides support for MQTT.
http://pubsubclient.knolleary.net/
MIT License
3.78k stars 1.46k forks source link

state() is reporting -3 and -4 when the broker sees the device as connected! #1010

Open papakpmartin opened 1 year ago

papakpmartin commented 1 year ago

On ESP32, I have code for which Wi-Fi and MQTT are working perfectly reliably in one task, but in another task the m_mqttClient.connect(…) call hangs until MQTT_SOCKET_TIMEOUT, at which point it tries again and never succeeds. Here is some debug:

SETUP::begin_setup()
COMMS: About to connect
WIFI: Connecting
WIFI: Status: 6
WIFI: Connecting...
WIFI: CONNECTED
MQTT: Beginning connection
MQTT: Server: ▊▊▊▊▊▊▊:11883
MQTT: connect(▊▊▊▊▊▊▊, ▊▊▊▊▊▊▊, ▊▊▊▊▊▊▊)
WIFI: Status: 3
MQTT: State: -3
MQTT: CLIENT NOT CONNECTED
WIFI: Status: 3
MQTT: State: -4
WIFI: Is connected
MQTT: m_mqttClient.disconnect()
MQTT: State: -1
MQTT: CLIENT NOT CONNECTED
WIFI: Status: 3
MQTT: State: -4
WIFI: Is connected
MQTT: m_mqttClient.disconnect()
MQTT: State: -1

However, at every MQTT: State: -3 and/or MQTT: State: -4 I can see from the mosquitto logs that the device is indeed connected:

0: New connection from 192.1.1.178:52799 on port 11883.
0: Client 58:CF:79:A0:10:DA already connected, closing old connection.
0: New client connected from 192.1.1.178:52799 as 58:CF:79:A0:10:DA (p2, c1, k15, u'▊▊▊▊▊▊▊▊').
0: Client 58:CF:79:A0:10:DA closed its connection.
0: New connection from 192.1.1.178:52800 on port 11883.
0: New client connected from 192.1.1.178:52800 as 58:CF:79:A0:10:DA (p2, c1, k15, u'▊▊▊▊▊▊▊▊').
0: Client 58:CF:79:A0:10:DA closed its connection.
0: New connection from 192.1.1.178:52800 on port 11883.
0: New client connected from 192.1.1.178:52800 as 58:CF:79:A0:10:DA (p2, c1, k15, u'▊▊▊▊▊▊▊▊').

In the “working perfectly” case, it looks like this:

COMMS: About to connect
WIFI: Connecting
WIFI: Status: 6
WIFI: Connecting...
WIFI: CONNECTED
MQTT: Beginning connection
MQTT: Server: ▊▊▊▊▊▊▊:11883
MQTT: connect(▊▊▊▊▊▊▊, ▊▊▊▊▊▊▊, ▊▊▊▊▊▊▊)
WIFI: Status: 3
MQTT: State: -1
MQTT: Connected to broker: ▊▊▊▊▊▊▊:11883
MQTT: Subscribe to `foo/bar/bat` successful
[mqttcallback] Message arrived [foo/bar/bat] 5
COMMS: Disconnecting from Wi-Fi and MQTT broker
WIFI: Disconnecting from Wi-Fi
COMMS: Disconnection complete

Project looks like this:

main.cpp            // set up and runs FreeRTOS tasks
Comms.hpp/cpp       // Wi-Fi and MQTT, and also OTA update
Setup.hpp/cpp       // Device setup which use MQTT pub/sub

For the connection that works reliably, a task in main.cpp calls the Comms.connect() which connects to both Wi-Fi and MQTT and then I set the callback in the task like Comms::instance().m_mqttClient.setCallback(mqtt_callback);.

For the one that is failing, a task in main.cpp calls Setup.begin(), and it's within Setup.begin() that Comms.connect() and setCallback() are done. In this case, the callback is a method of Setup.

The two connections never try to run at the same time.

Why would a connected client think it's not connected? Am I misusing something?

papakpmartin commented 1 year ago

Digging around here in this project, I did notice this comment on a feature that you decided not to do, and I was indeed using a member function for the callback, but i switched it to a lambda with no change in symptoms.