nRF9160 wont register but sees an available network

[RossJ]

Recently I've had an issue with 3 of our nRF9160 based products during production (several hundred of the same hardware/firmware/SIMs work fine). The issue is that while the modem has good signal and can see the network we wish to connect to (+COPS even reports <stat>=1 / available), +CEREG reports searching endlessly (<stat>=2). There doesn't appear to be any errors being reported, it's just not registering. I've tested numerous variations: different SIMs (and providers), our firmware and AT client, different locations to obtain a very strong signal, left it operating for many hours at a time...

I've run a modem trace (full) overnight (100MB). I've browsed through it but don't see anything obvious to explain my problem. The following are of note...

* There is a RESET LOOP event reported every 3 hours which coincides with our application rebooting (does do a CFUN 0). I assume this is just reporting the reset loop counter being stepped and not that it's reached the point of restriction. Regardless, 3 hours should be long enough to clear it. I see no evidence of modem reboots.

* There is a pattern where +CEREG includes <tac>,<ci> and <AcT> for a short period following an attach request then it returns about 13 minutes later. e.g.

   1929 2025-03-28 05:33:09.532628         AT       21     74720    Sent AT Command: AT+CEREG?
   1930 2025-03-28 05:33:09.532689         AT       29     74749    Rcvd AT Command: +CEREG: 5,2  OK  
   1931 2025-03-28 05:34:09.539311         AT       21     74770    Sent AT Command: AT+CEREG?
   1932 2025-03-28 05:34:09.539372         AT       29     74799    Rcvd AT Command: +CEREG: 5,2  OK  
   1933 2025-03-28 05:35:09.539952         AT       21     74820    Sent AT Command: AT+CEREG?
   1934 2025-03-28 05:35:09.540013         AT       29     74849    Rcvd AT Command: +CEREG: 5,2  OK  
   1935 2025-03-28 05:35:13.747593         AT       30     74879    Rcvd AT Command: %CESQ: 44,2,13,1  
   1936 2025-03-28 05:35:14.707646         AT       30     74909    Rcvd AT Command: %CESQ: 44,2,18,2  
   1937 2025-03-28 05:35:30.708104         AT       30     74939    Rcvd AT Command: %CESQ: 45,2,23,3  
   1938 2025-03-28 05:35:31.348118         AT       30     74969    Rcvd AT Command: %CESQ: 45,2,18,2  
   1939 2025-03-28 05:36:03.989049         AT       30     74999    Rcvd AT Command: %CESQ: 45,2,13,1  
   1940 2025-03-28 05:36:05.269078         AT       30     75029    Rcvd AT Command: %CESQ: 45,2,19,2  
   1941 2025-03-28 05:36:08.149174         AT       30     75059    Rcvd AT Command: %CESQ: 45,2,11,1  
   1942 2025-03-28 05:36:08.469182         AT       30     75089    Rcvd AT Command: %CESQ: 45,2,16,2  
   1943 2025-03-28 05:36:09.546635         AT       21     75110    Sent AT Command: AT+CEREG?
   1944 2025-03-28 05:36:09.546696         AT       29     75139    Rcvd AT Command: +CEREG: 5,2  OK  
   1945 2025-03-28 05:36:11.669285         AT       30     75169    Rcvd AT Command: %CESQ: 45,2,11,1  
   1946 2025-03-28 05:36:14.229588         AT       30     75199    Rcvd AT Command: %CESQ: 45,2,16,2  
   1947 2025-03-28 05:36:21.589787         AT       30     75229    Rcvd AT Command: %CESQ: 45,2,11,1  
   1948 2025-03-28 05:36:35.989964         AT       30     75259    Rcvd AT Command: %CESQ: 45,2,17,2  
   1949 2025-03-28 05:36:59.670628         AT       30     75289    Rcvd AT Command: %CESQ: 46,2,22,3  
   1950 2025-03-28 05:37:06.812993         NAS-EPS  83     75372    Attach request, PDN connectivity request
   1951 2025-03-28 05:37:06.861485         LTE RRC UL_CCCH 30     75402    RRCConnectionRequest
   1952 2025-03-28 05:37:09.547276         AT       21     75423    Sent AT Command: AT+CEREG?
   1953 2025-03-28 05:37:09.547398         AT       49     75472    Rcvd AT Command: +CEREG: 5,2,"304F","082D7B0C",7  OK  
   1954 2025-03-28 05:37:13.751042         AT       30     75502    Rcvd AT Command: %CESQ: 45,2,15,2  
   1955 2025-03-28 05:37:18.863377         NAS-EPS  83     75585    Attach request, PDN connectivity request
   1956 2025-03-28 05:37:18.867589         LTE RRC UL_CCCH 30     75615    RRCConnectionRequest
   1957 2025-03-28 05:37:20.784764         AT       30     75645    Rcvd AT Command: %CESQ: 46,2,20,2  
   1958 2025-03-28 05:37:29.751500         AT       30     75675    Rcvd AT Command: %CESQ: 45,2,14,2  
   1959 2025-03-28 05:37:30.869755         NAS-EPS  83     75758    Attach request, PDN connectivity request
   1960 2025-03-28 05:37:30.871586         LTE RRC UL_CCCH 30     75788    RRCConnectionRequest
   1961 2025-03-28 05:37:31.024754         AT       30     75818    Rcvd AT Command: %CESQ: 45,2,19,2  
   1962 2025-03-28 05:37:32.875676         AT       30     75848    Rcvd AT Command: %CESQ: 46,2,14,2  
   1963 2025-03-28 05:37:32.951939         AT       29     75877    Rcvd AT Command: %CESQ: 45,2,9,1  
   1964 2025-03-28 05:37:35.511632         AT       30     75907    Rcvd AT Command: %CESQ: 45,2,15,2  
   1965 2025-03-28 05:37:37.111699         AT       30     75937    Rcvd AT Command: %CESQ: 45,2,20,2  
   1966 2025-03-28 05:37:39.991765         AT       30     75967    Rcvd AT Command: %CESQ: 46,2,14,2  
   1967 2025-03-28 05:37:41.591801         AT       30     75997    Rcvd AT Command: %CESQ: 45,2,19,2  
   1968 2025-03-28 05:37:42.875493         NAS-EPS  83     76080    Attach request, PDN connectivity request
   1969 2025-03-28 05:37:42.925938         AT       32     76112    Rcvd AT Command: %CESQ: 255,0,255,0  
   1970 2025-03-28 05:37:42.977055         LTE RRC DL_SCH 117    76229    SystemInformationBlockType1
   1971 2025-03-28 05:37:42.978306         LTE RRC DL_SCH 103    76332    SystemInformation [ SIB2 SIB3 ]
   1972 2025-03-28 05:37:42.978367         LTE RRC DL_SCH 47     76379    SystemInformation [ SIB4 ]
   1973 2025-03-28 05:37:42.978459         LTE RRC DL_SCH 69     76448    SystemInformation [ SIB5 ]
   1974 2025-03-28 05:37:42.980473         NAS-EPS  83     76531    Attach request, PDN connectivity request
   1975 2025-03-28 05:37:42.982304         LTE RRC UL_CCCH 30     76561    RRCConnectionRequest
   1976 2025-03-28 05:37:42.982609         AT       29     76590    Rcvd AT Command: %CESQ: 37,1,2,0  
   1977 2025-03-28 05:37:42.982762         AT       43     76633    Rcvd AT Command: +CEREG: 2,"3053","08267201",7  
   1978 2025-03-28 05:37:43.185124         AT       29     76662    Rcvd AT Command: %CESQ: 41,2,8,1  
   1979 2025-03-28 05:37:45.125371         AT       29     76691    Rcvd AT Command: %CESQ: 31,1,0,0  
   1980 2025-03-28 05:37:54.984166         NAS-EPS  83     76774    Attach request, PDN connectivity request
   1981 2025-03-28 05:37:54.987584         AT       32     76806    Rcvd AT Command: %CESQ: 255,0,255,0  
   1982 2025-03-28 05:37:55.057377         LTE RRC DL_SCH 117    76923    SystemInformationBlockType1
   1983 2025-03-28 05:37:55.362523         LTE RRC DL_SCH 117    77040    SystemInformationBlockType1
   1984 2025-03-28 05:37:55.363469         LTE RRC DL_SCH 117    77157    SystemInformation [ SIB2 SIB3 ]
   1985 2025-03-28 05:37:55.363591         LTE RRC DL_SCH 69     77226    SystemInformation [ SIB4 ]
   1986 2025-03-28 05:37:55.363988         LTE RRC DL_SCH 103    77329    SystemInformation [ SIB5 ]
   1987 2025-03-28 05:37:55.366520         NAS-EPS  83     77412    Attach request, PDN connectivity request
   1988 2025-03-28 05:37:55.368290         AT       30     77442    Rcvd AT Command: %CESQ: 46,2,18,2  
   1989 2025-03-28 05:37:55.368443         AT       43     77485    Rcvd AT Command: +CEREG: 2,"304F","082D7B0C",7  
   1990 2025-03-28 05:37:55.373051         LTE RRC UL_CCCH 30     77515    RRCConnectionRequest
   1991 2025-03-28 05:38:09.554020         AT       21     77536    Sent AT Command: AT+CEREG?
   1992 2025-03-28 05:38:09.554082         AT       29     77565    Rcvd AT Command: +CEREG: 5,2  OK  
   1993 2025-03-28 05:39:09.554661         AT       21     77586    Sent AT Command: AT+CEREG?
   1994 2025-03-28 05:39:09.554753         AT       29     77615    Rcvd AT Command: +CEREG: 5,2  OK  
   1995 2025-03-28 05:39:19.834630         AT       30     77645    Rcvd AT Command: %CESQ: 45,2,11,1  
   1996 2025-03-28 05:39:20.794682         AT       30     77675    Rcvd AT Command: %CESQ: 45,2,18,2  
   1997 2025-03-28 05:39:25.274785         AT       30     77705    Rcvd AT Command: %CESQ: 45,2,12,1  
   1998 2025-03-28 05:39:26.234562         AT       30     77735    Rcvd AT Command: %CESQ: 45,2,17,2  
   1999 2025-03-28 05:39:30.074925         AT       30     77765    Rcvd AT Command: %CESQ: 45,2,11,1  
   2000 2025-03-28 05:39:30.714696         AT       30     77795    Rcvd AT Command: %CESQ: 45,2,17,2  
   2001 2025-03-28 05:39:34.874821         AT       30     77825    Rcvd AT Command: %CESQ: 45,2,12,1  
   2002 2025-03-28 05:39:36.474858         AT       30     77855    Rcvd AT Command: %CESQ: 45,2,18,2  
   2003 2025-03-28 05:39:37.434910         AT       30     77885    Rcvd AT Command: %CESQ: 45,2,11,1  
   2004 2025-03-28 05:39:38.394902         AT       30     77915    Rcvd AT Command: %CESQ: 45,2,17,2  
   2005 2025-03-28 05:39:49.915501         AT       30     77945    Rcvd AT Command: %CESQ: 45,2,11,1  
   2006 2025-03-28 05:39:51.835301         AT       30     77975    Rcvd AT Command: %CESQ: 44,2,16,2  
   2007 2025-03-28 05:39:58.875737         AT       30     78005    Rcvd AT Command: %CESQ: 45,2,10,1  
   2008 2025-03-28 05:39:59.515782         AT       30     78035    Rcvd AT Command: %CESQ: 45,2,16,2  
   2009 2025-03-28 05:40:03.355595         AT       30     78065    Rcvd AT Command: %CESQ: 45,2,11,1  
   2010 2025-03-28 05:40:05.595707         AT       30     78095    Rcvd AT Command: %CESQ: 45,2,18,2  
   2011 2025-03-28 05:40:05.915959         AT       30     78125    Rcvd AT Command: %CESQ: 45,2,13,1  
   2012 2025-03-28 05:40:06.555974         AT       30     78155    Rcvd AT Command: %CESQ: 45,2,18,2  
   2013 2025-03-28 05:40:08.156010         AT       30     78185    Rcvd AT Command: %CESQ: 45,2,13,1  
   2014 2025-03-28 05:40:09.561345         AT       21     78206    Sent AT Command: AT+CEREG?
   2015 2025-03-28 05:40:09.561406         AT       29     78235    Rcvd AT Command: +CEREG: 5,2  OK  

I'd appreciate any thoughts as to what might cause this behaviour and what additional analysis I can do.

Configuration: nRF9160 SICA B1, SDK 2.3.0, mfw 1.3.3 and 1.3.5

[RossJ]

I've captured a new modem trace over 20 min from the time the modem is turned on. It demonstrates the same cyclic behaviour as mentioned previously. It looks like several connection requests are being made before waiting 12 minutes and trying again.

trace-2025-03-28T04-31-13.603Z.mtrace

[Charlie]

Hi Ross,

Thanks for reporting this issue. I checked the modem trace, and it clearly shows the problem.

Before performing a chip swap between the good device and the faulty one to determine if the issue originates from the nRF9160 chip itself, could you first:

Record modem traces from both a working device and the problematic one side by side, using SIM cards from the same network operator. Share a picture of both devices.

This will help us analyze the issue further.

Best regards,
Charlie

[RossJ]

Hi Charlie,

I've run a new trace on two devices (700 works and 855 fails). I only have hardware to capture trace from one unit at a time so I ran the same test (same SIM) consecutively. The devices are sitting side by side. Both devices are the same hardware, firmware and mfw. 700 is a little older (still B1A). I've also attached photos of the nRF module on each.

700 trace (ok).mtrace855 trace (fail).mtrace

[Charlie]

Hi Ross,

Following is the analysis from our modem expert:

Situation is identical in pass and fail log. Received SIBs and signal levels are same. After ConnectionRequest, RSRP and patloss are same for both devices so everything indicates that devices are in the exact same location. In fail log UE loops prach until T300 expires (= Connection establishment failure). RAR is not received from NW. In pass log RAR is received immediately in first trial and Connection establishment is successful.

So either

1. NW doesn’t receive UE prach transmission

   1. UE increases prach transmission power and repetitions after every loop so this is very unlikely if HW is OK.

2. NW ignores UE prach

   1. Can’t figure out the reason for this because other device is OK

3. UE doesn’t receive or cannot decode RAR

   1. Very unlikely if HW is OK because RSRP level is same in both devices

None of these cannot be debugged further from UE log.

The analysis of the modem trace points to a potential HW issue. Could you hook up the faulty units to a protocol tester (or oscilloscope) and use XRFTEST to check if there is any energy in the uplink direction?

Alternatively, a chip swap between a good and faulty device could quickly verify whether this assumption about HW failure is correct.

Best regards,

Charlie