NRF9160: Serial LTE Modem app eventually crashes after switching to DATA and AT modes numerous times

Hi,

We used the SLM (serial LTE modem) application in our custom board with NRF9160 configured as a slave chip and interfaced with an STM32 MCU via UART interface. The SDK version we are using is v1.8.0.

Our STM32 MCU usually sends UDP packet via UART using data mode, and after observing the data mode silence interval, the STM32 MCU sends the "+++" data mode terminator to switch back to AT mode.

After performing this sequence numerous times, we observed that the SLM app will eventually crash as soon as "+++" is sent to NRF9160. Based on the RTT trace logs, SLM tried to send a response back to STM32 MCU but transmission failed. Here is an excerpt of the trace logs:

00> [00:08:00.190,643] <inf> slm_at_host: datamode off pending
00> [00:08:00.200,836] <wrn> slm_at_host: uart_tx failed: -16
00> [00:08:00.200,866] <inf> slm_at_host: Exit datamode
00> [00:08:00.245,239] <err> os: ***** HARD FAULT *****
00> [00:08:00.245,269] <err> os:   Fault escalation (see below)
00> [00:08:00.245,269] <err> os: ***** BUS FAULT *****
00> [00:08:00.245,269] <err> os:   Precise data bus error
00> [00:08:00.245,269] <err> os:   BFAR Address: 0xeb00eb
00> [00:08:00.245,300] <err> os: r0/a1:  0x00eb00eb  r1/a2:  0x20024874  r2/a3:  0x00000000
00> [00:08:00.245,300] <err> os: r3/a4:  0x00000020 r12/ip:  0x00000000 r14/lr:  0x0003d749
00> [00:08:00.245,300] <err> os:  xpsr:  0x2100001a
00> [00:08:00.245,300] <err> os: Faulting instruction address (r15/pc): 0x000379f2
00> [00:08:00.245,330] <err> os: >>> ZEPHYR FATAL ERROR 0: CPU exception on CPU 0
00> [00:08:00.245,330] <err> os: Fault during interrupt handling
00>
00> [00:08:00.245,330] <err> os: Current thread: 0x20016e48 (unknown)
00> [00:08:00.664,062] <err> fatal_error: Resetting system

The log indicates the UART failed TX with an error code of -16 or EBUSY. We looked at the code and followed the logic and found that after encountering such error, the code would free-up the malloc'd memory. Please refer to line 18 below.

static int uart_send(const uint8_t *str, size_t len)
{
	int ret;

	k_sem_take(&tx_done, K_FOREVER);

	uart_tx_buf = k_malloc(len);
	if (uart_tx_buf == NULL) {
		LOG_WRN("No ram buffer");
		k_sem_give(&tx_done);
		return -ENOMEM;
	}

	memcpy(uart_tx_buf, str, len);
	ret = uart_tx(uart_dev, uart_tx_buf, len, SYS_FOREVER_MS);
	if (ret) {
		LOG_WRN("uart_tx failed: %d", ret);
		k_free(uart_tx_buf);
		k_sem_give(&tx_done);
	}

	return ret;
}

Also, the trace logs also have the crash dump including the faulting instruction address (r15/pc) which points to line 6 of the code below:

void sys_heap_free(struct sys_heap *heap, void *mem)
{
	if (mem == NULL) {
		return; /* ISO C free() semantics */
	}
	struct z_heap *h = heap->heap;
	chunkid_t c = mem_to_chunkid(h, mem);

	/*
	 * This should catch many double-free cases.
	 * This is cheap enough so let's do it all the time.
	 */
	__ASSERT(chunk_used(h, c),
		 "unexpected heap state (double-free?) for memory at %p", mem);

	/*
	 * It is easy to catch many common memory overflow cases with
	 * a quick check on this and next chunk header fields that are
	 * immediately before and after the freed memory.
	 */
	__ASSERT(left_chunk(h, right_chunk(h, c)) == c,
		 "corrupted heap bounds (buffer overflow?) for memory at %p",
		 mem);

	set_chunk_used(h, c, false);
	free_chunk(h, c);
}

We did check the code and every shared resources seem well protected and we cannot figure out how returning a memory back to the heap would crash the application.

Any pointers and recommendations would be appreciated. 

Parents
  • Hi,

     

    Based on the PC content, the dereferencing of heap->heap lead to a fault. What is your configured heap size?

    ie. CONFIG_HEAP_MEM_POOL_SIZE.

     

    The log shows that it takes approx. 45 ms from when the uart failed to when the fault occurs. Could the content of "r14/lr:  0x0003d749" and the "Current thread: 0x20016e48 (unknown)" give any indication what happened?

     

    Since the current thread is a ram mapped variable, you will have to check the build/zephyr/zephyr.map to see which thread this belongs to.

     

    Kind regards,

    Håkon

Reply
  • Hi,

     

    Based on the PC content, the dereferencing of heap->heap lead to a fault. What is your configured heap size?

    ie. CONFIG_HEAP_MEM_POOL_SIZE.

     

    The log shows that it takes approx. 45 ms from when the uart failed to when the fault occurs. Could the content of "r14/lr:  0x0003d749" and the "Current thread: 0x20016e48 (unknown)" give any indication what happened?

     

    Since the current thread is a ram mapped variable, you will have to check the build/zephyr/zephyr.map to see which thread this belongs to.

     

    Kind regards,

    Håkon

Children
No Data
Related