[queue] queue sometimes give more than expected

[Ben.su]

Hi Nordic,

I met a issue on BUS FAULT, which caused by queue.

It core dumps that:

[2022-03-22 15:35:12.657] [xxx]index = 6,len = 158
[2022-03-22 15:35:12.660] [xxx]index = 6,len = 164

[2022-03-[00:01:17.729,248] <err> os: ***** BUS FAULT *****
[2022-03-22 15:35:[00:01:17.729,278] <err> os: Precise data bus error
[2022-03-22 15:35:[00:01:17.729,278] <err> os: BFAR Address: 0x38004c
[2022-03-22 15:35:[00:01:17.729,278] <err> os: r0/a1: 0x0038004c r1/a2: 0x2001efe4 r2/a3: 0x00000003
[2022-03-22 15:35:[00:01:17.729,278] <err> os: r3/a4: 0x00000020 r12/ip: 0xa0000000 r14/lr: 0x000564f5
[2022-03-22 15:35:[00:01:17.729,278] <err> os: xpsr: 0x21000000
[2022-03-22 15:35:[00:01:17.729,309] <err> os: Faulting instruction address (r15/pc): 0x00056dc0
[2022-03-22 15:35:[00:01:17.729,309] <err> os: >>> ZEPHYR FATAL ERROR 0: CPU exception on CPU 0
[2022-03-22 15:35:[00:01:17.729,309] <err> os: Current thread: 0x20003f60 (unknown)

And I find 0x00056dc0 in lst is:

00056dc0 <z_spin_lock_valid>:
uintptr_t thread_cpu = l->thread_cpu;
56dc0: 6800 ldr r0, [r0, #0]
if (thread_cpu != 0U) {

0x000564f4 is:

void k_heap_free(struct k_heap *h, void *mem)
{
564d4: b5f8 push {r3, r4, r5, r6, r7, lr}
564d6: 4604 mov r4, r0
564d8: 460e mov r6, r1
k_spinlock_key_t key = k_spin_lock(&h->lock);
564da: f100 0514 add.w r5, r0, #20
__asm__ volatile(
564de: f04f 0320 mov.w r3, #32
564e2: f3ef 8711 mrs r7, BASEPRI
564e6: f383 8812 msr BASEPRI_MAX, r3
564ea: f3bf 8f6f isb sy
__ASSERT(z_spin_lock_valid(l), "Recursive spinlock %p", l);
564ee: 4628 mov r0, r5
564f0: f000 fc66 bl 56dc0 <z_spin_lock_valid>
564f4: b1d0 cbz r0, 5652c <k_heap_free+0x58>

I consider that may be the k_fifo_get which return twice, for the two message arrive in a very short time.

And then it frees a buffer twice( assert at the beginning of 'z_spin_lock_valid').

[2022-03-22 15:35:12.657] [xxx]index = 6,len = 158
[2022-03-22 15:35:12.660] [xxx]index = 6,len = 164

Here is the code:

struct uart_data_t *buf = k_fifo_get(&fifo, K_FOREVER);

...

printk("index = %d,len = %d\n", i, len);

....

k_free(buf);

BR

Ben

[ovrebekk]

Hi Ben

k_fifo_get(..) shouldn't return twice with the same buffer, unless you have pushed the same buffer to the FIFO twice. 

Is there any chance you are calling k_fifo_get(..) from an interrupt? 

I assume the code is based on the peripheral_uart sample?

Best regards
Torbjørn

[Ben.su]

Hi Ovrebekk,

I'm not sure if I pushed FIFO twice, maybe I can check it.

And the code is based on 'nrf/samples/bluetooth/peripheral_uart' sample.

But I do NOT use the uart adapter. Instead, I set the configuration bellow:

# Disable interrupt support on port 1

CONFIG_UART_1_INTERRUPT_DRIVEN=n

# Enable Asynchronous API support on port 1

CONFIG_UART_1_ASYNC=y

BR

Ben 

[ovrebekk]

Hi Ben

What are you doing when the issue occurs?

Are you sending some particular string to the device over the UART BLE service?

Have you made any other significant changes to the sample, other than changing the configuration?

Best regards
Torbjørn

[Ben.su]

Hi Torbjørn,

I am using the sample to communicate with uart periperal.

I think the significant change is that I remove the uart adapter.

BR

Ben

[ovrebekk]

Hi Ben

Are you able to share your project with me so I can have a look at it?

If you don't want to share your code in a public case I can make the case private. 

Best regards
Torbjørn