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

Upgrading from ESP-IDF 5.1 to 5.3; breaking changes? (TZ-1396) #112

Open
3 tasks done
motters opened this issue Dec 17, 2024 · 11 comments
Open
3 tasks done

Upgrading from ESP-IDF 5.1 to 5.3; breaking changes? (TZ-1396) #112

motters opened this issue Dec 17, 2024 · 11 comments

Comments

@motters
Copy link

motters commented Dec 17, 2024

Checklist

  • Checked the issue tracker for similar issues to ensure this is not a duplicate.
  • Provided a clear description of your suggestion.
  • Included any relevant context or examples.

Issue or Suggestion Description

Hi,

Summary

Are there any API changes that could break routing data from the NAT to the backbone when migrating from IDF 5.1 to 5.3?

Details

We were having issues with the ESP BR crashing during high bursts of data, (https://github.com/orgs/openthread/discussions/11038). @chshu suggested we upgraded to IDF 5.3 which fixed a bug around this issue.

We have updated ESP-IDF to 5.3 and everything is working, except the BR is not passing requests from the NAT to the backbone.

For example, when a node tries to perform a DNS request using the BR's NAT, there is no reply. Below shows the BR log where fd6e:266c:4da0:1:7d59:1874:de24:c55e is the node.

I(727307) OPENTHREAD:[I] MeshForwarder-: Received IPv6 UDP msg, len:94, chksum:6b09, ecn:no, from:0x5c00, sec:yes, prio:normal, rss:-45.0
I(727320) OPENTHREAD:[I] MeshForwarder-:     src:[fd6e:266c:4da0:1:7d59:1874:de24:c55e]:41620
I(727322) OPENTHREAD:[I] MeshForwarder-:     dst:[fd6e:266c:4da0:2:0:0:808:808]:53
I(727338) OPENTHREAD:[I] Mac-----------: Frame rx failed, error:Duplicated, len:101, seqnum:227, type:Data, src:0x5c00, dst:0x3c00, sec:yes, ackreq:yes
I(727354) OPENTHREAD:[I] MeshForwarder-: Sent IPv6 UDP msg, len:199, chksum:fe68, ecn:no, to:0xffff, sec:yes, prio:net
I(727357) OPENTHREAD:[I] MeshForwarder-:     src:[fe80:0:0:0:2c81:3eaf:10a9:1e40]:19788
I(727369) OPENTHREAD:[I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
I(727408) OPENTHREAD:[I] MeshForwarder-: Received IPv6 UDP msg, len:199, chksum:1aea, ecn:no, from:42e2345cff43d991, sec:yes, prio:net, rss:-45.5
I(727421) OPENTHREAD:[I] MeshForwarder-:     src:[fe80:0:0:0:40e2:345c:ff43:d991]:19788
I(727423) OPENTHREAD:[I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
I(727436) OPENTHREAD:[I] Mle-----------: Receive Data Response (fe80:0:0:0:40e2:345c:ff43:d991)
I(728184) OPENTHREAD:[I] RoutingManager: Evaluating routing policy
I(728186) OPENTHREAD:[I] RoutingManager: Evaluating NAT64 prefix
I(728188) OPENTHREAD:[I] RoutingManager: Preparing RA
I(728199) OPENTHREAD:[I] RoutingManager: - RA Header - flags - M:0 O:0 S:1
I(728210) OPENTHREAD:[I] RoutingManager: - RA Header - default route - lifetime:0
I(728220) OPENTHREAD:[I] RoutingManager: - PIO fd00:0:0:0::/64 (valid:1800, preferred:1800)
I(728223) OPENTHREAD:[I] RoutingManager: - RIO fd6e:266c:4da0:1::/64 (lifetime:1800, prf:medium)
I(728237) OPENTHREAD:[I] RoutingManager: Sent RA on infra netif 2
I(728240) OPENTHREAD:[I] RoutingManager: Will evaluate routing policy in 03:02.308 (182308 msec)
I(728253) OPENTHREAD:[I] RoutingManager: Received RA from fe80:0:0:0:66b7:8ff:fe3d:d6ac on infra netif 2 (this BR routing-manager)
I(731700) OPENTHREAD:[I] Mle-----------: Send Advertisement (ff02:0:0:0:0:0:0:1)
I(731740) OPENTHREAD:[I] MeshForwarder-: Sent IPv6 UDP msg, len:91, chksum:d99d, ecn:no, to:0xffff, sec:no, prio:net
I(731742) OPENTHREAD:[I] MeshForwarder-:     src:[fe80:0:0:0:2c81:3eaf:10a9:1e40]:19788
I(731753) OPENTHREAD:[I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
I(741371) OPENTHREAD:[I] Mle-----------: Send Announce on channel 13
I(741399) OPENTHREAD:[I] MeshForwarder-: Sent IPv6 UDP msg, len:83, chksum:c9bf, ecn:no, to:0xffff, sec:yes, prio:net
I(741401) OPENTHREAD:[I] MeshForwarder-:     src:[fe80:0:0:0:2c81:3eaf:10a9:1e40]:19788
I(741413) OPENTHREAD:[I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
I(744228) OPENTHREAD:[I] Mle-----------: Send Advertisement (ff02:0:0:0:0:0:0:1)
I(744249) OPENTHREAD:[I] MeshForwarder-: Sent IPv6 UDP msg, len:91, chksum:d541, ecn:no, to:0xffff, sec:no, prio:net
I(744251) OPENTHREAD:[I] MeshForwarder-:     src:[fe80:0:0:0:2c81:3eaf:10a9:1e40]:19788
I(744263) OPENTHREAD:[I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
I(749409) OPENTHREAD:[I] MeshForwarder-: Received IPv6 UDP msg, len:91, chksum:382c, ecn:no, from:42e2345cff43d991, sec:no, prio:net, rss:-46.0

The BR can contact the node:

> ping fd6e:266c:4da0:1:7d59:1874:de24:c55e

I(868590) OPENTHREAD:[I] Icmp6---------: Sent echo request: (seq = 3)
I(868609) OPENTHREAD:[I] MeshForwarder-: Sent IPv6 ICMP6 msg, len:56, chksum:2217, ecn:no, to:0x5c00, sec:yes, prio:normal
I(868612) OPENTHREAD:[I] MeshForwarder-:     src:[fd6e:266c:4da0:1:167e:fa1f:76f2:7ec7]
I(868624) OPENTHREAD:[I] MeshForwarder-:     dst:[fd6e:266c:4da0:1:7d59:1874:de24:c55e]
I(868645) OPENTHREAD:[I] MeshForwarder-: Received IPv6 ICMP6 msg, len:56, chksum:2117, ecn:no, from:0x5c00, sec:yes, prio:normal, rss:-43.0
I(868658) OPENTHREAD:[I] MeshForwarder-:     src:[fd6e:266c:4da0:1:7d59:1874:de24:c55e]
I(868660) OPENTHREAD:[I] MeshForwarder-:     dst:[fd6e:266c:4da0:1:167e:fa1f:76f2:7ec7]
16 bytes from fd6e:266c:4da0:1:7d59:1874:de24:c55e: icmp_seq=3 hlim=64 time=85ms
1 packets transmitted, 1 packets received. Packet loss = 0.0%. Round-trip min/avg/max = 85/85.0/85 ms.

The BR's NAT is active:

> nat64 state

PrefixManager: Active
Done

The BR has an internet connection as we are running other libraries that use the same network. However OT cannot ping any external ip addresses:

> ping 8.8.8.8

Pinging synthesized IPv6 address: fd6e:266c:4da0:2:0:0:808:808
1 packets transmitted, 0 packets received. Packet loss = 100.0%.
Done

The BR's openthread stack can also not perform DNS requests

> dns resolve google.com 8.8.8.8

Synthesized IPv6 DNS server address: fd6e:266c:4da0:2:0:0:808:808
E (2195814) OPENTHREAD: Failed to Send UDP message, err: -12
E (2201814) OPENTHREAD: Failed to Send UDP message, err: -12
E (2207815) OPENTHREAD: Failed to Send UDP message, err: -12
DNS response for google.com. - 
Error 28: ResponseTimeout

The nodes use OT SRP and these services are registered to the building's router through the BR successfully. Hence proving the backbone is registered correctly. See the below output from a computer on the same network.

user@mac folder %  dns-sd -B _XXX._udp
Browsing for _XXX._udp
DATE: ---Tue 17 Dec 2024---
10:41:41.122  ...STARTING...
Timestamp     A/R    Flags  if Domain               Service Type         Instance Name
10:41:41.122  Add        2  11 local.               _XXX._udp.    f4ce36dc0e4c1111

Some BR logs that may help:

> bbr stateI

Primary
Done

> br state

running
Done

> netstat

| Local Address                                   | Peer Address                                    |
+-------------------------------------------------+-------------------------------------------------+
| [0:0:0:0:0:0:0:0]:1000                          | [0:0:0:0:0:0:0:0]:0                             |
| [0:0:0:0:0:0:0:0]:0                             | [0:0:0:0:0:0:0:0]:0                             |
| [0:0:0:0:0:0:0:0]:49156                         | [fda7:56f4:942:ab5e:4490:7063:15ef:77bf]:53549  |
| [0:0:0:0:0:0:0:0]:53549                         | [0:0:0:0:0:0:0:0]:0                             |
| [0:0:0:0:0:0:0:0]:49153                         | [0:0:0:0:0:0:0:0]:0                             |
| [0:0:0:0:0:0:0:0]:53                            | [0:0:0:0:0:0:0:0]:0                             |
| [0:0:0:0:0:0:0:0]:61631                         | [0:0:0:0:0:0:0:0]:0                             |
| [0:0:0:0:0:0:0:0]:19788                         | [0:0:0:0:0:0:0:0]:0                             |
| [0:0:0:0:0:0:0:0]:61631                         | [0:0:0:0:0:0:0:0]:0                             |
Done

> router table

| ID | RLOC16 | Next Hop | Path Cost | LQ In | LQ Out | Age | Extended MAC     | Link |
+----+--------+----------+-----------+-------+--------+-----+------------------+------+
| 15 | 0x3c00 |       63 |         0 |     0 |      0 |   0 | 0000000000000000 |    0 |
| 23 | 0x5c00 |       63 |         0 |     3 |      3 |   1 | 42e2345cff43d991 |    1 |

> netdata show

Prefixes:
fd6e:266c:4da0:1::/64 paos low 3c00
Routes:
fc00::/7 sa med 3c00
fd6e:266c:4da0:2:0:0::/96 sn low 3c00
Services:
44970 01 68000500000e10 s 3c00 0
44970 5d fda756f40942ab5e4490706315ef77bfd12d s 3c00 1
Contexts:
fd6e:266c:4da0:1::/64 1 c
Commissioning:
19608 3c00 - ff
Done

> domainname

DefaultDomain
Done

> ifconfig

up
Done

> ipaddr

fda7:56f4:942:ab5e:0:ff:fe00:fc30
fda7:56f4:942:ab5e:0:ff:fe00:fc11
fda7:56f4:942:ab5e:0:ff:fe00:fc38
fd6e:266c:4da0:1:167e:fa1f:76f2:7ec7
fda7:56f4:942:ab5e:0:ff:fe00:fc10
fda7:56f4:942:ab5e:0:ff:fe00:fc00
fda7:56f4:942:ab5e:0:ff:fe00:3c00
fda7:56f4:942:ab5e:4490:7063:15ef:77bf
fe80:0:0:0:2c81:3eaf:10a9:1e40
Done

> ipmaddr

ff33:40:fda7:56f4:942:ab5e:0:1
ff32:40:fda7:56f4:942:ab5e:0:1
ff02:0:0:0:0:0:0:2
ff03:0:0:0:0:0:0:2
ff02:0:0:0:0:0:0:1
ff03:0:0:0:0:0:0:1
ff03:0:0:0:0:0:0:fc
Done

> leaderdata

Partition ID: 1373084161
Weighting: 65
Data Version: 230
Stable Data Version: 103
Leader Router ID: 15
Done

Do you have any suggestion?

Thanks!

@github-actions github-actions bot changed the title Upgrading from ESP-IDF 5.1 to 5.3; breaking changes? Upgrading from ESP-IDF 5.1 to 5.3; breaking changes? (TZ-1396) Dec 17, 2024
@zwx1995esp
Copy link
Collaborator

Hi @motters did you use the tag: v5.3.2 for your test or could you please share the commit hash you used? I try to reproduce the issue you encountered but failed. All features related NAT64 works well on my side.

We found a problem on the tag v5.3.2 and we are investigating it these days.(There will be an error logs Failed to get LL address, error: Invalid If index during BR attaching and becoming router or leader. But even with this problem, I still can not reproduce the issues you encountered.)

So could you please try the code base metioned in the docs: https://docs.espressif.com/projects/esp-thread-br/en/latest/dev-guide/build_and_run.html#set-up-the-repositories and see if NAT64 works?

For the dns resolving command you metioned above:

The BR's openthread stack can also not perform DNS requests

> dns resolve google.com 8.8.8.8

Synthesized IPv6 DNS server address: fd6e:266c:4da0:2:0:0:808:808
E (2195814) OPENTHREAD: Failed to Send UDP message, err: -12
E (2201814) OPENTHREAD: Failed to Send UDP message, err: -12
E (2207815) OPENTHREAD: Failed to Send UDP message, err: -12
DNS response for google.com. - 
Error 28: ResponseTimeout

Did you execute the command on the BR device or on the node?

@motters
Copy link
Author

motters commented Dec 18, 2024

HI @zwx1995esp thanks for the reply. We have tried both 5.3.1 & 5.3.2 releases. I will try the commit mentioned in the documentation this morning.

All commands were executed from the BR, including dns resolve google.com 8.8.8.8. Although i can confirm the node side has the same issue (timing out connections).

Maybe one difference is we have https://github.com/espressif/arduino-esp32 package installed to speed up development. Could this be causing issues?

@chshu
Copy link
Collaborator

chshu commented Dec 18, 2024

Could you share the steps to reproduce the issue, including how you integrated Arduino-ESP32 into your application?

In the meantime, could you try running the basic_thread_border_router example as-is and let us know if the issue also occurs?

@motters
Copy link
Author

motters commented Dec 18, 2024

Hi @chshu, I've setup a new copy of basic_thread_border_router example with the following configuration:

  • Using the ESP-IDF release/5.3.2.
  • Change the H2 UART pins to the ones our hardware uses
  • Change the baud rate to 921600 which we historically used
  • Used the following esp terminal commands after flashing
    • wifi connect - s XXX -p XXXX
    • dataset init new
    • networkname vbr-123_1
    • dataset commit active
    • ifconfig up
    • thread up
    • (wait 2-30 seconds)
    • dns resolve google.com 8.8.8.8

We're having the same issues with connection timeouts:

image

Heres the (slightly tidied up) log from the above:

--- 
ets Jul 29 2019 12:21:46

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 153911750, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:7176
load:0x40078000,len:15564
ho 0 tail 12 room 4
load:0x40080400,len:4
--- 0x40080400: _init at ??:?

load:0x40080404,len:3904
entry 0x40080640
I (32) boot: ESP-IDF v5.3.2-dirty 2nd stage bootloader
I (32) boot: compile time Dec 16 2024 14:42:41
I (32) boot: Multicore bootloader
I (37) boot: chip revision: v3.1
I (40) boot.esp32: SPI Speed      : 40MHz
I (45) boot.esp32: SPI Mode       : DIO
I (50) boot.esp32: SPI Flash Size : 4MB
I (54) boot: Enabling RNG early entropy source...
I (60) boot: Partition Table:
I (63) boot: ## Label            Usage          Type ST Offset   Length
I (70) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (78) boot:  1 otadata          OTA data         01 00 0000f000 00002000
I (85) boot:  2 phy_init         RF data          01 01 00011000 00001000
I (93) boot:  3 ota_0            OTA app          00 10 00020000 00190000
I (100) boot:  4 ota_1            OTA app          00 11 001b0000 00190000
I (108) boot:  5 web_storage      Unknown data     01 82 00340000 00019000
I (115) boot:  6 rcp_fw           Unknown data     01 82 00359000 000a0000
I (123) boot: End of partition table
I (127) esp_image: segment 0: paddr=00020020 vaddr=3f400020 size=470cch (291020) map
I (236) esp_image: segment 1: paddr=000670f4 vaddr=3ffb0000 size=044d8h ( 17624) load
I (242) esp_image: segment 2: paddr=0006b5d4 vaddr=40080000 size=04a44h ( 19012) load
I (250) esp_image: segment 3: paddr=00070020 vaddr=400d0020 size=f50c4h (1003716) map
I (594) esp_image: segment 4: paddr=001650ec vaddr=40084a44 size=12b00h ( 76544) load
I (636) boot: Loaded app from partition at offset 0x20000
I (636) boot: Disabling RNG early entropy source...
I (649) cpu_start: Multicore app
I (657) cpu_start: Pro cpu start user code
I (657) cpu_start: cpu freq: 160000000 Hz
I (657) app_init: Application information:
I (660) app_init: Project name:     esp_ot_br
I (665) app_init: App version:      v5.4-beta2-8-g8e82a11
I (671) app_init: Compile time:     Dec 18 2024 12:40:52
I (677) app_init: ELF file SHA256:  0164f5911...
I (682) app_init: ESP-IDF:          v5.3.2-dirty
I (688) efuse_init: Min chip rev:     v0.0
I (692) efuse_init: Max chip rev:     v3.99 
I (697) efuse_init: Chip rev:         v3.1
I (702) heap_init: Initializing. RAM available for dynamic allocation:
I (709) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (715) heap_init: At 3FFC4458 len 0001BBA8 (110 KiB): DRAM
I (722) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (728) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (734) heap_init: At 40097544 len 00008ABC (34 KiB): IRAM
I (742) spi_flash: detected chip: gd
I (745) spi_flash: flash io: dio
W (749) spi_flash: Detected size(8192k) larger than the size in the binary image header(4096k). Using the size in the binary image header.
I (763) main_task: Started on CPU0
I (773) main_task: Calling app_main()
I (84I (843) uart: ESP_INTR_FLAG_IRAM flag not set while CONFIG_UART_ISR_IN_IRAM is enabled, flag updated
I (843) uart: ESP_INTR_FLAG_IRAM flag not set while CONFIG_UART_ISR_IN_IRAM is enabled, flag updated
I (853) OPENTHREAD: spinel UART interface initialization completed
I (843) main_task: Returned from app_main()
I(863) OPENTHREAD:[I] P-SpinelDrive-: co-processor reset: RESET_POWER_ON
E(873) OPENTHREAD:[C] P-SpinelDrive-: Software reset co-processor successfully
I(923) OPENTHREAD:[I] CslTxScheduler: Bus TX Time: 0 usec, Latency: 0 usec. Calculated CSL Frame Request Ahead: 20000 usec
I(933) OPENTHREAD:[I] ChildSupervsn-: Timeout: 0 -> 190
I(963) OPENTHREAD:[I] Settings------: Read NetworkInfo {rloc:0x3000, extaddr:c65af7d9909bbe4f, role:leader, mode:0x0f, version:5, keyseq:0x0, ...
I(973) OPENTHREAD:[I] Settings------: ... pid:0x9b30a08, mlecntr:0x7e4, maccntr:0x7d0, mliid:7e31e1924de0e29b}
I (993) esp_ot_br: Internal RCP Version: openthread-esp32/9d7f2d69f5-005c5cefc; esp32h2;  2024-12-12 14:10:40 UTC
I (993) esp_ot_br: Running  RCP Version: openthread-esp32/9d7f2d69f5-005c5cefc; esp32h2;  2024-12-12 14:10:40 UTC
I (1003) OPENTHREAD: OpenThread attached to netif
> wifi connect -s XXX -p XXXXXXX

ssid: XXX
psk: XXXXXXX
I (18593) wifi:wifi driver task: 3ffc61d4, prio:23, stack:6144, core=0
I (18593) wifi:wifi firmware version: b0fd6006b
I (18603) wifi:wifi certification version: v7.0
I (18603) wifi:config NVS flash: enabled
I (18603) wifi:config nano formating: enabled
I (18613) wifi:Init data frame dynamic rx buffer num: 32
I (18613) wifi:Init static rx mgmt buffer num: 5
I (18613) wifi:Init management short buffer num: 32
I (18623) wifi:Init dynamic tx buffer num: 32
I (18623) wifi:Init static rx buffer size: 1600
I (18623) wifi:Init static rx buffer num: 10
I (18633) wifi:Init dynamic rx buffer num: 32
I (18643) wifi_init: rx ba win: 6
I (18643) wifi_init: accept mbox: 6
I (18643) wifi_init: tcpip mbox: 32
I (18653) wifi_init: udp mbox: 6
I (18653) wifi_init: tcp mbox: 6
I (18653) wifi_init: tcp tx win: 5760
I (18663) wifi_init: tcp rx win: 5760
I (18663) wifi_init: tcp mss: 1440
I (18663) wifi_init: WiFi IRAM OP enabled
I (18673) wifi_init: WiFi RX IRAM OP enabled
I (18683) phy_init: phy_version 4840,02e0d70,Sep  2 2024,19:39:07
I (18763) wifi:mode : sta (64:b7:08:3d:d6:ac)
I (18763) wifi:enable tsf
I (18773) wifi:Set ps type: 2, coexist: 0

I (18773) ot_ext_cli: Start example_connect
I (18773) example_connect: Connecting to VM3832199...
W (18783) wifi:Password length matches WPA2 standards, authmode threshold changes from OPEN to WPA2
I (18793) example_connect: Waiting for IP(s)
I (21443) wifi:new:<6,0>, old:<1,0>, ap:<255,255>, sta:<6,0>, prof:1, snd_ch_cfg:0x0
I (21453) wifi:state: init -> auth (0xb0)
I (21453) wifi:state: auth -> assoc (0x0)
I (21463) wifi:state: assoc -> run (0x10)
I (21463) wifi:<ba-add>idx:0 (ifx:0, d0:6d:c9:6e:7d:c9), tid:0, ssn:1, winSize:64
I (21483) wifi:connected with VM3832199, aid = 16, channel 6, BW20, bssid = d0:6d:c9:6e:7d:c9
I (21483) wifi:security: WPA2-PSK, phy: bgn, rssi: -58
I (21483) wifi:pm start, type: 2

I (21493) wifi:dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us
I (21573) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (22843) example_connect: Got IPv6 event: Interface "example_netif_sta" address: fe80:0000:0000:0000:66b7:08ff:fe3d:d6ac, type: ESP_IP6_ADDR_IS_LINK_LOCAL
I (22993) esp_netif_handlers: example_netif_sta ip: 192.168.0.229, mask: 255.255.255.0, gw: 192.168.0.1
I (22993) example_connect: Got IPv4 event: Interface "example_netif_sta" address: 192.168.0.229
I(23013) OPENTHREAD:[N] RoutingManager: BR ULA prefix: fd05:aada:75e0::/48 (loaded)
I(23033) OPENTHREAD:[N] RoutingManager: Local on-link prefix: fd87:77fd:1b9:a622::/64
wifi sta is connected successfully
Done
I (23033) OPENTHREAD: Platform UDP bound to port 61631
I (23043) OPENTHREAD: NAT64 ready
> dataset init new

Done
> networkname vbr-1234_1

Done
I (30333) OPENTHREAD: NAT64 ready
> dataset commit active

Done
 I(36263) OPENTHREAD:[N] RoutingManager: Local on-link prefix: fd95:38ca:248a:3333::/64
I (36303) OPENTHREAD: NAT64 ready
> ifconfig up

I (41583) OPENTHREAD: Platform UDP bound to port 49153
Done
I (41593) OT_STATE: netif up
I (41593) OPENTHREAD: NAT64 ready
> thread start

I(47813) OPENTHREAD:[N] Mle-----------: Role disabled -> detached
Done
I (47843) OPENTHREAD: NAT64 ready

I(75323) OPENTHREAD:[N] Mle-----------: RLOC16 3000 -> fffe
I (75343) OPENTHREAD: NAT64 ready
I(75453) OPENTHREAD:[N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset
I(82073) OPENTHREAD:[N] RouterTable---: Allocate router id 12
I(82083) OPENTHREAD:[N] Mle-----------: RLOC16 fffe -> 3000
I(82083) OPENTHREAD:[N] Mle-----------: Role detached -> leader
I(82093) OPENTHREAD:[N] Mle-----------: Partition ID 0x30db6085
I (82123) OPENTHREAD: Platform UDP bound to port 49154
I (82153) OPENTHREAD: NAT64 ready
E (82363) OPENTHREAD: Failed to get LL address, error: Invalid If index
I (82623) OPENTHREAD: NAT64 ready
I (82893) OPENTHREAD: NAT64 ready
I (82893) OPENTHREAD: NAT64 ready
I (82963) OPENTHREAD: NAT64 ready
I (82973) OPENTHREAD: NAT64 ready
I (83573) OPENTHREAD: Platform UDP bound to port 53536
I (83583) OPENTHREAD: Platform UDP bound to port 49155
I (83593) OPENTHREAD: NAT64 ready
I (83593) OPENTHREAD: NAT64 ready
W(84953) OPENTHREAD:[W] DuaManager----: Failed to perform next registration: NotFound
I (85213) OPENTHREAD: NAT64 ready
E (86383) OPENTHREAD: Failed to get LL address, error: Invalid If index
E (90403) OPENTHREAD: Failed to get LL address, error: Invalid If index
E (91463) OPENTHREAD: Failed to get LL address, error: Invalid If index
I (91483) OPENTHREAD: NAT64 ready
I (92843) example_connect: Got IPv6 event: Interface "example_netif_sta" address: fd95:38ca:248a:3333:66b7:08ff:fe3d:d6ac, type: ESP_IP6_ADDR_IS_UNIQUE_LOCAL
I (92853) example_connect: Got IPv6 event: Interface "example_netif_sta" address: fd85:4b34:e70d:fb73:66b7:08ff:fe3d:d6ac, type: ESP_IP6_ADDR_IS_UNIQUE_LOCAL
I (92873) example_connect: Got IPv6 event: Interface "example_netif_sta" address: fd87:77fd:01b9:a622:66b7:08ff:fe3d:d6ac, type: ESP_IP6_ADDR_IS_UNIQUE_LOCAL
E (94503) OPENTHREAD: Failed to get LL address, error: Invalid If index
E (109773) OPENTHREAD: Failed to get LL address, error: Invalid If index
E (126293) OPENTHREAD: Failed to get LL address, error: Invalid If index
> dns resolve google.com 8.8.8.8

Synthesized IPv6 DNS server address: fd05:aada:75e0:2:0:0:808:808
E (134713) OPENTHREAD: Failed to Send UDP message, err: -12
DNS response for google.com. - 2a00:1450:4009:816:0:0:0:200e TTL:164 
Done
> 

As per our production firmware we integrated ESP-Ardunio using the manual method https://docs.espressif.com/projects/arduino-esp32/en/latest/esp-idf_component.html#manual-installation-of-arduino-framework . However since we're having the same issue with the basic_thread_border_router example i don't think this is the problem.

@zwx1995esp
Copy link
Collaborator

zwx1995esp commented Dec 18, 2024

Hi, @motters just a question, does this dns resolve google.com 8.8.8.8 work on BR if using the previous code? Based our docs: why-can-t-i-access-the-host-from-the-br-device-using-the-ping-command, DNS comand is also implemented on Thread layer, I don't think that BR can resovle any addresses using this command. If you want to performance DNS on BR, you need also implement and use the LWIP layer DNS resolving command.

@zwx1995esp
Copy link
Collaborator

This DNS resolve command is used for the end node devices which attached in BR's thread network. So could you please also try if it works on the end node devices?

@motters
Copy link
Author

motters commented Dec 18, 2024

@zwx1995esp i see, is there a command i can run on the BR to test the network?

I'll test from a node and post the result.

@motters
Copy link
Author

motters commented Dec 18, 2024

Good news the dns command does work from the node when using the BR is using the basic_thread_border_router example,
image

However it does not work from our modded / production version on the BR. I suppose next step is to exclude idf-ardunio causing the issue?
image

@motters
Copy link
Author

motters commented Dec 19, 2024

I'm comparing the logs of basic_thread_border_router to our production firmware we're upgrading. We're getting the following error which basic_thread_border_router does not. Any advise on what this could be?
image

We are also getting multiple of the following warnings:
image

However the basic_thread_border_router seems to get similar:
image

So i'm assuming the issues is todo with Failed to probe backbone multicast listeners

@motters
Copy link
Author

motters commented Dec 19, 2024

After more digging it seems the esp-arduino WebServer is the component causing the issues.

Once we remove all the WebSever code OpenThread is now working correctly.

@motters
Copy link
Author

motters commented Dec 23, 2024

@zwx1995esp @chshu I think this can be closed. It seems using any arduino-esp32 networking features breaks the OT routing, assuming NAT64.

arduino-esp32 mDNS and webserver library had to be removed and replaced with esp-idf libraries. As arduino-esp32 is an official Espressif product, might be worth looking into why?

However, i think it's worth noting in the README that OpenThread BR features cannot be used in conjunction with arduino-esp32 networking libraries. Hopefully this will save other people some time :)

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

No branches or pull requests

3 participants