Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

pre-sve [TC-MF-1.21][TC-MF-1.22] #19642

Closed
Shadi-Silabs opened this issue Jun 15, 2022 · 6 comments
Closed

pre-sve [TC-MF-1.21][TC-MF-1.22] #19642

Shadi-Silabs opened this issue Jun 15, 2022 · 6 comments

Comments

@Shadi-Silabs
Copy link

Shadi-Silabs commented Jun 15, 2022

TC-MF-1.21 and 1.22 step#5:

Not able to commission the 5th fabric for both tests. supported-fabrics parameter is 5, and I was able to commission 4 fabrics and open the 5th commissioning window without an error, but commissioning the 5th fabric failed.
The errors are either:
CHIP Error 0x00000003: Incorrect state
or
CHIP Error 0x00000032: Timeout
the logs are all below:
TC-MF-1.21.txt
TC-MF-1.21-DUT.txt
TC-MF-1.22.txt
TC-MF-1.22-DUT.txt

test Platform:
EFR32 as DUT
Lighting-app

@bzbarsky-apple
Copy link
Contributor

bzbarsky-apple commented Jun 16, 2022

So looking at the 1.21 logs, the relevant bit in the device log is this:

00> <detail> [SC] Waiting for PBKDF param request
00> <info  > [DIS] Updating services using commissioning mode 2
00> <detail> [DL] Using Thread extended MAC for hostname.
00> <info  > [DIS] Advertise operational node 582E4DF2865D058E-000000000000045A
00> <info  > [DL] advertising srp service: 582E4DF2865D058E-0000000000<info  > [DL] advertising srp service: 8B8E2196D4AAB953-000000000000045A._matter._tcp
00> <detail> [DL] Using Thread extended MAC for hostname.
00> <info  > [DIS] Advertise operational node 52A8427E8AFB31E7-000000000000045A
00> <info  > [DL] advertising srp service: 52A8427E8AFB31E7-000000000000045A._matter._tcp
00> <detail> [DL] Using Thread extended MAC for hostname.
00> <info  > [DIS] Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15
00> <info  > [DL] advertising srp service: 3C6802FE72614DB1._matterc._udp
...
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response
00> <info  > [SVR] Closing pairing window

I really wish it had timestamps there, but in practice that "Closing pairing window" log only happens when a RevokeCommissioning command is sent or when a commissioning window times out. Probably the latter.

OK, on the chip-tool side if we look for 3C6802FE72614DB1 in the log it never appears.

The previous commissionable SRV record (BB835F3784E81704._matterc._udp) does appear. We're seeing that one...

Based on the log above, I wonder whether we hit some sort of limit on the SRP server or something...

@bzbarsky-apple
Copy link
Contributor

TC-MF-1.22-DUT.txt is an empty file, so not much to say about that one....

@Shadi-Silabs
Copy link
Author

TC-MF-1.22 log files have been updated, sorry for that previous empty file

@bzbarsky-apple
Copy link
Contributor

OK, so in the 1.22 DUT log I see:

00> <info  > [DL] advertising srp service: 376851A89CC29C75._matterc._udp
00> <info  > [DL] removing srp service: 1A461415045D135D._matterc._udp
00> <info  > [ZCL] Commissioning window is now open
...
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response
00> <error > [DL] OnSrpClientNotification: Timed out waiting on server response

and again the TH log does not show 376851A89CC29C75 anywhere. So seems like the same issue...

@woody-apple
Copy link
Contributor

Cert Blocker Review: This appears to be an error around thread mDNS... @Damian-Nordic or @kkasperczyk-no are you able to take a peek at this, or maybe @andy31415 ?

@Damian-Nordic
Copy link
Contributor

If you get "Timed out waiting on server response" error, it's worth checking OTBR logs as well. In our testing we only encountered "Parsing operation failed" error when sending big SRP updates. #19803, merged yesterday, should reduce the size of our SRP updates, and openthread/openthread#7776 in OpenThread should help process big SRP updates anyway.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

6 participants