NOTE: This is related to the following issue: https://devzone.nordicsemi.com/f/nordic-q-a/63255/nrf9160-getting-stuck-after-cell-change
--------------------------------------------------------------------------------
Hi,
we are running into issues where the nRF9160 (in NB-IoT mode) does not seem to handle cell changes reliably. I am using modem firmware mfw_nrf9160_1.2.0 .
We made a simplified test firmware to debug the issue. The test firmware enables several unsolicited notifications from the modem and prints them to the log. It then sends a UDP packet every 30s to a server which logs them. It also calls AT%XMONITOR and AT%NBRGRSRP in hope to get additional information. The AT commands at startup are as follows:
AT%XSYSTEMMODE=0,1,0,2 // Set modem to NB-IoT mode AT+CGMR // Query modem firmware AT%XCBAND=? // Query supported bands AT+CMEE=1 // Subscribe to mobile termination error AT+CEREG=5 // Subscribe to network registration status AT+CGEREP=1 // Subscribe to packet domain events AT+CNEC=24 // Subscribe to network error codes AT%CESQ=1 // Subscribe to signal quality AT+CEINFO=1 // Subscribe to Coverage Enhancement notifications AT%XBANDLOCK=2,"10000000000000000000" // Run-time lock to band 20 AT+CFUN=1 // Enable modem // *** after connect *** AT%XCBAND // Query current band AT+CIMI // Query IMSI AT+CGPADDR // Query IP address
After a while, sendto starts to fail with errno=ENETUNREACH. The logs show that this is because there is no longer a packet domain connection. The problem can be provoked by driving the system around in a car (more cell changes), but also happens after a few days if the system is stationary. It does seem to fix itself eventually, but may take many hours to do so. However, if I reset the system, it instantly connects again.
The log file looks as follows:
2020-06-24T05:59:28.473Z DEBUG modem << [07:54:44.538,269] <inf> main: sendto done: seq_num=933, retval=20
2020-06-24T05:59:28.494Z DEBUG modem << [07:54:44.587,677] <inf> modem: Update: %XMONITOR: 5,"","","26202","AFA1",9,20,"00A21867",141,6346,44,2
2020-06-24T05:59:28.603Z DEBUG modem << [07:54:44.696,960] <inf> modem: Update: %NBRGRSRP: 141,6346,48,164,6346,44,212,6346,42,401,6346,36,400,
2020-06-24T05:59:28.938Z DEBUG modem << [07:54:45.030,364] <inf> modem: Update: +CEINFO: 1,1,R,8,1,44,25
2020-06-24T05:59:29.317Z DEBUG modem << [07:54:45.407,440] <inf> modem: Update: +CEINFO: 1,1,C,2,1,44,25
2020-06-24T05:59:34.744Z DEBUG modem << [07:54:50.837,341] <inf> modem: Update: +CEINFO: 1,1,I,8,1,44,25
2020-06-24T05:59:58.538Z DEBUG modem << [07:55:14.597,198] <inf> main: sendto done: seq_num=934, retval=20
2020-06-24T05:59:58.560Z DEBUG modem << [07:55:14.650,451] <inf> modem: Update: %XMONITOR: 5,"","","26202","AFA1",9,20,"00A21867",141,6346,44,2
2020-06-24T05:59:58.687Z DEBUG modem << [07:55:14.780,731] <inf> modem: Update: %NBRGRSRP: 141,6346,48,164,6346,45,212,6346,43,290,6346,37,400,
2020-06-24T05:59:58.797Z DEBUG modem << [07:55:14.891,418] <inf> modem: Update: +CEINFO: 1,1,R,8,1,44,25
2020-06-24T05:59:59.028Z DEBUG modem << [07:55:15.119,842] <inf> modem: Update: +CEINFO: 1,1,C,2,1,44,25
2020-06-24T06:00:04.342Z DEBUG modem << [07:55:20.437,744] <inf> modem: Update: +CEINFO: 1,1,I,8,1,44,28
2020-06-24T06:13:03.384Z DEBUG modem << [08:08:19.413,879] <inf> modem: Update: +CEINFO: 1,1,C,4,1,37,20
2020-06-24T06:13:11.361Z DEBUG modem << [08:08:27.413,604] <inf> modem: Update: +CEINFO: 1,1,I,8,1,37,20
2020-06-24T06:13:11.362Z DEBUG modem << +CEREG: 5,"AFAD","009FF867",9
2020-06-24T06:13:11.451Z DEBUG modem >> AT+COPS=3,2
2020-06-24T06:13:11.466Z DEBUG modem << [08:08:27.519,531] <inf> modem: Update: +CEREG: 5,"AFAD","009FF867",9,,,"11100000","11100000"
2020-06-24T06:13:11.468Z DEBUG modem << OK
2020-06-24T06:13:11.575Z DEBUG modem << [08:08:27.627,960] <inf> modem: Update: +CEINFO: 1,1,R,8,1,37,20
2020-06-24T06:13:12.021Z DEBUG modem << [08:08:28.071,899] <inf> modem: Update: +CEINFO: 1,1,C,2,1,37,20
2020-06-24T06:13:12.270Z DEBUG modem << [08:08:28.207,458] <inf> modem: Update: +CGEV: ME PDN DEACT 0
2020-06-24T06:13:12.275Z DEBUG modem << +CGEV: ME PDN DEACT 0
2020-06-24T06:13:12.293Z DEBUG modem << +CNEC_EMM: 10
2020-06-24T06:13:12.296Z DEBUG modem << +CEREG: 2,"AFAD","009FF867",9
2020-06-24T06:13:12.300Z DEBUG modem << +CIND: "service",0
2020-06-24T06:13:12.310Z DEBUG modem << +CIND: "roam",0
2020-06-24T06:13:12.314Z DEBUG modem << +CGEV: NW DETACH
2020-06-24T06:13:12.386Z DEBUG modem << [08:08:28.444,946] <inf> modem: Update: +CNEC_EMM: 10
2020-06-24T06:13:12.454Z DEBUG modem >> AT+COPS?
2020-06-24T06:13:12.475Z DEBUG modem << +COPS: 0
2020-06-24T06:13:12.477Z DEBUG modem << OK
2020-06-24T06:13:12.498Z DEBUG modem << [08:08:28.551,055] <inf> modem: Update: +CEREG: 2,"AFAD","009FF867",9,0,10,"11100000","11100000"
2020-06-24T06:13:12.606Z DEBUG modem << [08:08:28.670,196] <inf> modem: Update: +CGEV: NW DETACH
2020-06-24T06:13:13.244Z DEBUG modem >> AT+CGDCONT?
2020-06-24T06:13:14.084Z DEBUG modem << OK
2020-06-24T06:13:14.089Z DEBUG modem >> AT+CGDCONT?
2020-06-24T06:13:14.134Z DEBUG modem << OK
2020-06-24T06:13:14.139Z DEBUG modem >> AT%XCBAND
2020-06-24T06:13:14.171Z DEBUG modem << %XCBAND: 20
2020-06-24T06:13:14.186Z DEBUG modem << OK
2020-06-24T06:13:14.260Z DEBUG modem >> AT+CGACT?
2020-06-24T06:13:14.394Z DEBUG modem << [08:08:30.467,437] <inf> modem: Update: %CESQ: 42,2,14,2
2020-06-24T06:13:14.402Z DEBUG modem << %CESQ: 42,2,14,2
2020-06-24T06:13:14.404Z DEBUG modem << +CEREG: 2,"AFA1","00A21867",9
2020-06-24T06:13:14.406Z DEBUG modem << +CGACT: 0,0
2020-06-24T06:13:14.419Z DEBUG modem << OK
2020-06-24T06:13:14.441Z DEBUG modem >> AT+CGACT?
2020-06-24T06:13:14.481Z DEBUG modem << +CGACT: 0,0
2020-06-24T06:13:14.485Z DEBUG modem << OK
2020-06-24T06:13:14.512Z DEBUG modem >> AT+CGDCONT?
2020-06-24T06:13:14.514Z DEBUG modem << [08:08:30.572,662] <inf> modem: Update: +CEINFO: 1,1,I,8,1,42,23
2020-06-24T06:13:14.529Z DEBUG modem << +CGDCONT: 0,"IP","","",0,0
2020-06-24T06:13:14.533Z DEBUG modem << OK
2020-06-24T06:13:14.557Z DEBUG modem >> AT+CGACT?
2020-06-24T06:13:14.592Z DEBUG modem << +CGACT: 0,0
2020-06-24T06:13:14.595Z DEBUG modem << OK
2020-06-24T06:13:14.625Z DEBUG modem << [08:08:30.680,969] <inf> modem: Update: +CEREG: 2,"AFA1","00A21867",9,0,10,"11100000","11100000"
2020-06-24T06:13:14.735Z DEBUG modem << [08:08:30.793,304] <inf> modem: Update: +CEINFO: 1,1,R,8,1,42,23
2020-06-24T06:13:14.848Z DEBUG modem << [08:08:30.899,230] <inf> modem: Update: +CEINFO: 1,1,C,2,1,42,23
2020-06-24T06:13:21.096Z DEBUG modem << [08:08:37.163,635] <inf> modem: Update: +CEINFO: 1,1,R,8,1,42,23
2020-06-24T06:13:21.248Z DEBUG modem << [08:08:37.312,957] <inf> modem: Update: +CEINFO: 1,1,C,2,1,42,23
2020-06-24T06:13:30.093Z DEBUG modem << [08:08:46.177,490] <inf> modem: Update: %XMONITOR: 2 OK
2020-06-24T06:13:30.131Z DEBUG modem << [08:08:46.187,255] <err> main: sendto error: seq_num=961, retval=-1, errno=51
2020-06-24T06:13:30.210Z DEBUG modem << [08:08:46.287,322] <inf> modem: Update: OK
2020-06-24T06:14:00.103Z DEBUG modem << [08:09:16.195,800] <inf> modem: Update: %XMONITOR: 2 OK
2020-06-24T06:14:00.134Z DEBUG modem << [08:09:16.205,566] <err> main: sendto error: seq_num=962, retval=-1, errno=51
2020-06-24T06:14:00.220Z DEBUG modem << [08:09:16.305,633] <inf> modem: Update: OK
2020-06-24T06:14:26.827Z DEBUG modem >> AT+CFUN?
2020-06-24T06:14:26.865Z DEBUG modem << +CFUN: 1
2020-06-24T06:14:26.879Z DEBUG modem << OK
2020-06-24T06:14:26.906Z DEBUG modem >> AT+CGSN=1
2020-06-24T06:14:26.947Z DEBUG modem << +CGSN: "352656100338527"
2020-06-24T06:14:26.949Z DEBUG modem << OK
2020-06-24T06:14:26.951Z DEBUG modem >> AT+CGMI
2020-06-24T06:14:26.981Z DEBUG modem << Nordic Semiconductor ASA
2020-06-24T06:14:26.983Z DEBUG modem << OK
2020-06-24T06:14:26.985Z DEBUG modem >> AT+CGMM
2020-06-24T06:14:27.013Z DEBUG modem << nRF9160-SICA
2020-06-24T06:14:27.015Z DEBUG modem << OK
2020-06-24T06:14:27.018Z DEBUG modem >> AT+CGMR
2020-06-24T06:14:27.047Z DEBUG modem << mfw_nrf9160_1.2.0
2020-06-24T06:14:27.048Z DEBUG modem << OK
2020-06-24T06:14:27.049Z INFO Nordic Semiconductor ASA nRF9160-SICA [mfw_nrf9160_1.2.0] SerNr: 352656100338527
2020-06-24T06:14:27.051Z DEBUG modem >> AT+CEMODE?
2020-06-24T06:14:27.079Z DEBUG modem << +CEMODE: 0
2020-06-24T06:14:27.081Z DEBUG modem << OK
2020-06-24T06:14:27.108Z DEBUG modem >> AT%XCBAND=?
2020-06-24T06:14:27.134Z DEBUG modem << %XCBAND: (20)
2020-06-24T06:14:27.135Z DEBUG modem << OK
2020-06-24T06:14:27.162Z DEBUG modem >> AT+CMEE?
2020-06-24T06:14:27.188Z DEBUG modem << +CMEE: 1
2020-06-24T06:14:27.189Z DEBUG modem << OK
2020-06-24T06:14:27.215Z DEBUG modem >> AT+CNEC?
2020-06-24T06:14:27.246Z DEBUG modem << +CNEC: 24
2020-06-24T06:14:27.248Z DEBUG modem << OK
2020-06-24T06:14:27.250Z DEBUG modem >> AT+CGEREP?
2020-06-24T06:14:27.280Z DEBUG modem << +CGEREP: 1,0
2020-06-24T06:14:27.282Z DEBUG modem << OK
2020-06-24T06:14:27.284Z DEBUG modem >> AT+CIND=1,1,1
2020-06-24T06:14:27.312Z DEBUG modem << OK
2020-06-24T06:14:27.315Z DEBUG modem >> AT+CEREG=2
2020-06-24T06:14:27.345Z DEBUG modem << OK
2020-06-24T06:14:27.348Z DEBUG modem >> AT+CEREG?
2020-06-24T06:14:27.380Z DEBUG modem << +CEREG: 2,2,"AFA1","00A21867",9
2020-06-24T06:14:27.382Z DEBUG modem << OK
2020-06-24T06:14:27.411Z DEBUG modem >> AT%CESQ=1
2020-06-24T06:14:27.437Z DEBUG modem << OK
2020-06-24T06:14:27.463Z DEBUG modem >> AT+CESQ
2020-06-24T06:14:27.491Z DEBUG modem << +CESQ: 99,99,255,255,14,42
2020-06-24T06:14:27.492Z DEBUG modem << OK
2020-06-24T06:14:27.505Z DEBUG modem >> AT%XSIM=1
2020-06-24T06:14:27.532Z DEBUG modem << OK
2020-06-24T06:14:27.535Z DEBUG modem >> AT%XSIM?
2020-06-24T06:14:27.563Z DEBUG modem << %XSIM: 1
2020-06-24T06:14:27.565Z DEBUG modem << OK
2020-06-24T06:14:27.592Z DEBUG modem >> AT+CPIN?
2020-06-24T06:14:27.619Z DEBUG modem << +CPIN: READY
2020-06-24T06:14:27.620Z DEBUG modem << OK
2020-06-24T06:14:27.649Z DEBUG modem >> AT+CPINR="SIM PIN"
2020-06-24T06:14:27.677Z DEBUG modem << +CPINR: "SIM PIN",3
2020-06-24T06:14:27.678Z DEBUG modem << OK
2020-06-24T06:14:27.712Z DEBUG modem >> AT+CIMI
2020-06-24T06:14:27.739Z DEBUG modem << 901288001059920
2020-06-24T06:14:27.741Z DEBUG modem << OK
2020-06-24T06:14:27.742Z INFO IMSIdentity: 901288001059920
2020-06-24T06:14:30.122Z DEBUG modem << [08:09:46.214,202] <inf> modem: Update: %XMONITOR: 2 OK
2020-06-24T06:14:30.167Z DEBUG modem << [08:09:46.224,395] <err> main: sendto error: seq_num=963, retval=-1, errno=51
2020-06-24T06:14:30.238Z DEBUG modem << [08:09:46.324,493] <inf> modem: Update: OK
2020-06-24T06:15:00.139Z DEBUG modem << [08:10:16.233,459] <inf> modem: Update: %XMONITOR: 2 OK
2020-06-24T06:15:00.171Z DEBUG modem << [08:10:16.243,621] <err> main: sendto error: seq_num=964, retval=-1, errno=51
2020-06-24T06:15:00.255Z DEBUG modem << [08:10:16.343,688] <inf> modem: Update: OK
2020-06-24T06:15:03.982Z DEBUG modem << [08:10:20.066,528] <inf> modem: Update: %CESQ: 37,1,14,2
2020-06-24T06:15:03.984Z DEBUG modem << %CESQ: 37,1,14,2
2020-06-24T06:15:03.999Z DEBUG modem << +CEREG: 2,"AFAD","009FF867",9
2020-06-24T06:15:04.086Z DEBUG modem << [08:10:20.171,752] <inf> modem: Update: +CEINFO: 1,1,I,8,1,37,23
2020-06-24T06:15:04.196Z DEBUG modem << [08:10:20.279,418] <inf> modem: Update: +CEREG: 2,"AFAD","009FF867",9,0,10,"11100000","11100000"
2020-06-24T06:15:04.307Z DEBUG modem << [08:10:20.391,723] <inf> modem: Update: +CEINFO: 1,1,R,8,1,37,23
2020-06-24T06:15:04.419Z DEBUG modem << [08:10:20.501,403] <inf> modem: Update: +CEINFO: 1,1,C,2,1,37,23
2020-06-24T06:15:16.019Z DEBUG modem << [08:10:32.066,680] <inf> modem: Update: %CESQ: 37,1,8,1
2020-06-24T06:15:16.054Z DEBUG modem << %CESQ: 37,1,8,1
2020-06-24T06:15:16.140Z DEBUG modem << [08:10:32.224,609] <inf> modem: Update: +CEINFO: 1,1,I,8,1,37,23
2020-06-24T06:15:25.911Z DEBUG modem << [08:10:41.998,291] <inf> modem: Update: +CEINFO: 1,1,R,8,1,37,20
2020-06-24T06:15:28.550Z DEBUG modem << [08:10:44.632,781] <inf> modem: Update: +CEINFO: 1,1,C,32,1,37,20
2020-06-24T06:15:28.836Z DEBUG modem << [08:10:44.901,672] <inf> modem: Update: +CNEC_ESM: 26,0
2020-06-24T06:15:28.868Z DEBUG modem << +CNEC_ESM: 26,0
2020-06-24T06:15:28.882Z DEBUG modem << +CNEC_EMM: 19
2020-06-24T06:15:28.979Z DEBUG modem << [08:10:45.068,725] <inf> modem: Update: +CNEC_EMM: 19
2020-06-24T06:15:29.091Z DEBUG modem << [08:10:45.177,215] <inf> modem: Update: +CEREG: 2,"AFAD","009FF867",9,0,19,"11100000","11100000"
2020-06-24T06:15:30.175Z DEBUG modem << [08:10:46.260,925] <inf> modem: Update: %XMONITOR: 2 OK
2020-06-24T06:15:30.218Z DEBUG modem << [08:10:46.272,399] <err> main: sendto error: seq_num=965, retval=-1, errno=51
2020-06-24T06:15:30.273Z DEBUG modem << [08:10:46.372,467] <inf> modem: Update: OK
2020-06-24T06:15:32.632Z DEBUG modem << [08:10:48.723,815] <inf> modem: Update: %CESQ: 29,1,8,1
2020-06-24T06:15:32.636Z DEBUG modem << %CESQ: 29,1,8,1
2020-06-24T06:15:32.668Z DEBUG modem << %CESQ: 34,1,8,1
2020-06-24T06:15:32.681Z DEBUG modem << +CEREG: 2,"AFA1","00A21867",9
2020-06-24T06:15:32.744Z DEBUG modem << [08:10:48.837,158] <inf> modem: Update: %CESQ: 34,1,8,1
2020-06-24T06:15:32.865Z DEBUG modem << [08:10:48.950,439] <inf> modem: Update: +CEINFO: 1,1,I,8,1,34,23
2020-06-24T06:15:32.977Z DEBUG modem << [08:10:49.062,255] <inf> modem: Update: +CEREG: 2,"AFA1","00A21867",9,0,19,"11100000","11100000"
2020-06-24T06:15:36.539Z DEBUG modem << [08:10:52.640,747] <inf> modem: Update: %CESQ: 29,1,3,0
2020-06-24T06:15:36.579Z DEBUG modem << %CESQ: 29,1,3,0
2020-06-24T06:15:39.114Z DEBUG modem << [08:10:55.200,775] <inf> modem: Update: %CESQ: 29,1,11,1
2020-06-24T06:15:39.117Z DEBUG modem << %CESQ: 29,1,11,1
2020-06-24T06:15:46.780Z DEBUG modem << [08:11:02.880,859] <inf> modem: Update: %CESQ: 29,1,5,0
2020-06-24T06:15:46.823Z DEBUG modem << %CESQ: 29,1,5,0
2020-06-24T06:15:47.450Z DEBUG modem << [08:11:03.552,185] <inf> modem: Update: +CGEV: RESTR 2,2
2020-06-24T06:15:47.493Z DEBUG modem << +CGEV: RESTR 2,2
2020-06-24T06:15:47.530Z DEBUG modem >> AT+CGDCONT?
2020-06-24T06:15:47.568Z DEBUG modem << +CGDCONT: 0,"IP","","",0,0
2020-06-24T06:15:47.570Z DEBUG modem << OK
2020-06-24T06:15:47.600Z DEBUG modem >> AT+CGACT?
2020-06-24T06:15:47.632Z DEBUG modem << +CGACT: 0,0
2020-06-24T06:15:47.634Z DEBUG modem << OK
2020-06-24T06:15:49.353Z DEBUG modem << [08:11:05.440,917] <inf> modem: Update: %CESQ: 34,1,10,1
2020-06-24T06:15:49.356Z DEBUG modem << %CESQ: 34,1,10,1
2020-06-24T06:15:57.019Z DEBUG modem << [08:11:13.121,002] <inf> modem: Update: %CESQ: 34,1,4,0
2020-06-24T06:15:57.066Z DEBUG modem << %CESQ: 34,1,4,0
2020-06-24T06:15:59.593Z DEBUG modem << [08:11:15.677,978] <inf> modem: Update: %CESQ: 14,0,22,3
2020-06-24T06:15:59.595Z DEBUG modem << %CESQ: 14,0,22,3
2020-06-24T06:15:59.701Z DEBUG modem << [08:11:15.787,384] <inf> modem: Update: +CEINFO: 1,1,I,512,32,14,16
2020-06-24T06:16:00.210Z DEBUG modem << [08:11:16.296,356] <inf> modem: Update: %XMONITOR: 2 OK
2020-06-24T06:16:00.247Z DEBUG modem << [08:11:16.308,593] <err> main: sendto error: seq_num=966, retval=-1, errno=51\x0D
2020-06-24T06:16:00.322Z DEBUG modem << [08:11:16.408,691] <inf> modem: Update: %NBRGRSRP: 141,6346,27,86,6346,40,290,6346,32,400,6346,31,401,6
2020-06-24T06:16:02.140Z DEBUG modem << [08:11:18.238,006] <inf> modem: Update: %CESQ: 33,1,13,1
2020-06-24T06:16:02.180Z DEBUG modem << %CESQ: 33,1,13,1
2020-06-24T06:16:02.260Z DEBUG modem << [08:11:18.347,076] <inf> modem: Update: +CEINFO: 1,1,I,8,1,33,22
2020-06-24T06:16:20.059Z DEBUG modem << [08:11:36.161,346] <inf> modem: Update: %CESQ: 38,1,13,1
2020-06-24T06:16:20.102Z DEBUG modem << %CESQ: 38,1,13,1
2020-06-24T06:16:30.231Z DEBUG modem << [08:11:46.324,249] <err> main: sendto error: seq_num=967, retval=-1, errno=51
2020-06-24T06:16:30.274Z DEBUG modem << [08:11:46.324,340] <inf> modem: Update: %XMONITOR: 2 OK
2020-06-24T06:16:30.356Z DEBUG modem << [08:11:46.441,589] <inf> modem: Update: %NBRGRSRP: 141,6346,40,86,6346,36,290,6346,35,400,6346,31,164,6
2020-06-24T06:17:00.261Z DEBUG modem << [08:12:16.350,921] <inf> modem: Update: %XMONITOR: 2 OK
2020-06-24T06:17:00.302Z DEBUG modem << [08:12:16.363,616] <err> main: sendto error: seq_num=968, retval=-1, errno=51
2020-06-24T06:17:00.375Z DEBUG modem << [08:12:16.463,714] <inf> modem: Update: %NBRGRSRP: 141,6346,40,86,6346,40,290,6346,36,164,6346,35,400,6
2020-06-24T06:17:30.297Z DEBUG modem << [08:12:46.388,214] <inf> modem: Update: %XMONITOR: 2 OK
2020-06-24T06:17:30.340Z DEBUG modem << [08:12:46.400,451] <err> main: sendto error: seq_num=969, retval=-1, errno=51
2020-06-24T06:17:30.411Z DEBUG modem << [08:12:46.500,549] <inf> modem: Update: %NBRGRSRP: 141,6346,40,86,6346,38,290,6346,36,164,6346,36,400,6
2020-06-24T06:18:00.332Z DEBUG modem << [08:13:16.424,407] <inf> modem: Update: %XMONITOR: 2 OK
2020-06-24T06:18:00.374Z DEBUG modem << [08:13:16.436,676] <err> main: sendto error: seq_num=970, retval=-1, errno=51
2020-06-24T06:18:00.446Z DEBUG modem << [08:13:16.536,773] <inf> modem: Update: %NBRGRSRP: 141,6346,38,86,6346,39,440,6346,34,164,6346,33,290,6
2020-06-24T06:18:30.351Z DEBUG modem << [08:13:46.452,301] <inf> modem: Update: %XMONITOR: 2 OK
2020-06-24T06:18:30.384Z DEBUG modem << [08:13:46.462,951] <err> main: sendto error: seq_num=971, retval=-1, errno=51
2020-06-24T06:18:30.473Z DEBUG modem << [08:13:46.563,049] <inf> modem: Update: %NBRGRSRP: 141,6346,36,86,6346,39,290,6346,33,164,6346,33,438,6
2020-06-24T06:18:45.980Z DEBUG modem << [08:14:02.083,282] <inf> modem: Update: %CESQ: 38,1,18,2
2020-06-24T06:18:45.995Z DEBUG modem << %CESQ: 38,1,18,2
2020-06-24T06:19:00.390Z DEBUG modem << [08:14:16.479,949] <inf> modem: Update: %XMONITOR: 2 OK
2020-06-24T06:19:00.413Z DEBUG modem << [08:14:16.492,187] <err> main: sendto error: seq_num=972, retval=-1, errno=51
2020-06-24T06:19:00.505Z DEBUG modem << [08:14:16.592,315] <inf> modem: Update: %NBRGRSRP: 141,6346,39,86,6346,38,164,6346,34,401,6346,32,400,6
2020-06-24T06:20:00.466Z DEBUG modem << [08:15:16.552,429] <inf> modem: Update: %XMONITOR: 2 OK
2020-06-24T06:20:00.512Z DEBUG modem << [08:15:16.564,636] <err> main: sendto error: seq_num=974, retval=-1, errno=51
2020-06-24T06:20:00.584Z DEBUG modem << [08:15:16.664,733] <inf> modem: Update: %NBRGRSRP: 141,6346,49,212,6346,46,86,6346,43,328,6346,43,290,6
2020-06-24T06:20:05.348Z DEBUG modem << [08:15:21.444,366] <inf> modem: Update: %CESQ: 48,2,23,3
2020-06-24T06:20:05.363Z DEBUG modem << %CESQ: 48,2,23,3
2020-06-24T06:20:30.504Z DEBUG modem << [08:15:46.588,684] <inf> modem: Update: %XMONITOR: 2 OK
2020-06-24T06:20:30.540Z DEBUG modem << [08:15:46.600,006] <err> main: sendto error: seq_num=975, retval=-1, errno=51
2020-06-24T06:20:30.619Z DEBUG modem << [08:15:46.700,103] <inf> modem: Update: %NBRGRSRP: 141,6346,53,212,6346,48,86,6346,45,459,6346,44,328,6
2020-06-24T06:21:00.540Z DEBUG modem << [08:16:16.623,962] <inf> modem: Update: %XMONITOR: 2 OK
2020-06-24T06:21:00.583Z DEBUG modem << [08:16:16.636,260] <err> main: sendto error: seq_num=976, retval=-1, errno=51
2020-06-24T06:21:00.654Z DEBUG modem << [08:16:16.736,358] <inf> modem: Update: %NBRGRSRP: 141,6346,48,212,6346,41,328,6346,40,86,6346,38,459,6
2020-06-24T06:21:09.347Z DEBUG modem << [08:16:25.445,220] <inf> modem: Update: %CESQ: 48,2,16,2
2020-06-24T06:21:09.384Z DEBUG modem << %CESQ: 48,2,16,2
2020-06-24T06:21:17.040Z DEBUG modem << [08:16:33.125,305] <inf> modem: Update: %CESQ: 43,2,16,2
2020-06-24T06:21:17.041Z DEBUG modem << %CESQ: 43,2,16,2
2020-06-24T06:21:19.588Z DEBUG modem << [08:16:35.685,363] <inf> modem: Update: %CESQ: 43,2,10,1
2020-06-24T06:21:19.629Z DEBUG modem << %CESQ: 43,2,10,1
2020-06-24T06:21:22.162Z DEBUG modem << [08:16:38.242,309] <inf> modem: Update: %CESQ: 19,0,25,3
2020-06-24T06:21:22.165Z DEBUG modem << %CESQ: 19,0,25,3
2020-06-24T06:21:22.269Z DEBUG modem << [08:16:38.351,715] <inf> modem: Update: +CEINFO: 1,1,I,512,32,19,22
2020-06-24T06:21:24.708Z DEBUG modem << [08:16:40.802,337] <inf> modem: Update: %CESQ: 38,1,7,1
2020-06-24T06:21:24.745Z DEBUG modem << %CESQ: 38,1,7,1
2020-06-24T06:21:24.830Z DEBUG modem << [08:16:40.911,285] <inf> modem: Update: +CEINFO: 1,1,I,8,1,38,19
2020-06-24T06:21:30.565Z DEBUG modem << [08:16:46.593,017] <inf> modem: Update: +CEREG: 2,"AFA1","009DF767",9,0,19,"11100000","11100000"
2020-06-24T06:21:30.601Z DEBUG modem << +CEREG: 2,"AFA1","009DF767",9
2020-06-24T06:21:30.615Z DEBUG modem << +CGEV: RESTR 2,2
2020-06-24T06:21:30.618Z DEBUG modem << [08:16:46.673,797] <err> main: sendto error: seq_num=977, retval=-1, errno=51
2020-06-24T06:21:30.651Z DEBUG modem >> AT+CGDCONT?
2020-06-24T06:21:30.700Z DEBUG modem << [08:16:46.766,693] <inf> modem: Update: +CGEV: RESTR 2,2
2020-06-24T06:21:30.703Z DEBUG modem << +CGDCONT: 0,"IP","","",0,0
2020-06-24T06:21:30.704Z DEBUG modem << OK
2020-06-24T06:21:30.738Z DEBUG modem >> AT+CGACT?
2020-06-24T06:21:30.780Z DEBUG modem << +CGACT: 0,0
2020-06-24T06:21:30.782Z DEBUG modem << OK
In this case, we observe the following Error messages:
-
+CNEC_ESM: 26,0 (Session Management Error: Insufficient resources)
-
+CNEC_EMM: 19 (Mobility Management Error: ESM failure)
-
+CGEV: RESTR 2,2
-
Requested procedure restricted:
-
2 – Throttling. Procedure restricted by 3GPP or operator-specific throttling.
-
2 – Temporary restriction. Enabling requires e.g. back-off timer expiry.
-
According to the following site, this is related to the back-off timer T3396: https://itectec.com/spec/6-5-ue-requested-esm-procedures/
(see chapter 6.5.1.4.2 Handling of network rejection due to ESM cause #26)
What would be the appropriate action to prevent this error ?
Does Nordic use this timer, and can it be modified ?
Here is the complete logfile:
https://devzone.nordicsemi.com/cfs-file/__key/support-attachments/beef5d1b77644c448dabff31668f3a47-4fe3d670a3c74b3190355cbb48601128/2020_2D00_06_2D00_23-ESM-failure-_2300_26-_2D00_-T22_5F00_25_5F00_26.188Z_2D00_log.txt
