andy31415
commented
2 years ago @mideayanghui - could you attach the log instead of pasting? it is very long. For pasting, please do a human-curated paste.
Open mideayanghui opened 2 years ago
andy31415
commented
2 years ago @mideayanghui - could you attach the log instead of pasting? it is very long. For pasting, please do a human-curated paste.
andy31415
commented
2 years ago The description of So we can't get Verify the NOC and ICAC value during commissioning does not seem to match with the title of `Decoder.cpp: incorrect state'.
bzbarsky-apple
commented
2 years ago But there are no messages about 'InvokeRequestMessage '
Those would be coming from the DUT, not the TH, so why would you expect to see them in the TH log?
The Decoder.cpp bit seems like a bug in the trace decoder or in the messages it's decoding; more details on what the actual bytes look like would be needed to tell for sure.
@mideayanghui What exactly is this issue about? Please clearly describe:
liuck8
commented
2 years ago @andy31415 @bzbarsky-apple 【Problem】 The issue is about the TC-OPCREDS-3.2 in Matter 1.0 Formal test. Step4 and Step23 fail.
The detail of the test case is as below. Matter-1.0-test-case-TC-OPCREDS-3.2.xlsx
【Expected Outcome】 Step 4, "Verify the NOC and ICAC value during commissioning in TH2 Log" [1658819526.011801][8379:8385] CHIP:DMG: InvokeRequestMessage = [1658819526.011835][8379:8385] CHIP:DMG: { [1658819526.011869][8379:8385] CHIP:DMG: suppressResponse = false, [1658819526.011907][8379:8385] CHIP:DMG: timedRequest = false, [1658819526.011943][8379:8385] CHIP:DMG: InvokeRequests = [1658819526.011990][8379:8385] CHIP:DMG: [ [1658819526.012025][8379:8385] CHIP:DMG: CommandDataIB = [1658819526.012065][8379:8385] CHIP:DMG: { [1658819526.012102][8379:8385] CHIP:DMG: CommandPathIB = [1658819526.012148][8379:8385] CHIP:DMG: { [1658819526.012195][8379:8385] CHIP:DMG: EndpointId = 0x0, [1658819526.012245][8379:8385] CHIP:DMG: ClusterId = 0x3e, [1658819526.012298][8379:8385] CHIP:DMG: CommandId = 0x6, [1658819526.012340][8379:8385] CHIP:DMG: },
【Actual Outcome】 In the TH2's log, the Complete log is in this link. th-2.log
Step 4, There's no Noc Info. So we can't Verify the value of NOC and ICAC are same in step 22 and 4 are same.****
[1665561607.151350][17384:17389] CHIP:CTL: Commissioning stage next step: 'SendTrustedRootCert' -> 'SendNOC'
[1665561607.151409][17384:17389] CHIP:CTL: Performing next commissioning step 'SendNOC'
[1665561607.151545][17384:17389] CHIP:DMG: ICR moving to [AddingComm]
[1665561607.151626][17384:17389] CHIP:DMG: ICR moving to [AddedComma]
[1665561607.152553][17384:17389] CHIP:IN: Prepared secure message 0xffffa4010928 to 0xFFFFFFFB00000000 (0) of type 0x8 and protocolId (0, 1) on exchange 28399i with MessageCounter:174566280.
[1665561607.152648][17384:17389] CHIP:IN: Sending encrypted msg 0xffffa4010928 with MessageCounter:174566280 to 0xFFFFFFFB00000000 (0) at monotonic time: 0000000000FAD71F msec
[1665561607.153532][17384:17389] CHIP:DMG: ICR moving to [CommandSen]
[1665561607.153632][17384:17389] CHIP:CTL: Sent operational certificate to the device
[1665561607.153734][17384:17389] CHIP:DMG: ICR moving to [AwaitingDe]
[1665561607.153803][17384:17389] CHIP:EM: Sending Standalone Ack for MessageCounter:111034325 on exchange 28398i
[1665561607.154281][17384:17389] CHIP:DMG: >> to UDP:[fd5b:35de:ad5b:beef:ae93:c4ff:fec1:5cae%eth0]:5540 | 174566281 | [Secure Channel (0) / Standalone Ack (0x10) / Session = 28685 / Exchange = 28398]
[1665561607.154368][17384:17389] CHIP:DMG: Header Flags =
[1665561607.154424][17384:17389] CHIP:DMG: {
[1665561607.154507][17384:17389] CHIP:DMG: Exchange (0x03) =
[1665561607.154563][17384:17389] CHIP:DMG: {
[1665561607.154611][17384:17389] CHIP:DMG: Initiator = true
[1665561607.154667][17384:17389] CHIP:DMG: AckMsg = 111034325
[1665561607.154719][17384:17389] CHIP:DMG: }
[1665561607.154788][17384:17389] CHIP:DMG: }
[1665561607.154841][17384:17389] CHIP:DMG:
[1665561607.155065][17384:17389] CHIP:DMG: Error: ../../examples/common/tracing/decoder/secure_channel/Decoder.cpp:159: CHIP Error 0x00000003: Incorrect state
0 0xffffb6fdc12a, tag[Anonymous]: 0xffffffff, type: Signed Fixed Point (0x00), value: 13
0 0xffffb6fdc130, tag[Common Profile (4 Bytes)]: 0x0::0x0::0x67ab8800, type: Data (0x10), length: 10, value: 0xffffb6fdc130
【Reproduction steps】 Prerequisite:
There are two TH, one is TH1, another is TH2.
One DUT. Step: 1.Use TH1 to commission DUT: $ ./chip-tool pairing ble-wifi 0x2 wifi 12345678 20202021 3840 --trace_decode 1 > th-1.log th-1.log After finished commission, use follow command to open commissioning window: $ ./chip-tool pairing open-commissioning-window 2 1 400 2000 3840 Save the Manual pairing code: [35170644493]
Use TH2 to commission DUT: $ ./chip-tool pairing code 3 35170644493 --trace_decode 1 > th-2.log
DUT Log dut.log
liuck8
commented
2 years ago if I try the follow command to pair TH2 into another Fabric and test again, Step4 of the test case also fail.
1: .Use TH1 to commission DUT: $ ./chip-tool pairing ble-wifi 0x2 wifi 12345678 20202021 3840 --trace_decode 1 > th-1.log th-1.log th-1-window.log
2：After finished commission, use follow command to open commissioning window: $ ./chip-tool pairing open-commissioning-window 2 1 400 2000 3840 Save the Manual pairing code: [35170644493] th-2.log
3: Use TH2 to commission DUT: $ ./chip-tool pairing code 3 35170644493 --commissioner-name beta --trace_decode 1 > th-2.log th-2.log
Attach DUT's Log: dev.log
Can you give me some suggestion?
step0035
commented
2 years ago @bzbarsky-apple @andy31415 I happened to face this same issue, it happens intermittently. NoCValue and ICACValue is expected to be logged out correctly with trace_decoder enabled, but sometimes the chiptool decoder is getting errors like incorrect state / wrong TLV type.
Commissioning is still successful in the above logs so this suggests that the messages being transported is correct, and the problem might lie within the decoder.
liuck8
commented
2 years ago @andy31415 @bzbarsky-apple @step0035 Hello, I have another method to validate NOC in Step 23, Can you help me double check? NOC Chain Verify Method-V1.1.pdf
liuck8
commented
2 years ago @andy31415 @bzbarsky-apple @step0035 @mideayanghui I fix a bug on Chip-Tool in the trace decoder or in the messages it's decoding. I upload a patch based on commit 87bee4de25 , I test and pass the test case, Can you help me do a double check?
0001-TraceDecoder-fix-a-bug-in-the-trace-decoder-or-in-th.zip
bzbarsky-apple
commented
2 years ago @liuck8 Please create a pull request with that change? Then the folks who know the trace decoder code will see it....
liuck8
commented
2 years ago @bzbarsky-apple Thanks, I have created a pull request as this link.
Beside, I upload the chip-tool based on Raspberry-Pi 4, It's can run in TH2.5. chip-tool.tar.gz
stale[bot]
commented
1 year ago This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs.
Reproduction steps
Bug prevalence
always
GitHub hash of the SDK that was being used
26a054c31144478e3c27391c06b0dc3230bb0882
Platform
ameba
Platform Version(s)
Realtek 8720CMF
Type
Common Cluster Logic
Anything else?
No response