| # Copyright (c) 2021 Project CHIP Authors |
| # |
| # Licensed under the Apache License, Version 2.0 (the "License"); |
| # you may not use this file except in compliance with the License. |
| # You may obtain a copy of the License at |
| # |
| # http://www.apache.org/licenses/LICENSE-2.0 |
| # |
| # Unless required by applicable law or agreed to in writing, software |
| # distributed under the License is distributed on an "AS IS" BASIS, |
| # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
| # See the License for the specific language governing permissions and |
| # limitations under the License. |
| # Auto-generated scripts for harness use only, please review before automation. The endpoints and cluster names are currently set to default |
| |
| name: |
| 3.3.8. [TC-DD-3.8] Commissioning Flow - Non-concurrent - Negative Scenario |
| [DUT - Commissioner] |
| |
| PICS: |
| - MCORE.ROLE.COMMISSIONER |
| |
| config: |
| nodeId: 0x12344321 |
| cluster: "Basic" |
| endpoint: 0 |
| |
| tests: |
| - label: "Note" |
| verification: | |
| Chip-tool command used below are an example to verify the DUT as commissioner test cases. For certification test, we expect DUT should have a capability or way to run the equivalent command. |
| disabled: true |
| |
| - label: "Preconditions" |
| verification: | |
| 1 - 5.5 - Commissioner is on a network. - The network can either be WiFi or Thread. |
| 2 - 5.5 - Commissionee is not connected to an operational network |
| disabled: true |
| |
| - label: |
| "Commissioner has regulatory and fabric information available and has |
| accurate date, time and timezone" |
| verification: | |
| 1. Manually verify that the time, date and timezone is accurate for the DUT Commissioner |
| disabled: true |
| |
| - label: |
| "Commissioner and Commissionee discover each other and connect via the |
| discovery mode applicable for the DUT." |
| verification: | |
| Verify in TH as server side: start BLE Advertising by specific DUT implementation |
| |
| Verify in DUT as client side: start commissioning process(need to obtain the Thread dataset first) |
| |
| ./chip-tool pairing ble-thread 1 hex:0e080000000000010000000300000f35060004001fffe0020811111111222222220708fd27e57b1b1e22d9051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f01021234041061e1206d2c2b46e079eb775f41fc72190c0402a0fff8 20202021 3840 |
| disabled: true |
| |
| - label: |
| "Establish encryption keys with Password Authenticated Session |
| Establishment on the commissioning channel" |
| verification: | |
| Verify in DUT as client side |
| |
| CHIP:SC: Received PBKDF param response |
| disabled: true |
| |
| - label: |
| "Commissioner SHALL re-arm Fail-safe timer on Commissionee within 60s |
| (the autonomously Fail-safe timer length set by Commissionee)" |
| verification: | |
| Verify in DUT as client side |
| |
| CHIP:CTL: Arming failsafe (60 seconds) |
| disabled: true |
| |
| - label: |
| "Commissioner SHALL configure regulatory information in the |
| Commissionee." |
| PICS: MCORE.COM.WIRELESS |
| verification: | |
| Verify in DUT as client side |
| |
| Performing next commissioning step "ConfigRegulatory" |
| [1653471968.202645][30157:30162] CHIP:CTL: Setting Regulatory Config |
| [1653471968.202666][30157:30162] CHIP:CTL: No regulatory config supplied by controller, leaving as device default (0) |
| |
| Verify in TH as server side |
| NVS set: chip-config/regulatory-location = 0 (0x0) |
| disabled: true |
| |
| - label: |
| "Commissioner requests operational CSR from Commissionee with |
| OperationalCSRRequest command" |
| verification: | |
| Verify in DUT as client side |
| |
| CHIP:CTL: Sending CSR request to 0xffffa4001730 device |
| CHIP:DMG: ICR moving to [AddingComm] |
| CHIP:DMG: ICR moving to [AddedComma] |
| CHIP:IN: Prepared secure message 0xffffb9ba6db8 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 45042i with MessageCounter:12011388. |
| CHIP:IN: Sending encrypted msg 0xffffb9ba6db8 with MessageCounter:12011388 to 0x0000000000000001 (1) at monotonic time: 304120 msec |
| CHIP:DMG: ICR moving to [CommandSen] |
| CHIP:CTL: Sent CSR request, waiting for the CSR |
| CHIP:DMG: ICR moving to [AwaitingDe] |
| CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| CHIP:DL: Indication received, conn = 0xffffb0044210 |
| CHIP:DL: HandlePlatformSpecificBLEEvent 16389 |
| CHIP:DL: Indication received, conn = 0xffffb0044210 |
| CHIP:DL: HandlePlatformSpecificBLEEvent 16389 |
| CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8508040 on exchange 45042i |
| CHIP:EM: Found matching exchange: 45042i, Delegate: 0xffffb0040000 |
| CHIP:DMG: ICR moving to [ResponseRe] |
| CHIP:DMG: InvokeResponseMessage = |
| CHIP:DMG: { |
| CHIP:DMG: suppressResponse = false, |
| CHIP:DMG: InvokeResponseIBs = |
| CHIP:DMG: [ |
| CHIP:DMG: InvokeResponseIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandDataIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandPathIB = |
| CHIP:DMG: { |
| CHIP:DMG: EndpointId = 0x0, |
| CHIP:DMG: ClusterId = 0x3e, |
| CHIP:DMG: CommandId = 0x5, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: CommandData = |
| CHIP:DMG: { |
| CHIP:DMG: 0x0 = [ |
| CHIP:DMG: 0x15, 0x30, 0x1, 0xcd, 0x30, 0x81, 0xca, 0x30, 0x70, 0x2, 0x1, 0x0, 0x30, 0xe, 0x31, 0xc, 0x30, 0xa, 0x6, 0x3, 0x55, 0x4, 0xa, 0xc, 0x3, 0x43, 0x53, 0x52, 0x30, 0x59, 0x30, 0x13, 0x6, 0x7, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x2, 0x1, 0x6, 0x8, 0x2a, 0x86 |
| CHIP:DMG: ] |
| CHIP:DMG: 0x1 = [ |
| CHIP:DMG: 0xea, 0xd6, 0x96, 0x53, 0x4d, 0x46, 0x1d, 0xd6, 0xcc, 0x7f, 0x25, 0x50, 0x80, 0x4c, 0x2a, 0xe9, 0xc8, 0xb8, 0x1b, 0x34, 0xca, 0x98, 0x38, 0x42, 0x74, 0xc2, 0x13, 0xf4, 0x10, 0x4d, 0xa2, 0x44, 0x38, 0x98, 0x28, 0xb6, 0xb1, 0x94, 0x6b, 0xd, 0x29, 0x1b |
| CHIP:DMG: ] |
| CHIP:DMG: }, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: ], |
| CHIP:DMG: |
| CHIP:DMG: InteractionModelRevision = 1 |
| CHIP:DMG: }, |
| CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005 |
| CHIP:CTL: Received certificate signing request from the device |
| CHIP:CTL: Getting certificate chain for the device from the issuer |
| CHIP:CTL: Verifying Certificate Signing Request |
| CHIP:CTL: Generating NOC |
| CHIP:CTL: Providing certificate chain to the commissioner |
| CHIP:CTL: Received callback from the CA for NOC Chain generation. Status ../../src/controller/ExampleOperationalCredentialsIssuer.cpp:225: Success |
| disabled: true |
| |
| - label: |
| "Commissioner configures operational credentials on DUT if not |
| previously installed" |
| verification: | |
| Verify in DUT as client side |
| |
| [1651218829.220063][3273:3278] CHIP:CTL: Sending root certificate to the device |
| [1651218829.220201][3273:3278] CHIP:DMG: ICR moving to [AddingComm] |
| [1651218829.222415][3273:3278] CHIP:DMG: ICR moving to [AddedComma] |
| [1651218829.222549][3273:3278] CHIP:IN: Prepared secure message 0xffffb9ba6b98 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 45043i with MessageCounter:12011389. |
| [1651218829.222616][3273:3278] CHIP:IN: Sending encrypted msg 0xffffb9ba6b98 with MessageCounter:12011389 to 0x0000000000000001 (1) at monotonic time: 305872 msec |
| [1651218829.222746][3273:3278] CHIP:DMG: ICR moving to [CommandSen] |
| [1651218829.222789][3273:3278] CHIP:CTL: Sent root certificate to the device |
| [1651218829.223121][3273:3278] CHIP:DMG: ICR moving to [AwaitingDe] |
| [1651218829.306861][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| [1651218829.404144][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| [1651218829.454121][3273:3276] CHIP:DL: Indication received, conn = 0xffffb0044210 |
| [1651218829.454352][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 |
| CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8508041 on exchange 45043i |
| CHIP:EM: Found matching exchange: 45043i, Delegate: 0xffffa400def0 |
| CHIP:DMG: ICR moving to [ResponseRe] |
| CHIP:DMG: InvokeResponseMessage = |
| CHIP:DMG: { |
| CHIP:DMG: suppressResponse = false, |
| CHIP:DMG: InvokeResponseIBs = |
| CHIP:DMG: [ |
| CHIP:DMG: InvokeResponseIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandStatusIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandPathIB = |
| CHIP:DMG: { |
| CHIP:DMG: EndpointId = 0x0, |
| CHIP:DMG: ClusterId = 0x3e, |
| CHIP:DMG: CommandId = 0xb, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: StatusIB = |
| CHIP:DMG: { |
| CHIP:DMG: status = 0x0, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: ], |
| CHIP:DMG: |
| CHIP:DMG: InteractionModelRevision = 1 |
| CHIP:DMG: }, |
| CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0 |
| CHIP:CTL: Device confirmed that it has received the root certificate |
| disabled: true |
| |
| - label: |
| "Commissioner configures itself as administrator in ACL on TH if |
| needed" |
| verification: | |
| Verify in DUT as client side |
| |
| [1651218829.457248][3273:3278] CHIP:CTL: Sending operational certificate chain to the device |
| [1651218829.457372][3273:3278] CHIP:DMG: ICR moving to [AddingComm] |
| [1651218829.460013][3273:3278] CHIP:DMG: ICR moving to [AddedComma] |
| [1651218829.460273][3273:3278] CHIP:IN: Prepared secure message 0xffffb9ba7828 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 45044i with MessageCounter:12011390. |
| [1651218829.460374][3273:3278] CHIP:IN: Sending encrypted msg 0xffffb9ba7828 with MessageCounter:12011390 to 0x0000000000000001 (1) at monotonic time: 306110 msec |
| [1651218829.460602][3273:3278] CHIP:DMG: ICR moving to [CommandSen] |
| [1651218829.460684][3273:3278] CHIP:CTL: Sent operational certificate to the device |
| [1651218829.460778][3273:3278] CHIP:DMG: ICR moving to [AwaitingDe] |
| [1651218829.550574][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| [1651218829.648065][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| [1651218829.745594][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| [1651218833.988087][3273:3276] CHIP:DL: Indication received, conn = 0xffffb0044210 |
| [1651218833.988336][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 |
| [1651218833.988598][3273:3278] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8508042 on exchange 45044i |
| CHIP:EM: Found matching exchange: 45044i, Delegate: 0xffffb0040000 |
| CHIP:DMG: ICR moving to [ResponseRe] |
| CHIP:DMG: InvokeResponseMessage = |
| CHIP:DMG: { |
| CHIP:DMG: suppressResponse = false, |
| CHIP:DMG: InvokeResponseIBs = |
| CHIP:DMG: [ |
| CHIP:DMG: InvokeResponseIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandDataIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandPathIB = |
| CHIP:DMG: { |
| CHIP:DMG: EndpointId = 0x0, |
| CHIP:DMG: ClusterId = 0x3e, |
| CHIP:DMG: CommandId = 0x8, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: CommandData = |
| CHIP:DMG: { |
| CHIP:DMG: 0x0 = 0, |
| CHIP:DMG: 0x1 = 1, |
| CHIP:DMG: }, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: ], |
| CHIP:DMG: |
| CHIP:DMG: InteractionModelRevision = 1 |
| CHIP:DMG: }, |
| CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008 |
| CHIP:CTL: Device returned status 0 on receiving the NOC |
| CHIP:CTL: Operational credentials provisioned on device 0xffffa4001730 |
| disabled: true |
| |
| - label: |
| "Commissioner configures operational network on TH if TH both supports |
| and requires" |
| verification: | |
| Verify in DUT as client side |
| |
| [1651218833.995054][3273:3278] CHIP:CTL: Adding thread network |
| [1651218833.995176][3273:3278] CHIP:DMG: ICR moving to [AddingComm] |
| [1651218833.995253][3273:3278] CHIP:DMG: ICR moving to [AddedComma] |
| [1651218833.995431][3273:3278] CHIP:IN: Prepared secure message 0xffffb9ba7848 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 45045i with MessageCounter:12011391. |
| [1651218833.995523][3273:3278] CHIP:IN: Sending encrypted msg 0xffffb9ba7848 with MessageCounter:12011391 to 0x0000000000000001 (1) at monotonic time: 310645 msec |
| [1651218833.995723][3273:3278] CHIP:DMG: ICR moving to [CommandSen] |
| [1651218833.995823][3273:3278] CHIP:DMG: ICR moving to [AwaitingDe] |
| [1651218834.084548][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| [1651218834.134690][3273:3276] CHIP:DL: Indication received, conn = 0xffffb0044210 |
| [1651218834.134918][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 |
| CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8508043 on exchange 45045i |
| CHIP:EM: Found matching exchange: 45045i, Delegate: 0xffffa400def0 |
| CHIP:DMG: ICR moving to [ResponseRe] |
| CHIP:DMG: InvokeResponseMessage = |
| CHIP:DMG: { |
| CHIP:DMG: suppressResponse = false, |
| CHIP:DMG: InvokeResponseIBs = |
| CHIP:DMG: [ |
| CHIP:DMG: InvokeResponseIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandDataIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandPathIB = |
| CHIP:DMG: { |
| CHIP:DMG: EndpointId = 0x0, |
| CHIP:DMG: ClusterId = 0x31, |
| CHIP:DMG: CommandId = 0x5, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: CommandData = |
| CHIP:DMG: { |
| CHIP:DMG: 0x0 = 0, |
| CHIP:DMG: 0x1 = "", |
| CHIP:DMG: }, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: ], |
| CHIP:DMG: |
| CHIP:DMG: InteractionModelRevision = 1 |
| CHIP:DMG: }, |
| CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005 |
| CHIP:CTL: Received NetworkConfig response |
| disabled: true |
| |
| - label: |
| "Commissioner instructs Commissionee to connect to operational network |
| if not already connected" |
| verification: | |
| Verify in DUT as client side |
| |
| [1651218834.137891][3273:3278] CHIP:CTL: Enabling thread network |
| [1651218834.138014][3273:3278] CHIP:DMG: ICR moving to [AddingComm] |
| [1651218834.138086][3273:3278] CHIP:DMG: ICR moving to [AddedComma] |
| [1651218834.138236][3273:3278] CHIP:IN: Prepared secure message 0xffffb9ba7938 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 45046i with MessageCounter:12011392. |
| [1651218834.138325][3273:3278] CHIP:IN: Sending encrypted msg 0xffffb9ba7938 with MessageCounter:12011392 to 0x0000000000000001 (1) at monotonic time: 310788 msec |
| [1651218834.138522][3273:3278] CHIP:DMG: ICR moving to [CommandSen] |
| [1651218834.138628][3273:3278] CHIP:DMG: ICR moving to [AwaitingDe] |
| [1651218834.231701][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| [1651218834.426948][3273:3276] CHIP:DL: Indication received, conn = 0xffffb0044210 |
| [1651218834.427186][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 |
| [1651218834.427443][3273:3278] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8508044 on exchange 45046i |
| CHIP:EM: Found matching exchange: 45046i, Delegate: 0xffffb0040000 |
| CHIP:DMG: ICR moving to [ResponseRe] |
| CHIP:DMG: InvokeResponseMessage = |
| CHIP:DMG: { |
| CHIP:DMG: suppressResponse = false, |
| CHIP:DMG: InvokeResponseIBs = |
| CHIP:DMG: [ |
| CHIP:DMG: InvokeResponseIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandDataIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandPathIB = |
| CHIP:DMG: { |
| CHIP:DMG: EndpointId = 0x0, |
| CHIP:DMG: ClusterId = 0x31, |
| CHIP:DMG: CommandId = 0x7, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: CommandData = |
| CHIP:DMG: { |
| CHIP:DMG: 0x0 = 0, |
| CHIP:DMG: 0x1 = "", |
| CHIP:DMG: 0x2 = 0, |
| CHIP:DMG: }, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: ], |
| CHIP:DMG: |
| CHIP:DMG: InteractionModelRevision = 1 |
| CHIP:DMG: }, |
| CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007 |
| CHIP:CTL: Received ConnectNetwork response |
| disabled: true |
| |
| - label: |
| "Commissioning channel between the Commissioner and Commissionee is |
| terminated." |
| verification: | |
| 1. Verify the channel was terminated on DUT=chip-tool |
| [1651271753284] [23287:743790] CHIP: [CTL] Received CommissioningComplete response |
| [1651271753284] [23287:743790] CHIP: [CTL] Successfully finished commissioning step "SendComplete" |
| [1651271753284] [23287:743790] CHIP: [CTL] Commissioning stage next step: "SendComplete" -> "Cleanup" |
| [1651271753284] [23287:743790] CHIP: [CTL] Performing next commissioning step "Cleanup" |
| [1651271753284] [23287:743790] CHIP: [CTL] Successfully finished commissioning step "Cleanup" |
| [1651271753284] [23287:743790] CHIP: [TOO] Device commissioning completed with success |
| disabled: true |
| |
| - label: "Reboot TH and prepare for commissioning" |
| verification: | |
| 1. Using TH=all-clusters-app, exit the app, re-launch app |
| disabled: true |
| |
| - label: |
| "Establish encryption keys with Password Authenticated Session |
| Establishment on the commissioning channel" |
| verification: | |
| Verify in DUT as client side |
| |
| CHIP:SC: Received PBKDF param response |
| disabled: true |
| |
| - label: |
| "Commissioner re-arms Fail-safe timer on Commissionee within 60s (the |
| autonomously Fail-safe timer length set by Commissionee)" |
| verification: | |
| Verify in DUT as client side |
| |
| CHIP:CTL: Arming failsafe (60 seconds) |
| disabled: true |
| |
| - label: |
| "Commissioner SHALL configure regulatory information in the |
| Commissionee." |
| PICS: MCORE.COM.WIRELESS |
| verification: | |
| Verify in DUT as client side |
| |
| |
| Performing next commissioning step "ConfigRegulatory" |
| [1653471968.202645][30157:30162] CHIP:CTL: Setting Regulatory Config |
| [1653471968.202666][30157:30162] CHIP:CTL: No regulatory config supplied by controller, leaving as device default (0) |
| |
| Verify on TH: |
| NVS set: chip-config/regulatory-location = 0 (0x0) |
| disabled: true |
| |
| - label: |
| "Commissioner requests operational CSR from Commissionee with |
| OperationalCSRRequest command" |
| verification: | |
| Verify in DUT as client side |
| |
| CHIP:CTL: Sending CSR request to 0xffffa4001730 device |
| CHIP:DMG: ICR moving to [AddingComm] |
| CHIP:DMG: ICR moving to [AddedComma] |
| CHIP:IN: Prepared secure message 0xffffb9ba6db8 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 45042i with MessageCounter:12011388. |
| CHIP:IN: Sending encrypted msg 0xffffb9ba6db8 with MessageCounter:12011388 to 0x0000000000000001 (1) at monotonic time: 304120 msec |
| CHIP:DMG: ICR moving to [CommandSen] |
| CHIP:CTL: Sent CSR request, waiting for the CSR |
| CHIP:DMG: ICR moving to [AwaitingDe] |
| CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| CHIP:DL: Indication received, conn = 0xffffb0044210 |
| CHIP:DL: HandlePlatformSpecificBLEEvent 16389 |
| CHIP:DL: Indication received, conn = 0xffffb0044210 |
| CHIP:DL: HandlePlatformSpecificBLEEvent 16389 |
| CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8508040 on exchange 45042i |
| CHIP:EM: Found matching exchange: 45042i, Delegate: 0xffffb0040000 |
| CHIP:DMG: ICR moving to [ResponseRe] |
| CHIP:DMG: InvokeResponseMessage = |
| CHIP:DMG: { |
| CHIP:DMG: suppressResponse = false, |
| CHIP:DMG: InvokeResponseIBs = |
| CHIP:DMG: [ |
| CHIP:DMG: InvokeResponseIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandDataIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandPathIB = |
| CHIP:DMG: { |
| CHIP:DMG: EndpointId = 0x0, |
| CHIP:DMG: ClusterId = 0x3e, |
| CHIP:DMG: CommandId = 0x5, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: CommandData = |
| CHIP:DMG: { |
| CHIP:DMG: 0x0 = [ |
| CHIP:DMG: 0x15, 0x30, 0x1, 0xcd, 0x30, 0x81, 0xca, 0x30, 0x70, 0x2, 0x1, 0x0, 0x30, 0xe, 0x31, 0xc, 0x30, 0xa, 0x6, 0x3, 0x55, 0x4, 0xa, 0xc, 0x3, 0x43, 0x53, 0x52, 0x30, 0x59, 0x30, 0x13, 0x6, 0x7, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x2, 0x1, 0x6, 0x8, 0x2a, 0x86 |
| CHIP:DMG: ] |
| CHIP:DMG: 0x1 = [ |
| CHIP:DMG: 0xea, 0xd6, 0x96, 0x53, 0x4d, 0x46, 0x1d, 0xd6, 0xcc, 0x7f, 0x25, 0x50, 0x80, 0x4c, 0x2a, 0xe9, 0xc8, 0xb8, 0x1b, 0x34, 0xca, 0x98, 0x38, 0x42, 0x74, 0xc2, 0x13, 0xf4, 0x10, 0x4d, 0xa2, 0x44, 0x38, 0x98, 0x28, 0xb6, 0xb1, 0x94, 0x6b, 0xd, 0x29, 0x1b |
| CHIP:DMG: ] |
| CHIP:DMG: }, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: ], |
| CHIP:DMG: |
| CHIP:DMG: InteractionModelRevision = 1 |
| CHIP:DMG: }, |
| CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005 |
| CHIP:CTL: Received certificate signing request from the device |
| CHIP:CTL: Getting certificate chain for the device from the issuer |
| CHIP:CTL: Verifying Certificate Signing Request |
| CHIP:CTL: Generating NOC |
| CHIP:CTL: Providing certificate chain to the commissioner |
| CHIP:CTL: Received callback from the CA for NOC Chain generation. Status ../../src/controller/ExampleOperationalCredentialsIssuer.cpp:225: Success |
| disabled: true |
| |
| - label: |
| "Commissioner configures operational credentials on DUT if not |
| previously installed" |
| verification: | |
| Verify in DUT as client side |
| |
| [1651218829.220063][3273:3278] CHIP:CTL: Sending root certificate to the device |
| [1651218829.220201][3273:3278] CHIP:DMG: ICR moving to [AddingComm] |
| [1651218829.222415][3273:3278] CHIP:DMG: ICR moving to [AddedComma] |
| [1651218829.222549][3273:3278] CHIP:IN: Prepared secure message 0xffffb9ba6b98 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 45043i with MessageCounter:12011389. |
| [1651218829.222616][3273:3278] CHIP:IN: Sending encrypted msg 0xffffb9ba6b98 with MessageCounter:12011389 to 0x0000000000000001 (1) at monotonic time: 305872 msec |
| [1651218829.222746][3273:3278] CHIP:DMG: ICR moving to [CommandSen] |
| [1651218829.222789][3273:3278] CHIP:CTL: Sent root certificate to the device |
| [1651218829.223121][3273:3278] CHIP:DMG: ICR moving to [AwaitingDe] |
| [1651218829.306861][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| [1651218829.404144][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| [1651218829.454121][3273:3276] CHIP:DL: Indication received, conn = 0xffffb0044210 |
| [1651218829.454352][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 |
| CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8508041 on exchange 45043i |
| CHIP:EM: Found matching exchange: 45043i, Delegate: 0xffffa400def0 |
| CHIP:DMG: ICR moving to [ResponseRe] |
| CHIP:DMG: InvokeResponseMessage = |
| CHIP:DMG: { |
| CHIP:DMG: suppressResponse = false, |
| CHIP:DMG: InvokeResponseIBs = |
| CHIP:DMG: [ |
| CHIP:DMG: InvokeResponseIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandStatusIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandPathIB = |
| CHIP:DMG: { |
| CHIP:DMG: EndpointId = 0x0, |
| CHIP:DMG: ClusterId = 0x3e, |
| CHIP:DMG: CommandId = 0xb, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: StatusIB = |
| CHIP:DMG: { |
| CHIP:DMG: status = 0x0, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: ], |
| CHIP:DMG: |
| CHIP:DMG: InteractionModelRevision = 1 |
| CHIP:DMG: }, |
| CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0 |
| CHIP:CTL: Device confirmed that it has received the root certificate |
| disabled: true |
| |
| - label: |
| "Commissioner configures itself as administrator in ACL on TH if |
| needed" |
| verification: | |
| Verify in DUT as client side |
| |
| [1651218829.457248][3273:3278] CHIP:CTL: Sending operational certificate chain to the device |
| [1651218829.457372][3273:3278] CHIP:DMG: ICR moving to [AddingComm] |
| [1651218829.460013][3273:3278] CHIP:DMG: ICR moving to [AddedComma] |
| [1651218829.460273][3273:3278] CHIP:IN: Prepared secure message 0xffffb9ba7828 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 45044i with MessageCounter:12011390. |
| [1651218829.460374][3273:3278] CHIP:IN: Sending encrypted msg 0xffffb9ba7828 with MessageCounter:12011390 to 0x0000000000000001 (1) at monotonic time: 306110 msec |
| [1651218829.460602][3273:3278] CHIP:DMG: ICR moving to [CommandSen] |
| [1651218829.460684][3273:3278] CHIP:CTL: Sent operational certificate to the device |
| [1651218829.460778][3273:3278] CHIP:DMG: ICR moving to [AwaitingDe] |
| [1651218829.550574][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| [1651218829.648065][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| [1651218829.745594][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| [1651218833.988087][3273:3276] CHIP:DL: Indication received, conn = 0xffffb0044210 |
| [1651218833.988336][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 |
| [1651218833.988598][3273:3278] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8508042 on exchange 45044i |
| CHIP:EM: Found matching exchange: 45044i, Delegate: 0xffffb0040000 |
| CHIP:DMG: ICR moving to [ResponseRe] |
| CHIP:DMG: InvokeResponseMessage = |
| CHIP:DMG: { |
| CHIP:DMG: suppressResponse = false, |
| CHIP:DMG: InvokeResponseIBs = |
| CHIP:DMG: [ |
| CHIP:DMG: InvokeResponseIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandDataIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandPathIB = |
| CHIP:DMG: { |
| CHIP:DMG: EndpointId = 0x0, |
| CHIP:DMG: ClusterId = 0x3e, |
| CHIP:DMG: CommandId = 0x8, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: CommandData = |
| CHIP:DMG: { |
| CHIP:DMG: 0x0 = 0, |
| CHIP:DMG: 0x1 = 1, |
| CHIP:DMG: }, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: ], |
| CHIP:DMG: |
| CHIP:DMG: InteractionModelRevision = 1 |
| CHIP:DMG: }, |
| CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008 |
| CHIP:CTL: Device returned status 0 on receiving the NOC |
| CHIP:CTL: Operational credentials provisioned on device 0xffffa4001730 |
| disabled: true |
| |
| - label: |
| "Commissioner configures operational network on TH if TH both supports |
| and requires" |
| verification: | |
| Verify in DUT as client side |
| |
| [1651218833.995054][3273:3278] CHIP:CTL: Adding thread network |
| [1651218833.995176][3273:3278] CHIP:DMG: ICR moving to [AddingComm] |
| [1651218833.995253][3273:3278] CHIP:DMG: ICR moving to [AddedComma] |
| [1651218833.995431][3273:3278] CHIP:IN: Prepared secure message 0xffffb9ba7848 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 45045i with MessageCounter:12011391. |
| [1651218833.995523][3273:3278] CHIP:IN: Sending encrypted msg 0xffffb9ba7848 with MessageCounter:12011391 to 0x0000000000000001 (1) at monotonic time: 310645 msec |
| [1651218833.995723][3273:3278] CHIP:DMG: ICR moving to [CommandSen] |
| [1651218833.995823][3273:3278] CHIP:DMG: ICR moving to [AwaitingDe] |
| [1651218834.084548][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| [1651218834.134690][3273:3276] CHIP:DL: Indication received, conn = 0xffffb0044210 |
| [1651218834.134918][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 |
| CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8508043 on exchange 45045i |
| CHIP:EM: Found matching exchange: 45045i, Delegate: 0xffffa400def0 |
| CHIP:DMG: ICR moving to [ResponseRe] |
| CHIP:DMG: InvokeResponseMessage = |
| CHIP:DMG: { |
| CHIP:DMG: suppressResponse = false, |
| CHIP:DMG: InvokeResponseIBs = |
| CHIP:DMG: [ |
| CHIP:DMG: InvokeResponseIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandDataIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandPathIB = |
| CHIP:DMG: { |
| CHIP:DMG: EndpointId = 0x0, |
| CHIP:DMG: ClusterId = 0x31, |
| CHIP:DMG: CommandId = 0x5, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: CommandData = |
| CHIP:DMG: { |
| CHIP:DMG: 0x0 = 0, |
| CHIP:DMG: 0x1 = "", |
| CHIP:DMG: }, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: ], |
| CHIP:DMG: |
| CHIP:DMG: InteractionModelRevision = 1 |
| CHIP:DMG: }, |
| CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005 |
| CHIP:CTL: Received NetworkConfig response |
| disabled: true |
| |
| - label: |
| "Commissioner instructs Commissionee to connect to operational network |
| if not already connected" |
| verification: | |
| Verify in DUT as client side |
| |
| [1651218834.137891][3273:3278] CHIP:CTL: Enabling thread network |
| [1651218834.138014][3273:3278] CHIP:DMG: ICR moving to [AddingComm] |
| [1651218834.138086][3273:3278] CHIP:DMG: ICR moving to [AddedComma] |
| [1651218834.138236][3273:3278] CHIP:IN: Prepared secure message 0xffffb9ba7938 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 45046i with MessageCounter:12011392. |
| [1651218834.138325][3273:3278] CHIP:IN: Sending encrypted msg 0xffffb9ba7938 with MessageCounter:12011392 to 0x0000000000000001 (1) at monotonic time: 310788 msec |
| [1651218834.138522][3273:3278] CHIP:DMG: ICR moving to [CommandSen] |
| [1651218834.138628][3273:3278] CHIP:DMG: ICR moving to [AwaitingDe] |
| [1651218834.231701][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 |
| [1651218834.426948][3273:3276] CHIP:DL: Indication received, conn = 0xffffb0044210 |
| [1651218834.427186][3273:3278] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 |
| [1651218834.427443][3273:3278] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:8508044 on exchange 45046i |
| CHIP:EM: Found matching exchange: 45046i, Delegate: 0xffffb0040000 |
| CHIP:DMG: ICR moving to [ResponseRe] |
| CHIP:DMG: InvokeResponseMessage = |
| CHIP:DMG: { |
| CHIP:DMG: suppressResponse = false, |
| CHIP:DMG: InvokeResponseIBs = |
| CHIP:DMG: [ |
| CHIP:DMG: InvokeResponseIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandDataIB = |
| CHIP:DMG: { |
| CHIP:DMG: CommandPathIB = |
| CHIP:DMG: { |
| CHIP:DMG: EndpointId = 0x0, |
| CHIP:DMG: ClusterId = 0x31, |
| CHIP:DMG: CommandId = 0x7, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: CommandData = |
| CHIP:DMG: { |
| CHIP:DMG: 0x0 = 0, |
| CHIP:DMG: 0x1 = "", |
| CHIP:DMG: 0x2 = 0, |
| CHIP:DMG: }, |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: }, |
| CHIP:DMG: |
| CHIP:DMG: ], |
| CHIP:DMG: |
| CHIP:DMG: InteractionModelRevision = 1 |
| CHIP:DMG: }, |
| CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007 |
| CHIP:CTL: Received ConnectNetwork response |
| disabled: true |
| |
| - label: |
| "Commissioning channel between the Commissioner and Commissionee is |
| terminated." |
| verification: | |
| 1. Verify the channel was terminated on DUT=chip-tool |
| [1651271753284] [23287:743790] CHIP: [CTL] Received CommissioningComplete response |
| [1651271753284] [23287:743790] CHIP: [CTL] Successfully finished commissioning step "SendComplete" |
| [1651271753284] [23287:743790] CHIP: [CTL] Commissioning stage next step: "SendComplete" -> "Cleanup" |
| [1651271753284] [23287:743790] CHIP: [CTL] Performing next commissioning step "Cleanup" |
| [1651271753284] [23287:743790] CHIP: [CTL] Successfully finished commissioning step "Cleanup" |
| [1651271753284] [23287:743790] CHIP: [TOO] Device commissioning completed with success |
| disabled: true |
| |
| - label: "Commissioner starts discovery of TH using Operational Discovery" |
| verification: | |
| Verify in DUT as client side |
| |
| CHIP:DL: Avahi resolve found |
| CHIP:DIS: Node ID resolved for 0x0000000000000001 |
| CHIP:DIS: Addr 0: [fd11:22::9d96:8fcf:10cf:799e]:5540 |
| CHIP:CTL: OperationalDiscoveryComplete for device ID 0x0000000000000001 |
| disabled: true |
| |
| - label: |
| "Commissioner opens a CASE session with TH over operational network" |
| verification: | |
| Verify in DUT as client side |
| |
| CHIP:SC: Sent Sigma1 msg |
| CHIP:CTL: Address resolved for node: 0x0000000000000001 |
| CHIP:EM: Received message of type 0x31 with protocolId (0, 0) and MessageCounter:1066460336 on exchange 45047i |
| CHIP:EM: Found matching exchange: 45047i, Delegate: 0xffffa400f7f8 |
| CHIP:EM: Rxd Ack; Removing MessageCounter:2352378411 from Retrans Table on exchange 45047i |
| CHIP:EM: Removed CHIP MessageCounter:2352378411 from RetransTable on exchange 45047i |
| CHIP:SC: Received Sigma2 msg |
| CHIP:SC: Peer assigned session session ID 2 |
| CHIP:SC: The device does not support GetClock_RealTimeMS() API. This will eventually result in CASE session setup failures. |
| CHIP:IN: Generating compressed fabric ID using uncompressed fabric ID 0x0000000000000001 and root pubkey |
| CHIP:IN: 0x04, 0x6e, 0x3e, 0x58, 0x9d, 0x08, 0xd6, 0xae, |
| CHIP:IN: 0xe9, 0xff, 0x9b, 0x8f, 0xba, 0x6f, 0x57, 0x73, |
| CHIP:IN: 0x21, 0xc4, 0xe2, 0x7b, 0x09, 0xe4, 0x24, 0x7f, |
| CHIP:IN: 0x55, 0x44, 0x3b, 0xf2, 0x7c, 0x13, 0x45, 0x3b, |
| CHIP:IN: 0x82, 0xa8, 0x42, 0x96, 0xb4, 0x36, 0x78, 0x20, |
| CHIP:IN: 0xa1, 0x37, 0x69, 0xf0, 0x20, 0xc9, 0x20, 0x7e, |
| CHIP:IN: 0x66, 0x45, 0x84, 0x53, 0x1b, 0x3e, 0xd2, 0x61, |
| CHIP:IN: 0xb6, 0x89, 0x27, 0xfd, 0xe8, 0x23, 0x69, 0x6d, |
| CHIP:IN: 0x93, |
| CHIP:IN: Generated compressed fabric ID |
| CHIP:IN: 0xa3, 0x54, 0xab, 0x2a, 0xa2, 0x1f, 0x8e, 0x48, |
| CHIP:SC: Found MRP parameters in the message |
| CHIP:SC: Sending Sigma3 |
| CHIP:EM: Piggybacking Ack for MessageCounter:1066460336 on exchange: 45047i |
| CHIP:IN: Prepared unauthenticated message 0xaaaad7ce1bf8 to 0x0000000000000000 (0) of type 0x32 and protocolId (0, 0) on exchange 45047i with MessageCounter:2352378412. |
| CHIP:IN: Sending unauthenticated msg 0xaaaad7ce1bf8 with MessageCounter:2352378412 to 0x0000000000000000 at monotonic time: 315803 msec |
| CHIP:SC: Sent Sigma3 msg |
| CHIP:EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:1066460337 on exchange 45047i |
| CHIP:EM: Found matching exchange: 45047i, Delegate: 0xffffa400f7f8 |
| CHIP:EM: Rxd Ack; Removing MessageCounter:2352378412 from Retrans Table on exchange 45047i |
| CHIP:EM: Removed CHIP MessageCounter:2352378412 from RetransTable on exchange 45047i |
| CHIP:SC: Success status report received. Session was established |
| CHIP:IN: New secure session created for device 0x0000000000000001, LSID:2 PSID:2! |
| disabled: true |
| |
| - label: "Commissioner sends CommissioningComplete command" |
| verification: | |
| Verify in DUT as client side |
| |
| CHIP:CTL: Received CommissioningComplete response |
| CHIP:CTL: Rendezvous cleanup |
| CHIP:TOO: Device commissioning completed with success |
| disabled: true |
