search

esphome / issues

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

DHCP hostname not present on initial request, works on DHCP renewal #2069

Closed ilium007 closed 2 years ago

ilium007 commented 3 years ago

Operating environment/Installation (Hass.io/Docker/pip/etc.):

Docker

xxxx@debian01:~$ docker images
REPOSITORY                     TAG       IMAGE ID       CREATED        SIZE
homeassistant/home-assistant   stable    5c218400ef3f   3 days ago     1.1GB
esphome/esphome   latest    be838fb1be99   4 days ago     927MB

ESP (ESP32/ESP8266, Board/Sonoff):

Adafruit ESP8266 Huzzah

ESPHome version (latest production, beta, dev branch)

Affected component:

Description of problem:

DHCP hostname not being set in initial DHCP request. I lowered my router DHCP lease time to 5min to test. On the subsequent DHCP request the hostname then appears in the router DHCP lease table.

I need this to work as I have a script on the router which sets the local domain DNS A record based on DHCP request hostname. I can't use mDNS because my IoT devices sit on a different VLAN. I need DNS to work.

Problem-relevant YAML-configuration entries:

PASTE YAML FILE HERE

Logs (if applicable):

PASTE DEBUG LOG HERE

Additional information and things you've tried:

I have two packet captures showing the initial DHCP request and the lease renewal. When the lease is renewed the hostname appears in the router DHCP table but because my DHCP to DNS script only runs on initial lease request I don't ever get a DNS A record for the ESP devices. The 5min DHCP lease time is a hack, I have a 10hr DHCP lease time as part of my router config.

dhcp_3.pcap - initial DHCP request dhcp_4.pcap - DHCP renewal

dhcp_pcap.zip

ilium007 commented 3 years ago

This was resolved in https://github.com/esphome/esphome/pull/1789 for the ESP32. How does it get fixed for the ESP8266?

probot-esphome[bot] commented 3 years ago

network source network issues network recent changes (message by IssueLinks)

agners commented 3 years ago

ESP8266 uses Arduino release 2.7.4 from Aug 2, 2020 which seems to have that LWIP fix not in yet. The next release is 3.0.0, which seems to be a major new release with quite some changes. I guess to get this resolved for ESP8266 it would need the jump to 3.0.0.

ilium007 commented 3 years ago

So where should I be reporting / monitoring this? Kind of a deal breaker for ESPHome on ESP8266 for me.

ilium007 commented 3 years ago

I tried setting arduino_version: espressif8266@3.0.0

but it resulted in the below on compile:

INFO Reading configuration /config/livingroom_plug_0.yaml...
INFO Detected timezone 'UTC' with UTC offset 0
INFO Generating C++ source...
INFO Core config or version changed, cleaning build files...
INFO Deleting /config/livingroom_plug_0/.pioenvs
INFO Compiling app...
INFO Running:  platformio run -d /config/livingroom_plug_0
Processing livingroom_plug_0 (board: esp01_1m; framework: arduino; platform: espressif8266@3.0.0)
--------------------------------------------------------------------------------
Platform Manager: Installing espressif8266 @ 3.0.0
Platform Manager: espressif8266 @ 3.0.0 has been installed!
The platform 'espressif8266@3.0.0' has been successfully installed!
The rest of the packages will be installed later depending on your build environment.
Tool Manager: Installing platformio/toolchain-xtensa @ ~2.100200.0
Downloading  [####################################]  100%          
Unpacking  [####################################]  100%          
Tool Manager: toolchain-xtensa @ 2.100200.0 has been installed!
Tool Manager: Installing platformio/framework-arduinoespressif8266 @ ~3.30000.0
Downloading  [####################################]  100%          
Unpacking  [####################################]  100%          
Tool Manager: framework-arduinoespressif8266 @ 3.30000.210519 has been installed!
HARDWARE: ESP8266 80MHz, 80KB RAM, 1MB Flash
PACKAGES: 
 - framework-arduinoespressif8266 3.30000.210519 (3.0.0) 
 - tool-esptool 1.413.0 (4.13) 
 - tool-esptoolpy 1.30000.201119 (3.0.0) 
 - toolchain-xtensa 2.100200.0 (10.2.0)
Library Manager: Installing Update
Library Manager: Already installed, built-in library
Dependency Graph
|-- <ESPAsyncTCP-esphome> 1.2.3
|-- <ESPAsyncWebServer-esphome> 1.2.7
|   |-- <ESPAsyncTCP-esphome> 1.2.3
|   |-- <Hash> 1.0
|   |-- <ESP8266WiFi> 1.0
|-- <ESP8266WiFi> 1.0
|-- <ESP8266mDNS> 1.2
|   |-- <ESP8266WiFi> 1.0
|-- <DNSServer> 1.1.1
|   |-- <ESP8266WiFi> 1.0
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/api/api_connection.cpp.o
In file included from src/esphome/components/api/api_server.h:12,
                 from src/esphome/components/api/api_connection.h:7,
                 from src/esphome/components/api/api_connection.cpp:1:
src/esphome/components/api/homeassistant_service.h: In member function 'void esphome::api::HomeAssistantServiceCallAction<Ts>::play(Ts ...)':
src/esphome/components/api/homeassistant_service.h:55:18: warning: invalid use of incomplete type 'class esphome::api::APIServer'
   55 |     this->parent_->send_homeassistant_service_call(resp);
      |                  ^~
In file included from src/esphome/components/api/api_server.h:9,
                 from src/esphome/components/api/api_connection.h:7,
                 from src/esphome/components/api/api_connection.cpp:1:
src/esphome/components/api/util.h:13:7: note: forward declaration of 'class esphome::api::APIServer'
   13 | class APIServer;
      |       ^~~~~~~~~
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/api/api_pb2.cpp.o
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/api/api_pb2_service.cpp.o
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/api/api_server.cpp.o
In file included from src/esphome/components/api/api_server.h:12,
                 from src/esphome/components/api/api_server.cpp:1:
src/esphome/components/api/homeassistant_service.h: In member function 'void esphome::api::HomeAssistantServiceCallAction<Ts>::play(Ts ...)':
src/esphome/components/api/homeassistant_service.h:55:18: warning: invalid use of incomplete type 'class esphome::api::APIServer'
   55 |     this->parent_->send_homeassistant_service_call(resp);
      |                  ^~
In file included from src/esphome/components/api/api_server.h:9,
                 from src/esphome/components/api/api_server.cpp:1:
src/esphome/components/api/util.h:13:7: note: forward declaration of 'class esphome::api::APIServer'
   13 | class APIServer;
      |       ^~~~~~~~~
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/api/list_entities.cpp.o
In file included from src/esphome/components/api/api_server.h:12,
                 from src/esphome/components/api/list_entities.h:52,
                 from src/esphome/components/api/list_entities.cpp:1:
src/esphome/components/api/homeassistant_service.h: In member function 'void esphome::api::HomeAssistantServiceCallAction<Ts>::play(Ts ...)':
src/esphome/components/api/homeassistant_service.h:55:18: warning: invalid use of incomplete type 'class esphome::api::APIServer'
   55 |     this->parent_->send_homeassistant_service_call(resp);
      |                  ^~
In file included from src/esphome/components/api/list_entities.h:5,
                 from src/esphome/components/api/list_entities.cpp:1:
src/esphome/components/api/util.h:13:7: note: forward declaration of 'class esphome::api::APIServer'
   13 | class APIServer;
      |       ^~~~~~~~~
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/api/proto.cpp.o
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/api/subscribe_state.cpp.o
In file included from src/esphome/components/api/api_server.h:12,
                 from src/esphome/components/api/subscribe_state.h:47,
                 from src/esphome/components/api/subscribe_state.cpp:1:
src/esphome/components/api/homeassistant_service.h: In member function 'void esphome::api::HomeAssistantServiceCallAction<Ts>::play(Ts ...)':
src/esphome/components/api/homeassistant_service.h:55:18: warning: invalid use of incomplete type 'class esphome::api::APIServer'
   55 |     this->parent_->send_homeassistant_service_call(resp);
      |                  ^~
In file included from src/esphome/components/api/subscribe_state.h:6,
                 from src/esphome/components/api/subscribe_state.cpp:1:
src/esphome/components/api/util.h:13:7: note: forward declaration of 'class esphome::api::APIServer'
   13 | class APIServer;
      |       ^~~~~~~~~
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/api/user_services.cpp.o
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/api/util.cpp.o
In file included from src/esphome/components/api/api_server.h:12,
                 from src/esphome/components/api/util.cpp:2:
src/esphome/components/api/homeassistant_service.h: In member function 'void esphome::api::HomeAssistantServiceCallAction<Ts>::play(Ts ...)':
src/esphome/components/api/homeassistant_service.h:55:18: warning: invalid use of incomplete type 'class esphome::api::APIServer'
   55 |     this->parent_->send_homeassistant_service_call(resp);
      |                  ^~
In file included from src/esphome/components/api/util.cpp:1:
src/esphome/components/api/util.h:13:7: note: forward declaration of 'class esphome::api::APIServer'
   13 | class APIServer;
      |       ^~~~~~~~~
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/binary_sensor/automation.cpp.o
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/binary_sensor/binary_sensor.cpp.o
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/binary_sensor/filter.cpp.o
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/captive_portal/captive_portal.cpp.o
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/esp8266_pwm/esp8266_pwm.cpp.o
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/gpio/binary_sensor/gpio_binary_sensor.cpp.o
In file included from src/esphome/components/gpio/binary_sensor/gpio_binary_sensor.h:4,
                 from src/esphome/components/gpio/binary_sensor/gpio_binary_sensor.cpp:1:
src/esphome/components/gpio/binary_sensor/gpio_binary_sensor.cpp: In member function 'virtual void esphome::gpio::GPIOBinarySensor::dump_config()':
src/esphome/components/binary_sensor/binary_sensor.h:12:3: warning: 'nonnull' argument 'this' compared to NULL [-Wnonnull-compare]
   12 |   if (obj != nullptr) { \
      |   ^~
src/esphome/components/gpio/binary_sensor/gpio_binary_sensor.cpp:15:3: note: in expansion of macro 'LOG_BINARY_SENSOR'
   15 |   LOG_BINARY_SENSOR("", "GPIO Binary Sensor", this);
      |   ^~~~~~~~~~~~~~~~~
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/gpio/switch/gpio_switch.cpp.o
In file included from src/esphome/components/gpio/switch/gpio_switch.h:4,
                 from src/esphome/components/gpio/switch/gpio_switch.cpp:1:
src/esphome/components/gpio/switch/gpio_switch.cpp: In member function 'virtual void esphome::gpio::GPIOSwitch::dump_config()':
src/esphome/components/switch/switch.h:11:3: warning: 'nonnull' argument 'this' compared to NULL [-Wnonnull-compare]
   11 |   if (obj != nullptr) { \
      |   ^~
src/esphome/components/gpio/switch/gpio_switch.cpp:42:3: note: in expansion of macro 'LOG_SWITCH'
   42 |   LOG_SWITCH("", "GPIO Switch", this);
      |   ^~~~~~~~~~
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/homeassistant/time/homeassistant_time.cpp.o
In file included from src/esphome/components/api/api_server.h:12,
                 from src/esphome/components/homeassistant/time/homeassistant_time.h:5,
                 from src/esphome/components/homeassistant/time/homeassistant_time.cpp:1:
src/esphome/components/api/homeassistant_service.h: In member function 'void esphome::api::HomeAssistantServiceCallAction<Ts>::play(Ts ...)':
src/esphome/components/api/homeassistant_service.h:55:18: warning: invalid use of incomplete type 'class esphome::api::APIServer'
   55 |     this->parent_->send_homeassistant_service_call(resp);
      |                  ^~
In file included from src/esphome/components/api/api_server.h:9,
                 from src/esphome/components/homeassistant/time/homeassistant_time.h:5,
                 from src/esphome/components/homeassistant/time/homeassistant_time.cpp:1:
src/esphome/components/api/util.h:13:7: note: forward declaration of 'class esphome::api::APIServer'
   13 | class APIServer;
      |       ^~~~~~~~~
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/light/addressable_light.cpp.o
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/light/light_state.cpp.o
In file included from src/esphome/components/light/light_state.h:5,
                 from src/esphome/components/light/light_state.cpp:1:
src/esphome/core/preferences.h: In instantiation of 'bool esphome::ESPPreferenceObject::load(T*) [with T = esphome::light::LightStateRTCState]':
src/esphome/components/light/light_state.cpp:111:38:   required from here
src/esphome/core/preferences.h:105:9: warning: 'void* memcpy(void*, const void*, size_t)' copying an object of non-trivial type 'struct esphome::light::LightStateRTCState' from an array of 'uint32_t' {aka 'unsigned int'} [-Wclass-memaccess]
  105 |   memcpy(dest, this->data_, sizeof(T));
      |   ~~~~~~^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
src/esphome/components/light/light_state.cpp:85:8: note: 'struct esphome::light::LightStateRTCState' declared here
   85 | struct LightStateRTCState {
      |        ^~~~~~~~~~~~~~~~~~
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/logger/logger.cpp.o
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/ota/ota_component.cpp.o
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/output/automation.cpp.o
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/output/float_output.cpp.o
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/sensor/automation.cpp.o
Compiling .pioenvs/livingroom_plug_0/src/esphome/components/sensor/filter.cpp.o
src/esphome/components/sensor/filter.cpp: In member function 'virtual esphome::optional<float> esphome::sensor::FilterOutValueFilter::new_value(float)':
src/esphome/components/sensor/filter.cpp:240:27: error: 'pow10f' was not declared in this scope; did you mean 'powf'?
  240 |     float accuracy_mult = pow10f(accuracy);
      |                           ^~~~~~
      |                           powf
*** [.pioenvs/livingroom_plug_0/src/esphome/components/sensor/filter.cpp.o] Error 1
========================= [FAILED] Took 126.24 seconds =========================
agners commented 3 years ago

The build errors are fixed with https://github.com/esphome/esphome/pull/1897.

ilium007 commented 3 years ago

@agners how do I get this into my local build temporarily until a fixed ESPHome release is available? I am also running ESPHome in a docker container so I'd have to build from dockerfile I am assuming.

agners commented 3 years ago

@ilium007 the PR is merged to dev now, so it will be in 1.20.0. You can get a dev container too to test it out, see: https://esphome.io/guides/faq.html#how-do-i-use-the-latest-bleeding-edge-version

ilium007 commented 3 years ago

Didn't work in 1.20.0-dev for me. DHCP lease still had blank hostname which meant DHCP lease script was unable to set DNS entry.

arduino_version: latest

agners commented 3 years ago

@ilium007 just to be clear, only the build issues have been fixed, not the problem per-se. So you need to add arduino_version: espressif8266@3.0.0 to check if 3.0.0 will fix the problem.

ilium007 commented 3 years ago

Updated esphome to 1.20.0-dev, set arduino_version: espressif8266@3.0.0 and after reboot it still acquires an IP address but sends no hostname. Same issue.

ilium007 commented 3 years ago

Didn't fix the frequent reboots either when configured with DHCP vs static IP.

image

ilium007 commented 3 years ago

On the issue of the ESPHome reboots. I captured this in the serial log. There are a bunch of Disconnecting Home Assistnt messages before the Ftl exception 29(StoreProhibitedCuse) and reboot. This happens every 25mins when the ESP8266 is configured for DHCP.

[VV][scheduler:152]: Running intervl 'updte' with intervl=60000 lst_execution=1350813 (now=1410813)
[V][sensor:023]: 'office-test-0 Uptime': Received new stte 1410.813965
[D][sensor:117]: 'office-test-0 Uptime': Sending stte 1410.81396 s with 0 decimls of ccurcy
[VV][pi.service:105]: send_sensor_stte_response: SensorStteResponse {
                                                                       key: 4215636372
                                                                                        stte: 1410.81
                                                                                                       missing_stte: NO
                                                                                                                       }
[D][pi:067]: Disconnecting Home Assistnt 2021.5.5 (192.168.10.12)
[VV][pi.service:192]: on_hello_request: HelloRequest {
                                                        client_info: 'Home Assistnt 2021.5.5'
                                                                                             }
[V][pi.connection:614]: Hello from client: 'Home Assistnt 2021.5.5 (192.168.10.12)'
[VV][pi.service:012]: send_hello_response: HelloResponse {
                                                            pi_version_mjor: 1
                                                                                pi_version_minor: 5
                                                                                                     server_info: 'office-test-0 (esphome v1.20.0-dev)'
                                                                                                                                                       }
[D][pi:067]: Disconnecting Home Assistnt 2021.5.5 (192.168.10.12)
[VV][pi.service:192]: on_hello_request: HelloRequest {
                                                        client_info: 'Home Assistnt 2021.5.5'
                                                                                             }
[V][pi.connection:614]: Hello from client: 'Home Assistnt 2021.5.5 (192.168.10.12)'
[VV][pi.service:012]: send_hello_response: HelloResponse {
                                                            pi_version_mjor: 1
                                                                                pi_version_minor: 5
                                                                                                     server_info: 'office-test-0 (esphome v1.20.0-dev)'
                                                                                                                                                       }
[D][pi:067]: Disconnecting Home Assistnt 2021.5.5 (192.168.10.12)
[VV][pi.service:192]: on_hello_request: HelloRequest {
                                                        client_info: 'Home Assistnt 2021.5.5'
                                                                                             }
[V][pi.connection:614]: Hello from client: 'Home Assistnt 2021.5.5 (192.168.10.12)'
[VV][pi.service:012]: send_hello_response: HelloResponse {
                                                            pi_version_mjor: 1
                                                                                pi_version_minor: 5
                                                                                                     server_info: 'office-test-0 (esphome v1.20.0-dev)'
                                                                                                                                                       }
[D][pi:067]: Disconnecting Home Assistnt 2021.5.5 (192.168.10.12)
[VV][scheduler:152]: Running intervl 'updte' with intervl=60000 lst_execution=1376900 (now=1436902)
[V][sensor:023]: 'office-test-0 Wifi Signl': Received new stte -59.000000
[D][sensor:117]: 'office-test-0 Wifi Signl': Sending stte -59.00000 dBm with 0 decimls of ccurcy
[VV][pi.service:192]: on_hello_request: HelloRequest {
                                                        client_info: 'Home Assistnt 2021.5.5'
                                                                                             }
[V][pi.connection:614]: Hello from client: 'Home Assistnt 2021.5.5 (192.168.10.12)'
Ftl exception 29(StoreProhibitedCuse):
                                      epc1=0x40227b05, epc2=0x00000000, epc3=0x00000000, excvddr=0x00000004, depc=0x00000000

                                                                                                                            --------------- CUT HERE FOR EXCEPTION DECODER ---------------

Exception (29):
epc1=0x40227b05 epc2=0x00000000 epc3=0x00000000 excvddr=0x00000004 depc=0x00000000

>>>stck>>>

ctx: cont
sp: 3ffffbb0 end: 3fffffc0 offset: 0190
3ffffd40:  3ffffde0 0000004d 00000094 40227b00
3ffffd50:  40100c18 3fff22b4 3fffbf04 40227e21
3ffffd60:  3ffe8bd 0000004d 3ffffe50 40227e78
3ffffd70:  3ffffe10 3ffffe00 00000030 40100680
3ffffd80:  00000006 0000004d 3ffffe50 40227f41
3ffffd90:  3fffbf10 00000023 3ffffdc0 3ffffdb0
3ffffd0:  00000008 0000048e 3fff20d4 3ffe9fd7
3ffffdb0:  3ffffe70 3ffeb67 3ffffe50 40227fb4
3ffffdc0:  3ffe8bd 20200020 00000010 40227f62
3ffffdd0:  3ffffe3c 00000023 3ffffe50 4020290
3ffffde0:  3fff0035 3ffffe00 00000010 3fff3c68
3ffffdf0:  3ffffe10 3ffffe00 00000010 3fff3c68
3ffffe00:  00000001 3fff3c44 3ffffe30 40227b56
3ffffe10:  3ffe87d ff000000 3ffffe70 40227fc8
3ffffe20:  00000019 3fff3c44 3ffffe70 00000003
3ffffe30:  00000019 3ffffe70 3ffffe50 4020630d
3ffffe40:  0c08c0 3fffbe98 3fff3c44 40204c04
3ffffe50:  3fffbf10 3ffffe60 00000010 00000003
3ffffe60:  00000019 4021c868 3fff3c44 40204c6d
3ffffe70:  4021c888 00000001 00000005 3fff3d98
3ffffe80:  00000019 4021c868 3fff3c44 40205638
3ffffe90:  4021c868 3fffbcc0 0000001 00000000
3ffffe0:  4021984 3fffbec8 0000001c 00000002
3ffffeb0:  0000001c 00000019 3fff3c44 40201cb7
3ffffec0:  0000e01 2c9f0300 00000001 00000000
3ffffed0:  0000e01 2c9f0300 00000019 00000000
3ffffee0:  00000001 00000000 3fff26ec 40209fd4
3ffffef0:  3fff2964 3fff1d30 3fff3c44 0015f622
3fffff00:  3fff1d30 3fff1d30 3fff3c44 40201d58
3fffff10:  00000000 00000000 4bc67f0 00000000
3fffff20:  3fff394 00000002 3fff29e4 40205e6
3fffff30:  3fff398 00000002 3fff10c4 4021bd18
3fffff40:  3fff398 00000002 3fff10c4 4021bdd
3fffff50:  3fffdd0 00000002 3fff10c4 4020d079
3fffff60:  0071200 d32df 3fff2c00 3fff2c3c
3fffff70:  3fff29e4 3fff39b0 feefeffe feefeffe
3fffff80:  00000000 00000000 00000001 3fff139c
3fffff90:  3fffdd0 00000000 3fff135c 4020f838
3fffff0:  3fffdd0 00000000 3fff135c 40219880
3fffffb0:  feefeffe feefeffe 3ffe8540 4010137d
<<<stck<<<

lst filed lloc cll: 40227B00(161)

--------------- CUT HERE FOR EXCEPTION DECODER ---------------

 ets Jn  8 2013,rst cuse:2, boot mode:(3,6)

lod 0x4010f000, len 3584, room 16
til 0
chksum 0xb0
csum 0xb0
v28435c
~ld

SDK:2.2.2-dev(38443e)/Core:2.7.3-3-g28435c=20703003/lwIP:STABLE-2_1_2_RELEASE/glue:1.2-30-g92dd50/BerSSL:5c771be
[I][logger:170]: Log initilized
[VV][preferences:038]: LOAD 32: vlid=YES, 0=0x00000000 1=0x0DEFE4E3 (Type=233825507, CRC=0x0DEFE4E3)
[C][ot:366]: There hve been 0 suspected unsuccessful boot ttempts.
[VV][preferences:051]: SAVE 32: 0=0x00000001 1=0x42F4583F (Type=233825507, CRC=0x42F4583F)
[I][pp:029]: Running through setup()...
[V][pp:030]: Sorting components by setup priority...
[VV][scheduler:057]: set_intervl(nme='updte', intervl=60000, offset=25015)
[VV][scheduler:057]: set_intervl(nme='updte', intervl=900000, offset=291713)
[D][text_sensor:015]: 'office-test-0 ESPhome Version': Sending stte '1.20.0-dev Jul 13 2021, 09:21:45'
[C][wifi:037]: Setting up WiFi...
[V][wifi_esp8266:064]: Disbling AP.
bcn 0
     del if1
            usl
               mode : null
                          [VV][preferences:038]: LOAD 0: vlid=NO, 0=0xFFFFFFFF 1=0xFFFFFFFF (Type=1561410642, CRC=0x6DF57F71)
[V][wifi_esp8266:054]: Enbling STA.
mod[V][wifi_esp8266:502]: Event: Chnged Mode old=AP new=OFF
wifi evt: 8
           e : st(f4:cf:2:d7:ec:1e)
                                   dd if0
                                         [V][wifi_esp8266:502]: Event: Chnged Mode old=OFF new=STA
wifi evt: 8
           sleep disble
                       [I][wifi:235]: WiFi Connecting to 'LIBERTY'...
[V][wifi:237]: Connection Prms:
[V][wifi:238]:   SSID: 'LIBERTY'
[V][wifi:243]:   BSSID: Not Set
[V][wifi:261]:   Pssword: 'JneBrntHugh2019'
[V][wifi:268]:   Chnnel: Not Set
[V][wifi:276]:   Using DHCP IP
[V][wifi:278]:   Hidden: NO
[VV][scheduler:152]: Running intervl 'updte' with intervl=900000 lst_execution=4293775702 (now=215)
[VV][scheduler:152]: Running intervl 'updte' with intervl=60000 lst_execution=4294882391 (now=215)
[V][sensor:023]: 'office-test-0 Uptime': Received new stte 0.233000
[D][sensor:117]: 'office-test-0 Uptime': Sending stte 0.23300 s with 0 decimls of ccurcy
[V][wifi_esp8266:461]: Event: Chnged AuthMode old=OPEN new=WPA2 PSK
wifi evt: 2
           scndone
                  stte: 0 -> 2 (b0)
                                   stte: 2 -> 3 (0)
                                                   stte: 3 -> 5 (10)
                                                                    dd 0
                                                                        id 12
                                                                             cnt

                                                                                 connected with LIBERTY, chnnel 1
                                                                                                                 dhcp client strt...
                                                                                                                                    [V][wifi_esp8266:442]: Event: Connected ssid='LIBERTY' bssid=48:8F:5A:11:24:DD chnnel=1
wifi evt: 0
           ip:192.168.10.42,msk:255.255.255.0,gw:192.168.10.1
                                                             [V][wifi_esp8266:476]: Event: Got IP sttic_ip=192.168.10.42 gtewy=192.168.10.1 netmsk=255.255.255.0
wifi evt: 3
           [I][wifi:498]: WiFi Connected!
[C][wifi:344]:   SSID: 'LIBERTY'
[C][wifi:345]:   IP Address: 192.168.10.42
[C][wifi:347]:   BSSID: 48:8F:5A:11:24:DD
                          [VV][preferences:038]: LOAD 0: vlid=NO, 0=0xFFFFFFFF 1=0xFFFFFFFF (Type=1561410642, CRC=0x6DF57F71)
[V][wifi_esp8266:054]: Enbling STA.
mod[V][wifi_esp8266:502]: Event: Chnged Mode old=AP new=OFF
wifi evt: 8
           e : st(f4:cf:2:d7:ec:1e)
                                   dd if0
                                         [V][wifi_esp8266:502]: Event: Chnged Mode old=OFF new=STA
wifi evt: 8
           sleep disble
                       [I][wifi:235]: WiFi Connecting to 'LIBERTY'...
[V][wifi:237]: Connection Prms:
[V][wifi:238]:   SSID: 'LIBERTY'
[V][wifi:243]:   BSSID: Not Set
[V][wifi:261]:   Pssword: 'JneBrntHugh2019'
[V][wifi:268]:   Chnnel: Not Set
[V][wifi:276]:   Using DHCP IP
[V][wifi:278]:   Hidden: NO
[VV][scheduler:152]: Running intervl 'updte' with intervl=900000 lst_execution=4293775702 (now=215)
[VV][scheduler:152]: Running intervl 'updte' with intervl=60000 lst_execution=4294882391 (now=215)
[V][sensor:023]: 'office-test-0 Uptime': Received new stte 0.233000
[D][sensor:117]: 'office-test-0 Uptime': Sending stte 0.23300 s with 0 decimls of ccurcy
[V][wifi_esp8266:461]: Event: Chnged AuthMode old=OPEN new=WPA2 PSK
wifi evt: 2
           scndone
                  stte: 0 -> 2 (b0)
                                   stte: 2 -> 3 (0)
                                                   stte: 3 -> 5 (10)
                                                                    dd 0
                                                                        id 12
                                                                             cnt

                                                                                 connected with LIBERTY, chnnel 1
                                                                                                                 dhcp client strt...
                                                                                                                                    [V][wifi_esp8266:442]: Event: Connected ssid='LIBERTY' bssid=48:8F:5
A:11:24:DD chnnel=1
wifi evt: 0
           ip:192.168.10.42,msk:255.255.255.0,gw:192.168.10.1
                                                             [V][wifi_esp8266:476]: Event: Got IP sttic_ip=192.168.10.42 gtewy=192.168.10.1 netmsk=255.255.255.0
wifi evt: 3
           [I][wifi:498]: WiFi Connected!
[C][wifi:344]:   SSID: 'LIBERTY'
[C][wifi:345]:   IP Address: 192.168.10.42
[C][wifi:347]:   BSSID: 48:8F:5A:11:24:DD
[C][wifi:348]:   Hostnme: 'office-test-0'
[C][wifi:352]:   Signl strength: -57 dB ▂▄▆█
[C][wifi:356]:   Chnnel: 1
[C][wifi:357]:   Subnet: 255.255.255.0
[C][wifi:358]:   Gtewy: 192.168.10.1
[C][wifi:359]:   DNS1: 192.168.10.1
[C][wifi:360]:   DNS2: (IP unset)
[D][wifi:507]: Disbling AP...
[C][ot:029]: Over-The-Air Updtes:
[C][ot:030]:   Address: office-test-0.home:8266
[C][pi:022]: Setting up Home Assistnt API server...
[VV][scheduler:057]: set_intervl(nme='updte', intervl=60000, offset=449)
[I][pp:059]: setup() finished successfully!
ilium007 commented 3 years ago

Evidently exception 29 is 'storeprohibitedcause,' meaning that code tried to write to a protected area in memory.

ilium007 commented 3 years ago

I can't get the ESPExceptionDecoder to decode the stack trace above.

bdgit commented 3 years ago

I'm new to esphome over the last couple days. Looks like I may be troubleshooting the same issue. Here is what I recall.

  1. Installed locally; including esphome extension for vscode.
  2. Created and ran a sequence of firmware/yaml changes to add in components/features. (WiFi, MQTT, Switches, Cover)
  3. So far, DHCP/DNS was promptly getting and updating the hostname as the esphome.name (and then including the wifi.domain)

This is were I started playing to see what I can/can't do. The device has two gpio to toggle a motor left and right. I was playing with mqtt topic settings with good success and attempting to find a way to get rid of 'cover' from position topics. Around this time, I also stumbled upon a 'unique_id' challenge (which I am following another thread on).

Back on point, I am pretty sure this is when I upgraded my PlatformIO platforms in vscode. (I already use pio for other things).

Additionally, I decided to start leveraging substitutions, secrets, and imports. More builds and runs.

Everything was going great!

It was time to install the dashboard on my server in docker. Shared a volume between /config and vscode on my desktop. Switched from local to dashboard validation in vscode.

This is were I found the issue. WiFi upload wouldn't find the device. I confirmed the DHCP/DNS server had a registration, but it was ESP-AABBCC (using the mac address).

Short list of attempted things:

  1. Returned yaml to very basic. No substitutions, secrets, imports, packages, etc.
  2. Cleared all registrations from DHCP/DNS
  3. Added manual ip. (While it allowed for WiFi update, it didn't fix registration)
  4. Upgraded docker dashbard to from release to 1.20.0b2

Tcpdump for DHCP requests shows the device request with the hostname ESP-AABBCC

bdgit commented 3 years ago

With VERBOSE

[17:22:53][C][wifi:037]: Setting up WiFi...
[17:22:53][V][wifi_esp8266:064]: Disabling AP.
[17:22:53]bcn 0
[17:22:53]del if1
[17:22:53]usl
[17:22:53]mode : null
[17:22:53][V][wifi_esp8266:054]: Enabling STA.
[17:22:53]mod[V][wifi_esp8266:502]: Event: Changed Mode old=AP new=OFF
[17:22:53]wifi evt: 8
[17:22:53]e : sta(****MAC****)
[17:22:53]add if0
[17:22:53][V][wifi_esp8266:502]: Event: Changed Mode old=OFF new=STA
[17:22:53]wifi evt: 8
[17:22:53]sleep disable
[17:22:53][I][wifi:250]: WiFi Connecting to '****SSID****'...
[17:22:53][V][wifi:252]: Connection Params:
[17:22:53][V][wifi:253]:   SSID: '****SSID****'
[17:22:53][V][wifi:258]:   BSSID: Not Set
[17:22:53][V][wifi:276]:   Password: '****PWD****'
[17:22:53][V][wifi:283]:   Channel: Not Set
[17:22:53][V][wifi:291]:   Using DHCP IP
[17:22:53][V][wifi:293]:   Hidden: NO
[17:22:53][V][wifi_esp8266:188]: Setting WiFi Hostname failed!
[17:22:53][V][wifi_esp8266:188]: Setting WiFi Hostname failed!
[17:22:54][V][wifi_esp8266:461]: Event: Changed AuthMode old=OPEN new=WPA2 PSK
[17:22:54]wifi evt: 2
[17:22:56]scandone
[17:22:57]state: 0 -> 2 (b0)
[17:22:57]state: 2 -> 3 (0)
[17:22:57]state: 3 -> 5 (10)
[17:22:57]add 0
[17:22:57]aid 12
[17:22:57]cnt
[17:22:57]
[17:22:57]connected with ****SSID****, channel 11
[17:22:57]dhcp client start...
[17:22:57][V][wifi_esp8266:442]: Event: Connected ssid='****SSID****' bssid=****BSSID**** channel=11
[17:22:57]wifi evt: 0
[17:22:58]ip:192.168.1.200,mask:255.255.255.0,gw:192.168.1.1
[17:22:58][V][wifi_esp8266:476]: Event: Got IP static_ip=192.168.1.200 gateway=192.168.1.1 netmask=255.255.255.0
[17:22:58]wifi evt: 3
[17:22:58][I][wifi:513]: WiFi Connected!

Noticed: Setting WiFi Hostname failed!

bdgit commented 3 years ago

I added more LOGV to my local https://github.com/esphome/esphome/blob/dev/esphome/components/wifi/wifi_component_esp8266.cpp

bool WiFiComponent::wifi_apply_hostname_() {
  const std::string &hostname = App.get_name();
  ESP_LOGV(TAG, "App.get_name() is %s", hostname.c_str());
  bool ret = wifi_station_set_hostname(const_cast<char *>(hostname.c_str()));
  if (!ret) {
    ESP_LOGV(TAG, "Setting WiFi Hostname failed!");
  }

  // inform dhcp server of hostname change using dhcp_renew()
  for (netif *intf = netif_list; intf; intf = intf->next) {
    // unconditionally update all known interfaces
#if LWIP_VERSION_MAJOR == 1
    intf->hostname = (char *) wifi_station_get_hostname();
#else
    intf->hostname = wifi_station_get_hostname();
#endif
    if (netif_dhcp_data(intf) != nullptr) {
      ESP_LOGV(TAG, "Attempting DHCP renew [%s] on interface %c%c (index %d)", intf->hostname,
                 intf->name[0], intf->name[1], intf->num);
      // renew already started DHCP leases
      err_t lwipret = dhcp_renew(intf);
      if (lwipret != ERR_OK) {
        ESP_LOGW(TAG, "wifi_apply_hostname_(%s): lwIP error %d on interface %c%c (index %d)", intf->hostname,
                 (int) lwipret, intf->name[0], intf->name[1], intf->num);
        ret = false;
      }
    }
    else {
      ESP_LOGV(TAG, "DHCP data is null [%s] on interface %c%c (index %d)", intf->hostname,
                 intf->name[0], intf->name[1], intf->num);
    }
  }

  return ret;
}

Here are the results

[10:29:11][V][wifi_esp8266:186]: App.get_name() is sx-outdoor-backyard-water-controller
[10:29:11][V][wifi_esp8266:189]: Setting WiFi Hostname failed!
[10:29:11][V][wifi_esp8266:213]: DHCP data is null [ESP-AABBCC] on interface ap (index 1)
[10:29:11][V][wifi_esp8266:213]: DHCP data is null [ESP-AABBCC] on interface st (index 0)
[10:29:11][V][wifi_esp8266:186]: App.get_name() is sx-outdoor-backyard-water-controller
[10:29:11][V][wifi_esp8266:189]: Setting WiFi Hostname failed!
[10:29:11][V][wifi_esp8266:213]: DHCP data is null [ESP-AABBCC] on interface ap (index 1)
[10:29:11][V][wifi_esp8266:213]: DHCP data is null [ESP-AABBCC] on interface st (index 0)

Looks like App has the correct name. Failed update, so seeing the ESP-AABBCC seems expected.

bdgit commented 3 years ago

Found my issue.

Enhancement options to add LOGW message when too long.

bool WiFiComponent::wifi_apply_hostname_() {
  const std::string &hostname = App.get_name();  
  bool ret = wifi_station_set_hostname(const_cast<char *>(hostname.c_str()));
  if (!ret) {
    ESP_LOGV(TAG, "Setting WiFi Hostname failed!");
    if(hostname.length() > 32){
      ESP_LOGW(TAG, "Setting WiFi Hostname failed ('%s' is too long; max 32) (using '%s')", hostname.c_str(), (char *) wifi_station_get_hostname());
    }
  }

Also, noticed potential log message error after applying the above enhancement locally. Testing with value of esphome.name with len 36.

Actual:
[C][wifi:363]:   Hostname: 'sx-outdoor-backyard-water-controller'

Expected:
[C][wifi:363]:   Hostname: 'ESP-AABBCC'

Continued with:

Other related thoughts/questions:

I can work up pull requests based on your comments/thoughts.

ilium007 commented 3 years ago

Glad you found your issue but I don't think this is the same as mine. Mine fails on hostname "office_0".

ilium007 commented 3 years ago

I have done more investigation and packet captures during the DHCP process. The ESP8266 running ESPHome version 1.20.0-dev.

From a cold start (no power applied) the ESP8266 (Adafruit Huzzah breakout) only sends a DHCP DISCOVER packet followed by a DHCP REQUEST packet. The DISCOVER packet has no hostname included. By just sending these two packets the device successfully obtains an IP address.

image

routeros_6_dhcp_esp8266.pcap.zip

This is in contrast to a MacBook Pro connected to the same router where I see the expected DISCOVER, OFFER, REQUEST and ACK packets. The DISCOVER packet from the MacBook Pro does have a hostname field included.

image

routeros_6_dhcp_macbook.pcap.zip

Until this gets resolved I can go no further with ESPHome and designing custom hardware based on the ESP8266 / ESP32.

ilium007 commented 3 years ago

Also, this device has performed at least 5 DHCP renewals whilst Wireshark has been running but nothing showing up in packet capture from its MAC address apart from the original DHCP request. Something is seriously broken with DCHP.

image
agners commented 3 years ago

Mine fails on hostname "office_0".

I don't think that underline is a valid character in a domain name. Can you try without?

based on the ESP8266 / ESP32.

From what I understand this is mostly about ESP8266? ESP32 for sure does work fine here.

ilium007 commented 3 years ago

Mine fails on hostname "office_0".

I don't think that underline is a valid character in a domain name. Can you try without?

based on the ESP8266 / ESP32.

From what I understand this is mostly about ESP8266? ESP32 for sure does work fine here.

You are correct. ESP32 works fine now after latest version. It's only the ESP8266 now with the problem.

ilium007 commented 3 years ago

And yes. I had tried without the underscore, same issue.

agners commented 3 years ago

Updated esphome to 1.20.0-dev, set arduino_version: espressif8266@3.0.0 and after reboot it still acquires an IP address but sends no hostname. Same issue.

Just tried to reproduce your issue, with 3.0.0 the hostname is definitly transferred.

image

ping my-test-host.mytld works.

My config

esphome:
  name: my-test-host
  platform: ESP8266
  board: nodemcuv2
  arduino_version: espressif8266@3.0.0

web_server:
  port: 80

wifi:
  ssid: !secret wifi_iot_ssid
  password: !secret wifi_iot_password

logger:

api:
  password: !secret api_pw

ota:
  password: !secret ota_pw
ilium007 commented 3 years ago

I've tried exactly this but will set up another test this morning and post results.

ilium007 commented 3 years ago

Was this test done using ESPHome 1.20.0 release?

agners commented 3 years ago

1.21.0-dev as of today.

What I realized is that the Host Name option 12 is only provided in the DHCP Request, not in the DHCP Discover packets. For my router (OpenWrt) this seems to be not a problem, name resolution works in this case too. RFC seem not to specify when the options have to be provided.

ilium007 commented 3 years ago

I was going to comment with the same.... I noticed in previous packet captures that the DHCP Discover packets were missing the option 12. Works on my Ubiquiti EdgeRouter but not on Mikrotik RouterOS.

ilium007 commented 3 years ago

Tested with arduino_version: espressif8266@3.0.0, same problem.

image
agners commented 3 years ago

Unfortunately, RFC2132 is unclear in which messages the host name option should be set. The ESP32 seems to send it in both, the DHCPDISCOVER and DHCPREQUEST message. The related FQDN option (which replaces host name for more modern DHCP clients) is defined in RFC4702 does specify that it should be sent in both (...in both their DHCPDISCOVER and DHCPREQUEST messages). So it seems the ESP8266 is a bit on thin ice from a standards perspective and what others are doing.

That said, I also think that Router OS is on thin ice too: It seems weird that a DHCP Server uses the Host Name provided in the DHCPDISCOVER message: At that point, it is not guaranteed that the client actually accepts the address... So I'd expect that a DHCP Server uses the Host Name from the DHCPREQUEST message to update the DNS server information, since this is when the client really accepts the offer... So I'd also ask Router OS why they behave so unconventional (given that Ubiquiti EdgeRouter, OpenWrt and probably many other routers seem to use the Host Name option from the DHCPREQUEST message).

Btw, this behavior also got noticed in issue https://github.com/esp8266/Arduino/issues/5574 specifically in https://github.com/esp8266/Arduino/issues/5574#issuecomment-452108666. But it seem that this particular discrepancy (Host Name option not in DHCPDISCOVER but in DHCPREQUEST) got no further attention.

agners commented 3 years ago

It seems that ESP8266 uses upstream version of LwIP specifically STABLE-2_1_2_RELEASE. In that version dhcp_discover does not set the host name option (see https://git.savannah.nongnu.org/cgit/lwip.git/tree/src/core/ipv4/dhcp.c?h=STABLE-2_1_2_RELEASE#n981).

For ESP32 Espressif uses its own fork of LwIP, and the behavior got changed with this commit: https://github.com/espressif/esp-lwip/commit/13665c14e19dfda6b2ad30c1e5d88e0415cf8b7a

Since the standards are not clear I am not sure if this is a bug in LwIP. From that message seems its neither correct nor incorrect :monocle_face: http://lwip.100.n7.nabble.com/DHCP-discover-skips-hostname-td32513.html

IMHO, following the robustness principle "be conservative in what you send, be liberal in what you accept" I think ideally both should change behavior: LwIP should be conservative and send it in both, and Router OS should be liberal and accept in either one of the message.

ilium007 commented 3 years ago

Haha ok thanks. So essentially this will never be fixed. 👉👈

I've raised a case with Mikrotik.

github-actions[bot] commented 2 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.