search

esphome / issues

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

Nodemcu OTA not working #156

Closed infestdead closed 5 years ago

infestdead commented 5 years ago

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

Fedora 29 installed via pip following documentation, Version: 1.12.1. ESP (ESP32/ESP8266, Board/Sonoff): EPS8266 (amica nodemcu)

Affected component:

OTA

Description of problem: I can flash esphome no problem via USB, but OTA updates after that simply don't work, I've tried 4 different (same batch) nodemcu boards that I have. all fail the same way.

Problem-relevant YAML-configuration entries:

esphome:
  name: livingroom_ths
  platform: ESP8266
  board: nodemcuv2

wifi:
  ssid: "REDACTED"
  password: "REDACTED"
  manual_ip:
    static_ip: 192.168.1.151
    gateway: 192.168.1.1
    subnet: 255.255.255.0

sensor:
  - platform: dht
    pin: D2
    temperature:
      name: "Living Room Temperature"
    humidity:
      name: "Living Room Humidity"
    update_interval: 30s
    model: DHT22
  - platform: wifi_signal
    name: "Kitchen WiFi Signal"
    update_interval: 60s

# Enable logging
logger:

# Enable Home Assistant API
api:

ota:

Additional information and things you've tried: After a reboot of the board, the first error when I try to update over OTA is:

Uploading: [=                                                           ] 2% 
ERROR Error sending data: timed out

then if I retry I get

INFO Uploading livingroom_ths/.pioenvs/livingroom_ths/firmware.bin (332944 bytes)
DEBUG MD5 of binary is 0c42f7e3876851f9c4cc96f572853586
ERROR Error binary size: Error: Couldn't prepare flash memory for update. Is the binary too big? Please try restarting the ESP.

I've also attached the full output of esphome -v livingroom_ths.yaml run both runs after reboot of the nodemcu board.

1st_run.txt 2nd_run.txt

Viewing logs with esphome over wifi works, sensors work (send data to HA) etc - only OTA updates don't seem to work.

OttoWinter commented 5 years ago

What do you see when viewing the logs over WiFi while running the update?

infestdead commented 5 years ago

There you go, that's the relevant part (192.168.1.10 is my PC, 1902.168.1.151 is the Nodemcu board):

[22:35:35][D][sensor.dht:066]: Got Temperature=21.5°C Humidity=40.7%
[22:35:36][D][ota:179]: Starting OTA Update from 192.168.1.10...
[22:35:37][D][ota:353]: OTA in progress: 0.2%
[22:35:39][D][ota:353]: OTA in progress: 0.5%
[22:35:40][D][ota:353]: OTA in progress: 0.6%
[22:35:44][D][ota:353]: OTA in progress: 0.8%
WARNING Disconnected from API.
INFO Connecting to 192.168.1.151:6053 (192.168.1.151)
WARNING Couldn't connect to API (Timeout while waiting for message response!). Trying to reconnect in 1 seconds
WARNING Disconnected from API.
INFO Connecting to 192.168.1.151:6053 (192.168.1.151)
WARNING Couldn't connect to API (Timeout while waiting for message response!). Trying to reconnect in 2 seconds
WARNING Disconnected from API.
INFO Connecting to 192.168.1.151:6053 (192.168.1.151)
WARNING Couldn't connect to API (Timeout while waiting for message response!). Trying to reconnect in 4 seconds
WARNING Disconnected from API.
INFO Connecting to 192.168.1.151:6053 (192.168.1.151)
INFO Successfully connected to 192.168.1.151
[22:36:05][D][sensor.dht:066]: Got Temperature=21.5°C Humidity=40.7%
BertrumUK commented 5 years ago

I am seeing the same on my NodeMCU. Flashed an ESP01, Wemos D1 Mini and a NodeMCU via OTA yesterday after the latest update and only the NodeMCU is disconnecting every few minutes even though it can still be pinged.

I am only using it as a trial power meter pulse monitor so just reflashed OTA using the Wemos config 

esphome:
  name: esphome_nodemcu
  platform: ESP8266
  #board: nodemcuv2
  board: d1_mini

Currently it is looking more stable using the Wemos board config than the NodeMCU config.

Spoke too soon - it has just gone offline as well 👎

OttoWinter commented 5 years ago

@BertrumUK That is a different issue, this issue is about the ESP disconnecting while OTA is running. Please see the other issues. Also, board cannot fix any of that, it only changes pin aliases and board size.

BertrumUK commented 5 years ago

@BertrumUK That is a different issue, this issue is about the ESP disconnecting while OTA is running. Please see the other issues. Also, board cannot fix any of that, it only changes pin aliases and board size.

OK - thanks

infestdead commented 5 years ago

A small update from me, I tried this on latest Fedora, latest Debian and also via docker. Same results everywhere. Also no difference in output via cli and dashboard. Any idea what I can try to debug this further?

OttoWinter commented 5 years ago

Any idea what I can try to debug this further? USB logs on the device while it's uploading OTA.

infestdead commented 5 years ago

Here are the logs on the nodemcu via USB while the OTA is ongoing

INFO Reading configuration...
Found multiple options, please choose one:
  [1] /dev/ttyUSB0 (CP2102 USB to UART Bridge Controller)
  [2] Over The Air (192.168.1.152)
(number): 1
INFO Starting log output from /dev/ttyUSB0 with baud rate 115200
[23:36:34][D][sensor.dht:066]: Got Temperature=21.5°C Humidity=39.0%
[23:36:45][D][ota:179]: Starting OTA Update from 192.168.1.10...
[23:36:46][D][ota:353]: OTA in progress: 0.2%
[23:36:47][D][ota:353]: OTA in progress: 0.5%
[23:36:49][D][ota:353]: OTA in progress: 0.6%
[23:36:52][D][ota:353]: OTA in progress: 0.8%
[23:36:59][D][ota:353]: OTA in progress: 0.9%
[23:37:09][W][ota:420]: Timeout waiting for data!
[23:37:09][W][ota:386]: Update end failed! Error: ERROR[0]: No Error
[23:37:09]
[23:37:09][D][sensor.dht:066]: Got Temperature=21.4°C Humidity=37.9%
[23:37:09][D][api:073]: Disconnecting Home Assistant 0.90.0 (192.168.1.220)
[23:37:09][D][api:546]: Client 'Home Assistant 0.90.0 (192.168.1.220)' connected successfully
[23:37:34][D][sensor.dht:066]: Got Temperature=21.3°C Humidity=38.3%
[23:37:39][I][ota:152]: Boot seems successful, resetting boot loop counter.

and here are the logs from the console that the OTA is launched

[root@home config]# esphome livingroom_ths.yaml run
INFO Reading configuration...
INFO Generating C++ source...
INFO Compiling app...
INFO Running:  platformio run -d livingroom_ths
Processing livingroom_ths (platform: espressif8266@1.8.0; framework: arduino; board: nodemcuv2)
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Verbose mode can be enabled via `-v, --verbose` option
CONFIGURATION: https://docs.platformio.org/page/boards/espressif8266/nodemcuv2.html
PLATFORM: Espressif 8266 > NodeMCU 1.0 (ESP-12E Module)
HARDWARE: ESP8266 80MHz 80KB RAM (4MB Flash)
Library Dependency Finder -> http://bit.ly/configure-pio-ldf
LDF MODES: FINDER(chain) COMPATIBILITY(soft)
Collected 27 compatible libraries
Scanning dependencies...
Dependency Graph
|-- <ESP8266WiFi> 1.0
|-- <ESP8266mDNS>
|   |-- <ESP8266WiFi> 1.0
|-- <ESPAsyncTCP> 1.1.3
|   |-- <ESP8266WiFi> 1.0
|-- <Hash> 1.0
|-- <esphome-core> 1.12.1
|   |-- <ArduinoJson-esphomelib> 5.13.3
|   |-- <ESP8266mDNS>
|   |   |-- <ESP8266WiFi> 1.0
|   |-- <ESP8266WiFi> 1.0
|   |-- <ESPAsyncTCP> 1.1.3
|   |   |-- <ESP8266WiFi> 1.0
Retrieving maximum program size .pioenvs/livingroom_ths/firmware.elf
Checking size .pioenvs/livingroom_ths/firmware.elf
Memory Usage -> http://bit.ly/pio-memory-usage
DATA:    [====      ]  38.5% (used 31544 bytes from 81920 bytes)
PROGRAM: [===       ]  31.6% (used 329720 bytes from 1044464 bytes)
================================================================================ [SUCCESS] Took 3.09 seconds ================================================================================
INFO Successfully compiled program.
Found multiple options, please choose one:
  [1] /dev/ttyUSB0 (CP2102 USB to UART Bridge Controller)
  [2] Over The Air (192.168.1.152)
(number): 2
INFO Connecting to 192.168.1.152
INFO Uploading livingroom_ths/.pioenvs/livingroom_ths/firmware.bin (333872 bytes)
Uploading: [=                                                           ] 2% 
ERROR Error sending data: timed out
[root@home config]#
brandond commented 5 years ago

[23:36:46][D][ota:353]: OTA in progress: 0.2% [23:36:47][D][ota:353]: OTA in progress: 0.5% [23:36:49][D][ota:353]: OTA in progress: 0.6% [23:36:52][D][ota:353]: OTA in progress: 0.8% [23:36:59][D][ota:353]: OTA in progress: 0.9% [23:37:09][W][ota:420]: Timeout waiting for data!

This is an incredibly slow OTA - mine never take more than a few seconds to get to 100% while you've not even made it to 1% after 15 seconds. I'm not surprised it timed out. How poor is your wifi coverage where this device is located?

infestdead commented 5 years ago

It's half meter away from the router, it's a wrt3200acm router, 5ghz, 2.5ghz, all do their max speeds easily, no saturation, no channel overlap. All other devices on the network work great. It really doesn't seem like a network issue, or if it is - it's a bug. Ping is ~2ms, no packet loss, no drops, I also used the WIfi sensor module to measure the signal strength - it's -42 dB.

brandond commented 5 years ago

Something's clearly wrong with it, there's no reason for this behavior other than something at the wifi level. Is there anything on the network between the host sending the OTA and the device? Have you tried moving it to another location? How does the client signal quality look on the router side?

infestdead commented 5 years ago

I'll test on some other wifi routers today, I have ubiquiti at work and some old tp-links in the closet. What you're saying makes sense, signals look good at all sides, but could be some type of QoS or similar crap doing this.

infestdead commented 5 years ago

OK so it really was an issue with my router. I tried with WiFi hotstpot on my phone - works as expected, UniFi in the office - works as expected, old tplink from the drawer - works as expected. Disabled some stupid linksys QoS which was on by default - and now at home works as expected. :)

update.. OK so after some further testing, the culprit was not the QoS (Meidia prioritization) but - setting the 2.4Ghz band to mixed mode (802.11g+802.11n), if I set it to 802.11g it works as expected.

smurf12345 commented 5 years ago

update.. OK so after some further testing, the culprit was not the QoS (Meidia prioritization) but - setting the 2.4Ghz band to mixed mode (802.11g+802.11n), if I set it to 802.11g it works as expected.

Thank you! This worked for me as well. I disabled 802.11n on my Cisco WLC and instead of failing at 2-12% it zoomed right though the OTA push. I wonder what is isn't liking about 802.11n.

thiemok commented 5 years ago

Can this be reopened? I'm seeing the same issue with my cheap Wemos D1 mini. However I cant and to be honest don't want to downgrade my wifi to make ota work. My current esphome version is 1.12.2