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

No PINGREQ with sim7000 #809

Open jaka87 opened 3 years ago

jaka87 commented 3 years ago

Hi. Im using your library (latest) together with tinygsmclient (also latest version) while using sim7000 module. In general it is working fine but i notice i get disconnects after few minutes of inactivity (about 5min). I checked my broker log (mosquito 1.5.7) and to my surprise i see almost none PINGREQ and responses while they should be pinged regularly.

I tried different settings with the same end result. Most of the time I was using keepalive 60s which i set directly in PubSubClient.h and i ran loop every 10 seconds.

Here is the log from both AT command from the module, and server. Any idea why this is happening or how to debug it further?

08:44:14.400 ->  speed:0 next:18 count:2
08:44:14.433 -> AT+CIPRXGET=4,0
08:44:15.428 -> AT+CIPSTATUS=0
08:44:15.461 -> 
08:44:15.494 -> +CIPSTATUS: 0,0,"TCP","81.4.106.172","1883","CONNECTED"
08:44:15.593 -> 
08:44:15.593 -> OK
08:44:15.593 -> AT+CIPRXGET=4,0
08:44:15.627 -> 
08:44:15.627 -> +CIPRXGET: 4,0,0
08:44:15.660 -> 
08:44:15.660 -> OK
08:44:15.660 -> AT+CIPSTATUS=0
08:44:15.693 -> 
08:44:15.693 -> +CIPSTATUS: 0,0,"TCP","81.4.106.172","1883","CONNECTED"
08:44:15.792 -> 
08:44:15.792 -> OK
08:44:15.792 -> MQTT loop1
08:44:15.825 -> 4
08:44:26.295 ->  speed:0 next:17 count:3
08:44:26.328 -> AT+CIPRXGET=4,0
08:44:27.322 -> AT+CIPSTATUS=0
08:44:27.322 -> 
08:44:27.355 -> +CIPSTATUS: 0,0,"TCP","81.4.106.172","1883","CONNECTED"
08:44:27.454 -> 
08:44:27.454 -> OK
08:44:27.454 -> AT+CIPRXGET=4,0
08:44:27.487 -> 
08:44:27.520 -> +CIPRXGET: 4,0,0
08:44:27.520 -> 
08:44:27.520 -> OK
08:44:27.520 -> AT+CIPSTATUS=0
08:44:27.553 -> 
08:44:27.587 -> +CIPSTATUS: 0,0,"TCP","81.4.106.172","1883","CONNECTED"
08:44:27.686 -> 
08:44:27.686 -> OK
08:44:27.686 -> MQTT loop1
08:44:27.686 -> 3
08:44:38.157 ->  speed:0 next:16 count:4
08:44:38.190 -> AT+CIPRXGET=4,0
08:44:39.184 -> AT+CIPSTATUS=0
08:44:39.217 -> 
08:44:39.217 -> +CIPSTATUS: 0,0,"TCP","81.4.106.172","1883","REMOTE CLOSING"
08:44:39.349 -> 
08:44:39.349 -> OK
08:44:39.349 -> AT+CIPCLOSE=0
08:44:39.382 -> 
08:44:39.382 -> 0, CLOSE OK
08:44:39.382 -> MQTT loop0
08:44:39.416 -> 4
08:44:49.884 ->  speed:0 next:15 count:5
08:44:49.917 -> AT+CIPRXGET=4,0
08:44:50.911 -> AT+CIPSTATUS=0
08:44:50.911 -> 
08:44:50.944 -> +CIPSTATUS: 0,0,"TCP","81.4.106.172","1883","CLOSED"
08:44:51.043 -> 
08:44:51.043 -> OK
08:44:51.043 -> MQTT loop0
08:44:51.043 -> 3
08:45:01.520 ->  speed:0 next:14 count:6
08:45:01.553 -> AT+CIPRXGET=4,0
08:45:02.547 -> AT+CIPSTATUS=0
08:45:02.580 -> 
08:45:02.580 -> +CIPSTATUS: 0,0,"TCP","81.4.106.172","1883","CLOSED"
08:45:02.680 -> 
Jan 04 08:43:35  mosquitto[3132766]: 1609746215: New connection from 46.123.249.230 on port 1883.
Jan 04 08:43:35  mosquitto[3132766]: 1609746215: New client connected from 46.123.249.230 as 865234031873176 (c1, k30, u'vetercek').
Jan 04 08:43:35  mosquitto[3132766]: 1609746215: No will message specified.
Jan 04 08:43:35  mosquitto[3132766]: 1609746215: Sending CONNACK to 865234031873176 (0, 0)
Jan 04 08:43:36  mosquitto[3132766]: 1609746216: Received SUBSCRIBE from 865234031873176
Jan 04 08:43:36  mosquitto[3132766]: 1609746216:         get/865234031873176 (QoS 0)
Jan 04 08:43:36  mosquitto[3132766]: 1609746216: 865234031873176 0 get/865234031873176
Jan 04 08:43:36  mosquitto[3132766]: 1609746216: Sending SUBACK to 865234031873176
Jan 04 08:43:52  mosquitto[3132766]: 1609746232: Received PUBLISH from 865234031873176 (d0, q0, r0, m0, 'ws', ... (61 bytes))
Jan 04 08:44:37  mosquitto[3132766]: 1609746277: Client 865234031873176 has exceeded timeout, disconnecting.
Jan 04 08:44:37  mosquitto[3132766]: 1609746277: Socket error on client 865234031873176, disconnecting.
knolleary commented 3 years ago

Are you calling the loop function of the client object regularly?

jaka87 commented 3 years ago

Yes about every 10s. In the first part of the log "MQTT loop" is where this function is called

knolleary commented 3 years ago

The broker log shows a socket error, not a keepalive timeout. So the ping handling isn't relevant to whatever is causing the client to disconnect.

Not sure what to suggest. Never used the sim7000 so have no sense of what can cause it to drop connections.

jaka87 commented 3 years ago

Actualy I get both of them. If increase the frequency of sending data below 5min i get no problems...

Jan 04 18:19:56  mosquitto[3132766]: 1609780796: Client 865234031873176 has exceeded timeout, disconnecting.
Jan 04 18:19:56  mosquitto[3132766]: 1609780796: Socket error on client 865234031873176, disconnecting.