calvinmclean/automated-garden

MQTT or WiFi disconnect on controller

calvinmclean opened this issue · 4 comments

calvinmclean commented

MQTT logs after plugging controller in:

2023-01-26T22:55:34: New connection from 10.42.0.1:24331 on port 1883.
2023-01-26T22:55:34: New client connected from 10.42.0.1:24331 as seed-garden (p2, c0, k15).

Based on logs it looks like it was being disconnected due to conflict? Now I am no longer messing with different controllers so maybe it is a non-issue. I will keep an eye on it and check logs if it fails again.

So far this has not reproduced, probably since I haven't been configuring any other controllers, but I should still make sure the controller code supports wifi reconnect and MQTT reconnect.

calvinmclean commented

New logs (first 2 lines are from previous log):

2023-01-26T22:55:34: New connection from 10.42.0.1:24331 on port 1883.
2023-01-26T22:55:34: New client connected from 10.42.0.1:24331 as seed-garden (p2, c0, k15).
2023-01-28T17:00:17: Client seed-garden closed its connection.
2023-01-28T17:00:32: New connection from 10.42.0.1:26582 on port 1883.
2023-01-28T17:00:32: New client connected from 10.42.0.1:26582 as seed-garden (p2, c0, k15).
2023-01-29T18:21:15: Client seed-garden has exceeded timeout, disconnecting.
2023-01-29T18:21:20: New connection from 10.42.0.1:7686 on port 1883.
2023-01-29T18:21:20: New client connected from 10.42.0.1:7686 as seed-garden (p2, c0, k15).
2023-01-29T18:32:45: Client seed-garden has exceeded timeout, disconnecting.
2023-01-29T18:33:00: New connection from 10.42.0.1:57851 on port 1883.
2023-01-29T18:33:00: New client connected from 10.42.0.1:57851 as seed-garden (p2, c0, k15).
2023-01-29T18:34:09: Client seed-garden has exceeded timeout, disconnecting.

I did not run any other microcontrollers in this time that could have taken over the connection.

calvinmclean commented

More logs:

2023-01-30T06:35:51: New connection from 10.42.0.1:35660 on port 1883.
2023-01-30T06:35:51: New client connected from 10.42.0.1:35660 as seed-garden (p2, c0, k15).
2023-01-30T16:27:20: New connection from 10.42.0.1:5043 on port 1883.
2023-01-30T16:27:20: Client seed-garden already connected, closing old connection.
2023-01-30T16:27:20: New client connected from 10.42.0.1:5043 as seed-garden (p2, c0, k15).
2023-01-30T17:26:05: New connection from 10.42.0.1:53873 on port 1883.
2023-01-30T17:26:05: Client seed-garden already connected, closing old connection.
2023-01-30T17:26:05: New client connected from 10.42.0.1:53873 as seed-garden (p2, c0, k15).
2023-01-30T17:28:45: Client seed-garden has exceeded timeout, disconnecting.
2023-01-30T17:28:50: New connection from 10.42.0.1:39754 on port 1883.
2023-01-30T17:28:50: New client connected from 10.42.0.1:39754 as seed-garden (p2, c0, k15).
2023-01-30T17:30:25: New connection from 10.42.0.1:8402 on port 1883.
2023-01-30T17:30:25: Client seed-garden already connected, closing old connection.
2023-01-30T17:30:25: New client connected from 10.42.0.1:8402 as seed-garden (p2, c0, k15).
2023-01-31T15:40:27: Client seed-garden has exceeded timeout, disconnecting.
2023-01-31T15:40:29: New connection from 10.42.0.1:30574 on port 1883.
2023-01-31T15:40:29: New client connected from 10.42.0.1:30574 as seed-garden (p2, c0, k15).
2023-02-01T12:03:21: Client seed-garden has exceeded timeout, disconnecting.

Then one log showing reconnect after I unplug and plug the device back in:

2023-02-01T14:50:13: New connection from 10.42.0.1:59205 on port 1883.
2023-02-01T14:50:13: New client connected from 10.42.0.1:59205 as seed-garden (p2, c0, k15).
calvinmclean commented

Still an issue with keep-alive interval set on MQTT Client. It looks this time the ESP32 disconnected from WiFi and remains disconnected.

calvinmclean commented

With MQTT debug logs, I can see that the controller is connecting, subscribing, sending keep-alive pings, publishing health data. This happens multiple times, showing that the controller is restarting, which I might assume is due to WiFi disconnect but I cannot confirm that. Currently the device is not on my WiFi network.

2023-02-06T00:20:45: Sending CONNACK to seed-garden (1, 0)
2023-02-06T00:20:45: Received SUBSCRIBE from seed-garden
2023-02-06T00:20:45: 	seed-garden/command/water (QoS 1)
2023-02-06T00:20:45: Sending SUBACK to seed-garden
2023-02-06T00:20:45: Received SUBSCRIBE from seed-garden
2023-02-06T00:20:45: 	seed-garden/command/stop (QoS 1)
2023-02-06T00:20:45: Sending SUBACK to seed-garden
2023-02-06T00:20:45: Received SUBSCRIBE from seed-garden
2023-02-06T00:20:45: 	seed-garden/command/stop_all (QoS 1)
2023-02-06T00:20:45: Sending SUBACK to seed-garden
2023-02-06T00:20:45: Received SUBSCRIBE from seed-garden
2023-02-06T00:20:45: 	seed-garden/command/light (QoS 1)
2023-02-06T00:20:45: Sending SUBACK to seed-garden
2023-02-06T00:20:46: Received PUBLISH from seed-garden (d0, q0, r0, m0, 'seed-garden/data/logs', ... (47 bytes))
2023-02-06T00:20:46: Sending PUBLISH to Telegraf-Consumer-LcOeq (d0, q0, r0, m0, 'seed-garden/data/logs', ... (47 bytes))
2023-02-06T00:21:01: Received PINGREQ from seed-garden
2023-02-06T00:21:01: Sending PINGRESP to seed-garden
2023-02-06T00:21:16: Received PINGREQ from seed-garden
2023-02-06T00:21:16: Sending PINGRESP to seed-garden
2023-02-06T00:21:31: Received PINGREQ from seed-garden
2023-02-06T00:21:31: Sending PINGRESP to seed-garden
2023-02-06T00:21:45: Received PUBLISH from seed-garden (d0, q0, r0, m0, 'seed-garden/data/health', ... (27 bytes))
2023-02-06T00:21:45: Sending PUBLISH to Telegraf-Consumer-LcOeq (d0, q0, r0, m0, 'seed-garden/data/health', ... (27 bytes))