I see unexpected delays when running MQTT sample. The issue seems to be network related. When connecting delay is "normal" but after a few seconds roundtrip delay increases. Probably network related? Using Telia in Sweden.
2020-01-28 09:07:04.386316 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [.], ack 22, win 29200, length 0 2020-01-28 09:07:04.386642 IP 10.1.0.21.1883 > 193.181.245.212.40707: Flags [FP.], seq 39:41, ack 52, win 29200, length 2 2020-01-28 09:07:04.386751 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 1:5, ack 22, win 29200, length 4 2020-01-28 09:07:05.018045 IP 193.181.245.194.34634 > 10.1.0.21.1883: Flags [.], ack 10, win 4239, length 0 2020-01-28 09:07:06.068864 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 10:39, ack 50, win 29200, length 29 2020-01-28 09:07:06.226137 IP 193.181.245.194.34634 > 10.1.0.21.1883: Flags [P.], seq 50:75, ack 39, win 4210, length 25 2020-01-28 09:07:06.264280 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [.], ack 75, win 29200, length 0 2020-01-28 09:07:06.372303 IP 193.181.245.194.34634 > 10.1.0.21.1883: Flags [P.], seq 75:79, ack 39, win 4210, length 4 2020-01-28 09:07:06.372336 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [.], ack 79, win 29200, length 0 2020-01-28 09:07:06.372463 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 39:43, ack 79, win 29200, length 4 2020-01-28 09:07:06.772095 IP 193.181.245.194.34634 > 10.1.0.21.1883: Flags [.], ack 43, win 4206, length 0 2020-01-28 09:07:07.368346 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 43:72, ack 79, win 29200, length 29 2020-01-28 09:07:07.506123 IP 193.181.245.194.34634 > 10.1.0.21.1883: Flags [P.], seq 79:104, ack 72, win 4177, length 25 2020-01-28 09:07:07.544271 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [.], ack 104, win 29200, length 0 2020-01-28 09:07:07.658183 IP 193.181.245.194.34634 > 10.1.0.21.1883: Flags [P.], seq 104:108, ack 72, win 4177, length 4 2020-01-28 09:07:07.658222 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [.], ack 108, win 29200, length 0 2020-01-28 09:07:07.658303 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 72:76, ack 108, win 29200, length 4 2020-01-28 09:07:08.376324 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 72:76, ack 108, win 29200, length 4 2020-01-28 09:07:09.820274 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 72:76, ack 108, win 29200, length 4 2020-01-28 09:07:12.708309 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 72:76, ack 108, win 29200, length 4 2020-01-28 09:07:18.484299 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 72:76, ack 108, win 29200, length 4 2020-01-28 09:07:23.332201 IP 193.181.245.194.34634 > 10.1.0.21.1883: Flags [.], ack 76, win 4173, length 0 2020-01-28 09:07:23.332244 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 76:105, ack 108, win 29200, length 29 2020-01-28 09:07:23.506144 IP 193.181.245.194.34634 > 10.1.0.21.1883: Flags [P.], seq 108:133, ack 105, win 4144, length 25 2020-01-28 09:07:23.544256 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [.], ack 133, win 29200, length 0 2020-01-28 09:07:23.652238 IP 193.181.245.194.34634 > 10.1.0.21.1883: Flags [P.], seq 133:137, ack 105, win 4144, length 4 2020-01-28 09:07:23.652270 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [.], ack 137, win 29200, length 0 2020-01-28 09:07:23.652349 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 105:109, ack 137, win 29200, length 4 2020-01-28 09:07:23.812136 IP 193.181.245.194.34634 > 10.1.0.21.1883: Flags [.], ack 109, win 4140, length 0 2020-01-28 09:07:26.006977 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 109:138, ack 137, win 29200, length 29 2020-01-28 09:07:26.138150 IP 193.181.245.194.34634 > 10.1.0.21.1883: Flags [P.], seq 137:162, ack 138, win 4111, length 25 2020-01-28 09:07:26.176304 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [.], ack 162, win 29200, length 0 2020-01-28 09:07:26.292114 IP 193.181.245.194.34634 > 10.1.0.21.1883: Flags [P.], seq 162:166, ack 138, win 4111, length 4 2020-01-28 09:07:26.292160 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [.], ack 166, win 29200, length 0 2020-01-28 09:07:26.292288 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 138:142, ack 166, win 29200, length 4 2020-01-28 09:07:26.532227 IP 193.181.245.194.34634 > 10.1.0.21.1883: Flags [.], ack 142, win 4107, length 0 2020-01-28 09:07:29.011125 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 142:171, ack 166, win 29200, length 29 2020-01-28 09:07:29.592270 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 142:171, ack 166, win 29200, length 29 2020-01-28 09:07:30.764299 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 142:171, ack 166, win 29200, length 29 2020-01-28 09:07:33.108265 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 142:171, ack 166, win 29200, length 29 2020-01-28 09:07:37.796318 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 142:171, ack 166, win 29200, length 29 2020-01-28 09:07:47.172264 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 142:171, ack 166, win 29200, length 29 2020-01-28 09:08:05.924282 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [P.], seq 142:171, ack 166, win 29200, length 29 2020-01-28 09:08:39.972991 IP 193.181.245.194.34634 > 10.1.0.21.1883: Flags [P.], seq 166:168, ack 142, win 4107, length 2 2020-01-28 09:08:40.012260 IP 10.1.0.21.1883 > 193.181.245.194.34634: Flags [.], ack 168, win 29200, length 0
A TCP trace shows lots of retries:
[2020-01-28 09:05:12.327492] tests/subscribe/topic test [2020-01-28 09:07:06.069478] tests/subscribe/topic test [2020-01-28 09:07:06.372625] tests/publish/topic test [2020-01-28 09:07:07.368836] tests/subscribe/topic test [2020-01-28 09:07:07.658487] tests/publish/topic test [2020-01-28 09:07:08.659070] tests/subscribe/topic test [2020-01-28 09:07:23.652455] tests/publish/topic test [2020-01-28 09:07:26.007115] tests/subscribe/topic test [2020-01-28 09:07:26.292424] tests/publish/topic test [2020-01-28 09:07:29.011263] tests/subscribe/topic test
Any idea whats going on here?
The MQTT simple sample startedLTE Link Connecting ...+CEREG: 2,"0093","018D2B20",7,0,0,"11100000","11100000"+CEREG: 5,"0093","018D2B20",7,,,"11100000","11100000"LTE Link Connected!AT+COPS=3,2OKAT+COPS?+COPS: 0,2,"24001",7OKAT%XCBAND%XCBAND: 20OKAT+CGDCONT?IPv4 Address found 91.106.198.236+CGDCONT: 0,"IP","lpwa.telia.iot","10.81.186.2",0,0OKAT+CGACT?+CGACT: 0,1OK[mqtt_evt_handler:190] MQTT client connected!Subscribing to: tests/subscribe/topic len 21[mqtt_evt_handler:240] SUBACK packet id: 1234[mqtt_evt_handler:205] MQTT PUBLISH result=0 len=4Received: testPublishing: testto topic: tests/publish/topic len: 19[mqtt_evt_handler:230] PUBACK packet id: 50480[mqtt_evt_handler:205] MQTT PUBLISH result=0 len=4Received: testPublishing: testto topic: tests/publish/topic len: 19[mqtt_evt_handler:230] PUBACK packet id: 26790[mqtt_evt_handler:205] MQTT PUBLISH result=0 len=4Received: testPublishing: testto topic: tests/publish/topic len: 19[mqtt_evt_handler:230] PUBACK packet id: 25677[mqtt_evt_handler:205] MQTT PUBLISH result=0 len=4Received: testPublishing: testto topic: tests/publish/topic len: 19[mqtt_evt_handler:230] PUBACK packet id: 48551