NRF9160 reboot loop when network activated

[leap_lede]

I am building and running the Serial LTE application on a nrf9160. But am facing an issue with the application going into a reboot loop when network is activated.

I am using the SDK 2.6.1

The board is a Mikroe LTE 4. I have created a custom board definition based on the nrf9160dk. Board files attached below.

The app is configured with CONFIG_SLM_AUTO_CONNECT=y

When flashed, the application is constantly rebooting. If i deactivate the network connection with AT+CFUN=0, it stops rebooting.

Serial Console Output of the reboots:

[Sec Thread] Secure image initializing!
TF-M Float ABI: Hard
Lazy stacking enabled
Booting TF-M v2.0.0
Ready
[Sec Thread] Secure image initializing!
TF-M Float ABI: Hard
Lazy stacking enabled
Booting TF-M v2.0.0
Ready
[Sec Thread] Secure image initializing!
TF-M Float ABI: Hard
Lazy stacking enabled
Booting TF-M v2.0.0
Ready
[Sec Thread] Secure image initializing!
TF-M Float ABI: Hard
Lazy stacking enabled
Booting TF-M v2.0.0
Ready

RTT Output:

[00:00:00.253,112] <dbg> os: setup_thread_stack: stack 0x20028d00 for thread 0x20014628: obj_size=4096 buf_start=0x20028d00  buf_size 4096 stack_ptr=0x20029d00
[00:00:00.253,936] <dbg> os: z_impl_k_mutex_lock: 0x20014540 took mutex 0x2001114c, count: 1, orig prio: 0
[00:00:00.254,486] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001114c lock_count: 1
[00:00:00.254,943] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001114c: 0 (prio: -1000)
[00:00:00.255,462] <dbg> os: z_impl_k_mutex_lock: 0x20014540 took mutex 0x2001114c, count: 1, orig prio: 0
[00:00:00.256,011] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001114c lock_count: 1
[00:00:00.256,469] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001114c: 0 (prio: -1000)
[00:00:00.256,988] <dbg> os: z_impl_k_mutex_lock: 0x20014540 took mutex 0x2001114c, count: 1, orig prio: 0

mikroe_lte.zip

Config from the build folder

config.txt.zip

[leap_lede]

I was able to capture more logs by logging them directly to UART. Here are all the logs from boot until restart.

[Sec Thread] Secure image initializing!
TF-M Float ABI: Hard
Lazy stacking enabled
Booting TF-M v2.0.0
[00:00:00.253,112] <dbg> os: setup_thread_stack: stack 0x20028850 for thread 0x20014620: obj_size=4096 buf_start=0x20028850  buf_size 4096 stack_ptr=0x20029850
[00:00:00.267,974] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20011154, count: 1, orig prio: 0
[00:00:00.278,106] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20011154 lock_count: 1
[00:00:00.286,224] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20011154: 0 (prio: -1000)
[00:00:00.295,715] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20011154, count: 1, orig prio: 0
[00:00:00.305,877] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20011154 lock_count: 1
[00:00:00.313,964] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20011154: 0 (prio: -1000)
[00:00:00.323,455] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20011154, count: 1, orig prio: 0
[00:00:00.333,648] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20011154 lock_count: 1
[00:00:00.341,735] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20011154: 0 (prio: -1000)
[00:00:00.351,226] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20011154, count: 1, orig prio: 0
[00:00:00.361,389] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20011154 lock_count: 1
[00:00:00.369,506] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20011154: 0 (prio: -1000)
[00:00:00.378,997] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20011154, count: 1, orig prio: 0
[00:00:00.389,160] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20011154 lock_count: 1
[00:00:00.397,247] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20011154: 0 (prio: -1000)
[00:00:00.406,768] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20011140, count: 1, orig prio: 0
[00:00:00.416,992] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20011230, count: 1, orig prio: 0
[00:00:00.427,581] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20011230 lock_count: 1
[00:00:00.435,638] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20011230: 0 (prio: -1000)
[00:00:00.445,129] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20011140 lock_count: 1
[00:00:00.453,216] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20011140: 0 (prio: -1000)
[00:00:00.462,707] <dbg> os: setup_thread_stack: stack 0x2001f930 for thread 0x20011a98: obj_size=1504 buf_start=0x2001f930  buf_size 1504 stack_ptr=0x2001ff10
*** Booting nRF Connect SDK v3.5.99-ncs1-1 ***
[00:00:00.481,811] <dbg> os: setup_thread_stack: stack 0x20021210 for thread 0x20011d80: obj_size=1024 buf_start=0x20021210  buf_size 1024 stack_ptr=0x20021610
[00:00:00.496,643] <dbg> os: setup_thread_stack: stack 0x20021b10 for thread 0x20012890: obj_size=3072 buf_start=0x20021b10  buf_size 3072 stack_ptr=0x20022710
[00:00:00.511,474] <dbg> os: setup_thread_stack: stack 0x20021610 for thread 0x20011e68: obj_size=1280 buf_start=0x20021610  buf_size 1280 stack_ptr=0x20021b10
[00:00:00.526,306] <dbg> os: setup_thread_stack: stack 0x2001ff10 for thread 0x20011cb8: obj_size=768 buf_start=0x2001ff10  buf_size 768 stack_ptr=0x20020210
[00:00:00.540,954] <dbg> os: k_sched_unlock: scheduler unlocked (0x20014538:0)
[00:00:00.548,675] <dbg> slm: main: RR: 0x00000000
[00:00:00.553,955] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20011208, count: 1, orig prio: 0
[00:00:00.564,300] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20014d1c, count: 1, orig prio: 0
[00:00:00.574,462] <dbg> fs_nvs: nvs_recover_last_ate: Recovering last ate from sector 0
[00:00:00.589,447] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20014d1c lock_count: 1
[00:00:00.597,503] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20014d1c: 0 (prio: -1000)
[00:00:00.606,994] <inf> fs_nvs: 2 Sectors of 4096 bytes
[00:00:00.612,792] <inf> fs_nvs: alloc wra: 0, fe8
[00:00:00.618,072] <inf> fs_nvs: data wra: 0, 0
[00:00:00.623,077] <dbg> settings: settings_nvs_backend_init: Initialized
[00:00:00.630,371] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20011208 lock_count: 1
[00:00:00.638,458] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20011208: 0 (prio: -1000)
[00:00:00.647,949] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20011208, count: 1, orig prio: 0
[00:00:00.658,142] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20011208 lock_count: 1
[00:00:00.666,229] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20011208: 0 (prio: -1000)
[00:00:00.675,720] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20011208, count: 1, orig prio: 0
[00:00:00.685,913] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20011208 lock_count: 1
[00:00:00.694,000] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20011208: 0 (prio: -1000)
[00:00:00.936,340] <inf> nrf_modem_lib_trace: Trace thread ready
[00:00:00.942,840] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20015528, count: 1, orig prio: 0
[00:00:00.960,449] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20015528 lock_count: 1
[00:00:00.968,505] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20015528: 0 (prio: -1000)
[00:00:00.978,027] <inf> nrf_modem_lib_trace: Trace level override: 2
[00:00:00.984,954] <dbg> nrf_modem: nrf_modem_lib_init: Modem init callback: 0x1a24d
[00:00:00.993,194] <inf> slm: lib_modem init: 0
[00:00:00.998,260] <inf> mcuboot_util: Image index: 0, Swap type: none
[00:00:01.005,249] <inf> slm: Serial LTE Modem
[00:00:01.010,284] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x200111a4, count: 1, orig prio: 0
[00:00:01.020,416] <dbg> os: z_impl_k_mutex_unlock: mutex 0x200111a4 lock_count: 1
[00:00:01.028,503] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x200111a4: 0 (prio: -1000)
[00:00:01.038,757] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x200129f0, count: 1, orig prio: 0
[00:00:01.048,919] <dbg> os: setup_thread_stack: stack 0x20013380 for thread 0x200132a0: obj_size=4096 buf_start=0x20013380  buf_size 4096 stack_ptr=0x20014380
[00:00:01.063,751] <dbg> os: z_impl_k_mutex_unlock: mutex 0x200129f0 lock_count: 1
[00:00:01.071,838] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x200129f0: 0 (prio: -1000)
[00:00:01.081,359] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x2001117c, count: 1, orig prio: 0
[00:00:01.091,522] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001117c lock_count: 1
[00:00:01.099,609] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001117c: 0 (prio: -1000)
[00:00:01.109,252] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20015528, count: 1, orig prio: 0
[00:00:01.211,212] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20015528 lock_count: 1
[00:00:01.219,268] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20015528: 0 (prio: -1000)
[00:00:01.229,888] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x2001121c, count: 1, orig prio: 0
[00:00:01.240,051] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001121c lock_count: 1
[00:00:01.248,138] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001121c: 0 (prio: -1000)
[00:00:01.257,690] <dbg> os: setup_thread_stack: stack 0x20022710 for thread 0x20014388: obj_size=2048 buf_start=0x20022710  buf_size 2048 stack_ptr=0x20022f10
[00:00:01.272,552] <inf> slm_uart_handler: UART baud: 115200 d/p/s-bits: 3/0/1 HWFC: 0
[00:00:01.281,036] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x200111cc, count: 1, orig prio: 0
Ready
[00:00:01.291,198] <dbg> os: z_impl_k_mutex_unlock: mutex 0x200111cc lock_count: 1
[00:00:01.299,896] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x200111cc: 0 (prio: -1000)
[00:00:01.309,356] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      52 65 61 64 79 0d 0a                             |Ready..          
[00:00:01.325,714] <inf> slm_at_host: at_host init done
[00:00:01.331,542] <dbg> os: setup_thread_stack: stack 0x2001b930 for thread 0x200114d0: obj_size=4096 buf_start=0x2001b930  buf_size 4096 stack_ptr=0x2001c930
[00:00:01.346,710] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20015528, count: 1, orig prio: 0
[00:00:01.363,983] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20015528 lock_count: 1
[00:00:01.372,161] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20015528: 0 (prio: -1000)
[00:00:01.381,652] <inf> slm: lte auto connect
[00:00:01.387,023] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20015528, count: 1, orig prio: 0
[00:00:01.406,188] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20015528 lock_count: 1
[00:00:01.414,306] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20015528: 0 (prio: -1000)
[00:00:01.424,194] <dbg> os: z_impl_k_mutex_lock: 0x20014538 took mutex 0x20015528, count: 1, orig prio: 0
[00:00:01.472,717] <dbg> os: z_impl_k_mutex_unlock: mutex 0x20015528 lock_count: 1
[00:00:01.480,834] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x20015528: 0 (prio: -1000)

[Susheel Nuguru]

Hi Leap, this does not seem be giving much info about the restart. Can you please enable all the logging as mentioned in this thread?

It is important to understand the context of the reboot before we can proceed and the logs you provided does not give the context of reboot.

[leap_lede]

Hello Susheel,
Thank you for your reply.

I have activated the logging as per the link you shared but i'm afraid i'm not getting more insights.

But I have tested some more and this might provide more context. 
When Starting the program without a sim card but with auto connect it doesn't crash. But the moment i issue an AT+COPS=? command, it reboots. And it reboots without showing anything in the logs post command. Below are the logs with all the config enabled from the moment it turns on until the crash

[Sec Thread] Secure image initializing!
TF-M Float ABI: Hard
Lazy stacking enabled
Booting TF-M v2.0.0
[00:00:00.253,082] <dbg> os: setup_thread_stack: stack 0x20021c08 for thread 0x2000f9d8: obj_size=4096 buf_start=0x20021c08  buf_size 4096 stack_ptr=0x20022c08
[00:00:00.268,554] <dbg> os: z_impl_k_mutex_lock: 0x2000f8f0 took mutex 0x2000cad8, count: 1, orig prio: 0
[00:00:00.279,174] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2000cad8 lock_count: 1
[00:00:00.287,597] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2000cad8: 0 (prio: -1000)
*** Booting nRF Connect SDK v3.5.99-ncs1-1 ***
[00:00:00.301,818] <dbg> os: setup_thread_stack: stack 0x2001aec8 for thread 0x2000dc48: obj_size=3072 buf_start=0x2001aec8  buf_size 3072 stack_ptr=0x2001bac8
[00:00:00.317,291] <dbg> os: setup_thread_stack: stack 0x2001a9c8 for thread 0x2000d220: obj_size=1280 buf_start=0x2001a9c8  buf_size 1280 stack_ptr=0x2001aec8
[00:00:00.332,702] <dbg> os: k_sched_unlock: scheduler unlocked (0x2000f8f0:0)
[00:00:00.340,759] <dbg> slm: main: RR: 0x00040000
[00:00:00.346,313] <dbg> os: z_impl_k_mutex_lock: 0x2000f8f0 took mutex 0x2000cb8c, count: 1, orig prio: 0
[00:00:00.372,131] <dbg> os: z_impl_k_mutex_lock: 0x2000f8f0 took mutex 0x200100ec, count: 1, orig prio: 0
[00:00:00.397,857] <dbg> fs_nvs: nvs_recover_last_ate: Recovering last ate from sector 0
[00:00:00.427,978] <dbg> os: z_impl_k_mutex_unlock: mutex 0x200100ec lock_count: 1
[00:00:00.451,507] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x200100ec: 0 (prio: -1000)
[00:00:00.476,440] <inf> fs_nvs: 2 Sectors of 4096 bytes
[00:00:00.497,589] <inf> fs_nvs: alloc wra: 0, fe8
[00:00:00.518,218] <inf> fs_nvs: data wra: 0, 0
[00:00:00.538,574] <dbg> settings: settings_nvs_backend_init: Initialized
[00:00:00.561,248] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2000cb8c lock_count: 1
[00:00:00.584,747] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2000cb8c: 0 (prio: -1000)
[00:00:00.609,710] <dbg> os: z_impl_k_mutex_lock: 0x2000f8f0 took mutex 0x2000cb8c, count: 1, orig prio: 0
[00:00:00.635,406] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2000cb8c lock_count: 1
[00:00:00.658,905] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2000cb8c: 0 (prio: -1000)
[00:00:00.683,868] <dbg> os: z_impl_k_mutex_lock: 0x2000f8f0 took mutex 0x2000cb8c, count: 1, orig prio: 0
[00:00:00.709,564] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2000cb8c lock_count: 1
[00:00:00.733,062] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2000cb8c: 0 (prio: -1000)
[00:00:00.986,877] <dbg> nrf_modem: nrf_modem_lib_init: Modem init callback: 0x19dc5
[00:00:01.010,528] <inf> slm: lib_modem init: 0
[00:00:01.030,914] <inf> mcuboot_util: Image index: 0, Swap type: none
[00:00:01.053,283] <inf> slm: Serial LTE Modem
[00:00:01.073,608] <dbg> os: z_impl_k_mutex_lock: 0x2000f8f0 took mutex 0x2000cb14, count: 1, orig prio: 0
[00:00:01.099,304] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2000cb14 lock_count: 1
[00:00:01.122,802] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2000cb14: 0 (prio: -1000)
[00:00:01.148,498] <dbg> os: z_impl_k_mutex_lock: 0x2000f8f0 took mutex 0x2000dda8, count: 1, orig prio: 0
[00:00:01.174,194] <dbg> os: setup_thread_stack: stack 0x2000e738 for thread 0x2000e658: obj_size=4096 buf_start=0x2000e738  buf_size 4096 stack_ptr=0x2000f738
[00:00:01.204,681] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2000dda8 lock_count: 1
[00:00:01.228,179] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2000dda8: 0 (prio: -1000)
[00:00:01.253,173] <dbg> os: z_impl_k_mutex_lock: 0x2000f8f0 took mutex 0x2000caec, count: 1, orig prio: 0
[00:00:01.278,869] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2000caec lock_count: 1
[00:00:01.302,368] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2000caec: 0 (prio: -1000)
[00:00:01.327,453] <dbg> os: z_impl_k_mutex_lock: 0x2000f8f0 took mutex 0x200101e4, count: 1, orig prio: 0
[00:00:01.444,335] <dbg> os: z_impl_k_mutex_unlock: mutex 0x200101e4 lock_count: 1
[00:00:01.467,864] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x200101e4: 0 (prio: -1000)
[00:00:01.493,927] <dbg> os: z_impl_k_mutex_lock: 0x2000f8f0 took mutex 0x2000cba0, count: 1, orig prio: 0
[00:00:01.519,622] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2000cba0 lock_count: 1
[00:00:01.543,121] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2000cba0: 0 (prio: -1000)
[00:00:01.568,115] <dbg> os: setup_thread_stack: stack 0x2001bac8 for thread 0x2000f740: obj_size=2048 buf_start=0x2001bac8  buf_size 2048 stack_ptr=0x2001c2c8
[00:00:01.598,632] <inf> slm_uart_handler: UART baud: 115200 d/p/s-bits: 3/0/1 HWFC: 0
[00:00:01.622,589] <dbg> os: z_impl_k_mutex_lock: 0x2000f8f0 took mutex 0x2000cb3c, count: 1, orig prio: 0
[00:00:01.649,505] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2000cb3c lock_count: 1
[00:00:01.674,987] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2000cb3c: 0 (prio: -1000)
Ready
[00:00:01.699,981] <dbg> slm_at_host: slm_at_send_indicate: TX
                                      52 65 61 64 79 0d 0a                             |Ready..          
[00:00:01.735,137] <inf> slm_at_host: at_host init done
[00:00:01.758,056] <dbg> os: setup_thread_stack: stack 0x200159c8 for thread 0x2000cd40: obj_size=4096 buf_start=0x200159c8  buf_size 4096 stack_ptr=0x200169c8
[00:00:01.790,618] <dbg> os: z_impl_k_mutex_lock: 0x2000f8f0 took mutex 0x200101e4, count: 1, orig prio: 0
[00:00:01.822,937] <dbg> os: z_impl_k_mutex_unlock: mutex 0x200101e4 lock_count: 1
[00:00:01.848,358] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x200101e4: 0 (prio: -1000)
[00:00:01.873,382] <inf> slm: lte auto connect
[00:00:01.896,697] <dbg> os: z_impl_k_mutex_lock: 0x2000f8f0 took mutex 0x200101e4, count: 1, orig prio: 0
[00:00:01.931,945] <dbg> os: z_impl_k_mutex_unlock: mutex 0x200101e4 lock_count: 1
[00:00:01.957,214] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x200101e4: 0 (prio: -1000)
[00:00:01.982,269] <dbg> os: z_impl_k_mutex_lock: 0x2000f8f0 took mutex 0x200101e4, count: 1, orig prio: 0
[00:00:02.047,424] <dbg> os: z_impl_k_mutex_unlock: mutex 0x200101e4 lock_count: 1
[00:00:02.072,692] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x200101e4: 0 (prio: -1000)
> AT+COPS=?
[00:00:07.592,529] <dbg> os: z_impl_k_mutex_lock: 0x2000f9d8 took mutex 0x2000cb14, count: 1, orig prio: -1
[00:00:07.619,506] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2000cb14 lock_count: 1
[00:00:07.644,836] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2000cb14: 0 (prio: -1000)
[00:00:07.669,830] <dbg> slm_at_host: cmd_send: RX
                                      41 54 2b 43 4f 50 53 3d  3f                      |AT+COPS= ?       
[00:00:07.703,765] <dbg> os: z_impl_k_mutex_lock: 0x2000f9d8 took mutex 0x200101e4, count: 1, orig prio: -1

[Sec Thread] Secure image initializing!
TF-M Float ABI: Hard
Lazy stacking enabled
Booting TF-M v2.0.0
[00:00:00.253,112] <dbg> os: setup_thread_stack: stack 0x20021c08 for thread 0x2000f9d8: obj_size=4096 buf_start=0x20021c08  buf_size 4096 stack_ptr=0x20022c08
[00:00:00.268,585] <dbg> os: z_impl_k_mutex_lock: 0x2000f8f0 took mutex 0x2000cad8, count: 1, orig prio: 0
[00:00:00.279,205] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2000cad8 lock_count: 1
[00:00:00.287,628] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2000cad8: 0 (prio: -1000)
*** Booting nRF Connect SDK v3.5.99-ncs1-1 ***

I have also tried a different sample app, that provisions a soft sim. It is also crashing when attempting to connect. Note this was built using the nrf9160dk board config. Below are the full logs.:

[00:00:00.266,998] <dbg> os: setup_thread_stack: stack 0x20022cc8 for thread 0x2001c0a0: obj_size=5000 buf_start=0x20022cc8  buf_size 5000 stack_ptr=0x20024050
[00:00:00.267,028] <dbg> os: setup_thread_stack: stack 0x20022b88 for thread 0x2001c018: obj_size=320 buf_start=0x20022b88  buf_size 320 stack_ptr=0x20022cc8
[00:00:00.267,059] <dbg> clock_control: clkstarted_handle: lfclk: Clock started
[00:00:00.267,089] <dbg> os: setup_thread_stack: stack 0x2001f478 for thread 0x2001aa28: obj_size=768 buf_start=0x2001f478  buf_size 768 stack_ptr=0x2001f778
[00:00:00.267,120] <dbg> os: setup_thread_stack: stack 0x2002b580 for thread 0x2001c148: obj_size=1152 buf_start=0x2002b580  buf_size 1152 stack_ptr=0x2002ba00
[00:00:00.267,242] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001a8c0, count: 1, orig prio: 0
[00:00:00.267,272] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001a8c0 lock_count: 1
[00:00:00.267,303] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001a8c0: (nil) (prio: -1000)
*** Booting nRF Connect SDK v3.5.99-ncs1-1 ***
[00:00:00.267,364] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001c674, count: 1, orig prio: 0
[00:00:00.273,223] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001c674 lock_count: 1
[00:00:00.273,254] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001c674: (nil) (prio: -1000)
[00:00:00.278,869] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001a8e8, count: 1, orig prio: 0
[00:00:00.279,510] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001a8e8 lock_count: 1
[00:00:00.279,541] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001a8e8: (nil) (prio: -1000)
[00:00:00.279,632] <dbg> os: setup_thread_stack: stack 0x2001fc78 for thread 0x2001bf70: obj_size=10000 buf_start=0x2001fc78  buf_size 10000 stack_ptr=0x20022388
[00:00:00.279,998] <dbg> os: setup_thread_stack: stack 0x2001f878 for thread 0x2001be98: obj_size=1024 buf_start=0x2001f878  buf_size 1024 stack_ptr=0x2001fc78
[00:00:00.280,029] <dbg> os: k_sched_unlock: scheduler unlocked (0x2001c0a0:0)
[00:00:00.280,059] <inf> softsim_sample: SoftSIM sample started.
[00:00:00.511,077] <dbg> nrf_modem: nrf_modem_lib_init: Modem init callback: 0x19211
[00:00:00.511,138] <dbg> modem_antenna: set_antenna_configuration: Setting configuration: AT%XMAGPIO=1,0,0,1,1,1574,1577
[00:00:00.511,169] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001c3a0, count: 1, orig prio: 0
[00:00:00.517,791] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001c3a0 lock_count: 1
[00:00:00.517,822] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001c3a0: (nil) (prio: -1000)
[00:00:00.517,852] <dbg> modem_antenna: set_antenna_configuration: Setting configuration: AT%XCOEX0=1,1,1565,1586
[00:00:00.517,883] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001c3a0, count: 1, orig prio: 0
[00:00:00.518,432] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001c3a0 lock_count: 1
[00:00:00.518,432] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001c3a0: (nil) (prio: -1000)
[00:00:00.518,463] <dbg> nrf_modem: nrf_modem_lib_init: Modem init callback: 0x19149
[00:00:00.518,493] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001c3a0, count: 1, orig prio: 0
[00:00:00.520,629] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001c3a0 lock_count: 1
[00:00:00.520,660] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001c3a0: (nil) (prio: -1000)
[00:00:00.520,660] <dbg> lte_lc: lte_lc_system_mode_set: System mode set to 7, preference 3
[00:00:00.520,721] <dbg> lte_lc: lte_lc_psm_param_set: RPTAU set to 00000011
[00:00:00.520,751] <dbg> lte_lc: lte_lc_psm_param_set: RAT set to 00100001
[00:00:00.520,812] <dbg> lte_lc: on_modem_init: PSM configs set from string: tau=00000011, rat=00100001
[00:00:00.520,874] <dbg> lte_lc: lte_lc_psm_req: enable=0, tau=00000011, rat=00100001
[00:00:00.520,874] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001c3a0, count: 1, orig prio: 0
[00:00:00.527,404] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001c3a0 lock_count: 1
[00:00:00.527,435] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001c3a0: (nil) (prio: -1000)
[00:00:00.527,435] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001c3a0, count: 1, orig prio: 0
[00:00:00.528,106] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001c3a0 lock_count: 1
[00:00:00.528,137] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001c3a0: (nil) (prio: -1000)
[00:00:00.528,137] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001c3a0, count: 1, orig prio: 0
[00:00:00.528,472] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001c3a0 lock_count: 1
[00:00:00.528,472] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001c3a0: (nil) (prio: -1000)
[00:00:00.528,503] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001c3a0, count: 1, orig prio: 0
[00:00:00.529,113] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001c3a0 lock_count: 1
[00:00:00.529,144] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001c3a0: (nil) (prio: -1000)
[00:00:00.529,144] <dbg> nrf_modem: nrf_modem_lib_init: Modem init callback: 0x1a78d
[00:00:00.529,174] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001c3a0, count: 1, orig prio: 0
[00:00:00.529,632] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001c3a0 lock_count: 1
[00:00:00.529,663] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001c3a0: (nil) (prio: -1000)
[00:00:00.529,693] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001a8ac, count: 1, orig prio: 0
[00:00:00.529,724] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001a8ac lock_count: 1
[00:00:00.529,724] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001a8ac: (nil) (prio: -1000)
[00:00:00.529,754] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001c3a0, count: 1, orig prio: 0
[00:00:00.530,334] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001c3a0 lock_count: 1
[00:00:00.530,364] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001c3a0: (nil) (prio: -1000)
[00:00:00.530,395] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001c3a0, count: 1, orig prio: 0
[00:00:00.536,743] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001c3a0 lock_count: 1
[00:00:00.536,743] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001c3a0: (nil) (prio: -1000)
[00:00:00.536,773] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001c3a0, count: 1, orig prio: 0
[00:00:00.537,078] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001c3a0 lock_count: 1
[00:00:00.537,109] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001c3a0: (nil) (prio: -1000)
[00:00:00.537,109] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001c3a0, count: 1, orig prio: 0
[00:00:00.537,445] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001c3a0 lock_count: 1
[00:00:00.537,475] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001c3a0: (nil) (prio: -1000)
[00:00:00.537,475] <dbg> os: z_impl_k_mutex_lock: 0x2001c0a0 took mutex 0x2001c3a0, count: 1, orig prio: 0
[00:00:00.573,913] <dbg> nrf_modem: cfun_callback: CFUN callback 0x19029
[00:00:00.573,913] <dbg> os: z_impl_k_mutex_unlock: mutex 0x2001c3a0 lock_count: 1
[00:00:00.573,944] <dbg> os: z_impl_k_mutex_unlock: new owner of mutex 0x2001c3a0: (nil) (prio: -1000)
[00:00:00.573,944] <inf> softsim_sample: Waiting for LTE connect event.