Hi,
I’m using a BC660 NB-IoT modem running on a battery powered platform. One of the requirements is a long battery lifetime therefore the application sleeps most of the time. The BC660 modem should also enter hibernation as much as possible. I’m using the IP stack of the modem and instruct the modem to enter PSM a.s.ap. using the RAI mode flag of the AT+QISEND command.
This works 99 percent of the time but sometimes the modem keeps using a lot of energy directly after a message has been sent successfully. I therefore downloaded the EPAT tool and connected a TTL-USB converter to the DEBUG UART of the modem. From the captured logs I see that the modem is not entering Hibernation but instead starts a PLMN search. Why is the modem starting a PLMN search even though it is connected and has just sent a message successfully? The search seems to continue for up to 25 minutes (using a lot of energy). Note that when that application sends a new message before the search is finished (e.g. after 5 minutes) this message is sent successfully and the search is stopped and the modem goes to hibernation.
How can I prevent this PLMN search when the modem is connected just fine?
Below a fragment of the captured logs.
20000,24:1001:04:1103,CID: 0 , count:0 , Enum:1 ,2026-05-04 15:15:10.412
20004,24:1001:04:1901,CESM , RAI flag: 2 , RAI_NO_INFO ( 0 ) / NO_UL_DL ( 1 ) / ONLY_DL ( 2 ) / REVD ( 3 ) ,2026-05-04 15:15:10.412
20011,24:1001:05:1640,Sending ESM_DATA_TRANSPORT: ,2026-05-04 15:15:10.412
20014,24:1001:06:0530,UlInformationTransfer-NB , len ( 323 ) ,2026-05-04 15:15:10.412
20026,24:1001:08:0765,AT CMD , URC: SEND OK ,2026-05-04 15:15:10.412
20036,25:0032:08:1681,Trigger PRACH , cause: 2 , CCCH ( 0 ) / NPDCCH_ORDER ( 1 ) / UL_DATA ( 2 ) ,2026-05-04 15:15:10.966
20038,25:0032:09:0091,Current CE = 0 , lastSuccCE = 1 ,2026-05-04 15:15:10.966
20039,25:0032:09:1230,PRACH Transmitted , RA cause = UL_DATA ,2026-05-04 15:15:10.966
20040,25:0032:09:1245,CE level = 0 , RaContentionFlag = 1 ( contention free ( 0 ) / contention based ( 1 ) ) , CarrierIndex = 0 ( anchor carrier ( 0 ) / non-anchor carrier ( 1 -15 ) ) , SubCarrierIndex = 29 , RachTransCnt of current CE = 1 ,2026-05-04 15:15:10.966
20041,25:0035:08:0718,RAR_PDSCH received : NumOfRapid = 1 ,2026-05-04 15:15:11.045
20042,25:0035:08:1781,RAR received: backOffIndicator = 0 , tmpCrnti = 19325 , taCmd = 52 , rarGrant = 20992 ,2026-05-04 15:15:11.045
20050,25:0037:03:0231,Msg3 Transmitted : crnti = 19163 , tmpCrnti = 19325 , Msg3TransCnt = 1 ,2026-05-04 15:15:11.045
20056,25:0038:01:0782,PRACH SUCC ,2026-05-04 15:15:11.045
20086,25:0050:01:0936,CONNECTED: SERV CELL ( 6254 , 201 ) : RSRP ( -105 ) , RSRQ ( -13 ) , SNR ( -2 ) ,2026-05-04 15:15:11.187
20100,25:0056:02:0994,DlInformationTransfer-NB , len ( 75 ) ,2026-05-04 15:15:11.187
20104,25:0056:03:0527,Receiving ESM_DATA_TRANSPORT: ,2026-05-04 15:15:11.235
20121,25:0056:03:1767,CID: 0 , count:1 , Enum:2 ,2026-05-04 15:15:11.235
20123,25:0056:03:1810,CID: 0 , count:61 , Enum:4 ,2026-05-04 15:15:11.235
20129,25:0056:04:0423,PSIF DL DATA: ,2026-05-04 15:15:11.235
20175,25:0056:06:1206,URC put in list num:1 \r\n ,2026-05-04 15:15:11.235
20177,25:0056:06:1526,URC msg hadle !!type = 1\r\n ,2026-05-04 15:15:11.235
20178,25:0056:06:1562,URC in list num :1 \r\n ,2026-05-04 15:15:11.235
20179,25:0056:06:1622,URC in list need to set ri , delay sending\r\n ,2026-05-04 15:15:11.235
20180,25:0056:06:1651,URC ri set low !!\r\n ,2026-05-04 15:15:11.235
20182,25:0056:07:0253,URC timeout start !!time = 120 , timer_id = 170384\r\n ,2026-05-04 15:15:11.235
20202,25:0061:07:0254,RrcConnectionRelease-NB: ,2026-05-04 15:15:11.267
20211,25:0061:08:1337,PSIF , suspend ( 1 ) / resume ( 0 ) : 1 LWIP ,2026-05-04 15:15:11.267
20216,25:0068:06:0616,URC ri set high !!\r\n ,2026-05-04 15:15:11.347
20218,25:0068:06:1067,URC msg hadle !!type = 0\r\n ,2026-05-04 15:15:11.347
20219,25:0068:06:1446,URC in list num :1 \r\n ,2026-05-04 15:15:11.347
20220,25:0068:06:1523,AT CMD , URC: +QIURC: “recv”,0,33,“17fefd000100000000019400140001000000000194a8e8c5ea23c1144e8df67c2c” ,2026-05-04 15:15:11.347
20225,25:0098:09:1462,DL MEAS STATIS INFO: RSRP ( -10500 / 100 ) , RSRQ ( -1287 / 100 ) , SNR ( -225 / 100 ) ,2026-05-04 15:15:11.633
20226,25:0098:09:1473,DL TpT STATIS INFO: MCS Index ( 505 / 100 ) , BLER ( 3333 / 10000 ) ,2026-05-04 15:15:11.633
20227,25:0098:09:1484,UL TpT STATIS INFO: MCS Index ( 883 / 100 ) , BLER ( 2142 / 10000 ) ,2026-05-04 15:15:11.633
20233,25:0151:01:0799,CONNECTED: SERV CELL ( 6254 , 201 ) : RSRP ( -105 ) , RSRQ ( -12 ) , SNR ( -3 ) ,2026-05-04 15:15:12.178
20248,25:0253:06:0674,CONNECTED: SERV CELL ( 6254 , 201 ) : RSRP ( -105 ) , RSRQ ( -13 ) , SNR ( -3 ) ,2026-05-04 15:15:13.185
20269,25:0262:00:0788,MAC RESET , cause ( 3 ) , REEST ( 0 ) , REEST_RETRY ( 1 ) , EST_RETRY ( 2 ) , RETURN_IDLE ( 3 ) , SUSPEND ( 4 ) ,2026-05-04 15:15:13.249
20292,25:0262:01:1904,CELL ( 6254 , 201 ) , cellStatus ( 1 ) , SUITABLE ( 1 ) , BARRED ( 2 ) , PLMN_FORBIDDEN ( 3 ) , TA_FORBIDDEN ( 4 ) , selectedPlmnIdx ( 1 ) , band ( 20 ) ,2026-05-04 15:15:13.249
20298,25:0262:03:1065,pagingCycle is 2560 ( ms ) ,2026-05-04 15:15:13.249
20317,25:0262:06:1214,T3324 assigned by NW is zero ,2026-05-04 15:15:13.249
20318,25:0262:06:1248,Start T3412 ,2026-05-04 15:15:13.249
20323,25:0262:06:1861,Start DeepSleep Timer , ticks = 14400000 , timerID = 8 - T3346 ( 5 ) , T3402 ( 6 ) , T3411 ( 7 ) , T3412 ( 8 ) ,2026-05-04 15:15:13.280
20331,25:0262:07:1482,Can ’ t find DialPlmnCfg for PLMN: 0x901 , 0xf040 , can ’ t get prefer band ,2026-05-04 15:15:13.280
20332,25:0262:07:1492,CCM SIM , MCC: 0x901 , MNC: 0xf040 ,2026-05-04 15:15:13.280
20335,25:0262:07:1662,Start Plmn Search , Request Band ( s ) : 14 01 02 03 04 05 08 0C 0D 11 12 13 19 1C 42 46 55 ,2026-05-04 15:15:13.280
20347,25:0262:08:1262,PSIF , suspend ( 1 ) / resume ( 0 ) : 0 LWIP ,2026-05-04 15:15:13.280
20370,25:0271:07:1181,CELL ( 6254 , 201 ) , MIB-NB , len ( 5 ) ,2026-05-04 15:15:13.343
20371,25:0271:07:1191,MIB-NB: ,2026-05-04 15:15:13.343
20379,25:0271:07:1772,IDLE Meas Threshold: Intra-Threshold ( -140 ) , Inter-Threshold ( -140 ) , sIntraSearchP ( -2048 ) , sNonIntraSearchP ( -2048 ) , bDisableNCellMeas ( 1 ) ,2026-05-04 15:15:13.343
20393,25:0271:08:1139,CerrcPlmnSearchContext already exists! ,2026-05-04 15:15:13.343
20406,25:0271:09:0263,Start Cell Search: 20424,09:0870:07:0467,PLMN , PLMN search is ongoing when DEACT PLMN with cause: 2 , type: 5 , procStatus: 1 ,2026-05-04 15:15:13.343
20425,09:0870:07:0486,PLMN , PLMN search is ongoing , but EMM trigger to enter PSM , pending PSM deactivation ,2026-05-04 15:15:13.343
20426,09:0870:08:0189,Start Band Scan , EARFCN = 6154 ,2026-05-04 15:15:13.343
20466,09:0980:07:0153,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -107 ) , RSRQ ( -15 ) , SNR ( -5 ) ,2026-05-04 15:15:14.457
20612,10:0160:02:0365,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -106 ) , RSRQ ( -14 ) , SNR ( 0 ) ,2026-05-04 15:15:16.494
20781,10:0411:05:0153,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -106 ) , RSRQ ( -14 ) , SNR ( 0 ) ,2026-05-04 15:15:19.012
20954,10:0667:05:0428,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -106 ) , RSRQ ( -14 ) , SNR ( -2 ) ,2026-05-04 15:15:21.565
21114,10:0928:02:1240,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -105 ) , RSRQ ( -14 ) , SNR ( -2 ) ,2026-05-04 15:15:24.184
21160,11:0160:02:1259,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -106 ) , RSRQ ( -14 ) , SNR ( -3 ) ,2026-05-04 15:15:26.747
21207,11:0416:02:1155,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -105 ) , RSRQ ( -14 ) , SNR ( -3 ) ,2026-05-04 15:15:29.315
21221,11:0439:04:0702,Start Frequency Scan in Score List , First EARFCN: 6254 , Score = 250 , numOfFreq = 80 ,2026-05-04 15:15:29.551
21225,11:0454:04:1572,Cell ( 6254 201 ) Found! SNR Level ( 0 :UltraHigh->3:Low ) = 2 ,2026-05-04 15:15:29.662
21253,11:0498:04:1537,Cell ( 9644 201 ) Found! SNR Level ( 0 :UltraHigh->3:Low ) = 3 ,2026-05-04 15:15:30.109
21255,11:0511:01:1556,CarrierFreqOfst changed! prevOfst = 11 newOfst = 12 ,2026-05-04 15:15:30.237
21268,14:0935:07:1527,CELL ( 9644 , 201 ) , MIB-NB , len ( 5 ) ,2026-05-04 15:15:30.237
21269,14:0935:07:1537,MIB-NB: ,2026-05-04 15:15:30.237
21275,14:0975:06:0695,CELL ( 9644 , 201 ) , SIB1-NB , len ( 41 ) , RSRP ( -107 ) , RSRQ ( -16 ) ,2026-05-04 15:15:30.668
21277,14:0975:06:0707,SIB1-NB: ,2026-05-04 15:15:30.668
21294,11:0568:04:1585,Cell ( 3654 310 ) Found! SNR Level ( 0 :UltraHigh->3:Low ) = 2 ,2026-05-04 15:15:30.809
21296,11:0591:01:1527,CarrierFreqOfst changed! prevOfst = 11 newOfst = 12 ,2026-05-04 15:15:31.015
21307,14:1015:07:1515,CELL ( 3654 , 310 ) , MIB-NB , len ( 5 ) ,2026-05-04 15:15:31.047
21308,14:1015:07:1525,MIB-NB: ,2026-05-04 15:15:31.047
21326,15:0073:05:0778,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -106 ) , RSRQ ( -14 ) , SNR ( -2 ) ,2026-05-04 15:15:31.851
21355,15:0329:05:0696,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -105 ) , RSRQ ( -14 ) , SNR ( -2 ) ,2026-05-04 15:15:34.413
21397,12:0160:02:1250,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -105 ) , RSRQ ( -13 ) , SNR ( -3 ) ,2026-05-04 15:15:36.989
21417,12:0199:00:0763,UICC presence detect timer expired , send STATUS command ,2026-05-04 15:15:37.369
21505,12:0416:02:1337,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -105 ) , RSRQ ( -13 ) , SNR ( -3 ) ,2026-05-04 15:15:39.545
21546,12:0672:01:0784,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -105 ) , RSRQ ( -13 ) , SNR ( -2 ) ,2026-05-04 15:15:42.103
21561,12:0731:04:1591,Cell ( 1583 379 ) Found! SNR Level ( 0 :UltraHigh->3:Low ) = 3 ,2026-05-04 15:15:42.742
21587,12:0928:02:1000,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -105 ) , RSRQ ( -14 ) , SNR ( -4 ) ,2026-05-04 15:15:44.680
21634,13:0160:02:1154,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -105 ) , RSRQ ( -13 ) , SNR ( -3 ) ,2026-05-04 15:15:47.219
21681,13:0416:02:1320,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -105 ) , RSRQ ( -13 ) , SNR ( -4 ) ,2026-05-04 15:15:49.783
21724,13:0672:06:1774,IDLE: SERV CELL ( 6254 , 201 ) : RSRP ( -105 ) , RSRQ ( -14 ) , SNR ( -3 ) ,2026-05-04 15:15:52.347
21739,13:0750:04:1589,Cell ( 9622 302 ) Found! SNR Level ( 0 :UltraHigh->3:Low ) = 3 ,2026-05-04 15:15:53.107