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.

Sign up for GitHub

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

Jump to bottom

minmdns fails to discover devices during discovery #9099

Closed
mspang opened this issue Aug 18, 2021 · 1 comment · Fixed by #9102
Closed

minmdns fails to discover devices during discovery #9099

mspang opened this issue Aug 18, 2021 · 1 comment · Fixed by #9102
Assignees
@mspang

Comments

@mspang
Copy link
Contributor

mspang commented Aug 18, 2021

Problem

Commissioning thread devices that advertise via SRP+mdnsresponder is generally failing to resolve the device near the end of the commissioning flow if the querier is using the minimal mDNS implementation.

[1629250836.351033][8853:8853] CHIP:CTL: Read local id 0x000000000001B669, remote id 0x12BBCEA775C84516
[1629250836.353549][8853:8853] CHIP:CTL: Generating NOC
[1629250836.353880][8853:8853] CHIP:CTL: Generating ICAC
[1629250836.359712][8853:8853] CHIP:IN: UDP::Init bind&listen port=5541
[1629250836.359849][8853:8853] CHIP:IN: UDP::Init bind&listen port=5541
[1629250836.359947][8853:8853] CHIP:IN: TransportMgr initialized
[1629250836.359966][8853:8853] CHIP:DIS: Init fabric pairing table with server storage
[1629250836.361950][8853:8853] CHIP:DL: MDNS failed to join multicast group on wlan0 for address type IPv4: ../../src/inet/IPEndPointBasis.cpp:259: Inet Error 0x00000110: Address not found
[1629250836.363835][8853:8853] CHIP:DL: MDNS failed to join multicast group on wpan0 for address type IPv4: ../../src/inet/IPEndPointBasis.cpp:259: Inet Error 0x00000110: Address not found
[1629250836.363989][8853:8853] CHIP:ZCL: Using ZAP configuration...
[1629250836.364082][8853:8853] CHIP:ZCL: deactivate report event
[1629250836.364806][8853:8853] CHIP:DIS: Added new fabric at index: 1, Initialized: 1
[1629250836.364835][8853:8853] CHIP:DIS: Assigned fabric ID: 0x0000000000000000, node ID: 0x000000000001B669
[1629250836.364851][8853:8853] CHIP:CTL: Joined new fabric at index 1
[1629250836.365432][8853:8861] CHIP:DL: CHIP task running
[1629250836.365761][8853:8861] CHIP:CTL: Generated random node id: 0xC1119283526E614C
[1629250836.366741][8853:8861] CHIP:SC: Assigned local session key ID 3
[1629250836.366847][8853:8861] CHIP:IN: Message appended to BLE send queue
[1629250836.366871][8853:8861] CHIP:SC: Sent PBKDF param request
[1629250836.369717][8853:8862] CHIP:DL: TRACE: Bluez mainloop starting Thread
[1629250836.369847][8853:8857] CHIP:DL: TRACE: Bus acquired for name C-2295
[1629250836.380644][8853:8861] CHIP:DL: PlatformBlueZInit init success
[1629250836.388263][8853:8857] CHIP:BLE: BLE removing known devices.
[1629250836.388332][8853:8857] CHIP:BLE: BLE initiating scan.
[1629250836.771435][8853:8857] CHIP:BLE: New device scanned: DB:A7:ED:8B:6B:3B
[1629250836.771493][8853:8857] CHIP:BLE: Device discriminator match. Attempting to connect.
[1629250836.775109][8853:8857] CHIP:BLE: Scan complete notification without an active scan.
[1629250836.963918][8853:8857] CHIP:DL: ConnectDevice complete
[1629250838.524095][8853:8857] CHIP:DL: Char1 /org/bluez/hci0/dev_DB_A7_ED_8B_6B_3B/service0010
[1629250838.524146][8853:8857] CHIP:DL: Char1 /org/bluez/hci0/dev_DB_A7_ED_8B_6B_3B/service0010
[1629250838.524170][8853:8857] CHIP:DL: Char1 /org/bluez/hci0/dev_DB_A7_ED_8B_6B_3B/service0010
[1629250838.524183][8853:8857] CHIP:DL: Char1 /org/bluez/hci0/dev_DB_A7_ED_8B_6B_3B/service0010
[1629250838.524204][8853:8857] CHIP:DL: Char1 /org/bluez/hci0/dev_DB_A7_ED_8B_6B_3B/service0010
[1629250838.524217][8853:8857] CHIP:DL: Char1 /org/bluez/hci0/dev_DB_A7_ED_8B_6B_3B/service0010
[1629250838.524238][8853:8857] CHIP:DL: New BLE connection 0xffffb0036fe0, device DB:A7:ED:8B:6B:3B, path /org/bluez/hci0/dev_DB_A7_ED_8B_6B_3B
[1629250838.524352][8853:8861] CHIP:DL: HandlePlatformSpecificBLEEvent 16385
[1629250838.524386][8853:8861] CHIP:IN: BleConnectionComplete: endPoint 0xaaaab3a7aa88
[1629250839.058922][8853:8861] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1629250839.156753][8853:8861] CHIP:DL: HandlePlatformSpecificBLEEvent 16388
[1629250839.156813][8853:8861] CHIP:BLE: subscribe complete, ep = 0xaaaab3a7aa88
[1629250839.157191][8853:8857] CHIP:DL: Indication received, conn = 0xffffb0036fe0
[1629250839.157369][8853:8861] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1629250839.157515][8853:8861] CHIP:BLE: peripheral chose BTP version 3; central expected between 2 and 3
[1629250839.157549][8853:8861] CHIP:BLE: using BTP fragment sizes rx 20 / tx 20.
[1629250839.157573][8853:8861] CHIP:BLE: local and remote recv window size = 3
[1629250839.157774][8853:8861] CHIP:IN: BLE EndPoint 0xaaaab3a7aa88 Connection Complete
<snip BLE spew>
[1629250840.132239][8853:8861] CHIP:EM: Received message of type 0x21 with vendorId 0x0000 and protocolId 0x0000 on exchange 39017
[1629250840.132332][8853:8861] CHIP:SC: Received PBKDF param response
[1629250840.135497][8853:8861] CHIP:SC: Sent spake2p msg1
<snip BLE spew>
[1629250841.497207][8853:8861] CHIP:EM: Received message of type 0x23 with vendorId 0x0000 and protocolId 0x0000 on exchange 39017
[1629250841.497297][8853:8861] CHIP:SC: Received spake2p msg2
[1629250841.497332][8853:8861] CHIP:SC: Peer assigned session key ID 0
[1629250841.500363][8853:8861] CHIP:SC: Sent spake2p msg3
[1629250841.500439][8853:8861] CHIP:IN: New secure session created for device 0xC1119283526E614C, key 0!!
[1629250841.500545][8853:8861] CHIP:CTL: Remote device completed SPAKE2+ handshake
[1629250841.500578][8853:8861] CHIP:CTL: Sending OpCSR request to 0xffffee0b9868 device
[1629250841.500685][8853:8861] CHIP:DMG: ICR moving to [Initialize]
[1629250841.500741][8853:8861] CHIP:DMG: ICR moving to [AddCommand]
[1629250841.500868][8853:8861] CHIP:IN: Secure message was encrypted: Msg ID 0
[1629250841.500913][8853:8861] CHIP:IN: Encrypted message 0xffffabffd738 to 0xC1119283526E614C of type 8 and protocolId 5 on exchange 39018.
[1629250841.500953][8853:8861] CHIP:IN: Sending msg 0xffffabffd738 to 0xC1119283526E614C at utc time: 11615742 msec
[1629250841.500983][8853:8861] CHIP:IN: Sending secure msg on generic transport
[1629250841.501019][8853:8861] CHIP:IN: Secure msg send status ../../src/transport/raw/BLE.cpp:104: Success
[1629250841.501053][8853:8861] CHIP:DMG: ICR moving to [   Sending]
[1629250841.501084][8853:8861] CHIP:CTL: Sent OpCSR request, waiting for the CSR
<snip BLE spew>
[1629250844.417510][8853:8861] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0005 on exchange 39018
[1629250844.417620][8853:8861] CHIP:DMG: InvokeCommand =
[1629250844.417660][8853:8861] CHIP:DMG: {
[1629250844.417694][8853:8861] CHIP:DMG: 	CommandList =
[1629250844.417727][8853:8861] CHIP:DMG: 	[
[1629250844.417763][8853:8861] CHIP:DMG: 		CommandDataElement =
[1629250844.417796][8853:8861] CHIP:DMG: 		{
[1629250844.417825][8853:8861] CHIP:DMG: 			CommandPath =
[1629250844.417950][8853:8861] CHIP:DMG: 			{
[1629250844.417994][8853:8861] CHIP:DMG: 				EndpointId = 0x0,
[1629250844.418026][8853:8861] CHIP:DMG: 				ClusterId = 0x3e,
[1629250844.418058][8853:8861] CHIP:DMG: 				CommandId = 0x5,
[1629250844.418089][8853:8861] CHIP:DMG: 			},
[1629250844.418128][8853:8861] CHIP:DMG: 			
[1629250844.418157][8853:8861] CHIP:DMG: 			CommandData = 
[1629250844.418237][8853:8861] CHIP:DMG: 			{
[1629250844.418271][8853:8861] CHIP:DMG: 				0x0 = [
[1629250844.418352][8853:8861] CHIP:DMG: 					0x15, 0x30, 0x1, 0xcc, 0x30, 0x81, 0xc9, 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,
[1629250844.418389][8853:8861] CHIP:DMG: 			]
[1629250844.418420][8853:8861] CHIP:DMG: 				0x1 = [
[1629250844.418448][8853:8861] CHIP:DMG: 					
[1629250844.418478][8853:8861] CHIP:DMG: 			]
[1629250844.418509][8853:8861] CHIP:DMG: 			},
[1629250844.418537][8853:8861] CHIP:DMG: 		},
[1629250844.418579][8853:8861] CHIP:DMG: 		
[1629250844.418607][8853:8861] CHIP:DMG: 	],
[1629250844.418653][8853:8861] CHIP:DMG: 	
[1629250844.418681][8853:8861] CHIP:DMG: }
[1629250844.418761][8853:8861] CHIP:ZCL: Received Cluster Command: Cluster=3e Command=5 Endpoint=0
[1629250844.418871][8853:8861] CHIP:ZCL: OpCSRResponse:
[1629250844.418902][8853:8861] CHIP:ZCL:   NOCSRElements: 253
[1629250844.418928][8853:8861] CHIP:ZCL:   AttestationSignature: 0
[1629250844.418960][8853:8861] CHIP:CTL: Received certificate signing request from the device
[1629250844.418995][8853:8861] CHIP:CTL: Getting certificate chain for the device from the issuer
[1629250844.419023][8853:8861] CHIP:CTL: Verifying Certificate Signing Request
[1629250844.421079][8853:8861] CHIP:CTL: Generating NOC
[1629250844.421801][8853:8861] CHIP:CTL: Generating ICAC
[1629250844.422589][8853:8861] CHIP:CTL: Providing certificate chain to the commissioner
[1629250844.422653][8853:8861] CHIP:CTL: Received callback from the CA for NOC Chain generation. Status ../../src/controller/ExampleOperationalCredentialsIssuer.cpp:182: Success
[1629250844.422850][8853:8861] CHIP:CTL: Sending root certificate to the device
[1629250844.422934][8853:8861] CHIP:DMG: ICR moving to [Initialize]
[1629250844.422992][8853:8861] CHIP:DMG: ICR moving to [AddCommand]
[1629250844.423159][8853:8861] CHIP:IN: Secure message was encrypted: Msg ID 1
[1629250844.423289][8853:8861] CHIP:IN: Encrypted message 0xffffabffced8 to 0xC1119283526E614C of type 8 and protocolId 5 on exchange 39019.
[1629250844.423403][8853:8861] CHIP:IN: Sending msg 0xffffabffced8 to 0xC1119283526E614C at utc time: 11618665 msec
[1629250844.423438][8853:8861] CHIP:IN: Sending secure msg on generic transport
[1629250844.423646][8853:8861] CHIP:IN: Secure msg send status ../../src/transport/raw/BLE.cpp:104: Success
[1629250844.423700][8853:8861] CHIP:DMG: ICR moving to [   Sending]
[1629250844.423736][8853:8861] CHIP:CTL: Sent root certificate to the device
[1629250844.424129][8853:8861] CHIP:DMG: ICR moving to [Uninitiali]
<snip BLE spew>
[1629250846.464991][8853:8861] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0005 on exchange 39019
[1629250846.465117][8853:8861] CHIP:DMG: InvokeCommand =
[1629250846.465156][8853:8861] CHIP:DMG: {
[1629250846.465186][8853:8861] CHIP:DMG: 	CommandList =
[1629250846.465221][8853:8861] CHIP:DMG: 	[
[1629250846.465249][8853:8861] CHIP:DMG: 		CommandDataElement =
[1629250846.465281][8853:8861] CHIP:DMG: 		{
[1629250846.465313][8853:8861] CHIP:DMG: 			CommandPath =
[1629250846.465344][8853:8861] CHIP:DMG: 			{
[1629250846.465376][8853:8861] CHIP:DMG: 				EndpointId = 0x0,
[1629250846.465417][8853:8861] CHIP:DMG: 				ClusterId = 0x3e,
[1629250846.465518][8853:8861] CHIP:DMG: 				CommandId = 0xb,
[1629250846.465551][8853:8861] CHIP:DMG: 			},
[1629250846.465596][8853:8861] CHIP:DMG: 			
[1629250846.465625][8853:8861] CHIP:DMG: 			StatusElement =
[1629250846.465655][8853:8861] CHIP:DMG: 			{
[1629250846.465685][8853:8861] CHIP:DMG: 				GeneralCode = 0x0,
[1629250846.465715][8853:8861] CHIP:DMG: 				ProtocolId = 0x5,
[1629250846.465744][8853:8861] CHIP:DMG: 				protocolCode = 0x0,
[1629250846.465846][8853:8861] CHIP:DMG: 			},
[1629250846.465920][8853:8861] CHIP:DMG: 			
[1629250846.465958][8853:8861] CHIP:DMG: 		},
[1629250846.466026][8853:8861] CHIP:DMG: 		
[1629250846.466238][8853:8861] CHIP:DMG: 	],
[1629250846.466409][8853:8861] CHIP:DMG: 	
[1629250846.466440][8853:8861] CHIP:DMG: }
[1629250846.466515][8853:8861] CHIP:ZCL: DefaultResponse:
[1629250846.466719][8853:8861] CHIP:ZCL:   Transaction: 0xaaaab3a78308
[1629250846.466749][8853:8861] CHIP:ZCL:   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1629250846.466787][8853:8861] CHIP:CTL: Device confirmed that it has received the root certificate
[1629250846.466814][8853:8861] CHIP:CTL: Sending operational certificate chain to the device
[1629250846.466872][8853:8861] CHIP:DMG: ICR moving to [Initialize]
[1629250846.466938][8853:8861] CHIP:DMG: ICR moving to [AddCommand]
[1629250846.467201][8853:8861] CHIP:IN: Secure message was encrypted: Msg ID 2
[1629250846.467259][8853:8861] CHIP:IN: Encrypted message 0xffffabffd348 to 0xC1119283526E614C of type 8 and protocolId 5 on exchange 39020.
[1629250846.467302][8853:8861] CHIP:IN: Sending msg 0xffffabffd348 to 0xC1119283526E614C at utc time: 11620709 msec
[1629250846.467386][8853:8861] CHIP:IN: Sending secure msg on generic transport
[1629250846.467630][8853:8861] CHIP:IN: Secure msg send status ../../src/transport/raw/BLE.cpp:104: Success
[1629250846.467882][8853:8861] CHIP:DMG: ICR moving to [   Sending]
[1629250846.468109][8853:8861] CHIP:CTL: Sent operational certificate to the device
[1629250846.468369][8853:8861] CHIP:DMG: ICR moving to [Uninitiali]
<snip BLE spew>
[1629250850.170048][8853:8861] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0005 on exchange 39020
[1629250850.170208][8853:8861] CHIP:DMG: InvokeCommand =
[1629250850.170255][8853:8861] CHIP:DMG: {
[1629250850.170285][8853:8861] CHIP:DMG: 	CommandList =
[1629250850.170317][8853:8861] CHIP:DMG: 	[
[1629250850.170345][8853:8861] CHIP:DMG: 		CommandDataElement =
[1629250850.170381][8853:8861] CHIP:DMG: 		{
[1629250850.170411][8853:8861] CHIP:DMG: 			CommandPath =
[1629250850.170442][8853:8861] CHIP:DMG: 			{
[1629250850.170474][8853:8861] CHIP:DMG: 				EndpointId = 0x0,
[1629250850.170507][8853:8861] CHIP:DMG: 				ClusterId = 0x3e,
[1629250850.170543][8853:8861] CHIP:DMG: 				CommandId = 0x8,
[1629250850.170571][8853:8861] CHIP:DMG: 			},
[1629250850.170608][8853:8861] CHIP:DMG: 			
[1629250850.170637][8853:8861] CHIP:DMG: 			CommandData = 
[1629250850.170668][8853:8861] CHIP:DMG: 			{
[1629250850.170703][8853:8861] CHIP:DMG: 				0x0 = 0, 
[1629250850.170738][8853:8861] CHIP:DMG: 				0x1 = 1, 
[1629250850.170770][8853:8861] CHIP:DMG: 				0x2 = [
[1629250850.170798][8853:8861] CHIP:DMG: 					
[1629250850.170828][8853:8861] CHIP:DMG: 			]
[1629250850.170859][8853:8861] CHIP:DMG: 			},
[1629250850.170890][8853:8861] CHIP:DMG: 		},
[1629250850.170933][8853:8861] CHIP:DMG: 		
[1629250850.170961][8853:8861] CHIP:DMG: 	],
[1629250850.171004][8853:8861] CHIP:DMG: 	
[1629250850.171031][8853:8861] CHIP:DMG: }
[1629250850.171113][8853:8861] CHIP:ZCL: Received Cluster Command: Cluster=3e Command=8 Endpoint=0
[1629250850.171158][8853:8861] CHIP:ZCL: NOCResponse:
[1629250850.171185][8853:8861] CHIP:ZCL:   StatusCode: 0
[1629250850.171211][8853:8861] CHIP:ZCL:   FabricIndex: 1
[1629250850.171237][8853:8861] CHIP:ZCL:   DebugText: 0
[1629250850.171269][8853:8861] CHIP:CTL: Device returned status 0 on receiving the NOC
[1629250850.171298][8853:8861] CHIP:CTL: Operational credentials provisioned on device 0xffffee0b9868
[1629250850.175856][8853:8861] CHIP:TOO: Secure Pairing Success
[1629250850.178070][8853:8861] CHIP:TOO: Pairing Success
[1629250850.178369][8853:8861] CHIP:DMG: ICR moving to [Initialize]
[1629250850.178452][8853:8861] CHIP:DMG: ICR moving to [AddCommand]
[1629250850.178536][8853:8861] CHIP:IN: Marking old secure session for device 0xC1119283526E614C as expired
[1629250850.178581][8853:8861] CHIP:CTL: OnConnectionExpired was called for unknown device, ignoring it.
[1629250850.178620][8853:8861] CHIP:IN: New secure session created for device 0xC1119283526E614C, key 0!!
[1629250850.178886][8853:8861] CHIP:IN: Secure message was encrypted: Msg ID 4
[1629250850.178936][8853:8861] CHIP:IN: Encrypted message 0xffffabffd098 to 0xC1119283526E614C of type 8 and protocolId 5 on exchange 39021.
[1629250850.178974][8853:8861] CHIP:IN: Sending msg 0xffffabffd098 to 0xC1119283526E614C at utc time: 11624420 msec
[1629250850.179010][8853:8861] CHIP:IN: Sending secure msg on generic transport
[1629250850.179164][8853:8861] CHIP:IN: Secure msg send status ../../src/transport/raw/BLE.cpp:104: Success
[1629250850.179184][8853:8861] CHIP:DMG: ICR moving to [   Sending]
[1629250850.179222][8853:8861] CHIP:DMG: ICR moving to [Uninitiali]
<snip BLE spew>
[1629250851.486460][8853:8861] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0005 on exchange 39021
[1629250851.486570][8853:8861] CHIP:DMG: InvokeCommand =
[1629250851.486610][8853:8861] CHIP:DMG: {
[1629250851.486643][8853:8861] CHIP:DMG: 	CommandList =
[1629250851.486676][8853:8861] CHIP:DMG: 	[
[1629250851.486705][8853:8861] CHIP:DMG: 		CommandDataElement =
[1629250851.486742][8853:8861] CHIP:DMG: 		{
[1629250851.486771][8853:8861] CHIP:DMG: 			CommandPath =
[1629250851.486802][8853:8861] CHIP:DMG: 			{
[1629250851.486839][8853:8861] CHIP:DMG: 				EndpointId = 0x0,
[1629250851.486872][8853:8861] CHIP:DMG: 				ClusterId = 0x31,
[1629250851.486902][8853:8861] CHIP:DMG: 				CommandId = 0x6,
[1629250851.486930][8853:8861] CHIP:DMG: 			},
[1629250851.486970][8853:8861] CHIP:DMG: 			
[1629250851.487003][8853:8861] CHIP:DMG: 			StatusElement =
[1629250851.487034][8853:8861] CHIP:DMG: 			{
[1629250851.487066][8853:8861] CHIP:DMG: 				GeneralCode = 0x0,
[1629250851.487096][8853:8861] CHIP:DMG: 				ProtocolId = 0x5,
[1629250851.487126][8853:8861] CHIP:DMG: 				protocolCode = 0x0,
[1629250851.487153][8853:8861] CHIP:DMG: 			},
[1629250851.487189][8853:8861] CHIP:DMG: 			
[1629250851.487221][8853:8861] CHIP:DMG: 		},
[1629250851.487262][8853:8861] CHIP:DMG: 		
[1629250851.487290][8853:8861] CHIP:DMG: 	],
[1629250851.487332][8853:8861] CHIP:DMG: 	
[1629250851.487359][8853:8861] CHIP:DMG: }
[1629250851.487433][8853:8861] CHIP:ZCL: DefaultResponse:
[1629250851.487461][8853:8861] CHIP:ZCL:   Transaction: 0xaaaab3a78308
[1629250851.487487][8853:8861] CHIP:ZCL:   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1629250851.487521][8853:8861] CHIP:TOO: AddNetworkResponse
[1629250851.487583][8853:8861] CHIP:DMG: ICR moving to [Initialize]
[1629250851.487644][8853:8861] CHIP:DMG: ICR moving to [AddCommand]
[1629250851.487763][8853:8861] CHIP:IN: Secure message was encrypted: Msg ID 5
[1629250851.487805][8853:8861] CHIP:IN: Encrypted message 0xffffabffd3b8 to 0xC1119283526E614C of type 8 and protocolId 5 on exchange 39022.
[1629250851.487847][8853:8861] CHIP:IN: Sending msg 0xffffabffd3b8 to 0xC1119283526E614C at utc time: 11625729 msec
[1629250851.487876][8853:8861] CHIP:IN: Sending secure msg on generic transport
[1629250851.488025][8853:8861] CHIP:IN: Secure msg send status ../../src/transport/raw/BLE.cpp:104: Success
[1629250851.488079][8853:8861] CHIP:DMG: ICR moving to [   Sending]
[1629250851.488138][8853:8861] CHIP:DMG: ICR moving to [Uninitiali]
<snip BLE event spew>
[1629250852.461192][8853:8861] CHIP:EM: Received message of type 0x09 with vendorId 0x0000 and protocolId 0x0005 on exchange 39022
[1629250852.461291][8853:8861] CHIP:DMG: InvokeCommand =
[1629250852.461330][8853:8861] CHIP:DMG: {
[1629250852.461369][8853:8861] CHIP:DMG: 	CommandList =
[1629250852.461402][8853:8861] CHIP:DMG: 	[
[1629250852.461431][8853:8861] CHIP:DMG: 		CommandDataElement =
[1629250852.461467][8853:8861] CHIP:DMG: 		{
[1629250852.461497][8853:8861] CHIP:DMG: 			CommandPath =
[1629250852.461529][8853:8861] CHIP:DMG: 			{
[1629250852.461561][8853:8861] CHIP:DMG: 				EndpointId = 0x0,
[1629250852.461597][8853:8861] CHIP:DMG: 				ClusterId = 0x31,
[1629250852.461628][8853:8861] CHIP:DMG: 				CommandId = 0xc,
[1629250852.461656][8853:8861] CHIP:DMG: 			},
[1629250852.461696][8853:8861] CHIP:DMG: 			
[1629250852.461725][8853:8861] CHIP:DMG: 			StatusElement =
[1629250852.461755][8853:8861] CHIP:DMG: 			{
[1629250852.461785][8853:8861] CHIP:DMG: 				GeneralCode = 0x0,
[1629250852.461811][8853:8861] CHIP:DMG: 				ProtocolId = 0x5,
[1629250852.461836][8853:8861] CHIP:DMG: 				protocolCode = 0x0,
[1629250852.461863][8853:8861] CHIP:DMG: 			},
[1629250852.461894][8853:8861] CHIP:DMG: 			
[1629250852.462017][8853:8861] CHIP:DMG: 		},
[1629250852.462057][8853:8861] CHIP:DMG: 		
[1629250852.462081][8853:8861] CHIP:DMG: 	],
[1629250852.462117][8853:8861] CHIP:DMG: 	
[1629250852.462141][8853:8861] CHIP:DMG: }
[1629250852.462245][8853:8861] CHIP:ZCL: DefaultResponse:
[1629250852.462272][8853:8861] CHIP:ZCL:   Transaction: 0xaaaab3a781a8
[1629250852.462295][8853:8861] CHIP:ZCL:   status: EMBER_ZCL_STATUS_SUCCESS (0x00)
[1629250852.462325][8853:8861] CHIP:TOO: EnableNetworkResponse
[1629250852.462348][8853:8861] CHIP:TOO: Mdns: Updating NodeId: c1119283526e614c FabricId: 1b669 ...
[1629250852.463295][8853:8861] CHIP:DIS: mDNS broadcast success
[1629250852.464099][8853:8861] CHIP:DIS: mDNS broadcast success
[1629250852.464852][8853:8861] CHIP:DIS: mDNS broadcast success
[1629250852.465125][8853:8861] CHIP:DIS: mDNS broadcast success
[1629250852.465442][8853:8861] CHIP:DIS: mDNS broadcast success
[1629250852.466230][8853:8861] CHIP:DIS: mDNS broadcast success
[1629250852.466324][8853:8861] CHIP:DMG: ICR moving to [Uninitiali]
<snip BLE spew>
[1629250956.365654][8853:8853] CHIP:TOO: No response from device
[1629250956.365754][8853:8853] CHIP:TOO: Run command failure: ../../examples/chip-tool/commands/common/Command.h:217: CHIP Error 0x000000AC: Internal error
[1629250956.366397][8853:8853] CHIP:CTL: Shutting down the commissioner
[1629250956.366475][8853:8853] CHIP:CTL: Shutting down the controller
[1629250956.368097][8853:8853] CHIP:DL: Inet Layer shutdown
[1629250956.368327][8853:8859] CHIP:IN: Async DNS worker thread woke up.
[1629250956.368406][8853:8859] CHIP:IN: Async DNS worker thread exiting.
[1629250956.368452][8853:8860] CHIP:IN: Async DNS worker thread woke up.
[1629250956.368499][8853:8860] CHIP:IN: Async DNS worker thread exiting.
[1629250956.369515][8853:8853] CHIP:DL: BLE layer shutdown
[1629250956.369580][8853:8853] CHIP:IN: Clearing BLE pending packets.
[1629250956.369708][8853:8853] CHIP:BLE: Auto-closing end point's BLE connection.
[1629250956.369744][8853:8853] CHIP:DL: Closing BLE GATT connection (con 0xffffb0036fe0)
[1629250956.369818][8853:8853] CHIP:DL: System Layer shutdown
[1629250956.370239][8853:8857] CHIP:DL: BluezDisconnect peer=DB:A7:ED:8B:6B:3B

The discovery failure occurs despite other mDNS implementations successfully processing the query response:

+   eno1 IPv4 0000000000000000-C1119283526E614C             _matter._tcp         local
+   eno1 IPv6 0000000000000000-C1119283526E614C             _matter._tcp         local
=   eno1 IPv4 0000000000000000-C1119283526E614C             _matter._tcp         local
   hostname = [9221D67D37FF55A4.local]
   address = [fd21:771d:e2ef:3593:b3b6:4a75:7bd8:55b5]
   port = [5540]
   txt = ["CRA=300" "CRI=300"]
=   eno1 IPv6 0000000000000000-C1119283526E614C             _matter._tcp         local
   hostname = [9221D67D37FF55A4.local]
   address = [fd21:771d:e2ef:3593:b3b6:4a75:7bd8:55b5]
   port = [5540]
   txt = ["CRA=300" "CRI=300"]
@mspang mspang mentioned this issue Aug 18, 2021
Merged
mspang added a commit to mspang/connectedhomeip that referenced this issue Aug 18, 2021
@mspang
Fix discovery issues with minimal mDNS
590b5d6 
- Don't skip the rest of the packet if it contains an irrelevant
  resource record. DNS packets can contain records other than
  those directly requested.

- Don't terminate chip-tool commissioning if a device other than
  the commissionee is discovered. There is nothing preventing
  receiving OnAddressUpdateComplete for stale records and this
  will generally happening when doing tests in quick succession
  because stale records accumulate in the SRP server.

fixes project-chip#9099
@mspang mspang mentioned this issue Aug 18, 2021
Merged
mspang added a commit to mspang/connectedhomeip that referenced this issue Aug 18, 2021
@mspang
Fix discovery issues with minimal mDNS
a8d6156 
- Don't skip the rest of the packet if it contains an irrelevant
  resource record. DNS packets can contain records other than
  those directly requested.

- Don't terminate chip-tool commissioning if a device other than
  the commissionee is discovered. There is nothing preventing
  receiving OnAddressUpdateComplete for stale records and this
  will generally happen when doing tests in quick succession
  because stale records accumulate in the SRP server.

fixes project-chip#9099
@mspang mspang self-assigned this Aug 18, 2021
mspang added a commit that referenced this issue Aug 20, 2021
@mspang
Fix discovery issues with minimal mDNS (#9102)
3b145cb 
- Don't skip the rest of the packet if it contains an irrelevant
  resource record. DNS packets can contain records other than
  those directly requested.

- Don't terminate chip-tool commissioning if a device other than
  the commissionee is discovered. There is nothing preventing
  receiving OnAddressUpdateComplete for stale records and this
  will generally happen when doing tests in quick succession
  because stale records accumulate in the SRP server.

fixes #9099
sharadb-amazon pushed a commit to sharadb-amazon/connectedhomeip that referenced this issue Aug 23, 2021
@mspang @sharadb-amazon
Fix discovery issues with minimal mDNS (project-chip#9102)
f9366c5 
- Don't skip the rest of the packet if it contains an irrelevant
  resource record. DNS packets can contain records other than
  those directly requested.

- Don't terminate chip-tool commissioning if a device other than
  the commissionee is discovered. There is nothing preventing
  receiving OnAddressUpdateComplete for stale records and this
  will generally happen when doing tests in quick succession
  because stale records accumulate in the SRP server.

fixes project-chip#9099
@saumildmehta
Copy link

Is this issue resolved?
I am still facing same error from latest code of master branch!

nikita-s-wrk pushed a commit to nikita-s-wrk/connectedhomeip that referenced this issue Sep 23, 2021
@mspang
Fix discovery issues with minimal mDNS (project-chip#9102)
78bf945 
- Don't skip the rest of the packet if it contains an irrelevant
  resource record. DNS packets can contain records other than
  those directly requested.

- Don't terminate chip-tool commissioning if a device other than
  the commissionee is discovered. There is nothing preventing
  receiving OnAddressUpdateComplete for stale records and this
  will generally happen when doing tests in quick succession
  because stale records accumulate in the SRP server.

fixes project-chip#9099
@JasonHu1 JasonHu1 mentioned this issue Sep 26, 2021
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@mspang mspang

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix discovery issues with minimal mDNS mspang/connectedhomeip
2 participants
@mspang @saumildmehta