mDNS advertising fails with error 3 on esp32c6 light example (Thread) (MEGH-7115)

[crivi30]

Answers checklist.

• I have read the Rainmaker documentation and the issue is not addressed there.
• I have updated my IDF branch (release/vX.Y) to the latest version and checked that the issue is present there. This is not applicable if you are using Rainmaker with Arduino.
• I have searched the Rainmaker forum and issue tracker for a similar issue and not found a similar issue.

General issue report

I am attempting to run and commission the matter_light example over Thread on an ESP32-C6. I have a border router (esp32s3+h2) that is already configured, commissioned and running.

During the commissioning process with the ESP RainMaker Android app, the app successfully retrieves the Thread credentials from the border router and sends them to the light example. The device log shows that it joins the Thread network as a leader. However, immediately after, I encounter an error indicating that the device cannot advertise itself via mDNS. The error is Operational advertising failed: 3. The app cannot find the device in the wifi network, so it hangs until the fail safe expire.
(Note: i have the same issue with the esp-matter example light with thread )

I am using the default Thread configuration provided with the example and have not made any changes.

Questions:

1. Has anyone been able to successfully run this example with the Thread version on an ESP32-C6?
2. Is there a known issue with the current main branch of esp-matter and ESP-IDF v5.5 that could be causing this?

Environment:

• ESP-IDF: v5.5
• ESP-Matter: main branch (latest pull)
• ESP-RainMaker: main branch (latest pull)
• Hardware: ESP32-C6 for the matter_light example, ESP32-S3+H2 for the border router.

I would appreciate it if someone could provide some guidance.

I attach the most important part of the log where the error is visible:

I (1297) chip[ZCL]: Initiating Admin Commissioning cluster.
I (1307) chip[DIS]: Updating services using commissioning mode 1
E (1307) chip[DIS]: Failed to remove advertised services: 3
I (1307) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=0882/03 cm=1 cp=0
E (1317) chip[DIS]: Failed to advertise commissionable node: 3
E (1327) chip[DIS]: Failed to finalize service update: 3

...

I (43447) chip[SVR]: Commissioning completed session establishment step
I (43467) chip[DIS]: Updating services using commissioning mode 0
E (43467) chip[DIS]: Failed to remove advertised services: 3
I (43477) chip[DIS]: Advertise commission parameter vendorID=65521 productID=32768 discriminator=0882/03 cm=0 cp=0
E (43487) chip[DIS]: Failed to advertise extended commissionable node: 3
E (43487) chip[DIS]: Failed to finalize service update: 3
I (43497) chip[SVR]: Device completed Rendezvous process

...

I(71967) OPENTHREAD:[N] Mle-----------: Role disabled -> detached
I (71967) chip[DL]: Posting ESPSystemEvent: IP Event with eventId : 3
I (71967) chip[DL]: Posting ESPSystemEvent: IP Event with eventId : 3
I (71977) chip[DL]: Posting ESPSystemEvent: IP Event with eventId : 3
I (71987) chip[DL]: Posting ESPSystemEvent: IP Event with eventId : 3
I (71987) OT_STATE: netif up
I (71987) chip[DL]: Updating advertising data
I(72557) OPENTHREAD:[N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset
I (74437) NimBLE: GATT procedure initiated: indicate; 
I (74437) NimBLE: att_handle=18
I (74537) chip[DL]: Confirm received for CHIPoBLE TX characteristic indication (con 0) status= 14 
I (77017) CHIP[DL]: Write request received for CHIPoBLE RX characteristic con 0 16
I(79167) OPENTHREAD:[N] RouterTable---: Allocate router id 51
I(79167) OPENTHREAD:[N] Mle-----------: RLOC16 fffe -> cc00
I(79177) OPENTHREAD:[N] Mle-----------: Role detached -> leader
I(79177) OPENTHREAD:[N] Mle-----------: Partition ID 0x36cde1ba
I (79227) esp_matter_attribute: ********** R : Endpoint 0x0000's Cluster 0x00000030's Attribute 0x00000000 is 1 **********
I (79227) chip[EM]: <<< [E:48648r S:51812 M:170473744] (S) Msg TX from 0000000000000000 to 1:FFFFFFFB00000000 [52F1] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:65)
I (79247) NimBLE: GATT procedure initiated: indicate; 
I (79247) NimBLE: att_handle=18
I (79247) chip[DIS]: Advertise operational node 2972426A648952F1-4CB88576965A8D27
E (79257) chip[SVR]: Operational advertising failed: 3

[wqx6]

Looks like your Thread Border Router is not set up successfully. If you have already setup the Thread Border Router, the TBR will become the leader and then the light will become child or router after it joins the Thread network. Which Thread Border Router example are you using?

[crivi30]

I'm following the example from esp-rainmaker/examples/matter/matter_controller with sdkconfig.defaults.otbr

[wqx6]

@crivi30 Then could you also share the logs from the TBR under this issue?

[crivi30]

Hi @wqx6,

You were right, the issue seems to be within the OTBR. I'm encountering a DNS resolution error when the device tries to connect to the AWS IoT endpoint.

Here is the specific error from the log:

I (902904) chip[DIS]: Advertise operational node 2972426A648952F1-F3881D62C4E7212A
I (902904) chip[DIS]: Advertise operational node B162758A55DD268F-444B87F2643284CB
E (902914) mdns: mdns_service_remove_for_host(6677): Service doesn't exist

and

I (1789) esp_mqtt_glue: Connecting to a1p72mufdu6064-ats.iot.us-east-1.amazonaws.com
I (1789) esp_rmaker_core: Waiting for MQTT connection
E (1789) esp-tls: couldn't get hostname for :a1p72mufdu6064-ats.iot.us-east-1.amazonaws.com: getaddrinfo() returns 202, addrinfo=0x0
E (1789) esp-tls: Failed to open new connection
E (1789) transport_base: Failed to open a new connection
E (1789) mqtt_client: Error transport connect
E (1799) esp_mqtt_glue: MQTT_EVENT_ERROR

if I run the same controller example without Thread enabled, it works seamlessly. The problem only appears when the OTBR stack is active.

I will attach the full log for more context:

log.txt

I would appreciate any hints on how to debug this.

Thanks in advance.

[crivi30]

Update

I (1789) esp_mqtt_glue: Connecting to a1p72mufdu6064-ats.iot.us-east-1.amazonaws.com
I (1789) esp_rmaker_core: Waiting for MQTT connection
E (1789) esp-tls: couldn't get hostname for :a1p72mufdu6064-ats.iot.us-east-1.amazonaws.com: getaddrinfo() returns 202, addrinfo=0x0
E (1789) esp-tls: Failed to open new connection
E (1789) transport_base: Failed to open a new connection
E (1789) mqtt_client: Error transport connect
E (1799) esp_mqtt_glue: MQTT_EVENT_ERROR

This error (getaddrinfo() returns 202) was a "race condition": The esp_rmaker_start() function called in app_main() of the example, attempted to connect to the AWS MQTT broker before the Wi-Fi interface had successfully received an IP address and DNS server from the router.

The fix was to move the network-dependent service (esp_rmaker_start()) into the app_event_cb function, inside the IP_EVENT_STA_GOT_IP event case. In this way, the device only attempts to connect to the cloud after the network is fully initialized.

while

I (902904) chip[DIS]: Advertise operational node 2972426A648952F1-F3881D62C4E7212A
I (902904) chip[DIS]: Advertise operational node B162758A55DD268F-444B87F2643284CB
E (902914) mdns: mdns_service_remove_for_host(6677): Service doesn't exist

I checked with avahi-browse -r -t _matter._tcp and concluding that can be ignore given the fact that doesn't affect the advertisment

Next step

I fixed my commissioning issue by pressing the "Set up thread border router" button in the rmaker app, which successfully initiated the Thread network setup of the OTBR. The device commissioning is now successful, but the ESP32-C6 remains only locally reachable. How to allow the ESP32-C6 to be seen online and enable the remote control?

From the OBTR i can see is successfully connected:

| ID | RLOC16 | Next Hop | Path Cost | LQ In | LQ Out | Age | Extended MAC     | Link |
+----+--------+----------+-----------+-------+--------+-----+------------------+------+
| 44 | 0xb000 |       63 |         0 |     0 |      0 |   0 | b62da1588a4e1864 |    0 |
| 49 | 0xc400 |       63 |         0 |     3 |      3 |   0 | 2ae49b35f1d7b8bd |    1 |

But then, the esp32c6 device try to use mqtt to reach the rmaker cloud failing:

I (3701) esp_mqtt_glue: Connecting to a1p72mufdu6064-ats.iot.us-east-1.amazonaws.com
I (3711) esp_rmaker_core: Waiting for MQTT connection
E (10711) esp-tls: couldn't get hostname for :a1p72mufdu6064-ats.iot.us-east-1.amazonaws.com: getaddrinfo() returns 202, addrinfo=0x0
E (10711) esp-tls: Failed to open new connection
E (10711) transport_base: Failed to open a new connection
E (10721) mqtt_client: Error transport connect
E (10721) esp_mqtt_glue: MQTT_EVENT_ERROR

And here is the OBTR cli:

> matter esp ot_cli ping 8.8.8.8

Done
Pinging synthesized IPv6 address: fd1b:fe:cac9:2:0:0:808:808
> 1 packets transmitted, 0 packets received. Packet loss = 100.0%.

Thanks