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

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:

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

Parents Reply Children
  • Did you use a DK for this denghongyan?

    Regards,

    Elfving

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

    here is my prj_conf:

  • Hi EIfving,

    I build a pure verison, just prj.conf add rtt log:

    here is my commissiong log txt:

    *** Booting My Application v2.9.0-e3a4c1a2b782 ***
    *** Using nRF Connect SDK v2.9.0-7787b2649840 ***
    *** Using Zephyr OS v3.7.99-1f8f3dc29142 ***
    I: 1680 [DL]BLE address: FE:EF:E5:5C:34:F9
    I: 1683 [DL]CHIP task running
    I: Init CHIP stack
    I: 1684 [DL]OpenThread started: OK
    I: 1684 [DL]Setting OpenThread device type to MINIMAL END DEVICE
    I: 1685 [DL]Found DAC Private Key in factory data set. Copying to secure storage...
    I: 1689 [DL]The device does not support hardware protection against write.
    D: Registered new test event: 0xffffffff00000000
    D: Registered new test event: 0xffffffff10000000
    I: 1689 [SVR]Subscription persistence not supported
    I: 1689 [SVR]Server initializing...
    I: 1689 [TS]Last Known Good Time: [unknown]
    I: 1689 [TS]Setting Last Known Good Time to firmware build time 2023-10-14T01:16:48
    I: 1691 [DMG]AccessControl: initializing
    I: 1691 [DMG]Examples::AccessControlDelegate::Init
    I: 1691 [DMG]AccessControl: setting
    I: 1691 [DMG]DefaultAclStorage: initializing
    I: 1691 [DMG]DefaultAclStorage: 0 entriI: 31708 [DL]CHIPoBLE advertising mode changed to slow
    I: 31709 [DL]CHIPoBLE advertising started
    I: 51672 [DL]Current number of connections: 1/1
    I: 51673 [DL]BLE connection established (ConnId: 0x00)
    I: 51673 [DL]CHIPoBLE advertising stopped
    D: 52447 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 52447 [BLE]local and remote recv window sizes = 5
    I: 52447 [BLE]selected BTP version 4
    I: 52447 [BLE]using BTP fragment sizes rx 182 / tx 182.
    D: 52567 [DL]ConnId: 0x00, New CCCD value: 0x0002
    D: 52567 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6)
    D: 52567 [IN]BLE EndPoint 0x2001d650 Connection Complete
    I: 52568 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 185)
    D: 52627 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 52630 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 52630 [EM]>>> [E:28929r S:0 M:161786240] (U) Msg RX from 0:AED83A1987C1EA0B [0000] to 0000000000000000 --- Type 0000:20 (SecureChannel:PBKDFParamRequest) (B:98)
    I: 52632 [EM]<<< [E:28929r S:0 M:378125] (U) Msg TX from 0000000000000000 to 0:AED83A1987C1EA0B [0000] [BLE] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) (B:154)
    D: 52632 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 159)
    I: 52632 [SVR]Commissioning session establishment step started
    D: 52687 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 52690 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 52690 [EM]>>> [E:28929r S:0 M:161786241] (U) Msg RX from 0:AED83A1987C1EA0B [0000] to 0000000000000000 --- Type 0000:22 (SecureChannel:PASE_Pake1) (B:92)
    I: 52713 [EM]<<< [E:28929r S:0 M:378126] (U) Msg TX from 0000000000000000 to 0:AED83A1987C1EA0B [0000] [BLE] --- Type 0000:23 (SecureChannel:PASE_Pake2) (B:127)
    D: 52714 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 132)
    D: 52807 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 52809 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 52809 [EM]>>> [E:28929r S:0 M:161786242] (U) Msg RX from 0:AED83A1987C1EA0B [0000] to 0000000000000000 --- Type 0000:24 (SecureChannel:PASE_Pake3) (B:59)
    I: 52810 [EM]<<< [E:28929r S:0 M:378127] (U) Msg TX from 0000000000000000 to 0:AED83A1987C1EA0B [0000] [BLE] --- Type 0000:40 (SecureChannel:StatusReport) (B:30)
    D: 52810 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35)
    I: 52812 [SC]SecureSession[0x200137e8, LSID:2324]: State change 'kEstablishing' --> 'kActive'
    D: 52813 [IN]SecureSession[0x200137e8]: Activated - Type:1 LSID:2324
    D: 52813 [IN]New secure session activated for device <FFFFFFFB00000000, 0>, LSID:2324 PSID:1566!
    I: 52813 [SVR]Commissioning completed session establishment step
    I: 52813 [DIS]Updating services using commissioning mode 0
    E: 52814 [DIS]Failed to remove advertised services: 3
    E: 52814 [DIS]Failed to finalize service update: 3
    D: 52814 [DL]CHIPoBLE advertising set to off
    I: 52814 [SVR]Device completed Rendezvous process
    D: 52897 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 52899 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 52900 [EM]>>> [E:28930r S:2324 M:72307863] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:51)
    D: 52900 [IM]Received Read request
    I: 52902 [EM]<<< [E:28930r S:2324 M:116060134] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:66)
    D: 52902 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
    D: 53017 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 53019 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 53020 [EM]>>> [E:28931r S:2324 M:72307864] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:51)
    D: 53020 [IM]Received Read request
    I: 53022 [EM]<<< [E:28931r S:2324 M:116060135] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:86)
    D: 53022 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 91)
    D: 53137 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 53139 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 53140 [EM]>>> [E:28932r S:2324 M:72307865] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:52)
    D: 53140 [IM]Received Read request
    I: 53142 [EM]<<< [E:28932r S:2324 M:116060136] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:67)
    D: 53142 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72)
    D: 53257 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 53259 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 53260 [EM]>>> [E:28933r S:2324 M:72307866] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:51)
    D: 53260 [IM]Received Read request
    I: 53262 [EM]<<< [E:28933r S:2324 M:116060137] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:66)
    D: 53262 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
    D: 53377 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 53379 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 53380 [EM]>>> [E:28934r S:2324 M:72307867] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:52)
    D: 53380 [IM]Received Read request
    I: 53382 [EM]<<< [E:28934r S:2324 M:116060138] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:67)
    D: 53382 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 72)
    D: 53497 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
    D: 53499 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 53500 [EM]>>> [E:28935r S:2324 M:72307868] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:54)
    D: 53500 [IM]Received Read request
    E: 53501 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x1349_FC00, attributeId: 0x0000_0001err = 5c3
    I: 53502 [EM]<<< [E:28935r S:2324 M:116060139] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:66)
    D: 53502 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
    D: 53619 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
    I: 53620 [EM]>>> [E:28936r S:2324 M:72307869] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:51)
    D: 53620 [IM]Received Read request
    E: ***** SECURE FAULT *****
    E:   Address: 0x2b
    E:   Attribution unit violation
    E: r0/a1:  0x20010ddc  r1/a2:  0x20034f80  r2/a3:  0x00000000
    E: r3/a4:  0x00000000 r12/ip:  0x20035078 r14/lr:  0x0008f8b7
    E:  xpsr:  0x81000000
    E: Faulting instruction address (r15/pc): 0x0008f8f0
    E: >>> ZEPHYR FATAL ERROR 41: Unknown error on CPU 0
    E: Current thread: 0x2001e510 (CHIP)
    E: Halting system
    here is the error address to line:

Related