[1.1] NotifyUpdateApplied not sent due to failed "ConnectToProvider"

[eme-bennytang]

Reproduction steps

1. Trigger OTA by chip-tool
2. Wait until finish
3. Wait after device reboot
4. No NotifyUpdateApplied is sent

Bug prevalence

Depend on router

GitHub hash of the SDK that was being used

83f4163

Platform

esp32

Platform Version(s)

1.1

Type

Spec Compliance Issue

Anything else?

This issue seems to be repeatable on certain router, but I have got the success log / fail log anyway in below.

This occurs when I trigger an OTA by chip-tool, and upon finish, the device will apply the OTA and when it reboot it should connect back to network (and provider) then send out the NotifyUpdateApplied.

But for some reason (I guess timing difference due to different router), the device is just reporting failed to connect in the log but have no retry.

I did some digging on the github and I think there are some related issues but no further follow up:
#19192
#25570

My connectedhomeip SDK commit ID:
83f4163

Success and failed logs by different router
HP3 Fail log
ORBI10 success log

[bzbarsky-apple]

So looking at the failure log, here are the relevant bits, in order:

I (2675) chip[DL]: IP_EVENT_GOT_IP6
I (2676) chip[DL]: IPv6 addr available. Ready on WIFI_STA_DEF interface: fe80:0000:0000:0000:3685:18ff:fe97:955c
I (2677) MatterEvent: IP_EVENT_GOT_IP6
...
I (4988) chip[EM]: <<< [E:29627i S:0 M:67062224] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
I (4989) chip[IN]: (U) Sending msg 67062224 to IP address 'UDP:[FD9A:7660:9E8F:3327:BE9B:B56B:E1D2:E8B3]:5540'
E (4991) chip[SWU]: Failed to connect to node 0x0000000000002345: 3000004
...
I (7675) chip[DL]: IP_EVENT_GOT_IP6
I (7676) chip[DL]: IPv6 addr available. Ready on WIFI_STA_DEF interface: fd9a:7660:9e8f:3327:3685:18ff:fe97:955c
I (7677) MatterEvent: IP_EVENT_GOT_IP6

So we had a link-local IP, we tried to send a message to FD9A:7660:9E8F:3327:BE9B:B56B:E1D2:E8B3 and that failed: 3000004 is an LwIP error, and specifically ERR_RTE ("Routing problem.").

Then we got out non-link-local IP, but it was too late by then.

In the success log, our IP is fe80:0000:0000:0000:3685:18ff:fe97:955c, we are sending to FE80::3429:F19C:7B30:3B0E%st1, so everything is link-local and things work fine.

I wonder whether we can somehow detect the "we are not actually fully on the network" situation somehow. Alternately, in the failing case we resolved these IPs:

I (4781) chip[DIS]: UDP:[FD9A:7660:9E8F:3327:BE9B:B56B:E1D2:E8B3%st1]:5540: new best score: 4
I (4782) chip[DIS]: UDP:[FD9A:7660:9E8F:3327:394C:3EE1:F9F6:A0E7%st1]:5540: score has not improved: 4
I (4783) chip[DIS]: UDP:[FE80::785F:65AD:E457:2883%st1]:5540: score has not improved: 3
I (4783) chip[DIS]: UDP:10.10.1.254%st1:5540: score has not improved: 2

I think the logic on tip for prioritizing these has changed, but the SHA linked is from before that change.

@eme-bennytang Does applying the change from #27981 to the device in question help?

[eme-bennytang]

Hi @bzbarsky-apple

Thanks for the quick comment.
I didnt realize the change from #27981 is not applied in my version of the SDK. (In fact I missed the change too)

I will try to patch the change manually and see if that fix the problem.

[eme-bennytang]

Coming back to close this issue, this works brilliantly, thanks.