search

esphome / issues

Issue Tracker for ESPHome
https://esphome.io/
293 stars 36 forks source link

Unhandled C++ exception: OOM when using the SML component #4642

Open Santobert opened 1 year ago

Santobert commented 1 year ago

The problem

An unhandled C++ exception occurs when using the SML component.

I have connected the Hichi ir reading head via UART to a NodeMCU v3 board and then to my Apator Picus power meter. The error occurs exactly when the reading head is connected to the power meter. After that the NodeMCU restarts, reads some values and crashes again, in a loop.

If ESPHome is configured to read only one or two values instead of all of them, the loop time increases, but eventually it crashes again.

For debugging purposes, I used software UARTs, but the problem also occurs with hardware UARTs.

This is the reading head: https://www.ebay.com/itm/313460034498

The setup works with Tasmota, so I expect my hardware to be functional.

Which version of ESPHome has the issue?

2023.6.3

What type of installation are you using?

pip

Which version of Home Assistant has the issue?

No response

What platform are you using?

ESP8266

Board

NodeMCU V3

Component causing the issue

SML (Smart Message Language)

Example YAML snippet

esphome:
  name: power-meter
  friendly_name: Power Meter

esp8266:
  board: nodemcuv2

# Enable logging
logger:
  # baud_rate: 0

# Enable Home Assistant API
api:
  encryption:
    key: ""

ota:
  password: ""

wifi:
  ssid: ""
  password: ""

  # Enable fallback hotspot (captive portal) in case wifi connection fails
  ap:
    ssid: "Power-Meter Fallback Hotspot"
    password: ""

#captive_portal:

# Sync time with Home Assistant
time:
  - platform: homeassistant
    id: homeassistant_time

# UART SML
uart:
  id: uart_bus
  tx_pin: D1
  rx_pin: D2
  rx_buffer_size: 2048
  baud_rate: 9600
  data_bits: 8
  parity: NONE
  stop_bits: 1

sml:
  id: sml_id
  uart_id: uart_bus

# Text sensors with general information
text_sensor:
  # Expose ESPHome version as sensor
  - platform: version
    name: Power Meter ESPHome Version
  # Expose WiFi information as sensors
  - platform: wifi_info
    ip_address:
      name: Power Meter IP
    ssid:
      name: Power Meter SSID
    mac_address:
      name: Power Meter MAC

  # SML
  - platform: sml
    name: "Manufacturer"
    sml_id: sml_id
    obis_code: "1-0:96.50.1"
    format: text
  #- platform: sml
  #  name: "Device"
  #  sml_id: sml_id
  #  obis_code: "1-0:96.1.0"
  #  format: text
  - platform: sml
    name: "Firmware"
    sml_id: sml_id
    obis_code: "1-0:0.2.0"
    format: text

# Sensors with general information.
sensor:
  # Uptime sensor.
  - platform: uptime
    name: Power Meter Uptime

  # WiFi Signal sensor.
  - platform: wifi_signal
    name: Power Meter WiFi Signal
    update_interval: 60s

  # SML
  - platform: sml
    name: "Total incoming"
    sml_id: sml_id
    obis_code: "1-0:1.8.0"
    unit_of_measurement: kWh
    device_class: energy
    state_class: total_increasing
    filters:
      - multiply: 0.0001
  - platform: sml
    name: "Total outgoing"
    sml_id: sml_id
    obis_code: "1-0:2.8.0"
    unit_of_measurement: kWh
    device_class: energy
    state_class: total_increasing
    filters:
      - multiply: 0.0001
  - platform: sml
    name: "Instantaneous Power"
    sml_id: sml_id
    obis_code: "1-0:16.7.0"
    unit_of_measurement: W
    device_class: power
  - platform: sml
    name: "Frequency"
    sml_id: sml_id
    obis_code: "1-0:14.7.0"
    unit_of_measurement: Hz
    device_class: frequency

  - platform: sml
    name: "Instantaneous Power L1"
    sml_id: sml_id
    obis_code: "1-0:36.7.0"
    unit_of_measurement: kW
    device_class: power
  - platform: sml
    name: "Instantaneous Power L2"
    sml_id: sml_id
    obis_code: "1-0:56.7.0"
    unit_of_measurement: kW
    device_class: power
  - platform: sml
    name: "Instantaneous Power L3"
    sml_id: sml_id
    obis_code: "1-0:76.7.0"
    unit_of_measurement: kW
    device_class: power

  - platform: sml
    name: "Instantaneous Voltage L1"
    sml_id: sml_id
    obis_code: "1-0:32.7.0"
    unit_of_measurement: V
    device_class: voltage
  - platform: sml
    name: "Instantaneous Voltage L2"
    sml_id: sml_id
    obis_code: "1-0:52.7.0"
    unit_of_measurement: V
    device_class: voltage
  - platform: sml
    name: "Instantaneous Voltage L3"
    sml_id: sml_id
    obis_code: "1-0:72.7.0"
    unit_of_measurement: V
    device_class: voltage

  - platform: sml
    name: "Instantaneous Current L1"
    sml_id: sml_id
    obis_code: "1-0:31.7.0"
    unit_of_measurement: A
    device_class: current
  - platform: sml
    name: "Instantaneous Current L2"
    sml_id: sml_id
    obis_code: "1-0:51.7.0"
    unit_of_measurement: A
    device_class: current
  - platform: sml
    name: "Instantaneous Current L3"
    sml_id: sml_id
    obis_code: "1-0:71.7.0"
    unit_of_measurement: A
    device_class: current

Anything in the logs that might be useful for us?

[21:01:47]
[21:01:47]User exception (panic/abort/assert)
[21:01:47]--------------- CUT HERE FOR EXCEPTION DECODER ---------------
[21:01:47]
[21:01:47]Unhandled C++ exception: OOM
[21:01:47]
[21:01:47]>>>stack>>>
WARNING Found stack trace! Trying to decode it
[21:01:47]
[21:01:47]ctx: cont
[21:01:47]sp: 3ffffd70 end: 3fffffc0 offset: 0000
[21:01:47]3ffffd70:  3fffbc1c 00000000 3ffffdc0 3fffa398  
[21:01:47]3ffffd80:  000000fe 00000000 00000000 00000000  
[21:01:47]3ffffd90:  00000000 00000000 00000000 00000001  
[21:01:47]3ffffda0:  00007fff 00000000 3fffbaf4 3ffffedc  
[21:01:47]3ffffdb0:  00000000 402141ee 00000700 40225a46  
WARNING Decoded 0x402141ee: void std::vector<esphome::sml::ObisInfo, std::allocator<esphome::sml::ObisInfo> >::_M_realloc_insert<std::vector<unsigned char, std::allocator<unsigned char> >&, esphome::sml::SmlNode const&>(__gnu_cxx::__normal_iterator<esphome::sml::ObisInfo*, std::vector<esphome::sml::ObisInfo, std::allocator<esphome::sml::ObisInfo> > >, std::vector<unsigned char, std::allocator<unsigned char> >&, esphome::sml::SmlNode const&)
WARNING Decoded 0x40225a46: raise_exception at core_esp8266_postmortem.cpp
[21:01:47]3ffffdc0:  00000000 402141ee 00000020 40225a65  
WARNING Decoded 0x402141ee: void std::vector<esphome::sml::ObisInfo, std::allocator<esphome::sml::ObisInfo> >::_M_realloc_insert<std::vector<unsigned char, std::allocator<unsigned char> >&, esphome::sml::SmlNode const&>(__gnu_cxx::__normal_iterator<esphome::sml::ObisInfo*, std::vector<esphome::sml::ObisInfo, std::allocator<esphome::sml::ObisInfo> > >, std::vector<unsigned char, std::allocator<unsigned char> >&, esphome::sml::SmlNode const&)
WARNING Decoded 0x40225a65: __unhandled_exception
[21:01:47]3ffffdd0:  3fffbbb8 3fffbb9c 00000700 40225270  
WARNING Decoded 0x40225270: operator new(unsigned int)
[21:01:47]3ffffde0:  3fffa2f0 3fffbf9c 00000020 402141ee  
WARNING Decoded 0x402141ee: void std::vector<esphome::sml::ObisInfo, std::allocator<esphome::sml::ObisInfo> >::_M_realloc_insert<std::vector<unsigned char, std::allocator<unsigned char> >&, esphome::sml::SmlNode const&>(__gnu_cxx::__normal_iterator<esphome::sml::ObisInfo*, std::vector<esphome::sml::ObisInfo, std::allocator<esphome::sml::ObisInfo> > >, std::vector<unsigned char, std::allocator<unsigned char> >&, esphome::sml::SmlNode const&)
[21:01:47]3ffffdf0:  3fffbf9c 00000380 3ffffe84 3fffa30c  
[21:01:47]3ffffe00:  3fffbc1c 3fffbbb8 3fffbbb8 00000000  
[21:01:47]3ffffe10:  00000000 00000000 3ffffe84 3fffa398  
[21:01:47]3ffffe20:  3fffa30c 3ffffedc 3fff4ca8 402142e0  
WARNING Decoded 0x402142e0: esphome::sml::SmlFile::get_obis_info()
[21:01:47]3ffffe30:  3fff5407 00000000 00000000 00000000  
[21:01:47]3ffffe40:  3fffa14c 3fffa398 3fffa398 40101107  
WARNING Decoded 0x40101107: umm_init
[21:01:47]3ffffe50:  00000000 00000000 00000000 3fff835c  
[21:01:47]3ffffe60:  3fff8420 3fff8420 3fff4507 00000000  
[21:01:47]3ffffe70:  00000000 00000000 3fff544c 3fff5484  
[21:01:47]3ffffe80:  3fff5484 3fffa13c 3fffa146 3fffa146  
[21:01:47]3ffffe90:  3fff4cc4 00000000 00000000 00000000  
[21:01:47]3ffffea0:  3fff45a4 3fff464c 3fff464c 3fff157c  
[21:01:47]3ffffeb0:  3fff15a0 3fff157c 0000027c 402139a4  
WARNING Decoded 0x402139a4: esphome::sml::Sml::process_sml_file_(std::vector<unsigned char, std::allocator<unsigned char> > const&)
[21:01:47]3ffffec0:  3fff4c8c 3fff4cc4 3fff4cc4 3fff4a0c  
[21:01:47]3ffffed0:  3fff4c88 3fff4c88 00000264 3fffbc1c  
[21:01:47]3ffffee0:  3fffbf9c 3fffbf9c 122d0e56 3fff157c  
[21:01:47]3ffffef0:  3fff4f9f 3fff15a0 3fff4f98 40213c4b  
WARNING Decoded 0x40213c4b: esphome::sml::Sml::loop()
[21:01:47]3fffff00:  3fff32c7 40218af4 40100805 00000000  
WARNING Decoded 0x40218af4: esphome::wifi::WiFiComponent::wifi_sta_connect_status_()
WARNING Decoded 0x40100805: millis
[21:01:47]3fffff10:  0000be7b 00000000 3fff1114 402166c7  
WARNING Decoded 0x402166c7: esphome::wifi::WiFiComponent::is_connected()
[21:01:47]3fffff20:  0000be6a 3fff0060 3fff1114 3fff157c  
[21:01:47]3fffff30:  3fff3cf8 00000002 3ffefbe4 402281c0  
WARNING Decoded 0x402281c0: esphome::Component::call_loop()
[21:01:47]3fffff40:  3fff3d01 00000010 3ffefbe4 4022828c  
WARNING Decoded 0x4022828c: esphome::Component::call()
[21:01:47]3fffff50:  3fffdad0 00000002 3ffefbe4 40219a02  
WARNING Decoded 0x40219a02: esphome::Application::loop()
[21:01:47]3fffff60:  0000be7b 3fff157c 3fffff00 00000001  
[21:01:47]3fffff70:  3fff3d08 feefeffe feefeffe feefeffe  
[21:01:47]3fffff80:  00000000 00000000 00000001 3ffefff8  
[21:01:47]3fffff90:  3fffdad0 00000000 3ffeffe4 4021c518  
WARNING Decoded 0x4021c518: loop
[21:01:47]3fffffa0:  3fffdad0 00000000 3ffeffe4 40225588  
WARNING Decoded 0x40225588: loop_wrapper() at core_esp8266_main.cpp
[21:01:47]3fffffb0:  feefeffe feefeffe 3ffe8678 4010064d  
WARNING Decoded 0x4010064d: cont_wrapper
[21:01:47]<<<stack<<<
[21:01:47]
[21:01:47]last failed alloc call: 402141EE(1792)
WARNING Memory allocation of 1792 bytes failed at 402141EE
WARNING Decoded 0x402141ee: void std::vector<esphome::sml::ObisInfo, std::allocator<esphome::sml::ObisInfo> >::_M_realloc_insert<std::vector<unsigned char, std::allocator<unsigned char> >&, esphome::sml::SmlNode const&>(__gnu_cxx::__normal_iterator<esphome::sml::ObisInfo*, std::vector<esphome::sml::ObisInfo, std::allocator<esphome::sml::ObisInfo> > >, std::vector<unsigned char, std::allocator<unsigned char> >&, esphome::sml::SmlNode const&)
[21:01:47]
[21:01:47]--------------- CUT HERE FOR EXCEPTION DECODER ---------------
[21:01:47]
[21:01:47]last failed alloc caller: 0x402141ee
[21:01:47]
[21:01:47] ets Jan  8 2013,rst cause:2, boot mode:(3,6)
[21:01:47]
[21:01:47]load 0x4010f000, len 3460, room 16 
[21:01:47]tail 4
[21:01:47]chksum 0xcc
[21:01:47]load 0x3fff20b8, len 40, room 4 
[21:01:47]tail 4
[21:01:47]chksum 0xc9
[21:01:47]csum 0xc9
[21:01:47]v00073f70
[21:01:47]~ld

Additional information

Related issue

https://community.home-assistant.io/t/esp8266-crashes-when-receiving-sml-data/564514

OBIS info

[21:01:52][D][sml:065]: OBIS info:
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:96.50.1 [0x415041]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:96.1.0 [0x0a014150410100e5b85f]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:1.8.0 [0x000000000001d942]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:2.8.0 [0x0000000000201df5]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:16.7.0 [0x000000000000002e]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:36.7.0 [0x0000000000000019]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:56.7.0 [0x000000000000001a]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:76.7.0 [0xfffffffffffffffb]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:32.7.0 [0x00000000000008fe]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:52.7.0 [0x0000000000000901]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:72.7.0 [0x0000000000000903]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:31.7.0 [0x000000000000009b]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:51.7.0 [0x0000000000000099]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:71.7.0 [0x000000000000006f]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:81.7.1 [0x0000000000000076]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:81.7.2 [0x00000000000000ed]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:81.7.4 [0x0000000000000112]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:81.7.15 [0x0000000000000112]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:81.7.26 [0x000000000000010c]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:14.7.0 [0x00000000000001f3]
[21:01:52][D][sml:071]:   (0a014150410100e5b85f) 1-0:0.2.0 [0x31303030]
Santobert commented 1 year ago

Hi @alengwenus! I'm sorry to ping you directly, but I'm afraid this issue will be buried in oblivion otherwise. Can you please take a look at this issue and help me resolve it?

kr0ner commented 1 year ago

Hi @Santobert , I think the SML implementation on the Apator Picus is completely broken. I stumbled across this while trying to implement a C++17 SML parser and got random errors. They sometimes use 7 Byte for 64-bit integer and sometimes 8 byte. Also for other integer types they sometimes drop bytes. According to the standard this is somehow ok, in case leading zeroes/0xFFs are dropped. However the length field still tells you to read 8 bytes 🤷 

0x77,
    0x07, 0x01, 0x00, 0x01, 0x08, 0x00, 0xff,
    0x65, 0x00, 0x1c, 0x01, 0x04,
    0x01,
    0x62, 0x1e,
    0x52, 0xff,
    0x69, 0x00, 0x00, 0x00, 0x00, 0x00, 0x05, 0x8a, 0x36, <-- 8 Byte
    0x01,
0x77, 
    0x07, 0x01, 0x00, 0x02, 0x08, 0x00, 0xff,
    0x01,
    0x01,
    0x62, 0x1e,
    0x52, 0xff,
    0x69, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x8e, <- 7 Byte
    0x01,

IMHO it should say 0x68 in the 2nd case to allow proper parsing. Or how are we supposed to distinguish between

0x69, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x8e, 0x01

and

0x69, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x8e,
0x01

The only thing that comes to my mind would be some kind of look-ahead mechanism, in order to see how many bytes are left till the next list entry. But that s*cks

kr0ner commented 1 year ago

ESPHome impl does not handle this (properly? or gracefully?). But I might be wrong. Just had a quick look

Santobert commented 1 year ago

Tasmota seems to be more reliable on this part. Maybe it's worth a look how this is handled there.

Personally, I'd prefer to use esphome rather than tasmota.

Santobert commented 1 year ago

I just tested the SMLReader from mruettgers. It works well too. The code doesn't seem too complex. Maybe someone with a little more understanding than I have can pick something up there?

https://github.com/mruettgers/SMLReader

kr0ner commented 1 year ago

It's just a layer on top of https://github.com/volkszaehler/libsml

kr0ner commented 1 year ago

Do you see any output? Does it simply ignore the messages that have fields where bytes are dropped? Or is it able to actually detect that and still parse the data?

Santobert commented 1 year ago

There was at least some output. I can't tell whether or not some messages were dropped, but every value that the documentation said should be sent was sent at least once and then updated more or less regularly.

Santobert commented 1 year ago

Small update: I have been using SMLRecords for over a week now and it is as stable as it can be. The values are transmitted regularly, seemingly without records being dropped.

semicuda commented 1 year ago

I'm having the same issue, here's a log with UART Debug if that helps. Oddly, I have two Easymeter Q3A. On one, it works perfectly fine. On the other (which is outputting 2 tariffs) it doesnt.

[W][ota:107]: Last Boot was an unhandled reset, will proceed to safe mode in 8 restarts
[C][api:139]: API Server:
[C][api:140]:   Address: testzaehler.local:6053
[C][api:142]:   Using noise encryption: YES
[D][uart_debug:114]: <<< 1B:1B:1B:1B:01:01:01:01:76:0B:45:53:59:41:FB:96:01:6F:FE:49:62:00:62:00:72:63:01:01:76:01:04:45:53:59:08:45:53:59:AA:B8:FE:49:0B:09:01:45:53:59:11:03:B3:FB:96:01:01:63:0B:6E:00:76:0B:45:53:59:41:FB:96:01:6F:FE:4A:62:00:62:00:72:63:07:01:77:01:0B:09:01:45:53:59:11:03:B3:FB:96:07:01:00:62:0A:FF:FF:72:62:01:65:00:7A:AA:B8:F1:00:77:07:81:81:C7:82:03:FF:01:01:01
[D][uart_debug:114]: <<< 01:04:45:53:59:01:77:07:01:00:00:00:09:FF:01:01:01:01:0B:09:01:45:53:59:11:03:B3:FB:96:01:77:07:01:00:01:08:00:FF:64:00:02:80:01:62:1E:52:FC:59:00:00:00:01:D1:BD:FE:65:01:77:07:01:00:02:08:00:FF:64:00:02:80:01:62:1E:52:FC:59:00:00:00:00:00:1B:55:55:01:77:07:01:00:01:08:01:FF:01:01:62:1E:52:FC:59:00:00:00:00:9A:A8:6C:66:01:77:07:01:00:01:08:02:FF:01:01:62:1E:52:FC:59:00:00:00:01:37:15:91:FF:01:77:07:01:00:10:07:00:FF:01:01:62:1B:52:FE:59:00:00:00
[W][component:214]: Component sml took a long time for an operation (0.06 s).
[W][component:215]: Components should block for at most 20-30ms.
[D][uart_debug:114]: <<< 00:00:00:94:32:01:77:07:01:00:24:07:00:FF:01:01:62:1B:52:FE:59:00:00:00:00:00:00:82:A5:01:77:07:01:00:38:07:00:FF:01:01:62:1B:52:FE:59:00:00:00:00:00:00:11:8C:01:77:07:01:00:4C:07:00:FF:01:01:62:1B:52:FE:59:00:00:00:00:00:00:00:00:01:77:07:81:81:C7:82:05:FF:01:01:01:01:83:02:17:C1:19:77:6C:47:8F:DA:EC:A1:20:B6:76:47:02:6D:A9:3D:A6:2B:55:AA:AD:97:9C:6E:FA:20:5F:32:57:B9:03:0A:7F:F4:74:FE:86:3D:98:40:FF:22:0D:2C:23:7D:01:77:07:01:00:00:00:00:FF:01
[W][component:214]: Component sml took a long time for an operation (0.06 s).
[W][component:215]: Components should block for at most 20-30ms.
Guru Meditation Error: Core  1 panic'ed (LoadProhibited). Exception was unhandled.

Core  1 register dump:
PC      : 0x400dffcf  PS      : 0x00060b30  A0      : 0x800de4f6  A1      : 0x3ffb2670
A2      : 0x00000000  A3      : 0x00000000  A4      : 0x00000000  A5      : 0x00000000  
A6      : 0x00000000  A7      : 0x3ffd3700  A8      : 0x800dffe7  A9      : 0x3ffb2630
A10     : 0x00000000  A11     : 0x00000000  A12     : 0x3ffb26ac  A13     : 0x00000000  
A14     : 0x00000000  A15     : 0x00000000  SAR     : 0x0000001b  EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000054  LBEG    : 0x400845c5  LEND    : 0x400845cd  LCOUNT  : 0x00000027  

Backtrace:0x400dffcc:0x3ffb26700x400de4f3:0x3ffb2710 0x400de739:0x3ffb2760 0x4017978d:0x3ffb2790 0x4017983a:0x3ffb27b0 0x400e7228:0x3ffb27d0 0x400e9daa:0x3ffb2800 0x400f867d:0x3ffb2820 

  #0  0x400dffcc:0x3ffb2670 in std::_Vector_base<esphome::sml::SmlNode, std::allocator<esphome::sml::SmlNode> >::_Vector_impl::_Vector_impl() at c:\users\semicuda\.platformio\packages\toolchain-xtensa-esp32\xtensa-esp32-elf\include\c++\8.4.0\bits/stl_vector.h:96
      (inlined by) std::_Vector_base<esphome::sml::SmlNode, std::allocator<esphome::sml::SmlNode> >::_Vector_base() at c:\users\semicuda\.platformio\packages\toolchain-xtensa-esp32\xtensa-esp32-elf\include\c++\8.4.0\bits/stl_vector.h:249
      (inlined by) std::vector<esphome::sml::SmlNode, std::allocator<esphome::sml::SmlNode> >::vector() at c:\users\semicuda\.platformio\packages\toolchain-xtensa-esp32\xtensa-esp32-elf\include\c++\8.4.0\bits/stl_vector.h:395
      (inlined by) esphome::sml::SmlNode::SmlNode() at src/esphome/components/sml/sml_parser.h:14
      (inlined by) esphome::sml::SmlFile::get_obis_info() at src/esphome/components/sml/sml_parser.cpp:62
  #1  0x400de4f3:0x3ffb2710 in esphome::sml::Sml::process_sml_file_(std::vector<unsigned char, std::allocator<unsigned char> > const&) at src/esphome/components/sml/sml.cpp:59
  #2  0x400de739:0x3ffb2760 in esphome::sml::Sml::loop() at src/esphome/components/sml/sml.cpp:49
  #3  0x4017978d:0x3ffb2790 in esphome::Component::call_loop() at src/esphome/core/component.cpp:76
  #4  0x4017983a:0x3ffb27b0 in esphome::Component::call() at src/esphome/core/component.cpp:98
  #5  0x400e7228:0x3ffb27d0 in esphome::Application::loop() at src/esphome/core/application.cpp:74
  #6  0x400e9daa:0x3ffb2800 in loop() at src/main.cpp:368
  #7  0x400f867d:0x3ffb2820 in loopTask(void*) at C:/Users/semicuda/.platformio/packages/framework-arduinoespressif32@3.20005.220925/cores/esp32/main.cpp:50

ELF file SHA256: 0000000000000000

Rebooting...
kr0ner commented 12 months ago

@semicuda try this one ... https://github.com/kr0ner/OneESP32ToRuleThemAll/blob/master/sml_reader.h It utilizes libSML from Volkszaehler. They implement the variable length correctly

irgendwienet commented 10 months ago

I came across this issue too.

We have two meters from "ZPA Smart Energy a.s." "Drehstromzäher GH305.D-S1-21.00-51G" and they crash the SML component in ESPHome immediately.

Here is a SML dump that crashes ESPHome: zpa.zip

And the full log 

[I][app:102]: ESPHome version 2024.1.0-dev compiled on Jan 21 2024, 10:34:17
[C][logger:443]: Logger:
[C][logger:444]:   Level: VERBOSE
[C][logger:445]:   Log Baud Rate: 115200
[C][logger:447]:   Hardware UART: UART0
[C][uart.arduino_esp8266:102]: UART Bus:
[C][uart.arduino_esp8266:104]:   RX Pin: GPIO13
[C][uart.arduino_esp8266:106]:   RX Buffer Size: 256
[C][uart.arduino_esp8266:108]:   Baud Rate: 9600 baud
[C][uart.arduino_esp8266:109]:   Data Bits: 8
[C][uart.arduino_esp8266:110]:   Parity: NONE
[C][uart.arduino_esp8266:111]:   Stop bits: 1
[C][uart.arduino_esp8266:115]:   Using software serial
[C][sml:104]: SML:
[D][uart_debug:114]: <<< 1B:1B:1B:1B:01:01:01:01:76:05:01:9B:11:16:62:00:62:00:72:65:00:00:01:01:76:01:0B:0A:01:5A:50:41:00:01:3D:3E:FC:05:01:02:03:04:0B:0A:01:5A:50:41:00:01:3D:3E:FC:72:62:01:65:00:89:05:CD:01:63:90:A5:00:76:05:01:9B:11:17:62:00:62:00:72:65:00:00:07:01:77:01:0B:0A:01:5A:50:41:00:01:3D:3E:FC:07:01:00:62:0A:FF:FF:72:62:01:65:00:89:05:CD:F1:00:77:07:01:00:60:32:01:01:01:01:01:01:04:5A:50:41:01:77:07:01:00:60:01:00:FF:01:01:01:01:0B:0A:01:5A:50:41:00:01:3D
[W][component:214]: Component sml took a long time for an operation (0.09 s).
[W][component:215]: Components should block for at most 20-30ms.
[D][uart_debug:114]: <<< 3E:FC:01:77:07:01:00:01:08:00:FF:65:00:1C:01:04:01:62:1E:52:FF:69:00:00:00:00:00:34:F1:17:01:77:07:01:00:01:08:01:FF:01:01:62:1E:52:FF:69:00:00:00:00:00:34:F1:17:01:77:07:01:00:01:08:02:FF:01:01:62:1E:52:FF:69:00:00:00:00:00:00:00:00:01:77:07:01:00:0E:07:00:FF:01:01:62:2C:52:FE:69:00:00:00:00:00:00:13:8D:01:77:07:01:00:00:02:00:0F:01:01:01:01:03:32:31:01:77:07:01:00:60:5A:02:03:01:01:01:01:05:A3:DB:E8:B2:01:77:07:01:00:61:61:00:FF:01:01:01:01:05
[W][component:214]: Component sml took a long time for an operation (0.09 s).
[W][component:215]: Components should block for at most 20-30ms.
[D][uart_debug:114]: <<< 00:00:00:00:01:77:07:01:00:10:07:00:FF:01:01:62:1B:52:00:59:00:00:00:00:00:00:05:DA:01:77:07:01:00:20:07:00:FF:01:01:62:23:52:FE:69:00:00:00:00:00:00:57:D8:01:77:07:01:00:34:07:00:FF:01:01:62:23:52:FE:69:00:00:00:00:00:00:57:4F:01:77:07:01:00:48:07:00:FF:01:01:62:23:52:FE:69:00:00:00:00:00:00:57:56:01:77:07:01:00:1F:07:00:FF:01:01:62:21:52:FD:69:00:00:00:00:00:00:16:1E:01:77:07:01:00:33:07:00:FF:01:01:62:21:52:FD:69:00:00:00:00:00:00:02:CD:01:77
[V][sml:118]: Checksum verification successful with CRC16/X25.
[D][main:150]: Data!!!
Fatal exception 28(LoadProhibitedCause):
                                        epc1=0x40209ec8, epc2=0x00000000, epc3=0x00000000, excvaddr=0x00000004, depc=0x00000000

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

Exception (28):
epc1=0x40209ec8 epc2=0x00000000 epc3=0x00000000 excvaddr=0x00000004 depc=0x00000000

>>>stack>>>

ctx: cont
sp: 3ffffc90 end: 3fffffc0 offset: 0190
3ffffe20:  00000000 3ffffedc 3fff257c 40202ce0
3ffffe30:  00000007 00000000 00000000 00000000
3ffffe40:  00000000 00000000 00000000 40211b07
3ffffe50:  00000000 00000000 00000000 3fff29e4
3ffffe60:  3fff2aa8 3fff2aa8 3fff0b06 3fff240c
3ffffe70:  3fff240d 3fff240d 00000000 00000000
3ffffe80:  00000000 3fff2d84 3fff2d8e 3fff2d8e
3ffffe90:  3fff2720 3fff240c 3fff240e 3fff240e
3ffffea0:  00000000 00000000 00000000 3fff0034
3ffffeb0:  3fff066c 3fff0058 3fff0034 40202398
3ffffec0:  3fff2544 3fff2720 3fff28c4 3fff087c
3ffffed0:  3fff0a6c 3fff0a6c 000001d6 00000000
3ffffee0:  00000000 00000000 3fff0a7c 3fff0001
3ffffef0:  3fff086b 3fff0058 3fff085c 40202697
3fffff00:  00000201 00000000 401005b1 00000000
3fffff10:  000002bc 3fff00c4 00000010 3ffeff6c
3fffff20:  3fff0324 00000000 3fffff60 3fff0034
3fffff30:  3fff0328 00000002 3ffeea18 4020a05c
3fffff40:  3fff0301 00000010 3ffeea18 4020a0d0
3fffff50:  3fffdad0 00000002 3ffeea18 40203bfa
3fffff60:  000002bc 3fff0034 6f727400 65617a6d
3fffff70:  3fff032c feefef00 feefeffe feefeffe
3fffff80:  00000000 00000000 00000001 3ffeec48
3fffff90:  3fffdad0 00000000 3ffeec34 40206144
3fffffa0:  3fffdad0 00000000 3ffeec34 402074b8
3fffffb0:  feefeffe feefeffe 3ffe85d8 40101585
<<<stack<<<

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

 ets Jan  8 2013,rst cause:2, boot mode:(3,6)

load 0x4010f000, len 3460, room 16
tail 4
chksum 0xcc
load 0x3fff20b8, len 40, room 4
tail 4
chksum 0xc9
csum 0xc9
v00047d70
~ld

Maybe its useful for someone.

irgendwienet commented 10 months ago

At least for my issues I could figure out whats was going on AND created a PR https://github.com/esphome/esphome/pull/6148

gitolicious commented 3 months ago

@irgendwienet, what model number is your ZPA meter? I have a ZPA GH305. ESPHome runs fine with the reduced dataset (manufacturer code, ID, total consumption, total delivery) but crashes when I input the PIN and enable the extended dataset on the INFO switch which adds power values (watts) to the SML message. I tried with 2024.6.0, .7.0 and .7.3.