This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

DF beacon/scanner aging test crashes

Hi teams,

I am testing Direction Finding beacon/scanner pairs with nRF52833 DKs.

With nRFConnect SDK v1.7.1, I started beacon/scanner pair and leave untouched for a few days.

And I got the following crash in scanner side.

PER_ADV_SYNC[0]: [DEVICE]: 09:4D:94:E8:43:23 (random), tx_power 127, RSSI -36, CTE AOA, data length 0, data:
CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC OK, RSSI -360
PER_ADV_SYNC[0]: [DEVICE]: 09:4D:94:E8:43:23 (random), tx_power 127, RSSI -32, CTE AOA, data length 0, data:
CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC OK, RSSI -320
PER_ADV_SYNC[0]: [DEVICE]: 09:4D:94:E8:43:23 (random), tx_power 127, RSSI -40, CTE AOA, data length 0, data:
CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC OK, RSSI -400
PER_ADV_SYNC[0]: [DEVICE]: 09:4D:94:E8:43:23 (random), tx_power 127, RSSI -36, CTE AOA, data length 0, data:
CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC OK, RSSI -360
CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC not OK, CTE Info OK, RSSI -330
PER_ADV_SYNC[0]: [DEVICE]: 09:4D:94:E8:43:23 (random) sync terminated
Periodic sync lost.
Start scanning...success
Waiting for periodic advertising...
[DEVICE]: 52:67:5C:01:EC:12 (random), AD evt type 3, Tx Pwr: 127, RSSI -53  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: FC:4E:0F:24:19:EF (random), AD evt type 3, Tx Pwr: 127, RSSI -70  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 50:FA:50:77:47:3C (random), AD evt type 3, Tx Pwr: 127, RSSI -75  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 4F:A4:94:29:6A:3F (random), AD evt type 2, Tx Pwr: 127, RSSI -69  C:0 S:1 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 43:4B:56:39:DA:36 (random), AD evt type 3, Tx Pwr: 127, RSSI -58  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 27:E6:52:81:FF:86 (random), AD evt type 3, Tx Pwr: 127, RSSI -46  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: F7:BC:D8:95:B4:A7 (public), AD evt type 0, Tx Pwr: 127, RSSI -72 Trkr C:1 S:1 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 5F:13:0F:26:BB:3F (random), AD evt type 3, Tx Pwr: 127, RSSI -66  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 6F:1F:97:9D:52:45 (random), AD evt type 3, Tx Pwr: 127, RSSI -64  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 76:43:9B:F8:B3:A0 (random), AD evt type 2, Tx Pwr: 127, RSSI -72  C:0 S:1 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 39:87:AF:34:CE:86 (random), AD evt type 3, Tx Pwr: 127, RSSI -55  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 3A:A0:C3:5E:77:6A (random), AD evt type 3, Tx Pwr: 127, RSSI -74  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 07:F5:05:2F:B1:F0 (random), AD evt type 3, Tx Pwr: 127, RSSI -61  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 25:44:D8:19:64:A1 (random), AD evt type 3, Tx Pwr: 127, RSSI -37  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: EF:B8:58:DD:18:35 (random), AD evt type 0, Tx Pwr: 127, RSSI -61  C:1 S:1 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 09:4D:94:E8:43:23 (random), AD evt type 5, Tx Pwr: 127, RSSI -38 DF Connectionless Beacon App C:0 S:0 D:0 SR:0 E:1 Prim: LE 1M, Secn: LE 2M, Interval: 0x0780 (2400 ms), SID: 0
success. Found periodic advertising.
Creating Periodic Advertising Sync...success.
Waiting for periodic sync...
[DEVICE]: 6A:44:79:77:C8:B9 (random), AD evt type 0, Tx Pwr: 127, RSSI -73  C:1 S:1 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 6A:44:79:77:C8:B9 (random), AD evt type 4, Tx Pwr: 127, RSSI -73  C:1 S:1 D:0 SR:1 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 38:B0:4D:2C:06:CE (random), AD evt type 3, Tx Pwr: 127, RSSI -70  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: DB:79:BA:19:4E:FC (public), AD evt type 3, Tx Pwr: 127, RSSI -27  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 4D:11:5F:F5:10:02 (random), AD evt type 0, Tx Pwr: 127, RSSI -69  C:1 S:1 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: D9:81:B8:AB:70:37 (random), AD evt type 3, Tx Pwr: 127, RSSI -66  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 52:67:5C:01:EC:12 (random), AD evt type 3, Tx Pwr: 127, RSSI -52  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 5B:21:9D:9F:90:3F (random), AD evt type 0, Tx Pwr: 127, RSSI -68  C:1 S:1 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 7B:3A:E3:51:51:0E (random), AD evt type 3, Tx Pwr: 127, RSSI -52  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: E2:AD:AA:18:56:2D (public), AD evt type 0, Tx Pwr: 127, RSSI -63 Tracker C:1 S:1 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 27:E6:52:81:FF:86 (random), AD evt type 3, Tx Pwr: 127, RSSI -46  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 5F:A4:3C:9E:E8:6D (random), AD evt type 0, Tx Pwr: 127, RSSI -77  C:1 S:1 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 3A:06:40:74:14:2B (random), AD evt type 3, Tx Pwr: 127, RSSI -68  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: EC:1C:4B:7B:26:4A (random), AD evt type 0, Tx Pwr: 127, RSSI -58  C:1 S:1 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: DE:81:64:E5:57:95 (public), AD evt type 0, Tx Pwr: 127, RSSI -61  C:1 S:1 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 6F:1F:97:9D:52:45 (random), AD evt type 3, Tx Pwr: 127, RSSI -67  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 7E:37:ED:3B:FB:10 (random), AD evt type 3, Tx Pwr: 127, RSSI -54  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 3A:A0:C3:5E:77:6A (random), AD evt type 3, Tx Pwr: 127, RSSI -76  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
[DEVICE]: 7D:42:FC:F2:37:B1 (random), AD evt type 3, Tx Pwr: 127, RSSI -67  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
ASSERTION FAIL [0] @ WEST_TOPDIR/zephyr/subsys/bluetooth/controller/ll_sw/ull.c:1171
[08:51:14.308,135] <wrn> bt_hci_core: Malformed data
[08:51:14.915,740] <err> os: r0/a1:  0x00000003  r1/a2:  0x00012908  r2/a3:  0x00000001
[08:51:14.915,740] <err> os: r3/a4:  0x00002845 r12/ip:  0x00000000 r14/lr:  0x00008295
[08:51:14.915,740] <err> os:  xpsr:  0x41000000
[08:51:14.915,740] <err> os: Faulting instruction address (r15/pc): 0x000082a0
[08:51:14.915,740] <err> os: >>> ZEPHYR FATAL ERROR 3: Kernel oops on CPU 0
[08:51:14.915,771] <err> os: Current thread: 0x20000628 (unknown)
[08:51:14.987,884] <err> os: Halting system

Any ideas?

P.S.> I have been testing this since it is available (v1.6.0, maybe), and has similar crashes in all tests.

  • OK, now it is running as before.

    I'll leave additional notes if something happens.

  • During longivity test, the following crash happens.

    It seems to be similar to the original crash. Please check.

    Thread analyze:
     BT RX               : STACK: unused 1960 usage 2136 / 4096 (52 %); CPU: 5 %
     BT RX pri           : STACK: unused 304 usage 144 / 448 (32 %); CPU: 0 %
     BT TX               : STACK: unused 224 usage 416 / 640 (65 %); CPU: 0 %
     thread_analyzer     : STACK: unused 592 usage 432 / 1024 (42 %); CPU: 0 %
     sysworkq            : STACK: unused 856 usage 168 / 1024 (16 %); CPU: 0 %
     logging             : STACK: unused 192 usage 576 / 768 (75 %); CPU: 0 %
     idle 00             : STACK: unused 248 usage 72 / 320 (22 %); CPU: 93 %
     main                : STACK: unused 536 usage 488 / 1024 (47 %); CPU: 0 %
    PER_ADV_SYNC[0]: [DEVICE]: 2A:A5:C4:9B:42:4A (random), tx_power 127, RSSI -32, CTE AOA, data length 0, data: 
    CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC OK, RSSI -320
    PER_ADV_SYNC[0]: [DEVICE]: 2A:A5:C4:9B:42:4A (random), tx_power 127, RSSI -31, CTE AOA, data length 0, data: 
    CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC OK, RSSI -310
    PER_ADV_SYNC[0]: [DEVICE]: 2A:A5:C4:9B:42:4A (random), tx_power 127, RSSI -31, CTE AOA, data length 0, data: 
    CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC OK, RSSI -310
    PER_ADV_SYNC[0]: [DEVICE]: 2A:A5:C4:9B:42:4A (random), tx_power 127, RSSI -31, CTE AOA, data length 0, data: 
    CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC OK, RSSI -310
    PER_ADV_SYNC[0]: [DEVICE]: 2A:A5:C4:9B:42:4A (random), tx_power 127, RSSI -32, CTE AOA, data length 0, data: 
    CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC OK, RSSI -320
    PER_ADV_SYNC[0]: [DEVICE]: 2A:A5:C4:9B:42:4A (random), tx_power 127, RSSI -31, CTE AOA, data length 0, data: 
    CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC OK, RSSI -310
    PER_ADV_SYNC[0]: [DEVICE]: 2A:A5:C4:9B:42:4A (random), tx_power 127, RSSI -31, CTE AOA, data length 0, data: 
    CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC OK, RSSI -310
    PER_ADV_SYNC[0]: [DEVICE]: 2A:A5:C4:9B:42:4A (random), tx_power 127, RSSI -32, CTE AOA, data length 0, data: 
    CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC OK, RSSI -320
    PER_ADV_SYNC[0]: [DEVICE]: 2A:A5:C4:9B:42:4A (random), tx_power 127, RSSI -32, CTE AOA, data length 0, data: 
    CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC OK, RSSI -320
    PER_ADV_SYNC[0]: [DEVICE]: 2A:A5:C4:9B:42:4A (random), tx_power 127, RSSI -32, CTE AOA, data length 0, data: 
    CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC OK, RSSI -320
    PER_ADV_SYNC[0]: [DEVICE]: 2A:A5:C4:9B:42:4A (random), tx_power 127, RSSI -31, CTE AOA, data length 0, data: 
    CTE[0]: samples count 45, cte type AOA, slot durations: 2 [us], packet status CRC OK, RSSI -310
    PER_ADV_SYNC[0]: [DEVICE]: 2A:A5:C4:9B:42:4A (random) sync terminated
    Periodic sync lost.
    Start scanning...success
    Waiting for periodic adv[DEVICE]: FC:4E:0F:24:19:EF (random), AD evt type 3, Tx Pwr: 127, RSSI -70  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
    [DEVICE]: F6:D4:16:A4:BB:25 (random), AD evt type 0, Tx Pwr: 127, RSSI -67  C:1 S:1 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
    [DEVICE]: F6:D4:16:A4:BB:25 (random), AD evt type 4, Tx Pwr: 127, RSSI -68 IP-BS-US_BB25 C:1 S:1 D:0 SR:1 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
    [DEVICE]: 19:1F:C9:0A:D6:68 (random), AD evt type 3, Tx Pwr: 127, RSSI -73  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
    ertising...
    [DEVICE]: 0D:84:31:5B:80:76 (random), AD evt type 3, Tx Pwr: 127, RSSI -76  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
    [DEVICE]: 25:69:85:AB:4F:47 (random), AD evt type 3, Tx Pwr: 127, RSSI -39  C:0 S:0 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
    [DEVICE]: 2A:A5:C4:9B:42:4A (random), AD evt type 5, Tx Pwr: 127, RSSI -32 DF Connectionless Beacon App C:0 S:0 D:0 SR:0 E:1 Prim: LE 1M, Secn: LE 2M, Interval: 0x0780 (2400 ms), SID: 0
    success. Found periodic advertising.
    Creating Periodic Advertising Sync...success.
    Waiting for periodic sync...
    [DEVICE]: 80:EA:CA:80:D2:76 (public), AD evt type 0, Tx Pwr: 127, RSSI -57 Dialog WRBL C:1 S:1 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
    [DEVICE]: 80:EA:CA:80:D2:76 (public), AD evt type 4, Tx Pwr: 127, RSSI -56  C:1 S:1 D:0 SR:1 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
    [DEVICE]: DE:81:64:E5:57:95 (public), AD evt type 0, Tx Pwr: 127, RSSI -54  C:1 S:1 D:0 SR:0 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
    [DEVICE]: DE:81:64:E5:57:95 (public), AD evt type 4, Tx Pwr: 127, RSSI -54 IF-WT100 C:1 S:1 D:0 SR:1 E:0 Prim: LE 1M, Secn: No packets, Interval: 0x0000 (0 ms), SID: 255
    ASSERTION FAIL [0] @ WEST_TOPDIR/zephyr/subsys/bluetooth/controller/ll_sw/ull.c:1171
    [07:27:20.840,667] <wrn> bt_hci_core: Malformed data
    [07:27:21.064,697] <err> os: r0/a1:  0x00000003  r1/a2:  0x0001580c  r2/a3:  0x00000001
    [07:27:21.064,727] <err> os: r3/a4:  0x00003251 r12/ip:  0x00000000 r14/lr:  0x000090a1
    [07:27:21.064,727] <err> os:  xpsr:  0x41000000
    [07:27:21.064,727] <err> os: Faulting instruction address (r15/pc): 0x000090ac
    [07:27:21.064,727] <err> os: >>> ZEPHYR FATAL ERROR 3: Kernel oops on CPU 0
    [07:27:21.064,758] <err> os: Current thread: 0x200007b0 (BT RX pri)
    [07:27:21.115,447] <err> os: Halting system
    

  • Can you follow the case there for progress?
    Kenneth
  • OK, I'll monitor that issue, too.

  • After I upgraded to nRFConnect SDK v1.8.0, regression test for more than a week does not show the same error above.

    Since the issue seems to be solved, I will close this.

Related