eclipse / mosquitto

Eclipse Mosquitto - An open source MQTT broker
https://mosquitto.org
Other
8.89k stars 2.37k forks source link

Latest Release 1.5.5 - causes timeout errors #1085

Closed rwaynestronach closed 5 years ago

rwaynestronach commented 5 years ago

I have been using mosquitto on a raspberry-pi to get/send information out to a number of arduino nodes for about 3 years. It was easy to setup and has run continuously until a few days ago when I updated the Raspberry PI.

Mosquitto essentially stopped working. I added "socket_domain ipv4" to my .conf file as there seemed to an issue with ipv6/websockets.

I have tried adding a keepalive_interval setting, however this causes mosquitto to terminate. The problem seems to be that the client exceeds the timeout and disconnects. Sample from the log file below: Any ideas?

=====================================================

1545270405: New connection from 192.168.1.73 on port 1883. 1545270405: New client connected from 192.168.1.73 as MSB-RFM7 (c1, k15, u'meg8one1!'). 1545270405: No will message specified. 1545270405: Sending CONNACK to MSB-RFM7 (0, 0) 1545270407: Received SUBSCRIBE from MSB-RFM7 1545270407: home/rfm_gw/sb/# (QoS 0) 1545270407: MSB-RFM7 0 home/rfm_gw/sb/# 1545270407: Sending SUBACK to MSB-RFM7 1545270409: Received PUBLISH from MSB-RFM7 (d0, q0, r0, m0, 'home/rfm_gw/nb/node37/dev00', ... (9 bytes)) 1545270409: Sending PUBLISH to mosqsub|10876-OH32B (d0, q0, r0, m0, 'home/rfm_gw/nb/node37/dev00', ... (9 bytes)) 1545270409: Received PUBLISH from MSB-RFM7 (d0, q0, r0, m0, 'home/rfm_gw/nb/node37/dev02', ... (3 bytes)) 1545270409: Sending PUBLISH to mosqsub|10876-OH32B (d0, q0, r0, m0, 'home/rfm_gw/nb/node37/dev02', ... (3 bytes)) 1545270410: Received PUBLISH from MSB-RFM7 (d0, q0, r0, m0, 'home/rfm_gw/nb/node77/dev50', ... (4 bytes)) 1545270410: Sending PUBLISH to mosqsub|10876-OH32B (d0, q0, r0, m0, 'home/rfm_gw/nb/node77/dev50', ... (4 bytes)) 1545270414: Received PINGREQ from mosqsub|10876-OH32B 1545270414: Sending PINGRESP to mosqsub|10876-OH32B 1545270433: Client MSB-RFM7 has exceeded timeout, disconnecting.

ralight commented 5 years ago

Looking at your logs, everything looks good to me from the broker side.

This is the client connecting with a keepalive of 15 seconds:

1545270405: New connection from 192.168.1.73 on port 1883.
1545270405: New client connected from 192.168.1.73 as MSB-RFM7 (c1, k15, u'meg8one1!').

This is the last communication with the client:

1545270410: Received PUBLISH from MSB-RFM7 (d0, q0, r0, m0, 'home/rfm_gw/nb/node77/dev50', ... (4 bytes))

This is the client being disconnected by the broker:

1545270433: Client MSB-RFM7 has exceeded timeout, disconnecting.

The time between the last communication (....410) and the client being disconnected (....433) is 23 seconds. The broker will disconnect a client if the client doesn't communicate within keepalive*1.5. This client chose 15 seconds as its keepalive, so it has 22 seconds of leeway. At 23 seconds it is disconnected. I'm afraid it looks like everything is working as expected and your client isn't sending a PINGREQ or other message soon enough - or it needs to set a higher keepalive value.

rwaynestronach commented 5 years ago

Thanks Roger - I will have a good look at client :-)

rwaynestronach commented 5 years ago

Issue was a damaged arduino - hard to find as the spare unit also malfunctioned