esphome / issues

Issue Tracker for ESPHome
https://esphome.io/
290 stars 35 forks source link

W5500 w/ESP32-S3-N16R8 [W][ethernet:237]: Connecting via ethernet failed! Re-connecting... [V][ethernet:424]: DHCP Client Status: 0 #5689

Open NonaSuomy opened 5 months ago

NonaSuomy commented 5 months ago

The problem

Trying to connect ESP32-S3-N16R8 to a W5500 Lite module (USR-ES1) also tried a full-sized W5500 also had the same issue just DHCP looking for an address over and over again.

Tried to set manual IP and got error 2 instead of 0

Tried different pins listed in the pull request still no go

https://github.com/esphome/esphome/pull/4424

Tried Arduino IDE on the board seems to have a different issue:

E (1121) w5500.mac: W5500 version mismatched, expected 0x04, got 0x00
E (1123) w5500.mac: emac_w5500_init(795): vefiry chip ID failed
E (1124) esp_eth: esp_eth_driver_install(228): init mac failed

Which, some said it was because some module takes too long and require a 10ms delay after reset. It seems a few fixes went in for this but not sure if that meshes with esphome. https://github.com/espressif/esp-idf/pull/11337/commits/177f70c056e87b48117646e79b7eca8d920cfd4d https://github.com/espressif/esp-idf/issues/11331

Tried to do a TCPDUMP but it never requested for DHCP on the network. sudo tcpdump -v -i any port 67 or port 68 -e -n -vv Tested plugging in a laptop to the that port and it tossed up the dhcp of that unit in the dump

21:26:00.952592 enp8s0 B   ifindex 4 de:ad:be:ef:01 ethertype IPv4 (0x0800), length 376: (tos 0x0, ttl 128, id 55867, offset 0, flags [none], proto UDP (17), length 356)
    0.0.0.0.68 > 255.255.255.255.67: [udp sum ok] BOOTP/DHCP, Request from de:ad:be:ef:01, length 328, xid 0x187f1e34, Flags [none] (0x0000)
          Client-Ethernet-Address de:ad:be:ef:01
          Vendor-rfc1048 Extensions
            Magic Cookie 0x#######
            DHCP-Message (53), length 1: Request
            Client-ID (61), length 7: ether de:ad:be:ef:01
            Requested-IP (50), length 4: 10.0.42.145
            Server-ID (54), length 4: 10.0.42.40
            Hostname (12), length 15: "DESKTOP-#######"
            FQDN (81), length 18: "DESKTOP-#######"
            Vendor-Class (60), length 8: "MSFT 5.0"
            Parameter-Request (55), length 14:
              Subnet-Mask (1), Default-Gateway (3), Domain-Name-Server (6), Domain-Name (15)
              Router-Discovery (31), Static-Route (33), Vendor-Option (43), Netbios-Name-Server (44)
              Netbios-Node (46), Netbios-Scope (47), Unknown (119), Classless-Static-Route (121)
              Classless-Static-Route-Microsoft (249), Unknown (252)
            END (255), length 0

Guessing because the w5500 module never fully comes up to make the DHCP request.

Tried changing the clock from 30 default to 25,20,16,10MHz.

Which version of ESPHome has the issue?

2024.3.2

What type of installation are you using?

Docker

Which version of Home Assistant has the issue?

Issue with ESPHome not HA

What platform are you using?

ESP32-IDF

Board

ESP32-S3-N16R8 https://www.aliexpress.com/item/1005006266375800.html image

W5500 https://www.aliexpress.com/item/1005006246720540.html image

Component causing the issue

Ethernet/W5500

Example YAML snippet

esphome:
  name: esp32-s3-n16r8-001
  friendly_name: ESP32-S3-N16R8-001
  platformio_options:
    board_build.flash_mode: dio

esp32:
  board: esp32-s3-devkitc-1
  variant: esp32s3
  flash_size: 16MB
  framework:
    #type: arduino
    type: esp-idf

# Enable logging
logger:
  level: VERY_VERBOSE

psram:
  mode: octal
  speed: 80MHz

# Enable Home Assistant API
api:
  encryption:
    key: !secret encryption_key010

ota:
  password: !secret ota_pass010

# wifi:
#   ssid: !secret wifi_ssid
#   password: !secret wifi_password
#   use_address: !secret use_address_wifi010
#   # Enable fallback hotspot (captive portal) in case wifi connection fails
#   ap:
#     ssid: "ESP32-S3-N16R8-001 Fallback Hotspot"
#     password: !secret fallbackhotspot0010

ethernet:
 type: W5500
 clk_pin: GPIO05 #19
 mosi_pin: GPIO04 #21
 miso_pin: GPIO13 #23
 cs_pin: GPIO09 #18
 interrupt_pin: GPIO10 #36
 reset_pin: GPIO12 #22
 use_address: !secret use_address_wired010

#captive_portal:

web_server:

sensor:
  - platform: uptime
    name: "_Uptime"

Anything in the logs that might be useful for us?

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0x2b (SPI_FAST_FLASH_BOOT)
Saved PC:0x40378c1b
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3808,len:0x1658
load:0x403c9700,len:0xbc0
load:0x403cc700,len:0x2f3c
entry 0x403c9950
I (24) boot: ESP-IDF 4.4.6 2nd stage bootloader
I (25) boot: compile time 20:27:40
I (25) boot: Multicore bootloader
I (27) boot: chip revision: v0.2
I (30) boot.esp32s3: Boot SPI Speed : 80MHz
I (35) boot.esp32s3: SPI Mode       : DIO
I (40) boot.esp32s3: SPI Flash Size : 16MB
I (45) boot: Enabling RNG early entropy source...
I (50) boot: Partition Table:
I (54) boot: ## Label            Usage          Type ST Offset   Length
I (61) boot:  0 otadata          OTA data         01 00 00009000 00002000
I (68) boot:  1 phy_init         RF data          01 01 0000b000 00001000
I (76) boot:  2 app0             OTA app          00 10 00010000 007c0000
I (83) boot:  3 app1             OTA app          00 11 007d0000 007c0000
I (91) boot:  4 nvs              WiFi data        01 02 00f90000 0006d000
I (98) boot: End of partition table
I (103) boot: No factory image, trying OTA 0
I (107) esp_image: segment 0: paddr=00010020 vaddr=3c070020 size=237c4h (145348) map
I (142) esp_image: segment 1: paddr=000337ec vaddr=3fc93d30 size=02ee8h ( 12008) load
I (145) esp_image: segment 2: paddr=000366dc vaddr=40374000 size=0993ch ( 39228) load
I (156) esp_image: segment 3: paddr=00040020 vaddr=42000020 size=67030h (421936) map
I (233) esp_image: segment 4: paddr=000a7058 vaddr=4037d93c size=063ech ( 25580) load
I (245) boot: Loaded app from partition at offset 0x10000
I (269) boot: Set actual ota_seq=1 in otadata[0]
I (269) boot: Disabling RNG early entropy source...
I (270) cpu_start: Multicore app
I (273) opi psram: vendor id : 0x0d (AP)
I (277) opi psram: dev id    : 0x02 (generation 3)
I (283) opi psram: density   : 0x03 (64 Mbit)
I (288) opi psram: good-die  : 0x01 (Pass)
I (292) opi psram: Latency   : 0x01 (Fixed)
I (297) opi psram: VCC       : 0x01 (3V)
I (302) opi psram: SRF       : 0x01 (Fast Refresh)
I (307) opi psram: BurstType : 0x01 (Hybrid Wrap)
I (313) opi psram: BurstLen  : 0x01 (32 Byte)
I (318) opi psram: Readlatency  : 0x02 (10 cycles@Fixed)
I (324) opi psram: DriveStrength: 0x00 (1/1)
I (329) MSPI Timing: PSRAM timing tuning index: 5
I (334) spiram: Found 64MBit SPI RAM device
I (339) spiram: SPI RAM mode: sram 80m
I (343) spiram: PSRAM initialized, cache is in normal (1-core) mode.
I (350) cpu_start: Pro cpu up.
I (354) cpu_start: Starting app cpu, entry point is 0x403767cc
I (0) cpu_start: App cpu up.
I (787) spiram: SPI SRAM memory test OK
I (795) cpu_start: Pro cpu start user code
I (796) cpu_start: cpu freq: 160000000
I (796) cpu_start: Application information:
I (796) cpu_start: Project name:     esp32-s3-n16r8-001
I (796) cpu_start: App version:      2024.3.2
I (796) cpu_start: Compile time:     Apr  8 2024 20:26:21
I (797) cpu_start: ELF file SHA256:  939d0893d66027d8...
I (797) cpu_start: ESP-IDF:          4.4.6
I (797) cpu_start: Min chip rev:     v0.0
I (797) cpu_start: Max chip rev:     v0.99 
I (798) cpu_start: Chip rev:         v0.2
I (798) heap_init: Initializing. RAM available for dynamic allocation:
I (798) heap_init: At 3FC9A698 len 0004F078 (316 KiB): D/IRAM
I (798) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DIRAM
I (799) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (799) heap_init: At 600FE000 len 00002000 (8 KiB): RTCRAM
I (799) spiram: Adding pool of 8192K of external SPI memory to heap allocator
I (800) spi_flash: detected chip: gd
I (801) spi_flash: flash io: dio
I (802) sleep: Configure to isolate all GPIO pins in sleep state
I (802) sleep: Enable automatic switching of GPIO sleep configuration
I (803) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
[I][logger:158]: Log initialized
[V][esp32.preferences:059]: nvs_get_blob('233825507'): ESP_ERR_NVS_NOT_FOUND - the key might not be set yet
[C][ota:483]: There have been 0 suspected unsuccessful boot attempts.
[VV][esp32.preferences:040]: s_pending_save: key: 233825507, len: 4
[D][esp32.preferences:114]: Saving 1 preferences to flash...
[VV][esp32.preferences:123]: Checking if NVS data 233825507 has changed
[V][esp32.preferences:163]: nvs_get_blob('233825507'): ESP_ERR_NVS_NOT_FOUND - the key might not be set yet
[V][esp32.preferences:126]: sync: key: 233825507, len: 4
[D][esp32.preferences:143]: Saving 1 preferences to flash: 0 cached, 1 written, 0 failed
[I][app:029]: Running through setup()...
[V][app:030]: Sorting components by setup priority...
[VV][scheduler:063]: set_interval(name='', interval=60000, offset=24045)
[VV][scheduler:063]: set_interval(name='update', interval=60000, offset=13508)
[C][ethernet:034]: Setting up Ethernet...
[VV][esp-idf:000]: I (485) w5500.mac: version=0
[VV][esp-idf:000]: I (497) system_api: Base MAC address is not set

[VV][esp-idf:000]: I (498) system_api: read default base MAC address from EFUSE

[VV][esp-idf:000]: I (500) esp_eth.netif.netif_glue: 3c:84:27:c7:14:9b

[VV][esp-idf:000]: I (501) esp_eth.netif.netif_glue: ethernet attached to netif

[V][ethernet:367]: [Ethernet event] ETH started (num=0)
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0
[VV][scheduler:226]: Running interval '' with interval=60000 last_execution=4294944233 (now=36937)
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0
[VV][scheduler:226]: Running interval 'update' with interval=60000 last_execution=4294954771 (now=47475)
[V][sensor:043]: '_Uptime': Received new state 47.476002
[D][sensor:094]: '_Uptime': Sending state 47.47600 s with 0 decimals of accuracy
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0
[VV][scheduler:226]: Running interval '' with interval=60000 last_execution=36937 (now=96937)
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0
[VV][scheduler:226]: Running interval 'update' with interval=60000 last_execution=47475 (now=107475)
[V][sensor:043]: '_Uptime': Received new state 107.475998
[D][sensor:094]: '_Uptime': Sending state 107.47600 s with 0 decimals of accuracy
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0

Additional information

Tested both modules on an Arduino Uno and both worked fine like so:

Starting WebServer on mac index = 17
Connected! IP address: 10.0.42.192
W6100 => Speed: 100 MB, Duplex: FULL DUPLEX, Link status: LINK
===
Using mac index = 17
Connected! IP address: 10.0.42.192
W6100 => Speed: 100 MB, Duplex: FULL DUPLEX, Link status: LINK
===
Using mac index = 17

Host: 10.0.42.192
Connection: keep-alive
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.9

image

jjcszxh commented 5 months ago

Could it be a problem with your use of DuPont cables

NonaSuomy commented 5 months ago

Same wires above worked fine on the Arduino test above. I even attached longer ones to the ones I was using for the S3 to swap from female to male and it worked just fine. Went from 10CM female to female ones, attached to those another 20CM male to male, Is the S3 more sensitive?

NonaSuomy commented 5 months ago

Just to show it's not the wires I custom handmade my own 70mm dupont wires, still same issue.

E2746468-9569-40B3-9702-9CD11CFB2884 Note: The PoE splitter is not plugged in fo this test. image

[V][esp32.preferences:059]: nvs_get_blob('233825507'): ESP_ERR_NVS_NOT_FOUND - the key might not be set yet
[C][ota:483]: There have been 0 suspected unsuccessful boot attempts.
[VV][esp32.preferences:040]: s_pending_save: key: 233825507, len: 4
[D][esp32.preferences:114]: Saving 1 preferences to flash...
[VV][esp32.preferences:123]: Checking if NVS data 233825507 has changed
[V][esp32.preferences:163]: nvs_get_blob('233825507'): ESP_ERR_NVS_NOT_FOUND - the key might not be set yet
[V][esp32.preferences:126]: sync: key: 233825507, len: 4
[D][esp32.preferences:143]: Saving 1 preferences to flash: 0 cached, 1 written, 0 failed
[I][app:029]: Running through setup()...
[V][app:030]: Sorting components by setup priority...
[VV][scheduler:063]: set_interval(name='', interval=60000, offset=15372)
[VV][scheduler:063]: set_interval(name='update', interval=60000, offset=29769)
[D][binary_sensor:034]: 'Status': Sending initial state OFF
[C][ethernet:034]: Setting up Ethernet...
[VV][esp-idf:000]: I (483) w5500.mac: version=0

[VV][esp-idf:000]: I (495) system_api: Base MAC address is not set

[VV][esp-idf:000]: I (496) system_api: read default base MAC address from EFUSE

[VV][esp-idf:000]: I (498) esp_eth.netif.netif_glue: 3c:84:27:c7:14:9b

[VV][esp-idf:000]: I (499) esp_eth.netif.netif_glue: ethernet attached to netif

[V][ethernet:367]: [Ethernet event] ETH started (num=0)
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0
[VV][scheduler:226]: Running interval 'update' with interval=60000 last_execution=4294938004 (now=30708)
[V][sensor:043]: '_Uptime': Received new state 30.709000
[D][sensor:094]: '_Uptime': Sending state 30.70900 s with 0 decimals of accuracy
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0
[VV][scheduler:226]: Running interval '' with interval=60000 last_execution=4294952400 (now=45104)
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0

Plug in the network cable:

[VV][esp-idf:000]: E (84971) w5500.mac: w5500_send_command(123): send command timeout
[VV][esp-idf:000]: E (84972) w5500.mac: emac_w5500_start(279): issue OPEN command failed
[VV][esp-idf:000]: E (84973) w5500.mac: emac_w5500_set_link(422): w5500 start failed
[VV][esp-idf:000]: E (84974) esp_eth: eth_on_state_changed(121): ethernet mac set link failed
[VV][esp-idf:000]: E (84975) w5500.phy: w5500_update_link_duplex_speed(84): change link failed
[VV][esp-idf:000]: E (84976) w5500.phy: w5500_get_link(108): update link duplex speed failed
[VV][scheduler:226]: Running interval 'update' with interval=60000 last_execution=30708 (now=90708)
[V][sensor:043]: '_Uptime': Received new state 90.709000
[D][sensor:094]: '_Uptime': Sending state 90.70900 s with 0 decimals of accuracy
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0
[VV][scheduler:226]: Running interval '' with interval=60000 last_execution=45104 (now=105104)
[W][ethernet:237]: Connecting via ethernet failed! Re-connecting...
[V][ethernet:424]: DHCP Client Status: 0

Doing a reset I see this not sure if it's something?

[I][ethernet:220]: Starting ethernet connection
[W][ethernet:152]: Warning set: unspecified
NonaSuomy commented 5 months ago

I think it has something to do with trying to use GPIO09 as the CS Pin or just generally using some of the FSPI pins in the wrong configuration. Need to further test.

I switched to using the UART0 and JTAG pins which were not in use and the interface came up.

  clk_pin: GPIO42       # MTMS
  mosi_pin: GPIO44      # U0RXD
  miso_pin: GPIO40      # MTDO
  cs_pin: GPIO39        # MTCK
  interrupt_pin: GPIO41 # MTDI
  reset_pin: GPIO43     # U0TXD

image image Maybe it has something to do with this but I am setting DIO mode above

Most ESP32-S3 modules use qio, but are also dual I/O.

In qio mode, two additional GPIOs (9 and 10) are used for SPI flash communications. If flash mode is set to dio then these pins are available for other purposes.

~If switched all the pins to this layout would probably fix it as well:~

Note: Did further testing the only way to get it working was to not use GPIO13/11 not sure why? Swapped them to multiple other pins with no issues.

ethernet:
 type: W5500
 clk_pin: GPIO12
 mosi_pin: GPIO13
 miso_pin: GPIO11
 cs_pin: GPIO10
 interrupt_pin: GPIO14
 reset_pin: GPIO09
nikito7 commented 1 month ago

With S3 N4R2 I had same issue. In tasmota it works fine (4 pins).

It's interrupt_pin mandatory?