Hi
I am working on a custom board and have hit an issue with the software part. When the nrf_modem_lib_init function is invoked, it always ends with a timeout (errno -116). Same code works with the dev kit (nrf9160dk). Are there any common pitfalls, that could causes this issue?
Best Regards
Casper Mogensen
Did you happen to find out what was the hardware issue?
We see this behaviour on 3 out of 20 prototypes of a revised product (custom PCB). See below the log trace produced by attached code (calling nrf_modem_lib_init):
5426 1731337418.120 1 rx *** Booting MCUboot v2.1.0-dev-daf2946a0f07 *** 5427 1731337418.120 1 rx *** Using nRF Connect SDK v2.7.0-5cb85570ca43 *** 5428 1731337418.123 1 rx *** Using Zephyr OS v3.6.99-100befc70c74 *** 5429 1731337418.124 1 rx I: Starting bootloader 5430 1731337418.124 1 rx I: Primary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3 5431 1731337418.124 x tt 1731337418.124 2024-11-11T16:03:38.123639 5432 1731337418.124 1 rx I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3 5433 1731337418.124 1 rx I: Boot source: none 5434 1731337418.125 1 rx I: Image index: 0, Swap type: none 5435 1731337418.125 1 rx I: Bootloader chainload address offset: 0x10000 5436 1731337418.712 1 rx I: Jumping to the first image slot *** Booting nRF Connect SDK v2.7.0-5cb85570ca43 *** 5437 1731337418.713 1 rx *** Using Zephyr OS v3.6.99-100befc70c74 *** 5438 1731337418.713 1 rx [00:00:00.254,882] [1;33m<wrn> net_config: No auto-started network interface - network-bound app initialization skipped.[0m 5439 1731337418.713 1 rx Hello, world 5440 1731337418.713 1 rx 0 5441 1731337420.715 1 rx 1 5442 1731337420.715 1 rx 2 5443 1731337422.715 1 rx 3 5444 1731337422.715 1 rx 4 5445 1731337422.718 0 dp COM23 30:30:F9:BC:BA:40 5446 1731337422.718 0 op 5447 1731337424.721 1 rx 5 5448 1731337424.721 1 rx 6 5449 1731337426.712 1 rx 7 5450 1731337426.712 1 rx 8 5451 1731337428.124 x tt 1731337428.124 2024-11-11T16:03:48.123912 5452 1731337428.716 1 rx 9 5453 1731337428.716 1 rx [00:00:10.256,896] [0m<inf> nrf_modem: Initializing libmodem 2.7.0-cellular-28f48961a8dc[0m 5454 1731337428.719 1 rx [00:00:10.257,324] [0m<dbg> nrf_modem: Control region at 0x20008000 (0x4e8 bytes)[0m 5455 1731337428.720 1 rx [00:00:10.257,385] [0m<dbg> nrf_modem: TX region at 0x200084e8 (0x2000 bytes)[0m 5456 1731337428.720 1 rx [00:00:10.257,415] [0m<dbg> nrf_modem: RX region at 0x2000a568 (0x2000 bytes)[0m 5457 1731337428.720 1 rx [00:00:10.257,446] [0m<dbg> nrf_modem: Trace region at 0x2000c568 (0x4000 bytes)[0m 5458 1731337429.916 1 rx [00:00:10.434,265] [0m<dbg> nrf_modem: IPC trace ready[0m 5459 1731337438.224 x tt 1731337438.224 2024-11-11T16:03:58.224192 5460 1731337448.312 x tt 1731337448.312 2024-11-11T16:04:08.312444 5461 1731337458.424 x tt 1731337458.424 2024-11-11T16:04:18.423607 5462 1731337468.521 x tt 1731337468.521 2024-11-11T16:04:28.521142 5463 1731337478.615 x tt 1731337478.615 2024-11-11T16:04:38.614545 5464 1731337488.615 x tt 1731337488.615 2024-11-11T16:04:48.615181 5465 1731337498.626 x tt 1731337498.626 2024-11-11T16:04:58.625960 5466 1731337508.627 x tt 1731337508.627 2024-11-11T16:05:08.626704 5467 1731337518.715 x tt 1731337518.715 2024-11-11T16:05:18.715142 5468 1731337528.725 x tt 1731337528.725 2024-11-11T16:05:28.725108 5469 1731337538.817 x tt 1731337538.817 2024-11-11T16:05:38.817073 5470 1731337548.924 x tt 1731337548.924 2024-11-11T16:05:48.923729 5471 1731337558.925 x tt 1731337558.925 2024-11-11T16:05:58.924871 5472 1731337569.026 x tt 1731337569.026 2024-11-11T16:06:09.026002 5473 1731337578.811 1 rx main: err=-116 5474 1731337578.812 1 rx [00:02:40.258,056] [0m<dbg> nrf_modem: Power off[0m 5475 1731337578.814 1 rx [00:02:40.258,117] [1;31m<err> nrf_modem: Modem library initialization failed, err -116[0m 5476 1731337578.815 1 rx trace_backend_init 5477 1731337578.815 1 rx [00:02:40.258,148] [0m<inf> nrf_modem_lib_trace: Trace thread ready[0m 5478 1731337578.815 1 rx [00:02:40.258,178] [1;31m<err> nrf_modem_lib_trace: Failed to set trace level, err: -1[0m 5479 1731337578.815 1 rx [00:02:40.258,178] [0m<inf> nrf_modem_lib_trace: Trace level override: 2[0m 5480 1731337578.816 1 rx [00:02:40.258,209] [1;31m<err> nrf_modem_lib_trace: Failed to start tracing, err -8[0m 5481 1731337578.816 1 rx [00:02:40.258,209] [1;31m<err> nrf_modem: Unable to obtain modem FW version (ERR: -16711681, ERR TYPE: 255)[0m 5482 1731337578.816 1 rx [00:02:40.258,239] [1;31m<err> nrf_modem: Unable to obtain modem FW UUID (ERR: -16711681, ERR TYPE: 255) 5483 1731337578.817 1 rx [0m 5484 1731337578.817 1 rx [00:02:40.258,270] [0m<dbg> nrf_modem: nrf_modem_lib_init: Modem init callback: 0x24f91[0m 5485 1731337578.817 1 rx [00:02:40.258,300] [0m<dbg> nrf_modem: nrf_modem_lib_init: Modem init callback: 0x2619d[0m 5486 1731337578.817 1 rx [00:02:40.258,300] [0m<dbg> nrf_modem: nrf_modem_lib_init: Modem init callback: 0x32717[0m 5487 1731337578.817 1 rx zzz 5488 1731337578.818 1 rx trace_backend_write len=5 efbe300063 5489 1731337578.818 1 rx trace_backend_write len=48 b007b007b007b007b007b007b007b0070404180003000000010000006000000000800000ffffffff0000000000000000 5490 1731337578.818 1 rx [00:02:40.260,101] [0m<inf> nrf_modem_lib_trace: Modem was turned off, no more traces[0m 5491 1731337578.818 x tt 1731337578.818 2024-11-11T16:06:18.817976 5492 1731337578.818 1 rx trace_backend_deinit 5493 1731337580.712 1 rx zzz
#include <arpa/inet.h>
#include <stdio.h>
#include <string.h>
#include <zephyr/kernel.h>
#include <zephyr/drivers/clock_control.h>
#include <zephyr/drivers/clock_control/nrf_clock_control.h>
#include <nrf_modem.h>
#include <modem/nrf_modem_lib.h>
#include <modem/nrf_modem_lib_trace.h>
#include <modem/trace_backend.h>
/* To strictly comply with UART timing, enable external XTAL oscillator */
static void enable_xtal(void)
{
struct onoff_manager *clk_mgr;
static struct onoff_client cli = {};
clk_mgr = z_nrf_clock_control_get_onoff(CLOCK_CONTROL_NRF_SUBSYS_HF);
sys_notify_init_spinwait(&cli.notify);
(void)onoff_request(clk_mgr, &cli);
}
static trace_backend_processed_cb trace_processed_callback;
int trace_backend_init(trace_backend_processed_cb processed)
{
/* initialize transport backend here */
printk("%s\n", __func__);
trace_processed_callback = processed;
return 0;
}
int trace_backend_deinit(void)
{
/* optional deinitialization code here */
printk("%s\n", __func__);
return 0;
}
static void dump_buffer(const void *buf, uint32_t length)
{
for (uint32_t i = 0; i < length; ) {
if (!((int)buf & 0x3) && length - i >= 8) {
printk("%08x%08x", htonl(*((const uint32_t *)(const void *)((const uint8_t *)buf + i))), htonl(*((const uint32_t *)(const void *)((const uint8_t *)buf + i + 4))));
i += 8;
} else {
printk("%02x", *((uint8_t *)buf + i));
i++;
}
}
}
int trace_backend_write(const void *data, size_t len)
{
printk("%s len=%d ", __func__, len);
dump_buffer(data, len);
printk("\n");
int r = len;
int err = trace_processed_callback(r);
if (err) {
printk("%s err=%d\n", __func__, err);
return err;
}
return r;
}
struct nrf_modem_lib_trace_backend trace_backend = {
.init = trace_backend_init,
.deinit = trace_backend_deinit,
.write = trace_backend_write,
.data_size = NULL,
.read = NULL,
.clear = NULL,
};
void nrf_modem_fault_handler(struct nrf_modem_fault_info *fault_info)
{
printk(":<Mfh t=%u reason=%u pc=%08x\n", k_uptime_get_32(), fault_info->reason, fault_info->program_counter);
}
/**
* Application entry point: initialization and main loop.
*/
void main(void)
{
enable_xtal();
printk("Hello, world\n");
uint32_t i;
for (i = 0; i < 10; i++) {
printk("%d\n", i);
k_sleep(K_MSEC(1000));
}
int err = nrf_modem_lib_init();
printf("main: err=%d\n", err);
while (1) {
printk("zzz\n");
k_sleep(K_MSEC(1000));
}
}
/* End */
I have not found any abnormal voltages on the board. Visually there is no indication of any problem.
Product: nRF9160-SICA-B1 (Device identified as NRF9160_xxAA_REV2)
The SDK version was v2.3.0 at the time of first testing, now it is updated to v2.7.0.
The modem core FW version is v1.3.6. I tried downgrading to v1.3.5, v1.3.3 and v1.2.1. Applying firmware updates still works as for old PCBs (for some reason, after updating pynrfjprog I do have to pass reset=HighLevel.ResetAction.RESET_PIN or RESET_DEBUG to bypass error -90 NOT_AVAILABLE_BECAUSE_PROTECTION).
We noticed the affected devices in this series all have the same production mark (2227RY), but so do the devices that work normally.
I think there is either a hardware issue, or the modem core has reached a nonfunctioning state.
Is there any way to trigger a factory reset before the modem library is initialized?
Any suggestions on how to troubleshoot further?
Kind regards, Hermen
Hi
I just exchanged the nRF9160 on my board and that fixed it. Don't know if the actual problem was a bad chip or soldering
Best Regards
Casper
Hi
I just exchanged the nRF9160 on my board and that fixed it. Don't know if the actual problem was a bad chip or soldering
Best Regards
Casper