search

GammaTroniques / TICMeter

TICMeter is a small product to collect data from a Linky meter and send them to a home automation server via MQTT, Zigbee or HTTP
Other
29 stars 4 forks source link

Failed to process OTA #26

Open ludrao opened 3 days ago

ludrao commented 3 days ago

The problem encountered

While investigating #24 I wanted to update to new latest revision. OTA failed see logs bellow

Firmware version

V3.2.7

Steps for reproducing the error

trigger OTA either with button or command ota-start

What I've already tested

No response

Relevant log output

I (165349) GPIO: OTA available, starting update
I (165891) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 40
I (165893) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 2
I (165894) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 40
I (165895) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 12
I (165895) WIFI: Connecting to Constantinople
I (166463) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 40
I (166603) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 4
I (166604) WIFI: Connected
I (169603) WIFI: GOT EVENT: event_base: IP_EVENT, event_id: 0
I (169604) WIFI: IP:192.168.0.127
I (169704) WIFI: Connected to ap SSID:Constantinople
I (169705) OTA: Trying to get version from https://update.gammatroniques.fr/ticmeter/manifest.json
I (170663) OTA: HTTP Status = 200, content_length = 1150
I (170668) OTA: Current Version: V3.2.7
I (170668) OTA: Latest version: V3.2.8
I (170668) OTA: Target: esp32c6
I (170669) OTA: HW Version: 
I (170669) OTA: APP URL: https://update.gammatroniques.fr/ticmeter/V3.2.8/download/TICMeter.bin
I (170670) OTA: Storage URL: https://update.gammatroniques.fr/ticmeter/V3.2.8/download/storage.bin
I (170670) OTA: MD5: 
I (170671) OTA: Update available
I (170771) OTA: Starting OTA...
I (170771) OTA: Starting download from https://update.gammatroniques.fr/ticmeter/V3.2.8/download/storage.bin
I (170772) OTA: Starting spiffs update
E (170804) esp-tls-mbedtls: mbedtls_ssl_setup returned -0x7F00
E (170804) esp-tls: create_ssl_handle failed
E (170805) esp-tls: Failed to open new connection
E (170805) transport_base: Failed to open a new connection
E (170808) HTTP_CLIENT: Connection failed, sock < 0
E (170808) OTA: HTTP_EVENT_ERROR
E (170809) OTA: HTTP Request Failed
E (170809) OTA: Version size is not correct: 1150 != 65536
I (170810) OTA: Starting download from https://update.gammatroniques.fr/ticmeter/V3.2.8/download/TICMeter.bin
I (170810) OTA: OTA started
E (170843) esp-tls-mbedtls: mbedtls_ssl_setup returned -0x7F00
E (170844) esp-tls: create_ssl_handle failed
E (170844) esp-tls: Failed to open new connection
E (170844) transport_base: Failed to open a new connection
E (170846) HTTP_CLIENT: Connection failed, sock < 0
E (170847) esp_https_ota: Failed to open HTTP connection: UNKNOWN ERROR
E (170847) esp_https_ota: Failed to establish HTTP connection
E (170848) OTA: ESP HTTPS OTA Begin failed
E (170849) OTA: ESP_HTTPS_OTA upgrade failed
I (173852) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 5
I (173852) WIFI: Disconnected from SSID:Constantinople, reason:8, rssi-26
W (173853) WIFI: Retry to connect to the AP: 1/4
I (173854) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 3
I (173854) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 13
ESP-ROM:esp32c6-20220919
Build:Sep 19 2022
xmow49 commented 2 days ago

Hi, Your WiFi signal strength is good where the ticmeter is located ? Here you have a problem durring the downloading. And in the #24 you have also sends errors. I think it could be related.

ludrao commented 2 days ago

I am trying the OTA at my desk with the TICMeter unplugged from the Linky Meter. the device is at less than 2 meters, line of sight from the WiFi Access point, so I would be surprised if this is WiFi signal strengh issue. Another datapoint is that the error/download failure is instantaneous. It would be good to check the return code meaning (I suspect is is in the ESP library?); it feels like an SSL or space error: E (170804) esp-tls-mbedtls: mbedtls_ssl_setup returned -0x7F00 It is happening 100% of the time and very consistantly failing.

Another Note: when I received the TICMeter a week ago, it did the OTA without any issue (to version v3.2.7)

ludrao commented 2 days ago

Hum ok, I did a quick google search this error code seems memory/space related: https://esp32.com/viewtopic.php?t=10030 Another log like that could be of interest:E (170809) OTA: Version size is not correct: 1150 != 65536

ludrao commented 2 days ago

A longer log output with a boot sequence, if that'sh helping: `I (1366) MAIN: MQTT init... I (1463) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 40 I (1465) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 2 I (1466) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 40 I (1467) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 12 I (1467) WIFI: Connecting to Constantinople I (2059) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 40 I (2172) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 4 I (2173) WIFI: Connected I (5172) WIFI: GOT EVENT: event_base: IP_EVENT, event_id: 0 I (5173) WIFI: IP:192.168.0.127 I (5273) WIFI: Connected to ap SSID:Constantinople I (5274) MQTT: init done I (5274) WIFI: Getting time over NTP I (5634) WIFI: The current date/time is: Wed Jul 3 09:40:43 2024 I (5638) OTA: Trying to get version from https://update.gammatroniques.fr/ticmeter/manifest.json I (6633) OTA: HTTP Status = 200, content_length = 1150 I (6638) OTA: Current Version: V3.2.7 I (6638) OTA: Latest version: V3.2.9 I (6638) OTA: Target: esp32c6 I (6639) OTA: HW Version: I (6639) OTA: APP URL: https://update.gammatroniques.fr/ticmeter/V3.2.9/download/TICMeter.bin I (6640) OTA: Storage URL: https://update.gammatroniques.fr/ticmeter/V3.2.9/download/storage.bin I (6641) OTA: MD5: I (6641) OTA: Update available I (7643) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 5 I (7644) WIFI: Disconnected I (7645) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 3 I (7646) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 13 I (7647) MAIN: Starting fetch linky data task I (7648) MAIN: Waiting for 50 seconds I (7648) MAIN: Frame size: 0 I (7648) main_task: Returned from app_main() I (33411) GPIO: Start pushing 32494 I (33711) GPIO: Button pushed for 200 ms I (33711) GPIO: OTA available, starting update I (34255) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 40 I (34256) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 2 I (34258) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 40 I (34258) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 12 I (34259) WIFI: Connecting to Constantinople I (34827) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 40 I (34876) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 4 I (34877) WIFI: Connected I (37876) WIFI: GOT EVENT: event_base: IP_EVENT, event_id: 0 I (37877) WIFI: IP:192.168.0.127 I (37977) WIFI: Connected to ap SSID:Constantinople I (37978) OTA: Trying to get version from https://update.gammatroniques.fr/ticmeter/manifest.json I (38991) OTA: HTTP Status = 200, content_length = 1150 I (38996) OTA: Current Version: V3.2.7 I (38996) OTA: Latest version: V3.2.9 I (38997) OTA: Target: esp32c6 I (38997) OTA: HW Version: I (38997) OTA: APP URL: https://update.gammatroniques.fr/ticmeter/V3.2.9/download/TICMeter.bin I (38998) OTA: Storage URL: https://update.gammatroniques.fr/ticmeter/V3.2.9/download/storage.bin I (38999) OTA: MD5: I (38999) OTA: Update available I (39100) OTA: Starting OTA... I (39100) OTA: Starting download from https://update.gammatroniques.fr/ticmeter/V3.2.9/download/storage.bin I (39101) OTA: Starting spiffs update E (39136) esp-tls-mbedtls: mbedtls_ssl_setup returned -0x7F00 E (39137) esp-tls: create_ssl_handle failed E (39137) esp-tls: Failed to open new connection E (39138) transport_base: Failed to open a new connection E (39140) HTTP_CLIENT: Connection failed, sock < 0 E (39140) OTA: HTTP_EVENT_ERROR E (39140) OTA: HTTP Request Failed E (39141) OTA: Version size is not correct: 1150 != 65536 I (39141) OTA: Starting download from https://update.gammatroniques.fr/ticmeter/V3.2.9/download/TICMeter.bin I (39142) OTA: OTA started E (39178) esp-tls-mbedtls: mbedtls_ssl_setup returned -0x7F00 E (39178) esp-tls: create_ssl_handle failed E (39179) esp-tls: Failed to open new connection E (39179) transport_base: Failed to open a new connection E (39181) HTTP_CLIENT: Connection failed, sock < 0 E (39182) esp_https_ota: Failed to open HTTP connection: UNKNOWN ERROR E (39182) esp_https_ota: Failed to establish HTTP connection E (39183) OTA: ESP HTTPS OTA Begin failed E (39184) OTA: ESP_HTTPS_OTA upgrade failed I (42187) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 5 I (42187) WIFI: Disconnected from SSID:Constantinople, reason:8, rssi-34 W (42188) WIFI: Retry to connect to the AP: 1/4 I (42189) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 3 I (42189) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 13 ESP-ROM:esp32c6-20220919 Build:Sep 19 2022 rst:0xc (SW_CPU),boot:0x6f (SPI_FAST_FLASH_BOOT) Saved PC:0x4001975a SPIWP:0xee mode:DIO, clock div:2 load:0x40875720,len:0x17d8 load:0x4086c410,len:0xe20 load:0x4086e610,len:0x3428 entry 0x4086c41a I (22) boot: ESP-IDF v5.2.1 2nd stage bootloader I (22) boot: compile time Jun 9 2024 11:19:00 I (24) boot: chip revision: v0.0 I (25) boot.esp32c6: SPI Speed : 80MHz I (30) boot.esp32c6: SPI Mode : DIO I (34) boot.esp32c6: SPI Flash Size : 4MB I (39) boot: Enabling RNG early entropy source... I (45) boot: Partition Table: I (48) boot: ## Label Usage Type ST Offset Length I (55) boot: 0 ro_nvs WiFi data 01 02 00009000 00002000 I (63) boot: 1 nvs WiFi data 01 02 0000b000 00004000 I (70) boot: 2 phy_init RF data 01 01 0000f000 00001000 I (78) boot: 3 otadata OTA data 01 00 00010000 00002000 I (85) boot: 4 zb_storage Unknown data 01 81 00012000 00004000 I (93) boot: 5 zb_fct Unknown data 01 81 00016000 00000400 I (100) boot: 6 storage Unknown data 01 82 00017000 00010000 I (108) boot: 7 nvs_key NVS keys 01 04 00027000 00001000 I (115) boot: 8 ota_0 OTA app 00 10 00030000 001db000 I (123) boot: 9 ota_1 OTA app 00 11 00210000 001db000 I (130) boot: End of partition table I (135) esp_image: segment 0: paddr=00210020 vaddr=42150020 size=4b4c0h (308416) map I (250) esp_image: segment 1: paddr=0025b4e8 vaddr=40800000 size=04b30h ( 19248) load I (259) esp_image: segment 2: paddr=00260020 vaddr=42000020 size=14f5a4h (1373604) map I (733) esp_image: segment 3: paddr=003af5cc vaddr=40804b30 size=1d500h (120064) load I (780) esp_image: segment 4: paddr=003ccad4 vaddr=50000000 size=00048h ( 72) load I (793) boot: Loaded app from partition at offset 0x210000 I (794) boot: Disabling RNG early entropy source... I (797) cpu_start: Unicore app W (807) clk: esp_perip_clk_init() has not been implemented yet I (807) cpu_start: Pro cpu start user code I (809) cpu_start: cpu freq: 80000000 Hz I (813) cpu_start: Application information: I (818) cpu_start: Project name: TICMeter I (823) cpu_start: App version: V3.2.7 I (828) cpu_start: Compile time: Jun 19 2024 21:11:35 I (834) cpu_start: ELF file SHA256: a4ebbec04b6a9305... I (840) cpu_start: ESP-IDF: v5.2.1 I (845) cpu_start: Min chip rev: v0.0 I (850) cpu_start: Max chip rev: v0.99 I (855) cpu_start: Chip rev: v0.0 I (859) heap_init: Initializing. RAM available for dynamic allocation: I (867) heap_init: At 4083A580 len 00042090 (264 KiB): RAM I (873) heap_init: At 4087C610 len 00002F54 (11 KiB): RAM I (879) heap_init: At 50000048 len 00003FA0 (15 KiB): RTCRAM I (886) spi_flash: detected chip: generic I (890) spi_flash: flash io: dio I (894) nvs_sec_provider: NVS Encryption - Registering HMAC-based scheme... I (902) sleep: Configure to isolate all GPIO pins in sleep state I (908) sleep: Enable automatic switching of GPIO sleep configuration I (916) sleep_clock: Modem Power, Clock and Reset sleep retention initialization I (916) coexist: coex firmware version: 77cd7f8 I (917) coexist: coexist rom version 5b8dcfa I (917) main_task: Started on CPU0 I (917) main_task: Calling app_main() I (917) MAIN: Starting TICMeter... I (917) pm: Frequency switching config: CPU_MAX: 80, APB_MAX: 80, APB_MIN: 10, Light sleep: ENABLED I (918) POWER: PM initialized I (918) SHELL: Reset reason: software I (919) gpio: GPIO[5]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 I (920) gpio: GPIO[1]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (921) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (922) gpio: GPIO[3]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:4 I (922) gpio: GPIO[1]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 I (923) GPIO: USB already connected I (923) GPIO: VUSB level: 1 I (923) gpio: GPIO[1]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:4 I (924) GPIO: VCondo: 4.002000V I (924) Config: Coding Scheme RS (Reed-Solomon coding) I (925) Config: MAC address: 404CCA545520 I (925) Config: Serial number: TICM32400634 I (925) Config: Hardware version: 3.4.1 I (931) gdma: GDMA pair (0, 0) retention initialization I (1006) nvs: NVS partition "nvs" is encrypted. I (1031) Config: Config read 9 bytes I (1046) Config: Config written 699 bytes I (1065) Config: Config read 9 bytes I (1065) Config: Config OK I (1066) LINKY: Setting mode to STD I (1066) LINKY: Changed mode to STD I (1066) uart: queue free spaces: 64 D (1067) LINKY: UART configured: pins RX:23

Type 'help' to get the list of commands. Use UP/DOWN arrows to navigate through command history. Press TAB when typing command name to auto-complete.

I (1166) MAIN: Config found. Starting... I (1366) MAIN: Linky found I (1366) MAIN: MQTT init... I (1555) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 40 I (1556) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 2 I (1558) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 40 I (1558) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 12 I (1559) WIFI: Connecting to Constantinople I (2126) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 40 I (2177) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 4 I (2178) WIFI: Connected I (5177) WIFI: GOT EVENT: event_base: IP_EVENT, event_id: 0 I (5178) WIFI: IP:192.168.0.127 I (5278) WIFI: Connected to ap SSID:Constantinople I (5279) MQTT: init done I (5279) WIFI: Getting time over NTP I (8273) WIFI: The current date/time is: Wed Jul 3 09:41:28 2024 I (8277) OTA: Trying to get version from https://update.gammatroniques.fr/ticmeter/manifest.json I (9364) OTA: HTTP Status = 200, content_length = 1150 I (9369) OTA: Current Version: V3.2.7 I (9370) OTA: Latest version: V3.2.9 I (9370) OTA: Target: esp32c6 I (9370) OTA: HW Version: I (9371) OTA: APP URL: https://update.gammatroniques.fr/ticmeter/V3.2.9/download/TICMeter.bin I (9371) OTA: Storage URL: https://update.gammatroniques.fr/ticmeter/V3.2.9/download/storage.bin I (9372) OTA: MD5: I (9372) OTA: Update available I (10375) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 5 I (10376) WIFI: Disconnected I (10377) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 3 I (10378) WIFI: GOT EVENT: event_base: WIFI_EVENT, event_id: 13 I (10379) MAIN: Starting fetch linky data task I (10380) MAIN: Waiting for 50 seconds I (10380) MAIN: Frame size: 0 I (10380) main_task: Returned from app_main() I (60381) MAIN: Frame size: 0 I (60382) MAIN: ----------------------------------------------------------------- I (60382) MAIN: Waking up, VCondo: 4.153000 I (60383) LINKY: Mode: STD I (60384) LINKY: Reading frame... I (60384) LINKY: Reading frame: size: 0 remaining: 7000 I (61385) LINKY: Reading frame: size: 0 remaining: 5999 I (62385) LINKY: Reading frame: size: 0 remaining: 4999 I (63385) LINKY: Reading frame: size: 0 remaining: 3999 I (64385) LINKY: Reading frame: size: 0 remaining: 2999 I (65385) LINKY: Reading frame: size: 0 remaining: 1999 I (66385) LINKY: Reading frame: size: 0 remaining: 999 I (67385) LINKY: Decoding frame... size: 0 I (67385) LINKY: No group found E (67485) LINKY: Error: Decode failed E (67485) MAIN: Linky update failed I (67486) MAIN: Waiting for 50 seconds I (67486) MAIN: Frame size: 0 I (117487) MAIN: Frame size: 0 I (117487) MAIN: ----------------------------------------------------------------- I (117488) MAIN: Waking up, VCondo: 4.224000 I (117489) LINKY: Mode: STD I (117489) LINKY: Reading frame... I (117490) LINKY: Reading frame: size: 0 remaining: 7000 I (118490) LINKY: Reading frame: size: 0 remaining: 6000 I (119490) LINKY: Reading frame: size: 0 remaining: 5000 I (120490) LINKY: Reading frame: size: 0 remaining: 4000 I (121490) LINKY: Reading frame: size: 0 remaining: 3000 I (122490) LINKY: Reading frame: size: 0 remaining: 2000 I (123490) LINKY: Reading frame: size: 0 remaining: 1000 I (124490) LINKY: Decoding frame... size: 0 I (124490) LINKY: No group found E (124590) LINKY: Error: Decode failed E (124590) MAIN: Linky update failed I (124591) MAIN: Waiting for 50 seconds I (124591) MAIN: Frame size: 0

`

ludrao commented 2 days ago

Is there a procedure to do a local upgrade using USB? It looks my device will not accept an OTA update

ebretteville commented 2 days ago

My TicMeter is never waving blue. First it was connected in ZigBee, then I tried to associate it in wifi and then I'm back in ZigBee for my personnal usage with HomeAssistant. And no update notified... How can we focre even in USB as suggested by @ludrao via usb?

ludrao commented 2 days ago

There is site maybe: https://update.gammatroniques.fr/ticmeter/, using Chrome or Edge. Unfortunately for me it does not detect the USB link (I am under linux, not sure if it is supposed to work)

ludrao commented 2 days ago

Maybe later today I'll try to reset to factory default and try again OTA to see if I can recover it.

ludrao commented 1 day ago

Update: I finaly was able to OTA. Reset To Factory Default did not help.

To be able to do the ota I switched the ticmeter in HTTP mode and configured the wifi access point. Then I went to the console and typed:

wifi-connect
ota-start

I am now in v3.2.9. However when trying to configure MQTT again I had a crash, I'll open a dedicated bug for that :sweat:

ebretteville commented 1 day ago

Update: I finaly was able to OTA. Reset To Factory Default did not help.

To be able to do the ota I switched the ticmeter in HTTP mode and configured the wifi access point. Then I went to the console and typed:

wifi-connect
ota-start

I am now in v3.2.9. However when trying to configure MQTT again I had a crash, I'll open a dedicated bug for that :sweat:

How did you managed to go into console mode?

ludrao commented 1 day ago

Connect to the serial port. On Linux I have a ttyACM0 device that is created when I plug the TICmeter into USB. On Windows it might require a specific driver.

ebretteville commented 1 day ago

I did update (install through chrome on macos) but how can I check the current version? In ZHA I see this Screenshot_20240703_210618.jpg

ebretteville commented 16 hours ago

Screenshot_20240704_230930.jpg

There is a problem has it doesn't detect the latest available version