When building a tfm setting with nrf54l15, an error occurs during Matter commissioning.

[H-ogawa]

Hi,

If you use the following settings, an error will occur during commissioning.

Board: Custom board

SDK:ncsv2.9.2
OS: Windows10
Sample code:Matter Lock
bord target:nrf54l15dk/nrf54l15/cpuapp/ns

Border router: Home pod mini

iphone:ios 18.5

The serial log during commissioning is as follows:

Fullscreen nrf54l15_ns_homepod_mini_log.txt Download

I: 110374 [DIS]Updating services using commissioning mode 1
E: 110380 [DIS]Failed to remove advertised services: 3
I: 110385 [DIS]Advertise commission parameter vendorID=65521 productID=32774 discriminator=3840/15 cm=1 cp=0
E: 110394 [DIS]Failed to advertise commissionable node: 3
E: 110399 [DIS]Failed to finalize service update: 3
I: 110405 [DL]CHIPoBLE advertising started
I: 140409 [DL]CHIPoBLE advertising mode changed to slow
I: 140415 [DL]CHIPoBLE advertising started
・*** Booting My Application v2.9.2-8c3b414bb1e8 ***
*** Using nRF Connect SDK v2.9.2-4ab7b98fc76f ***
*** Using Zephyr OS v3.7.99-aa34a5632971 ***

I: 1412 [DL]BLE address: F4:F9:24:5F:02:AD
I: No users indexes stored
I: No stored indexes for credential of type: 1
I: 1426 [DL]CHIP task running
I: Init CHIP stack
I: 1431 [DL]OpenThread started: OK
I: 1435 [DL]Setting OpenThread device type to SLEEPY END DEVICE
I: 1441 [DL]The device does not support hardware protection against write.
I: 1447 [SVR]Subscription persistence not supported
I: 1452 [SVR]Server initializing...
I: 1455 [TS]Last Known Good Time: 2023-10-14T01:16:48
I: 1460 [DMG]AccessControl: initializing
I: 1464 [DMG]Examples::AccessControlDelegate::Init
I: 1469 [DMG]AccessControl: setting
I: 1472 [DMG]DefaultAclStorage: initializing
I: 1476 [DMG]DefaultAclStorage: 0 entries loaded
E: 1480 [IN]IPV6_PKTINFO failed: 109
uart:~$ I: 1485 [ZCL]Using ZAP configuration...
I: 1490 [DMG]AccessControlCluster: initializing
I: 1494 [ZCL]Initiating Admin Commissioning cluster.
I: 1499 [ZCL]Door Lock server initialized
I: 1502 [ZCL]Door Lock cluster initialized at endpoint #1
I: 1508 [ZCL]0xdabb2 ep 1 clus 0x0000_0101 attr 0x0000_0013 not supported
E: 1514 [ZCL]Failed to set DoorLock number of RFID users: 86
I: 1519 [DIS]Updating services using commissioning mode 0
E: 1525 [DIS]Failed to remove advertised services: 3
E: 1529 [DIS]Failed to finalize service update: 3
I: 1534 [IN]CASE Server enabling CASE session setups
I: 1539 [SVR]Joining Multicast groups
I: 1542 [SVR]Server Listening...
I: 1545 [DL]Device Configuration:
I: 1548 [DL]  Serial Number: 11223344556677889900
I: 1553 [DL]  Vendor Id: 65521 (0xFFF1)
I: 1556 [DL]  Product Id: 32774 (0x8006)
I: 1560 [DL]  Product Name: not-specified
I: 1564 [DL]  Hardware Version: 0
I: 1567 [DL]  Setup Pin Code (0 for UNKNOWN/ERROR): 20202021
I: 1572 [DL]  Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)
I: 1579 [DL]  Manufacturing Date: 2022-01-01
I: 1583 [DL]  Device Type: 65535 (0xFFFF)
I: 1586 [SVR]SetupQRCode: [MT:8IXS142C00KA0648G00]
I: 1591 [SVR]Copy/paste the below URL in a browser to see the QR Code:
I: 1597 [SVR]https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A8IXS142C00KA0648G00
I: 1606 [SVR]Manual pairing code: [34970112332]
E: 1610 [DL]Long dispatch time: 181 ms, for event type 2
I: 147476 [DIS]Updating services using commissioning mode 1
E: 147481 [DIS]Failed to remove advertised services: 3
I: 147486 [DIS]Advertise commission parameter vendorID=65521 productID=32774 discriminator=3840/15 cm=1 cp=0
E: 147496 [DIS]Failed to advertise commissionable node: 3
E: 147501 [DIS]Failed to finalize service update: 3
I: 147506 [DL]CHIPoBLE advertising started
I: 147576 [DL]Current number of connections: 1/1
I: 147581 [DL]BLE connection established (ConnId: 0x00)
I: 147586 [DL]CHIPoBLE advertising stopped
I: 148316 [BLE]local and remote recv window sizes = 5
I: 148321 [BLE]selected BTP version 4
I: 148324 [BLE]using BTP fragment sizes rx 182 / tx 182.
I: 148436 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 185)
I: 148499 [EM]>>> [E:21625r S:0 M:137350978] (U) Msg RX from 0:60521467054A5DC3 [0000] to 0000000000000000 --- Type 0000:20 (SecureChannel:PBKDFParamRequest) (B:98)
I: 148515 [EM]<<< [E:21625r S:0 M:37729224] (U) Msg TX from 0000000000000000 to 0:60521467054A5DC3 [0000] [BLE] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) (B:154)
I: 148530 [SVR]Commissioning session establishment step started
I: 148739 [EM]>>> [E:21625r S:0 M:137350979] (U) Msg RX from 0:60521467054A5DC3 [0000] to 0000000000000000 --- Type 0000:22 (SecureChannel:PASE_Pake1) (B:92)
I: 148777 [EM]<<< [E:21625r S:0 M:37729225] (U) Msg TX from 0000000000000000 to 0:60521467054A5DC3 [0000] [BLE] --- Type 0000:23 (SecureChannel:PASE_Pake2) (B:127)
I: 148828 [EM]>>> [E:21625r S:0 M:137350980] (U) Msg RX from 0:60521467054A5DC3 [0000] to 0000000000000000 --- Type 0000:24 (SecureChannel:PASE_Pake3) (B:59)
I: 148843 [EM]<<< [E:21625r S:0 M:37729226] (U) Msg TX from 0000000000000000 to 0:60521467054A5DC3 [0000] [BLE] --- Type 0000:40 (SecureChannel:StatusReport) (B:30)
I: 148859 [SC]SecureSession[0x20014088, LSID:39875]: State change 'kEstablishing' --> 'kActive'
I: 148868 [SVR]Commissioning completed session establishment step
I: 148874 [DIS]Updating services using commissioning mode 0
E: 148879 [DIS]Failed to remove advertised services: 3
E: 148884 [DIS]Failed to finalize service update: 3
I: 148889 [SVR]Device completed Rendezvous process
I: 148949 [EM]>>> [E:21626r S:39875 M:205759558] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:51)
I: 148964 [EM]<<< [E:21626r S:39875 M:241130563] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:68)
I: 149069 [EM]>>> [E:21627r S:39875 M:205759559] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:51)
I: 149084 [EM]<<< [E:21627r S:39875 M:241130564] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:96)
I: 149189 [EM]>>> [E:21628r S:39875 M:205759560] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:52)
I: 149204 [EM]<<< [E:21628r S:39875 M:241130565] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:67)
I: 149309 [EM]>>> [E:21629r S:39875 M:205759561] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:51)
I: 149324 [EM]<<< [E:21629r S:39875 M:241130566] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:66)
I: 149488 [EM]>>> [E:21630r S:39875 M:205759562] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:52)
I: 149503 [EM]<<< [E:21630r S:39875 M:241130567] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:67)
I: 149669 [EM]>>> [E:21631r S:39875 M:205759563] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:54)
E: 149683 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x1349_FC00, attributeId: 0x0000_0001err = 5c3
I: 149695 [EM]<<< [E:21631r S:39875 M:241130568] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:66)
I: 149789 [EM]>>> [E:21632r S:39875 M:205759564] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:51)
E: ***** SECURE FAULT *****
E:   Address: 0x2b
E:   Attribution unit violation
E: r0/a1:  0x20010dcc  r1/a2:  0x20036a00  r2/a3:  0x00000000
E: r3/a4:  0x00000000 r12/ip:  0x20036af8 r14/lr:  0x00094a9b
E:  xpsr:  0x81000000
E: Faulting instruction address (r15/pc): 0x00094ad4
E: >>> ZEPHYR FATAL ERROR 41: Unknown error on CPU 0
E: Current thread: 0x2001ed40 (CHIP)
E: Halting system

If the board target is nrf54l15dk/nrf54l15/cpuapp, no error occurs.

Also, no commissioning errors occurred with nrf54l15dk/nrf54l15/cpuapp/ns on Google Nest Hub.

best regards,

Hiroki

[Elfving]

Hello Hiroki,

That sounds a bit odd.

What homepod version are you using?

Are you getting the same issue every time?

Regards,

Elfving

[Denghongyan]

Hi Hiroki and Elfving,

I got the same issue, my homepod mini version 18.5(22L572), this issue occurs every time during commission process.
My homepod mini can add other thread device successfully, and I have tried template demo with NRF54L15DK, got the same error log.

[Denghongyan]

1. Yes, I use nrf54l15DK physical board to do the test, and I only modified one place:

2. I will try, wait one moment.

3. I use NCS2.9.0

[H-ogawa]

Hi Elfving

Elfving said:

this is the completely unmodified sample?

I didn't change it because I wanted to verify the problem with the sample code base.

Elfving said:

I see you say that the DK is the board target, but it is also the physical board that you are using for this test, right?

I confirmed this phenomenon in a custom product equipped with an nRF54l15 SoC. The custom product has the same external flash as the nrf54ldk, so the sample code works as is.

Elfving said:

Could you try looking at these addresses it fails at with addr2line for me? Could be worth checking both r15/pc and r14/l5. There are some guides in devacademy (here and here).

I'll check it out, but I'm not sure if I'll get a reply right away.

best regards,

Hiroki

[Denghongyan]

here is my log and addr-line, I tested with default factory data:

[Elfving]

Did you use a DK for this denghongyan?

Regards,

Elfving

[Denghongyan]

Yeah, for addr2line, I opened some log, if not, cannot use addr2lie:

here is my prj_conf: