This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

nrf9160 MQTT delay / network problem?

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

Parents
  • I had a meeting with Telia yesterday to discuss this issue. According to them the RLC relase timeout is set to 5 seconds. PDP Context timeout is set to 60 minutes. This issue with intermittent connection failure and latency remains unsolved. We will probably have to move to another LTE-M chip for our project.

    As for now it also seems like LTE-M is in a very early stage in Sweden. NB-IoT has good coverage and is working. LTE-M has good coverage but Telia is still, according to them, evaluating network settings and parameters.

  • I am sorry to hear that you have had a bad experience with the network, but the issue does most likely not lie in the nRF9160 SiP.
    If you switched to another LTE-M chip you would most probably see that the issue persists since this is most likely an issue on the network site.

    I would first recommend you to try connecting to another operator at your location since that seems to have helped other developers with the same issue.

  • I can confirm that when I switch from Telia to Telenor (using the same hardware and the same SIM card from iBasis) the problem is gone. RTT delay for MQTT messages within Telenor is about 300 - 500 ms. Using Telia client to server delay is more about 15 seconds and server to client not possible at all. Messages server to client could sometimes be delivered upon next transmission from client to server.

    SAMPLE SESSION TELIA
    
    [2020-01-30 13:37:20.47]< *** Booting Zephyr OS version 2.1.0  ***
    [2020-01-30 13:37:20.57]< The MQTT simple sample started
    [2020-01-30 13:37:20.58]< LTE Link Connecting ...
    AT+COPS=1,2,"24001"   manually chose Telia
    [2020-01-30 13:37:23.134]> AT+COPS=1,2,"24001"
    [2020-01-30 13:37:23.163]< +CEREG: 2,"FFFE","FFFFFFFF",7,0,0,"11100000","11100000"
    [2020-01-30 13:37:27.814]< +CEREG: 2,"0093","018D2820",7,0,0,"11100000","11100000"
    [2020-01-30 13:37:30.507]< OK
    [2020-01-30 13:37:30.512]< +CEREG: 5,"0093","018D2820",7,,,"11100000","11100000"
    [2020-01-30 13:37:30.539]< LTE Link Connected!
    [2020-01-30 13:37:30.540]< client_init
    [2020-01-30 13:37:30.683]< IPv4 Address found **************
    [2020-01-30 13:37:30.686]< mqtt_connect
    [2020-01-30 13:37:31.44]< [mqtt_evt_handler:181] MQTT client connected!
    [2020-01-30 13:37:31.52]< Subscribing to: tests/subscribe/topic len 21
    [2020-01-30 13:37:31.269]< [mqtt_evt_handler:231] SUBACK packet id: 1234
    AT+COPS?
    [2020-01-30 13:37:39.850]> AT+COPS?
    [2020-01-30 13:37:39.857]< +COPS: 1,2,"24001",7
    [2020-01-30 13:37:39.857]< OK
    AT%XSYSTEMMODE?
    [2020-01-30 13:37:44.666]> AT%XSYSTEMMODE?
    [2020-01-30 13:37:44.674]< %XSYSTEMMODE: 1,0,0,0
    [2020-01-30 13:37:44.674]< OK
    AT%XCBAND
    [2020-01-30 13:37:50.462]> AT%XCBAND
    [2020-01-30 13:37:50.470]< %XCBAND: 20
    [2020-01-30 13:37:50.470]< OK
    AT+CGDCONT?
    [2020-01-30 13:37:55.294]> AT+CGDCONT?
    [2020-01-30 13:37:55.307]< +CGDCONT: 0,"IP","ibasis.iot","10.160.248.194",0,0
    [2020-01-30 13:37:55.308]< OK
    AT+CESQ
    [2020-01-30 13:38:02.188]> AT+CESQ
    [2020-01-30 13:38:02.195]< +CESQ: 99,99,255,255,5,31
    [2020-01-30 13:38:02.196]< OK
    AT+CGSN
    [2020-01-30 13:38:11.92]> AT+CGSN
    [2020-01-30 13:38:11.98]< ***************
    [2020-01-30 13:38:11.99]< OK
    AT+CGMI
    [2020-01-30 13:38:19.858]> AT+CGMI
    [2020-01-30 13:38:19.864]< Nordic Semiconductor ASA
    [2020-01-30 13:38:19.865]< OK
    AT+CGMM
    [2020-01-30 13:38:25.650]> AT+CGMM
    [2020-01-30 13:38:25.657]< nRF9160-SICA
    [2020-01-30 13:38:25.657]< OK
    AT+CGMR
    [2020-01-30 13:38:31.26]> AT+CGMR
    [2020-01-30 13:38:31.33]< mfw_nrf9160_1.1.0
    [2020-01-30 13:38:31.34]< OK
    [2020-01-30 13:38:41.241]< +CEREG: 5,"0324","018D2920",7,,,"11100000","11100000"
    AT+CIMI
    [2020-01-30 13:39:06.288]> AT+CIMI
    [2020-01-30 13:39:06.294]< ***************
    [2020-01-30 13:39:06.294]< OK
    AT+CGSN
    [2020-01-30 13:39:16.810]> AT+CGSN
    [2020-01-30 13:39:16.816]< ******************
    [2020-01-30 13:39:16.817]< OK
    AT+CGSN=1
    [2020-01-30 13:39:22.882]> AT+CGSN=1
    [2020-01-30 13:39:22.889]< +CGSN: "*********************"
    [2020-01-30 13:39:22.890]< OK
    [2020-01-30 13:39:37.597]< button_handler
    [2020-01-30 13:39:37.600]< Publishing: button handler
    [2020-01-30 13:39:37.612]< to topic: tests/publish/topic len: 19  MQTT message generated at device
    
    [2020-01-30 13:39:52.052063] tests/publish/topic button handler  message arrives at MQTT broker, delay 15 s
    
    [2020-01-30 13:39:52.136]< [mqtt_evt_handler:221] PUBACK packet id: 58103
    [2020-01-30 13:39:57.948]< button_handler
    [2020-01-30 13:39:57.950]< Publishing: button handler
    [2020-01-30 13:39:57.955]< to topic: tests/publish/topic len: 19  MQTT message generated at device
    
    [2020-01-30 13:40:06.850188] tests/publish/topic button handler  message arrives at MQTT broker, delay 9 s
    
    [2020-01-30 13:40:06.923]< [mqtt_evt_handler:221] PUBACK packet id: 4061
    
    [2020-01-30 13:40:24.718005] tests/subscribe/topic test  MQTT message generated at server
    
    [2020-01-30 13:41:15.794]< button_handler
    [2020-01-30 13:41:15.796]< Publishing: button handler
    [2020-01-30 13:41:15.799]< to topic: tests/publish/topic len: 19  MQTT message generated at device
    
    [2020-01-30 13:41:18.289871] tests/publish/topic button handler  message arrives at MQTT broker, delay 3 s
    
    [2020-01-30 13:41:34.972]< button_handler
    [2020-01-30 13:41:34.974]< Publishing: button handler
    [2020-01-30 13:41:34.980]< to topic: tests/publish/topic len: 19  MQTT message generated at device
    
    
    [2020-01-30 13:41:42.576]< [mqtt_evt_handler:196] MQTT PUBLISH result=0 len=4  MQTT message 13:40:24.718005 arrives at device, delay 78 s
    [2020-01-30 13:41:42.579]< Received: test
    [2020-01-30 13:41:42.581]< Publishing: test
    [2020-01-30 13:41:42.612]< to topic: tests/publish/topic len: 19  MQTT message generated at device
    
    [2020-01-30 13:41:42.713264] tests/publish/topic button handler  message 13:41:34.980 arrives at MQTT broker, delay 8 s
    
    [2020-01-30 13:41:42.713350] tests/publish/topic test  message 13:41:34.980 arrives at MQTT broker, delay 0.1 s, RTT 78.1 s
    
    [2020-01-30 13:41:42.815]< [mqtt_evt_handler:221] PUBACK packet id: 64592
    
    [2020-01-30 13:41:42.877461] tests/subscribe/topic test  MQTT message generated at server
    
    [2020-01-30 13:41:43.427]< [mqtt_evt_handler:221] PUBACK packet id: 37673
    [2020-01-30 13:41:43.435]< [mqtt_evt_handler:221] PUBACK packet id: 24755
    [2020-01-30 13:41:43.440]< [mqtt_evt_handler:196] MQTT PUBLISH result=0 len=4  MQTT message arrives at device, delay 1 s
    [2020-01-30 13:41:43.443]< Received: test
    [2020-01-30 13:41:43.444]< Publishing: test
    [2020-01-30 13:41:43.452]< to topic: tests/publish/topic len: 19
    
    [2020-01-30 13:41:43.809424] tests/publish/topic test  message 13:41:34.980 arrives at MQTT broker, delay 0.1 s, RTT 1s
    
    [2020-01-30 13:41:43.972]< [mqtt_evt_handler:221] PUBACK packet id: 53118
    [2020-01-30 13:42:19.639]< +CEREG: 5,"0093","018D2B20",7,,,"11100000","11100000"
    [2020-01-30 13:42:21.515]< +CEREG: 5,"0324","018D2920",7,,,"11100000","11100000"
    
    

    SAMPLE SESSION TELENOR:
    
    [2020-01-30 13:43:51.811]< *** Booting Zephyr OS version 2.1.0  ***
    [2020-01-30 13:43:51.821]< The MQTT simple sample started
    [2020-01-30 13:43:51.841]< LTE Link Connecting ...
    AT+COPS=1,2,"24008"   manually chose Telenor
    [2020-01-30 13:43:57.159]> AT+COPS=1,2,"24008"
    [2020-01-30 13:43:57.186]< +CEREG: 2,"FFFE","FFFFFFFF",7,0,0,"11100000","11100000"
    [2020-01-30 13:44:00.419]< +CEREG: 2,"2EE0","01AE9B0B",7,0,0,"11100000","11100000"
    [2020-01-30 13:44:04.569]< +CEREG: 5,"2EE0","01AE9B0B",7,,,"11100000","11100000"
    [2020-01-30 13:44:04.572]< LTE Link Connected!
    [2020-01-30 13:44:04.621]< client_init
    [2020-01-30 13:44:04.621]< OK
    [2020-01-30 13:44:05.2]< IPv4 Address found 91.106.198.236
    [2020-01-30 13:44:05.4]< mqtt_connect
    [2020-01-30 13:44:05.275]< [mqtt_evt_handler:181] MQTT client connected!
    [2020-01-30 13:44:05.281]< Subscribing to: tests/subscribe/topic len 21
    [2020-01-30 13:44:05.476]< [mqtt_evt_handler:231] SUBACK packet id: 1234
    [2020-01-30 13:44:15.863]< button_handler
    [2020-01-30 13:44:15.865]< Publishing: button handler
    [2020-01-30 13:44:15.876]< to topic: tests/publish/topic len: 19
    
    [2020-01-30 13:44:16.242521] tests/publish/topic button handler  message arrives at MQTT broker, delay 0.4 s
    
    [2020-01-30 13:44:16.281]< [mqtt_evt_handler:221] PUBACK packet id: 8904
    [2020-01-30 13:44:25.943]< button_handler
    [2020-01-30 13:44:25.947]< Publishing: button handler
    [2020-01-30 13:44:25.949]< to topic: tests/publish/topic len: 19
    
    [2020-01-30 13:44:26.483625] tests/publish/topic button handler  message arrives at MQTT broker, delay 0.5 s
    
    [2020-01-30 13:44:26.520]< [mqtt_evt_handler:221] PUBACK packet id: 11575
    
    [2020-01-30 13:44:32.471463] tests/subscribe/topic test  MQTT message generated at server
    
    [2020-01-30 13:44:32.517]< [mqtt_evt_handler:196] MQTT PUBLISH result=0 len=4   MQTT message arrives at device, delay 0.1 s
    [2020-01-30 13:44:32.519]< Received: test
    [2020-01-30 13:44:32.520]< Publishing: test
    [2020-01-30 13:44:32.527]< to topic: tests/publish/topic len: 19  MQTT message generated at device
    
    [2020-01-30 13:44:32.879250] tests/publish/topic test  message arrives at MQTT broker, delay 0.4 s, RTT 0.5s
    
    [2020-01-30 13:44:32.916]< [mqtt_evt_handler:221] PUBACK packet id: 30462
    [2020-01-30 13:44:44.148]< button_handler
    [2020-01-30 13:44:44.151]< Publishing: button handler
    [2020-01-30 13:44:44.183]< to topic: tests/publish/topic len: 19
    [2020-01-30 13:44:44.761]< [mqtt_evt_handler:221] PUBACK packet id: 18290
    [2020-01-30 13:44:50.426]< [mqtt_evt_handler:196] MQTT PUBLISH result=0 len=4
    [2020-01-30 13:44:50.427]< Received: test
    [2020-01-30 13:44:50.428]< Publishing: test
    [2020-01-30 13:44:50.445]< to topic: tests/publish/topic len: 19
    [2020-01-30 13:44:50.841]< [mqtt_evt_handler:221] PUBACK packet id: 27424
    AT+COPS?
    [2020-01-30 13:44:59.204]> AT+COPS?
    [2020-01-30 13:44:59.219]< +COPS: 1,2,"24008",7
    [2020-01-30 13:44:59.220]< OK
    AT%XSYSTEMMODE?
    [2020-01-30 13:45:11.351]> AT%XSYSTEMMODE?
    [2020-01-30 13:45:11.367]< %XSYSTEMMODE: 1,0,0,0
    [2020-01-30 13:45:11.371]< OK
    AT%XCBAND
    [2020-01-30 13:45:16.112]> AT%XCBAND
    [2020-01-30 13:45:16.127]< %XCBAND: 20
    [2020-01-30 13:45:16.128]< OK
    AT+CGDCONT?
    [2020-01-30 13:45:24.296]> AT+CGDCONT?
    [2020-01-30 13:45:24.315]< +CGDCONT: 0,"IP","IBASIS.IOT","10.160.250.251",0,0
    [2020-01-30 13:45:24.319]< OK
    AT+CESQ
    [2020-01-30 13:45:29.960]> AT+CESQ
    [2020-01-30 13:45:29.967]< +CESQ: 99,99,255,255,21,47
    [2020-01-30 13:45:29.968]< OK
    AT+CGMI
    [2020-01-30 13:45:36.340]> AT+CGMI
    [2020-01-30 13:45:36.355]< Nordic Semiconductor ASA
    [2020-01-30 13:45:36.356]< OK
    AT+CGMM
    [2020-01-30 13:45:41.910]> AT+CGMM
    [2020-01-30 13:45:41.923]< nRF9160-SICA
    [2020-01-30 13:45:41.924]< OK
    AT+CGMR
    [2020-01-30 13:45:47.712]> AT+CGMR
    [2020-01-30 13:45:47.727]< mfw_nrf9160_1.1.0
    [2020-01-30 13:45:47.728]< OK
    AT+CGSN
    [2020-01-30 13:45:53.156]> AT+CGSN
    [2020-01-30 13:45:53.162]< ***************
    [2020-01-30 13:45:53.163]< OK
    AT+CIMI
    [2020-01-30 13:45:58.268]> AT+CIMI
    [2020-01-30 13:45:58.273]< ***************
    [2020-01-30 13:45:58.275]< OK
    [2020-01-30 13:46:04.704]< button_handler
    [2020-01-30 13:46:04.707]< Publishing: button handler
    [2020-01-30 13:46:04.710]< to topic: tests/publish/topic len: 19
    [2020-01-30 13:46:05.293]< [mqtt_evt_handler:221] PUBACK packet id: 36509
    [2020-01-30 13:46:07.864]< [mqtt_evt_handler:196] MQTT PUBLISH result=0 len=4
    [2020-01-30 13:46:07.866]< Received: test
    [2020-01-30 13:46:07.867]< Publishing: test
    [2020-01-30 13:46:07.872]< to topic: tests/publish/topic len: 19
    [2020-01-30 13:46:08.281]< [mqtt_evt_handler:221] PUBACK packet id: 9079
    [2020-01-30 14:13:39.608]< button_handler
    [2020-01-30 14:13:39.611]< Publishing: button handler
    [2020-01-30 14:13:39.615]< to topic: tests/publish/topic len: 19
    [2020-01-30 14:13:39.799]< button_handler
    [2020-01-30 14:13:39.802]< Publishing: button handler
    [2020-01-30 14:13:39.807]< to topic: tests/publish/topic len: 19
    [2020-01-30 14:13:40.192]< [mqtt_evt_handler:221] PUBACK packet id: 1166
    [2020-01-30 14:13:40.790]< [mqtt_evt_handler:221] PUBACK packet id: 7432
    [2020-01-30 14:14:18.393]< [mqtt_evt_handler:196] MQTT PUBLISH result=0 len=4
    [2020-01-30 14:14:18.394]< Received: test
    [2020-01-30 14:14:18.395]< Publishing: test
    [2020-01-30 14:14:18.406]< to topic: tests/publish/topic len: 19
    [2020-01-30 14:14:18.838]< [mqtt_evt_handler:221] PUBACK packet id: 26932
    [2020-01-30 14:14:36.319]< [mqtt_evt_handler:196] MQTT PUBLISH result=0 len=4
    [2020-01-30 14:14:36.321]< Received: test
    [2020-01-30 14:14:36.324]< Publishing: test
    [2020-01-30 14:14:36.357]< to topic: tests/publish/topic len: 19
    [2020-01-30 14:14:36.569]< [mqtt_evt_handler:221] PUBACK packet id: 24471
    [2020-01-30 14:14:40.525]< [mqtt_evt_handler:196] MQTT PUBLISH result=0 len=4
    [2020-01-30 14:14:40.527]< Received: test
    [2020-01-30 14:14:40.528]< Publishing: test
    [2020-01-30 14:14:40.535]< to topic: tests/publish/topic len: 19
    [2020-01-30 14:14:40.784]< [mqtt_evt_handler:221] PUBACK packet id: 31271
    [2020-01-30 14:14:45.28]< [mqtt_evt_handler:196] MQTT PUBLISH result=0 len=4
    [2020-01-30 14:14:45.29]< Received: test
    [2020-01-30 14:14:45.31]< Publishing: test
    [2020-01-30 14:14:45.39]< to topic: tests/publish/topic len: 19
    [2020-01-30 14:14:45.426]< [mqtt_evt_handler:221] PUBACK packet id: 47747
    [2020-01-30 14:15:09.588]< [mqtt_evt_handler:196] MQTT PUBLISH result=0 len=4
    [2020-01-30 14:15:09.590]< Received: test
    [2020-01-30 14:15:09.591]< Publishing: test
    [2020-01-30 14:15:09.599]< to topic: tests/publish/topic len: 19
    [2020-01-30 14:15:09.856]< [mqtt_evt_handler:221] PUBACK packet id: 592
    [2020-01-30 15:04:07.615]< button_handler
    [2020-01-30 15:04:07.617]< Publishing: button handler
    [2020-01-30 15:04:07.620]< to topic: tests/publish/topic len: 19
    [2020-01-30 15:04:08.164]< [mqtt_evt_handler:221] PUBACK packet id: 2377
    
    [2020-01-30 13:44:44.724036] tests/publish/topic button handler
    [2020-01-30 13:44:50.254561] tests/subscribe/topic test
    [2020-01-30 13:44:50.803992] tests/publish/topic test
    [2020-01-30 13:46:05.255560] tests/publish/topic button handler
    [2020-01-30 13:46:07.729265] tests/subscribe/topic test
    [2020-01-30 13:46:08.243789] tests/publish/topic test
    [2020-01-30 14:13:40.140719] tests/publish/topic button handler
    [2020-01-30 14:13:40.140817] tests/publish/topic button handler
    [2020-01-30 14:14:17.048272] tests/subscribe/topic test
    [2020-01-30 14:14:18.802388] tests/publish/topic test
    [2020-01-30 14:14:35.243317] tests/subscribe/topic test
    [2020-01-30 14:14:36.534303] tests/publish/topic test
    [2020-01-30 14:14:40.488603] tests/subscribe/topic test
    [2020-01-30 14:14:40.744108] tests/publish/topic test
    [2020-01-30 14:14:44.779795] tests/subscribe/topic test
    [2020-01-30 14:14:45.363597] tests/publish/topic test
    [2020-01-30 14:15:09.097062] tests/subscribe/topic test
    [2020-01-30 14:15:09.820748] tests/publish/topic test
    [2020-01-30 15:04:08.135284] tests/publish/topic button handler
    
    
    

  • Just to confirm we have done some experiments using another LTE-M modem (SIMCOM SIM7000e) and we experience the exact same behaviour with Telias network. Seems to me this is clearly a problem with Telia and LTE-M. Hard though to find any providers not roaming with Telia so probably we need to find a way to blacklist them from the modem.

Reply Children
No Data
Related