Closed firstdominator closed 1 year ago
One more thing my esp32 is just next to the Bedjet.
Already spent over 5h on this trying 3 different ESP32 boards. @jhansche
OK so after some more digging.... I started from fresh and remove the BLE proxy from the ESP32. Now it's seems I'm going somewhere since it's getting some data from the Bedjet.... BUt I'm still stuck.
As soon it's get some data from the BedJet the ESPHOME API crashed and disconnects the ESP32.
If I remove the bedjet component the API doesn't crash anymore.
My code is pretty simple it's the minimum possible. Don't even want to add the BedJet climate component since I want first to get this API not crashing.
Here is my code.
Can someone try to help me here? I actually brought the Bedjet V3 just for that.... If I can't control it from HA i don't want it. PLEASE @jhansche
Also, if worth mentionning. If I leave it runnning for like 2-3 minutes I can't even get the log anymor eof the ESP32. I need to disconnect it and reconnect and then the same thing happens. Also, I notice that the bluetooth error logo on the Bedjet turn on and off everytime the esp32 is getting info from it.
Thanks!
Here is my complete log logs_bedjet_logs.txt
My first thought was also the ble proxy, because I see app_id 4, and the esp32 only supports 3 connections.
But without the proxy, it looks like your esp32 is crashing, but because you're getting logs over the air, you can't see the crash. Can you try plugging the device into USB and get logs directly from the UART console instead? That'll be the only way to see the actual crash logs. Basically, instead of powering it with a wall wart, plug it into your laptop or computer; and when you select logs or install, instead of choosing "wirelessly", select the option for USB over this computer. You can also use the esphome command line.
Once you have the UART console log, it should show where the crash is happening.
Is your BedJet firmware up to date? Have you been able to pair it with your phone app yet? And have you tried power cycling the BedJet (just unplug and replug)?
@jhansche Here is the log. I just letft in there one intance for clearer reading. logs.txt
Yes my firmware is up to date V.120 (140). Yes it has been paired with the phone. I know the BLE_Client isn't found when the app is open, but closed what mentionned above happens.
I did try factory reset of bedjet, unplug replug, hold down the LOW Power for pairing, unplug the bedjet remote, disabling wifi on it. I tried all sort of combinations.
Any posibility that my esp32 board is too old. Got those like 1.5-2 years ago. NODEMCU - ESP-32s
I did try with 3 different ESP32 boards, (2x NODEMCU - ESP-32s and 1x ESP32 DEVKITv1)
Thanks for your help.
This is the error you find in the log
`Guru Meditation Error: Core 1 panic'ed (LoadProhibited). Exception was unhandled.
Core 1 register dump:
PC : 0x4000c2e0 PS : 0x00060a30 A0 : 0x800deaf0 A1 : 0x3ffce4e0
A2 : 0x3ffce574 A3 : 0x00000000 A4 : 0x00000012 A5 : 0x3ffce574
A6 : 0x00060823 A7 : 0x00000001 A8 : 0x00000000 A9 : 0x0000abab
A10 : 0x3fff5c40 A11 : 0x3ffbc230 A12 : 0x3ffe55f0 A13 : 0x3fff4514
A14 : 0x00000358 A15 : 0x3ffbcc50 SAR : 0x0000000a EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000000 LBEG : 0x4000c2e0 LEND : 0x4000c2f6 LCOUNT : 0x00000000
ELF file SHA256: 0000000000000000
Backtrace: 0x4000c2e0:0x3ffce4e0 0x400deaed:0x3ffce4f0 0x400ddd2e:0x3ffce510 0x400dab15:0x3ffce5b0 0x401f529d:0x3ffce5e0 0x400df811:0x3ffce600 0x401f5555:0x3ffce700 0x401f5631:0x3ffce720 0x400e508e:0x3ffce740 0x400e7576:0x3ffce770 0x400f42d8:0x3ffce790 0x400909d6:0x3ffce7b0 `
Yeah, usually when you run with logs from the same source that compiled the image, it should unwind the stacktrace. This panic can't be read unless you decode it with your compiled symbols table.
How did you run this? Was it through the browser or through the command line esphome? If it was through the command line, can you copy your yaml config to a file in the directory, and install it using the command line as well? That will ensure that it has the compiled symbols available. Otherwise if it was installed over the browser, and pulling logs from somewhere else, it wouldn't decode it. Might need some help figuring out how to get a proper stack trace
This was done with Edge Broswer (since Brave doesn't support WebSerial.)
With the WebESPHome and the device connected to the computer. This is how I got the logs. The reason I used ESP Home web, is because my home assitant instance it's not under HTTPS for now. And if not secured esphome doesn't let you get the log from USB.... so I had to use ESP Home WEB.
https://web.esphome.io/?dashboard_wizard
Thanks for your help.
So i just tough I could try this onver HTTPS with my NabuCasa link.
I was able to connect to with with Microsoft Edge and the ESPHome addons from my NabuCasa instead of the ESP HOME WEB.
Same result, visually.
Here the log from NabuCasa ESPHome addon on my HA instance.
One more thing I decided to be proactive 2 days ago and brought a more recent ESP32. This one: https://www.amazon.ca/gp/product/B09QJ7SNJ8/ref=ppx_yo_dt_b_asin_title_o00_s00?ie=UTF8&psc=1
Is it possible that this one isn't compatible with ESPHOME? Because I can't seem to adapt it to ESPHOME. I see it in the WebSerial but can't adopt it. Is there a link that you are aware of the supported esp32 with ESPHOME?
Thanks!
It's hard to say without having the stack trace. When you're connecting it via USB and getting the console logs, are you also installing at the same time, or only clicking "logs"? It does seem to panic right as it's connecting, but without the stack trace I can't tell what is causing it. The panic you see in the logs just shows memory addresses, but that doesn't help by itself - those addresses have to be decoded against your compiled symbols in order to know what function was executing when the panic happened.
You could try to narrow down what could be causing it, by commenting out the BedJet component, and see if it still happens, since it might be just the ble tracker itself. In fact, I don't see esp32_ble_tracker in your config, and I thought that was required, but I may be misremembering. I'm away for the next week or so, so I wouldn't be able to make any fixes anyway until I'm back. But I have a feeling this is either a misconfiguration, or a hardware issue. If you can either rule out the BedJet component, or get the decoded stack trace, that will help figure out the root cause.
You could also try jumping on the esphome discord to get some help decoding the panic stack. I can't seem to find the documentation about that right now, but I know it is supposed to decode the panic for you automatically, so I'm not sure why it isn't.
As for supported boards, you can check https://esphome.io/components/esp32.html and https://registry.platformio.org/packages/platforms/platformio/espressif32/boards
I have the same issue. I have been using it successfully for months and the latest update seems to be crashing the ESP32.
@gardiner4 are you able to get a decoded panic stack trace?
Is this it?
[14:56:03][D][wifi:386]: Starting sca\xc0\xe0\xe0\xf0\xe0\xe0\xe0j5
[14:56:03][D][esp32_ble_tracker:809]: Found device 52:A2:32:53:8C:12 RSSI=-70
[14:56:03][D][esp32_ble_tracker:830]: Address Type: RANDOM
[14:56:03][D][esp32_ble_tracker:809]: Found device 4C:C9:5E:0D:14:EB RSSI=-91
[14:56:03][D][esp32_ble_tracker:830]: Address Type: PUBLIC
[14:56:04]\xe0\xc0\xc0\xc0\xc0\xe0\xe0]j\x95\x91\xa5хѥ\xbd\xb9\x81Error: Core 0 panic'ed (IllegalInstruction). Exception was unhandled.
[14:56:04]Memory dump at 0x401de784: 82ff3361 788c0016 026d440c
[14:56:04]Core 0 register dump:
[14:56:04]PC : 0x401de78a PS : 0x00060933 A0 : 0x801cf0a2 A1 : 0x3ffd2970
WARNING Decoded 0x401de78a: r_rwip_sleep
[14:56:04]A2 : 0x00000001 A3 : 0x3ffc3ec8 A4 : 0x3ffb8d40 A5 : 0x3ffc3eb0
[14:56:04]A6 : 0x3ffb8bcc A7 : 0x3ffc3eb8 A8 : 0x00000000 A9 : 0x3ffd2950
[14:56:04]A10 : 0x00000001 A11 : 0x00000000 A12 : 0x0000001f A13 : 0x00000001
[14:56:04]A14 : 0x00060920 A15 : 0x00000000 SAR : 0x0000001c EXCCAUSE: 0x00000000
[14:56:04]EXCVADDR: 0x00000000 LBEG : 0x4000c2e0 LEND : 0x4000c2f6 LCOUNT : 0xffffffff
[14:56:04]
[14:56:04]ELF file SHA256: 0000000000000000
[14:56:04]
[14:56:04]Backtrace: 0x401de78a:0x3ffd2970 0x401cf09f:0x3ffd29b0 0x401cf69d:0x3ffd29d0 0x400909d6:0x3ffd2a00
WARNING Found stack trace! Trying to decode it
WARNING Decoded 0x401de78a: r_rwip_sleep
WARNING Decoded 0x401cf09f: r_rw_schedule
WARNING Decoded 0x401cf69d: btdm_controller_task
WARNING Decoded 0x400909d6: vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c:355 (discriminator 1)
[14:56:04]
[14:56:04]Rebooting...
Yeah that's the decoded trace I'm looking for. Unfortunately none of that belongs to the BedJet component, so it might be an Arduino or espressif platform issue.
Have either of you tried using the esp-idf framework instead of Arduino? I would recommend trying that next, just to rule out the Arduino framework.
When I comment out BedJet the esp32 does not crash. I just tried esp-idf and it does briefly connect to the BedJet, but eventually crashes in a similar fashion.
@jesserockz do you have any insight or ideas here? I haven't tried 2022.11 yet, and I'm away for the week. Do you think this might be BedJet related, or framework?
The panic occurs at r_rwip_sleep
.
I can try to do the update remotely and see if it comes back up. Edit: well the update succeeded remotely, but it's not coming up in HA and can't get logs. So it may be panicking in the same way. I won't be able to check until I get back home. Edit 2: I spoke too soon. It did come back up and connected to two BedJets. So now I don't know what else could be causing this issue. It's starting to sound like a hardware issue.
I did not have a backup so I used Portainer to recreate the docker image with the 2022.10.2 version. The issue is gone, and my BedJet is now working. I see some other open issues of ESP32s restarting in 2022.11.xx.
Can confirm - this also broke in my house around the approximate time I upgraded ESPHome -- or perhaps even HA itself -- to 2022.11.x. I had been using it successfully for a month until then -- notably on the same ESP32 device.
I have ESPhome 2022.11 working with my bedjet but I have noticed some increased instability. I noticed that something wasn't quite right because a portion of my HA dashboard was missing.
I have ESPhome expose the fan speed as a slider directly to HA because there still isn't a built in UI widget for that.
# We already have fan speed control via the climate entity in HA but there's no automagic UI element for easy
# fan speed control. We fix that here.
number:
- name: "${friendly_name_short} Fan Speed"
platform: template
id: inp_fan_speed
icon: "mdi:fan"
entity_category: config
unit_of_measurement: "%"
mode: "slider"
min_value: 0
max_value: 100
step: 5
# We'll get a string like `85%` back. Delete the last char, turn into a float and we're golden :)
lambda: |-
std::string speed = id(climate_bedjet_88fa).custom_fan_mode.value();
speed.pop_back();
return atoi(speed.c_str());
# Called when HA sets the number
set_action:
then:
- lambda: |-
auto call = id(climate_bedjet).make_call();
call.set_fan_mode(str_sprintf("%i%%", (int)x));
call.perform();
It was this slider that wasn't showing up as expected that tipped me off. I had ~35 min I could spend on investigation so I didn't get far. Here's what I tried
v2022.11.1
After a new flash / cold boot, there's usually some difficulty in connecting. This time was no exception and it took a few crash -> boot cycles before the module managed to connect to the bedjet.
I was working from a terminal that didn't have a particularly large scrollback at the time so I don't have the exact details but I distinctly remember one of the errors just before the stack trace was dumped. It was lamenting the lack of room for JSON buffer.
That would make sense; if there's some issue w/ allocating the JSON buffer, the auto-discovery payload wouldnt get published and the slider wouldn't show up.
Unfortunately that was only one of the ~5 stack traces I saw before the module appeared to stabalize.
I was running out of time so I put a simple on_time:
automation in place so the module reboots every day at 2 PM. It's been stable since then.
¯\(ツ)/¯
I am having i guess same issue tried 2 different esp32 and both times getting this
[22:48:37][I][bedjet:216]: - Command char: 0x33
[22:48:37][I][bedjet:217]: - Status char: 0x2a
[22:48:37][I][bedjet:218]: - config descriptor: 0x2b
[22:48:37][I][bedjet:219]: - Name char: 0x2d
[22:48:37][D][bedjet:237]: [30:c6:f7:39:46:86] Services complete: obtained char handles.
[22:48:37]Guru Meditation Error: Core 1 panic'ed (LoadProhibited). Exception was unhandled.
[22:48:37]Core 1 register dump:
[22:48:37]PC : 0x4000c2e0 PS : 0x00060230 A0 : 0x800deaec A1 : 0x3ffce4e0
[22:48:37]A2 : 0x3ffce574 A3 : 0x00000000 A4 : 0x00000012 A5 : 0x3ffce574
[22:48:37]A6 : 0x00060223 A7 : 0x00000001 A8 : 0x00000000 A9 : 0x00000001
[22:48:37]A10 : 0x3fff5a84 A11 : 0x3fff67dd A12 : 0x3fff6544 A13 : 0x3fff65d4
[22:48:37]A14 : 0x3fff6525 A15 : 0x3fff65d5 SAR : 0x00000004 EXCCAUSE: 0x0000001c
[22:48:37]EXCVADDR: 0x00000000 LBEG : 0x4000c2e0 LEND : 0x4000c2f6 LCOUNT : 0x00000000
[22:48:37]
[22:48:37]ELF file SHA256: 0000000000000000
[22:48:37]
[22:48:37]Backtrace: 0x4000c2e0:0x3ffce4e0 0x400deae9:0x3ffce4f0 0x400ddd2e:0x3ffce510 0x400dab15:0x3ffce5b0 0x401f52a1:0x3ffce5e0 0x400df815:0x3ffce600 0x401f5559:0x3ffce700 0x401f5635:0x3ffce720 0x400e5092:0x3ffce740 0x400e757a:0x3ffce770 0x400f42dc:0x3ffce790 0x400909d6:0x3ffce7b0
WARNING Found stack trace! Trying to decode it
WARNING Decoded 0x400deae9: esphome::esp32_ble_tracker::ESPBTUUID::get_uuid() const at /config/esphome/.esphome/build/bedjet/src/esphome/components/esp32_ble_tracker/esp32_ble_tracker.cpp:567
WARNING Decoded 0x400ddd2e: esphome::esp32_ble_client::BLEClientBase::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t) at /config/esphome/.esphome/build/bedjet/src/esphome/components/esp32_ble_client/ble_client_base.cpp:286
WARNING Decoded 0x400dab15: esphome::ble_client::BLEClient::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t) at /config/esphome/.esphome/build/bedjet/src/esphome/components/ble_client/ble_client.cpp:54
WARNING Decoded 0x401f52a1: esphome::esp32_ble_tracker::ESP32BLETracker::real_gattc_eventhandler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t) at /config/esphome/.esphome/build/bedjet/src/esphome/components/esp32_ble_tracker/esp32_ble_tracker.cpp:368
WARNING Decoded 0x400df815: esphome::esp32_ble_tracker::ESP32BLETracker::loop() at /config/esphome/.esphome/build/bedjet/src/esphome/components/esp32_ble_tracker/esp32_ble_tracker.cpp:78
WARNING Decoded 0x401f5559: esphome::Component::call_loop() at /config/esphome/.esphome/build/bedjet/src/esphome/core/component.cpp:150
WARNING Decoded 0x401f5635: esphome::Component::call() at /config/esphome/.esphome/build/bedjet/src/esphome/core/component.cpp:150
WARNING Decoded 0x400e5092: esphome::Application::loop() at /config/esphome/.esphome/build/bedjet/src/esphome/core/application.cpp:74
WARNING Decoded 0x400e757a: loop() at /config/esphome/.esphome/build/bedjet/src/esphome/components/esp32_ble_tracker/esp32_ble_tracker.h:166
WARNING Decoded 0x400f42dc: loopTask(void) at /data/cache/platformio/packages/framework-arduinoespressif32/cores/esp32/main.cpp:23
WARNING Decoded 0x400909d6: vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c:355 (discriminator 1)
[22:48:38]
[22:48:38]Rebooting..
Still same issue going on... Anyone got a resolution?
@kquinsland unrelated: you could try the new fan
platform to replace your template number slider. The hub component also exposes fan speed controls now, without having to use the custom fan preset string, if you want to continue using the number template. The docs explain how to add the BedJet fan component.
As for the crash, my esp32 has been running 2022.11.1 since Nov 22, without any issues. I'm even connecting to two BedJets from the same esp32, which of course increases complexity, but still running stable. I'm using framework: esp-idf
, without HA BLE proxy, and with log level set to INFO
. Note that using a more verbose log level has caused stability issues for me in the past. I'm also using some slightly relaxed BLE scan parameters, though I'm not sure that it's making any difference:
esp32_ble_tracker:
scan_parameters:
interval: 1sec # 320ms
window: 300ms # 30ms
duration: 5min # 5min
At this point I've seen several different stack traces that all point to different places in the code that don't appear to be directly caused by the BedJet component. There has been a lot of work done recently in the BLE stack (including BLE proxy), so unless I can reproduce it myself, or get a consistent stack trace that shows BedJet is the culprit, I can only guess that the issue is caused by something else in the stack.
Still same issue going on... Anyone got a resolution?
i used linux to install a older version of esphom and it works
@kquinsland unrelated: you could try the new
fan
platform to replace your template number slider. The hub component also exposes fan speed controls now, without having to use the custom fan preset string, if you want to continue using the number template. The docs explain how to add the BedJet fan component.
Thanks for confirming. I was thinking that there might be some instability induced in the bed jet component by way of changes in other components.
Regardless, the reason for the number slider is that HA does not have any fan card. If you add a fan.my_bedjet
entity to a lovelace card, you'll get a single toggle switch. You have to resort to a custom card or other DIY automations if you want to toggle the speed.
I did recently discover the mushroom cards, though, and there is a fantastic fan card that does support percentages so I've switched to that :).
using
framework: esp-idf
, without HA BLE proxy, and with log level set toINFO
. Note that using a more verbose log level has caused stability issues for me in the past. I'm also using some slightly relaxed BLE scan parameters, though I'm not sure that it's making any difference:esp32_ble_tracker: scan_parameters: interval: 1sec # 320ms window: 300ms # 30ms duration: 5min # 5min
Good tip! In addition to removing the template number, i'll remove my daily reboot and switch to ESP-IDF w/ those relaxed values.
At this point I've seen several different stack traces that all point to different places in the code that don't appear to be directly caused by the BedJet component. There has been a lot of work done recently in the BLE stack (including BLE proxy), so unless I can reproduce it myself, or get a consistent stack trace that shows BedJet is the culprit, I can only guess that the issue is caused by something else in the stack.
While implementing the changes I mentioned above, I got two. Both happened immediately after flashing / initial reset. The stack traces come from a build using your scan parameters and:
esp32:
board: mhetesp32minikit
framework:
type: esp-idf
The build does not have the template number
component but does have the bedjet fan
component and this version;
❯ esphome version
Version: 2022.11.4
[09:56:23][I][esp32_ble_client:054]: [0] [de:ad:be:ef:88:fa] Attempting BLE connection
[09:56:26][I][esp32_ble_client:154]: [0] [de:ad:be:ef:88:fa] Service UUID: 0x1801
[09:56:26][I][esp32_ble_client:156]: [0] [de:ad:be:ef:88:fa] start_handle: 0x1 end_handle: 0x5
[09:56:26][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 0x2A05, handle 0x3, properties 0x20
[09:56:26][I][esp32_ble_client:154]: [0] [de:ad:be:ef:88:fa] Service UUID: 0x1800
[09:56:26][I][esp32_ble_client:156]: [0] [de:ad:be:ef:88:fa] start_handle: 0x14 end_handle: 0x1c
[09:56:26][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 0x2A00, handle 0x16, properties 0x2
[09:56:26][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 0x2A01, handle 0x18, properties 0x2
[09:56:26][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 0x2AA6, handle 0x1a, properties 0x2
[09:56:26][I][esp32_ble_client:154]: [0] [de:ad:be:ef:88:fa] Service UUID: 00001000-BED0-0080-AA55-4265644A6574
[09:56:26][I][esp32_ble_client:156]: [0] [de:ad:be:ef:88:fa] start_handle: 0x28 end_handle: 0xffff
[09:56:26][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 00002000-BED0-0080-AA55-4265644A6574, handle 0x2a, properties 0x1a
[09:56:26][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 00002001-BED0-0080-AA55-4265644A6574, handle 0x2d, properties 0xa
[09:56:26][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 00002002-BED0-0080-AA55-4265644A6574, handle 0x2f, properties 0xa
[09:56:26][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 00002003-BED0-0080-AA55-4265644A6574, handle 0x31, properties 0x8
[09:56:26][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 00002004-BED0-0080-AA55-4265644A6574, handle 0x33, properties 0x8
[09:56:26][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 00002005-BED0-0080-AA55-4265644A6574, handle 0x35, properties 0xa
[09:56:26][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 00002006-BED0-0080-AA55-4265644A6574, handle 0x37, properties 0xa
[09:56:26][I][bedjet:215]: [de:ad:be:ef:88:fa] Discovered service characteristics:
[09:56:26][I][bedjet:216]: - Command char: 0x33
[09:56:26][I][bedjet:217]: - Status char: 0x2a
[09:56:26][I][bedjet:218]: - config descriptor: 0x2b
[09:56:26][I][bedjet:219]: Guru Meditation Error: Core 1 panic'ed (StoreProhibited). Exception was unhandled.
[09:56:26]
[09:56:26]Core 1 register dump:
[09:56:26]PC : 0x4000c46c PS : 0x00060030 A0 : 0x800d339a A1 : 0x3ffcf720
[09:56:26]A2 : 0x0000000c A3 : 0x00000000 A4 : 0x00000023 A5 : 0x0000000c
[09:56:26]A6 : 0x00000001 A7 : 0x00000002 A8 : 0xfa000000 A9 : 0x00000000
[09:56:26]A10 : 0x0f100000 A11 : 0xb9800000 A12 : 0x00060e23 A13 : 0x00060e23
[09:56:26]A14 : 0x00000001 A15 : 0x0000ea60 SAR : 0x0000000a EXCCAUSE: 0x0000001d
[09:56:26]EXCVADDR: 0x0000000c LBEG : 0x4000c46c LEND : 0x4000c477 LCOUNT : 0x00000001
[09:56:26]
[09:56:26]Backtrace:0x4000c469:0x3ffcf720 0x400d3397:0x3ffcf730 0x400d4524:0x3ffcf750 0x400d6192:0x3ffcf7a0 0x401b9d69:0x3ffcf7d0 0x400d96e7:0x3ffcf7f0 0x401ba87d:0x3ffcf8f0 0x401ba969:0x3ffcf910 0x400e4ada:0x3ffcf930 0x400e7412:0x3ffcf960 0x400d729b:0x3ffcfa80
WARNING Found stack trace! Trying to decode it
WARNING Decoded 0x400d3397: esphome::bedjet::BedjetCodec::decode_notify(unsigned char const*, unsigned short) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/bedjet/bedjet_codec.cpp:95
WARNING Decoded 0x400d4524: esphome::bedjet::BedJetHub::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/bedjet/bedjet_hub.cpp:376
WARNING Decoded 0x400d6192: esphome::ble_client::BLEClient::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/ble_client/ble_client.cpp:58 (discriminator 2)
WARNING Decoded 0x401b9d69: esphome::esp32_ble_tracker::ESP32BLETracker::real_gattc_event_handler_(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/esp32_ble_tracker/esp32_ble_tracker.cpp:368 (discriminator 2)
WARNING Decoded 0x400d96e7: esphome::esp32_ble_tracker::ESP32BLETracker::loop() at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/esp32_ble_tracker/esp32_ble_tracker.cpp:77
WARNING Decoded 0x401ba87d: esphome::Component::call_loop() at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/core/component.cpp:76
WARNING Decoded 0x401ba969: esphome::Component::call() at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/core/component.cpp:98
WARNING Decoded 0x400e4ada: esphome::Application::setup() at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/core/application.cpp:52 (discriminator 2)
WARNING Decoded 0x400e7412: setup() at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/projects/bedjet.yaml:251 (discriminator 4)
WARNING Decoded 0x400d729b: esphome::loop_task(void*) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/esp32/core.cpp:72
And the second one:
[10:01:39][I][esp-idf:000]: pm start, type: 1
[10:01:39]
[10:01:39][I][esp-idf:000]:
[10:01:39]
[10:01:39][I][esp-idf:000]: I (5887) wifi:
[10:01:39][I][esp-idf:000]: AP's beacon interval = 102400 us, DTIM period = 1
[10:01:39][I][esp-idf:000]:
[10:01:39]
[10:01:39]Guru Meditation Error: Core 1 panic'ed (StoreProhibited). Exception was unhandled.
[10:01:39]
[10:01:39]Core 1 register dump:
[10:01:39]PC : 0x4000c46c PS : 0x00060e30 A0 : 0x800d339a A1 : 0x3ffcf770
[10:01:39]A2 : 0x0000000c A3 : 0x00000000 A4 : 0x00000023 A5 : 0x0000000c
[10:01:39]A6 : 0x00000001 A7 : 0x00000002 A8 : 0xfa000000 A9 : 0x00000000
[10:01:39]A10 : 0x14060000 A11 : 0xd2000000 A12 : 0x00060c23 A13 : 0x00060c23
[10:01:39]A14 : 0x00000001 A15 : 0x0000ea60 SAR : 0x0000000a EXCCAUSE: 0x0000001d
[10:01:39]EXCVADDR: 0x0000000c LBEG : 0x4000c46c LEND : 0x4000c477 LCOUNT : 0x00000001
[10:01:39]
[10:01:39]Backtrace:0x4000c469:0x3ffcf770 0x400d3397:0x3ffcf780 0x400d4524:0x3ffcf7a0 0x400d6192:0x3ffcf7f0 0x401b9d69:0x3ffcf820 0x400d96e7:0x3ffcf840 0x401ba87d:0x3ffcf940 0x401ba969:0x3ffcf960 0x400e4ada:0x3ffcf980 0x400e7412:0x3ffcf9b0 0x400d729b:0x3ffcfad0
WARNING Found stack trace! Trying to decode it
WARNING Decoded 0x400d3397: esphome::bedjet::BedjetCodec::decode_notify(unsigned char const*, unsigned short) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/bedjet/bedjet_codec.cpp:95
WARNING Decoded 0x400d4524: esphome::bedjet::BedJetHub::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/bedjet/bedjet_hub.cpp:376
WARNING Decoded 0x400d6192: esphome::ble_client::BLEClient::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/ble_client/ble_client.cpp:58 (discriminator 2)
WARNING Decoded 0x401b9d69: esphome::esp32_ble_tracker::ESP32BLETracker::real_gattc_event_handler_(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/esp32_ble_tracker/esp32_ble_tracker.cpp:368 (discriminator 2)
WARNING Decoded 0x400d96e7: esphome::esp32_ble_tracker::ESP32BLETracker::loop() at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/esp32_ble_tracker/esp32_ble_tracker.cpp:77
WARNING Decoded 0x401ba87d: esphome::Component::call_loop() at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/core/component.cpp:76
WARNING Decoded 0x401ba969: esphome::Component::call() at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/core/component.cpp:98
WARNING Decoded 0x400e4ada: esphome::Application::setup() at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/core/application.cpp:52 (discriminator 2)
WARNING Decoded 0x400e7412: setup() at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/projects/bedjet.yaml:251 (discriminator 4)
WARNING Decoded 0x400d729b: esphome::loop_task(void*) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/esp32/core.cpp:72
[10:01:39]
[10:01:39]
[10:01:39]ELF file SHA256: 353ab9a5bf847275
[10:01:39]
[10:01:39]Rebooting...
[10:01:39]ets Jun 8 2016 00:22:57
EDIT:
And immediately after posting, I realized that I didn't actually remove the on_time:
event that I was using to reboot the ESP daily. I removed that and re-compiled and got another stack trace during the initial boot:
[10:19:22][I][esp32_ble_client:154]: [0] [de:ad:be:ef:88:fa] Service UUID: 0x1801
[10:19:22][I][esp32_ble_client:156]: [0] [de:ad:be:ef:88:fa] start_handle: 0x1 end_handle: 0x5
[10:19:22][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 0x2A05, handle 0x3, properties 0x20
[10:19:22][I][esp32_ble_client:154]: [0] [de:ad:be:ef:88:fa] Service UUID: 0x1800
[10:19:22][I][esp32_ble_client:156]: [0] [de:ad:be:ef:88:fa] start_handle: 0x14 end_handle: 0x1c
[10:19:22][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 0x2A00, handle 0x16, properties 0x2
[10:19:22][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 0x2A01, handle 0x18, properties 0x2
[10:19:22][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 0x2AA6, handle 0x1a, properties 0x2
[10:19:22][I][esp32_ble_client:154]: [0] [de:ad:be:ef:88:fa] Service UUID: 00001000-BED0-0080-AA55-4265644A6574
[10:19:22][I][esp32_ble_client:156]: [0] [de:ad:be:ef:88:fa] start_handle: 0x28 end_handle: 0xffff
[10:19:22][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 00002000-BED0-0080-AA55-4265644A6574, handle 0x2a, properties 0x1a
[10:19:22][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 00002001-BED0-0080-AA55-4265644A6574, handle 0x2d, properties 0xa
[10:19:22][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 00002002-BED0-0080-AA55-4265644A6574, handle 0x2f, properties 0xa
[10:19:22][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 00002003-BED0-0080-AA55-4265644A6574, handle 0x31, properties 0x8
[10:19:22][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 00002004-BED0-0080-AA55-4265644A6574, handle 0x33, properties 0x8
[10:19:22][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 00002005-BED0-0080-AA55-4265644A6574, handle 0x35, properties 0xa
[10:19:22][I][esp32_ble_client:059]: [0] [de:ad:be:ef:88:fa] characteristic 00002006-BED0-0080-AA55-4265644A6574, handle 0x37, properties 0xa
[10:19:22][I][bedjet:215]: [de:ad:be:ef:88:fa] Discovered service characteristics:
[10:19:22][I][bedjet:216]: - Command char: 0x33
[10:19:22][I][bedjet:217]: - Status char: 0x2a
[10:19:22][I][bedjet:218]: - config descriptor: 0x2b
[10:19:22][I][bedjet:219]: - Name char: 0x2d
[10:19:22]Guru Meditation Error: Core 1 panic'ed (StoreProhibited). Exception was unhandled.
[10:19:22]
[10:19:22]Core 1 register dump:
[10:19:22]PC : 0x4000c46c PS : 0x00060030 A0 : 0x800d3342 A1 : 0x3ffcf790
[10:19:22]A2 : 0x0000000c A3 : 0x00000000 A4 : 0x00000023 A5 : 0x0000000c
[10:19:22]A6 : 0x00000001 A7 : 0x00000002 A8 : 0xfa000000 A9 : 0x00000000
[10:19:22]A10 : 0x0eec0000 A11 : 0xe3800000 A12 : 0x00060e23 A13 : 0x00060e23
[10:19:22]A14 : 0x00000001 A15 : 0x0000ea60 SAR : 0x0000000a EXCCAUSE: 0x0000001d
[10:19:22]EXCVADDR: 0x0000000c LBEG : 0x4000c46c LEND : 0x4000c477 LCOUNT : 0x00000001
[10:19:22]
[10:19:22]Backtrace:0x4000c469:0x3ffcf790 0x400d333f:0x3ffcf7a0 0x400d44cc:0x3ffcf7c0 0x400d613a:0x3ffcf810 0x401b97c1:0x3ffcf840 0x400d968f:0x3ffcf860 0x401ba1a9:0x3ffcf960 0x401ba295:0x3ffcf980 0x400e4696:0x3ffcf9a0 0x400e6eae:0x3ffcf9d0 0x400d7243:0x3ffcfac0
WARNING Found stack trace! Trying to decode it
WARNING Decoded 0x400d333f: esphome::bedjet::BedjetCodec::decode_notify(unsigned char const*, unsigned short) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/bedjet/bedjet_codec.cpp:95
WARNING Decoded 0x400d44cc: esphome::bedjet::BedJetHub::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/bedjet/bedjet_hub.cpp:376
WARNING Decoded 0x400d613a: esphome::ble_client::BLEClient::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/ble_client/ble_client.cpp:58 (discriminator 2)
WARNING Decoded 0x401b97c1: esphome::esp32_ble_tracker::ESP32BLETracker::real_gattc_event_handler_(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/esp32_ble_tracker/esp32_ble_tracker.cpp:368 (discriminator 2)
WARNING Decoded 0x400d968f: esphome::esp32_ble_tracker::ESP32BLETracker::loop() at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/esp32_ble_tracker/esp32_ble_tracker.cpp:77
WARNING Decoded 0x401ba1a9: esphome::Component::call_loop() at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/core/component.cpp:76
WARNING Decoded 0x401ba295: esphome::Component::call() at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/core/component.cpp:98
WARNING Decoded 0x400e4696: esphome::Application::setup() at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/core/application.cpp:52 (discriminator 2)
WARNING Decoded 0x400e6eae: setup() at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/projects/bedjet.yaml:233 (discriminator 4)
WARNING Decoded 0x400d7243: esphome::loop_task(void*) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/esp32/core.cpp:72
[10:19:23]
[10:19:23]
[10:19:23]ELF file SHA256: 065d335de4fef67e
After this crash/reboot, things are stable though so. Could just be something off about how memory is after flash/first boot that is corrected after crash and is fine for subsiquent boots.
Additionally I think there's an off by one error somewhere. When I set the mushroom fan card to 100%, the ESPHome logs had this:
[10:20:37][W][bedjet:056]: Invalid fan speed index 20, expecting 0-19.
Which makes a bit of sense as the HA interface is always 5% off relative to what the bed jet remote shows. E.G.: HA shows 30%, bed jet remote shows 35%.
OK, yeah those 3 stack traces point to:
https://github.com/esphome/esphome/blob/dev/esphome/components/bedjet/bedjet_codec.cpp#L95
which is clearing the memory of the status packet that was already allocated here: https://github.com/esphome/esphome/blob/dev/esphome/components/bedjet/bedjet_codec.h#L187
Since the class already owns that memory, there's no reason that it should be prohibited, and it's not even a memory allocation issue, because it is not a pointer so the class already allocates that memory when it's first created. You could be right that there's some kind of memory issue in that board, but I don't know how I would track that down since it doesn't seem to happen for me. I haven't used the mhetesp32minikit
board - Mine is a generic board: esp32dev
.
I'll see if I can get some time to verify that: this could actually be happening to me as well, but the watchdog causes it to reboot after panic automatically, and maybe that's why my "edit/edit2" comments above took longer than usual for it to come online 🤔 If that's the case, then I would also only see the logs while plugged into USB.
The fan index sounds like a bug, and your explanation makes sense. Feel free to open a ticket or PR for that and I'll take a look. Should be simple enough. I think the root of the issue is that HA wants to allow setting 0%, but that should actually be "off". I don't think we have a way to tell HA that we want to start at min=5% ("fan speed index 0 == 5%"), so we probably need to update the fan component to have a range of 0-20 and subtract one when sending the speed to BedJet, with a special case for 0==off.
OK, yeah those 3 stack traces point to: https://github.com/esphome/esphome/blob/dev/esphome/components/bedjet/bedjet_codec.cpp#L95 which is clearing the memory of the status packet that was already allocated here: https://github.com/esphome/esphome/blob/dev/esphome/components/bedjet/bedjet_codec.h#L187
Thanks for the explanation. I didn't go digging through the code but could see the call stack and the basic "handler/hook/callback function -> decode function" pattern just smelled like some sort of unexpected bytes which isn't unheard of on embedded electronics ... especially when doing a "warm" boot just after flashing.
Since the class already owns that memory, there's no reason that it should be prohibited, and it's not even a memory allocation issue, because it is not a pointer so the class already allocates that memory when it's first created. You could be right that there's some kind of memory issue in that board, but I don't know how I would track that down since it doesn't seem to happen for me. I haven't used the
mhetesp32minikit
board - Mine is a genericboard: esp32dev
.
This is the board in question: https://www.amazon.com/Bluetooth-Internet-Development-Functional-Ardu-ino/dp/B08MFCC4SR
(that was the first link I found; the board is sold under a zillion different brands / stores / etc. I buy mine in bulk from Ali Express for ~$3 each)
It's basically as close to a generic/dev unit as you can get. It's a basic USB <-> UART chip with ESD protection and an LDO to power the ESP32 module.
There might be some difference in the generation of ESP32 chips, perhaps? E.G.: the way the compiler works for extensa
stuff results in a prohibited exception from time to time but the same class is compiled in an exception-free way for the newer RISC based cores? I'm grasping at straws to explain it :).
I'll see if I can get some time to verify that: this could actually be happening to me as well, but the watchdog causes it to reboot after panic automatically, and maybe that's why my "edit/edit2" comments above took longer than usual for it to come online thinking If that's the case, then I would also only see the logs while plugged into USB.
Not sure what edit/edit2
you're referring to. I was getting the provided stack traces via USB so it could very well be that log lines emitted to MQTT are not seen before the reboot.
It could also be a bug in the underlying SDK/APIs that's exacerbated by my wireless environment. /shrug.
Feel free to open a ticket or PR for that and I'll take a look. Should be simple enough.
Will do! Didn't know if you wanted a distinct thread or not.
It works on a older version so its not a issue in hardware it was broken in software by mistake
Not sure what
edit/edit2
you're referring to. I was getting the provided stack traces via USB so it could very well be that log lines emitted to MQTT are not seen before the reboot.
The edits I'm talking are at the end of this comment earlier in this thread: https://github.com/esphome/issues/issues/3807#issuecomment-1324278203 I tested updating to latest esphome, but I was out of town so the update happened blindly. At first I didn't see it come back up as quickly as I'd expect so I assumed that the update also broke mine. But it did eventually come back up, with no intervention. What I'm saying now is that mine may have actually hit a crash but got automatically restarted and then remained stable after that (which sounds like that's what you're seeing now?)
It works on a older version so its not a issue in hardware it was broken in software by mistake
I understand what you're saying, but the relationship between hardware and software is not as cut-and-dry as this implies. Applying your logic to my situation actually says the opposite: "I updated with no issues therefore the software must be fine." However that's not what I'm saying. I'm aware that multiple people are reporting this issue, but the issue is not affecting me or my devices. If it was just "broken in software" as your suggesting, then it would have broken for me, and it didn't. Therefore there must be something else at play that either a) makes it work unexpectedly for me (that is, it's truly broken in software, but by some fluke mine didn't break), or b) makes it break unexpectedly for the handful of you in this thread.
Most commonly and most likely, it's something very specific, like a particular board manufacturers, something else in the esphome config or framework, the power source, flash layout, or dozens of other things that could be aligning (or misaligning) just right, to either make it work or make it break.
I'll also point out that the BedJet code itself hasn't changed in a few months (Aug 30); but the BLE proxy changes in October did precipitate some refactoring (doesn't appear to have made any functional changes however, at least not in the BedJet component itself) https://github.com/esphome/esphome/commits/dev/esphome/components/bedjet
It's possible that something did change in the Bluetooth stack or some other hardware-specific code path, but I'm not aware of anything specific. So again, I can't really do anything here if I can't reproduce the problem myself.
SO Ir ead everything, but you guys are talking a different language that I can't follow... I still have my issue and can't seem to resolve. Can someone give me the minimal code at least so I can connect to it. With my code on the orignal post, I'm not able too...
I'm still stuck at the same point.
Thanks in advance.
SO Ir ead everything, but you guys are talking a different language that I can't follow... I still have my issue and can't seem to resolve. Can someone give me the minimal code at least so I can connect to it. With my code on the orignal post, I'm not able too...
I'm still stuck at the same point.
Thanks in advance.
Go to esphome github go to release download v2022.9.0 install on Linux then compile in Linux and install thru esphome web
The edits I'm talking are at the end of this comment earlier in this thread: #3807 (comment) I tested updating to latest esphome, but I was out of town so the update happened blindly. At first I didn't see it come back up as quickly as I'd expect so I assumed that the update also broke mine. But it did eventually come back up, with no intervention. What I'm saying now is that mine may have actually hit a crash but got automatically restarted and then remained stable after that (which sounds like that's what you're seeing now?)
Ah, i get you now. Yeah, very likely could be the case that a watchdog hid the issue from you initially. For what it's worth, my ESP32 module has been up a bit over 26h so far after I switched to esp-idf
and used your relaxed bluetooth settings. That's more stable than things had been. I'll keep an eye on it :).
Can someone give me the minimal code at least so I can connect to it. With my code on the orignal post, I'm not able too...
@firstdominator
We need the "decocded" stack trace to figure out what your crash means. You'll want to access esphome
program directly so you can esphome run path/to/your.yaml
. That will compile and then upload. If the crash still happens, esphome
should be able to detect it and will be able to put meaning to the addresses.
It'll look like this:
esphome run your.yaml
<...>
[10:19:22]Core 1 register dump:
[10:19:22]PC : 0x4000c46c PS : 0x00060030 A0 : 0x800d3342 A1 : 0x3ffcf790
[10:19:22]A2 : 0x0000000c A3 : 0x00000000 A4 : 0x00000023 A5 : 0x0000000c
[10:19:22]A6 : 0x00000001 A7 : 0x00000002 A8 : 0xfa000000 A9 : 0x00000000
[10:19:22]A10 : 0x0eec0000 A11 : 0xe3800000 A12 : 0x00060e23 A13 : 0x00060e23
[10:19:22]A14 : 0x00000001 A15 : 0x0000ea60 SAR : 0x0000000a EXCCAUSE: 0x0000001d
[10:19:22]EXCVADDR: 0x0000000c LBEG : 0x4000c46c LEND : 0x4000c477 LCOUNT : 0x00000001
[10:19:22]
[10:19:22]Backtrace:0x4000c469:0x3ffcf790 ....
WARNING Found stack trace! Trying to decode it
WARNING Decoded 0x400d333f: esphome::bedjet::BedjetCodec::decode_notify(unsigned char const*, unsigned short) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/bedjet/bedjet_codec.cpp:95
<....>
The edits I'm talking are at the end of this comment earlier in this thread: #3807 (comment) I tested updating to latest esphome, but I was out of town so the update happened blindly. At first I didn't see it come back up as quickly as I'd expect so I assumed that the update also broke mine. But it did eventually come back up, with no intervention. What I'm saying now is that mine may have actually hit a crash but got automatically restarted and then remained stable after that (which sounds like that's what you're seeing now?)
Ah, i get you now. Yeah, very likely could be the case that a watchdog hid the issue from you initially. For what it's worth, my ESP32 module has been up a bit over 26h so far after I switched to
esp-idf
and used your relaxed bluetooth settings. That's more stable than things had been. I'll keep an eye on it :).Can someone give me the minimal code at least so I can connect to it. With my code on the orignal post, I'm not able too...
@firstdominator
We need the "decocded" stack trace to figure out what your crash means. You'll want to access
esphome
program directly so you canesphome run path/to/your.yaml
. That will compile and then upload. If the crash still happens,esphome
should be able to detect it and will be able to put meaning to the addresses.It'll look like this:
esphome run your.yaml <...> [10:19:22]Core 1 register dump: [10:19:22]PC : 0x4000c46c PS : 0x00060030 A0 : 0x800d3342 A1 : 0x3ffcf790 [10:19:22]A2 : 0x0000000c A3 : 0x00000000 A4 : 0x00000023 A5 : 0x0000000c [10:19:22]A6 : 0x00000001 A7 : 0x00000002 A8 : 0xfa000000 A9 : 0x00000000 [10:19:22]A10 : 0x0eec0000 A11 : 0xe3800000 A12 : 0x00060e23 A13 : 0x00060e23 [10:19:22]A14 : 0x00000001 A15 : 0x0000ea60 SAR : 0x0000000a EXCCAUSE: 0x0000001d [10:19:22]EXCVADDR: 0x0000000c LBEG : 0x4000c46c LEND : 0x4000c477 LCOUNT : 0x00000001 [10:19:22] [10:19:22]Backtrace:0x4000c469:0x3ffcf790 .... WARNING Found stack trace! Trying to decode it WARNING Decoded 0x400d333f: esphome::bedjet::BedjetCodec::decode_notify(unsigned char const*, unsigned short) at /home/karl/Projects/esphome/hardware/projects/.esphome/build/bedjet-controller/src/esphome/components/bedjet/bedjet_codec.cpp:95 <....>
[03:14:44][D][bedjet:239]: [94:B5:55:17:E8:CA] Services complete: obtained char handles. [03:14:44][D][esp32_ble_tracker:246]: Starting scan... [03:14:44][D][bedjet:435]: [94:B5:55:17:E8:CA] wrote notify=true to status config 0x002b, for conn 0 [03:14:44]Guru Meditation Error: Core 1 panic'ed (StoreProhibited). Exception was unhandled. [03:14:44] [03:14:44]Core 1 register dump: [03:14:44]PC : 0x400909a0 PS : 0x00060330 A0 : 0x800d9a51 A1 : 0x3ffcf540 WARNING Decoded 0x400909a0: memset at /builds/idf/crosstool-NG/.build/xtensa-esp32-elf/src/newlib/newlib/libc/machine/xtensa/memset.S:150 [03:14:44]A2 : 0x0000000c A3 : 0x00000000 A4 : 0x00000023 A5 : 0x0000000c [03:14:44]A6 : 0x3ffc3e24 A7 : 0x00000002 A8 : 0xfa000000 A9 : 0x00000000 [03:14:44]A10 : 0x0f990000 A11 : 0xb3400000 A12 : 0x3ffcc7dc A13 : 0x3fff44e4 [03:14:44]A14 : 0x3ffc55c0 A15 : 0x00000001 SAR : 0x0000000a EXCCAUSE: 0x0000001d [03:14:44]EXCVADDR: 0x0000000c LBEG : 0x400909a0 LEND : 0x400909ab LCOUNT : 0x00000001 [03:14:44] [03:14:44] [03:14:44]Backtrace:0x4009099d:0x3ffcf5400x400d9a4e:0x3ffcf550 0x400dae00:0x3ffcf570 0x400dcc66:0x3ffcf5c0 0x402077b9:0x3ffcf5f0 0x400e064d:0x3ffcf610 0x40207781:0x3ffcf630 0x400df2fd:0x3ffcf650 0x40207b75:0x3ffcf670 0x40207c35:0x3ffcf690 0x400e8252:0x3ffcf6b0 0x400ea9dd:0x3ffcf6e0 0x400f5e82:0x3ffcf7e0 WARNING Found stack trace! Trying to decode it WARNING Decoded 0x4009099d: memset at /builds/idf/crosstool-NG/.build/xtensa-esp32-elf/src/newlib/newlib/libc/machine/xtensa/memset.S:143 WARNING Decoded 0x400d9a4e: esphome::bedjet::BedjetCodec::decode_notify(unsigned char const, unsigned short) at /home/nochum/.esphome/build/bedjet-3/src/esphome/components/bedjet/bedjet_codec.cpp:95 WARNING Decoded 0x400dae00: esphome::bedjet::BedJetHub::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t) at /home/Redacted/.esphome/build/bedjet-3/src/esphome/components/bedjet/bedjet_hub.cpp:378 WARNING Decoded 0x400dcc66: esphome::ble_client::BLEClient::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t) at /home/Redacted/.esphome/build/bedjet-3/src/esphome/components/ble_client/ble_client.cpp:58 (discriminator 2) WARNING Decoded 0x402077b9: esphome::esp32_ble_tracker::ESP32BLETracker::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t) at /home/Redacted/.esphome/build/bedjet-3/src/esphome/components/esp32_ble_tracker/esp32_ble_tracker.cpp:346 (discriminator 2) WARNING Decoded 0x400e064d: non-virtual thunk to esphome::esp32_ble_tracker::ESP32BLETracker::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t) WARNING Decoded 0x40207781: esphome::esp32_ble::ESP32BLE::real_gattc_eventhandler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t) at /home/Redacted/.esphome/build/bedjet-3/src/esphome/components/esp32_ble/ble.cpp:208 (discriminator 2) WARNING Decoded 0x400df2fd: esphome::esp32_ble::ESP32BLE::loop() at /home/Redacted/.esphome/build/bedjet-3/src/esphome/components/esp32_ble/ble.cpp:158 WARNING Decoded 0x40207b75: esphome::Component::call_loop() at /home/Redacted/.esphome/build/bedjet-3/src/esphome/core/component.cpp:76 WARNING Decoded 0x40207c35: esphome::Component::call() at /home/Redacted/.esphome/build/bedjet-3/src/esphome/core/component.cpp:98 WARNING Decoded 0x400e8252: esphome::Application::setup() at /home/Redacted/.esphome/build/bedjet-3/src/esphome/core/application.cpp:52 (discriminator 2) WARNING Decoded 0x400ea9dd: setup() at /home/Redacted/.esphome/build/bedjet-3/src/main.cpp:330 WARNING Decoded 0x400f5e82: loopTask(void*) at /home/Redacted/.platformio/packages/framework-arduinoespressif32/cores/esp32/main.cpp:42 [03:14:45] [03:14:45] [03:14:45] [03:14:45] [03:14:45]ELF file SHA256: 0000000000000000 [03:14:45]
is this good?
Yeah, and it looks like the same problem as reported earlier in the comments: memset() from BedjetCodec::decode_notify.
What doesn't make sense however, is that I'm not manually allocating that memory address - it's allocated automatically. So I don't understand how it can be getting StoreProhibited
here, if that object was already allocated by the platform.
// Clear old buffer
memset(&this->buf_, 0, sizeof(BedjetStatusPacket));
class BedjetCodec {
...
BedjetStatusPacket buf_;
}
The buf_
field is allocated for us.
For those of you having this crash, can you try with this branch, and provide the logs of the same stack trace, as well as the bedjet
logs leading up to the crash?
# for debugging https://github.com/esphome/issues/issues/3807
external_components:
- source: github://jhansche/esphome@test/3807
components: [ bedjet ]
refresh: 5sec
I've added a new DEBUG level log message before the crashing code. The log I'm looking for will look like:
[00:00:00][D][bedjet:000]: Writing ## bytes to @0x####, from @0x####…
cc @nochlab1 @kquinsland
For those of you having this crash, can you try with this branch, and provide the logs of the same stack trace, as well as the
bedjet
logs leading up to the crash?# for debugging https://github.com/esphome/issues/issues/3807 external_components: - source: github://jhansche/esphome@test/3807 components: [ bedjet ] refresh: 5sec
I've added a new DEBUG level log message before the crashing code. The log I'm looking for will look like:
[00:00:00][D][bedjet:000]: Writing ## bytes to @0x####, from @0x####…
cc @nochlab1 @kquinsland
uto-detected Flash size: 4MB Flash will be erased from 0x00010000 to 0x001a5fff... Flash will be erased from 0x00001000 to 0x00005fff... Flash will be erased from 0x00008000 to 0x00008fff... Flash will be erased from 0x0000e000 to 0x0000ffff... Compressed 1661312 bytes to 1098030... Wrote 1661312 bytes (1098030 compressed) at 0x00010000 in 25.0 seconds (effective 531.2 kbit/s)... Hash of data verified. Compressed 17440 bytes to 12127... Wrote 17440 bytes (12127 compressed) at 0x00001000 in 0.5 seconds (effective 275.4 kbit/s)... Hash of data verified. Compressed 3072 bytes to 144... Wrote 3072 bytes (144 compressed) at 0x00008000 in 0.0 seconds (effective 520.6 kbit/s)... Hash of data verified. Compressed 8192 bytes to 47... Wrote 8192 bytes (47 compressed) at 0x0000e000 in 0.1 seconds (effective 737.5 kbit/s)... Hash of data verified.
Leaving...
Hard resetting via RTS pin...
INFO Successfully uploaded program.
INFO Starting log output from /dev/ttyUSB0 with baud rate 115200
[00:39:17][I][logger:258]: Log initialized
[00:39:17][C][ota:469]: There have been 5 suspected unsuccessful boot attempts.
[00:39:17][D][esp32.preferences:113]: Saving 1 preferences to flash...
[00:39:17][D][esp32.preferences:142]: Saving 1 preferences to flash: 0 cached, 1 written, 0 failed
[00:39:17][I][app:029]: Running through setup()...
[00:39:17][C][esp32_ble:026]: Setting up BLE...
[00:39:18][D][esp32_ble:042]: BLE setup complete
[00:39:18][D][esp32_ble_tracker:246]: Starting scan...
[00:39:18][C][wifi:037]: Setting up WiFi...
[00:39:18][C][wifi:038]: Local MAC: EC:62:60:75:D5:30
[00:39:18][D][wifi:386]: Starting scan...
[00:39:18][D][switch:056]: 'Enable Bedjet': Sending state ON
[00:39:18][D][esp32_ble_client:048]: [0] [94:B5:55:17:E8:CA] Found device
[00:39:18][D][esp32_ble_tracker:214]: Pausing scan to make connection...
[00:39:18][D][esp32_ble_tracker:214]: Pausing scan to make connection...
[00:39:18][I][esp32_ble_client:064]: [0] [94:B5:55:17:E8:CA] 0x00 Attempting BLE connection
[00:39:21][I][esp32_ble_client:196]: [0] [94:B5:55:17:E8:CA] Connected
[00:39:21][I][bedjet:217]: [94:B5:55:17:E8:CA] Discovered service characteristics:
[00:39:21][I][bedjet:218]: - Command char: 0x33
[00:39:21][I][bedjet:219]: - Status char: 0x2a
[00:39:21][I][bedjet:220]: - config descriptor: 0x2b
[00:39:21][I][bedjet:221]: - Name char: 0x2d
[00:39:21][D][bedjet:239]: [94:B5:55:17:E8:CA] Services complete: obtained char handles.
[00:39:21][D][esp32_ble_tracker:246]: Starting scan...
[00:39:21][D][bedjet:435]: [94:B5:55:17:E8:CA] wrote notify=true to status config 0x002b, for conn 0
[00:39:21][D][bedjet:096]: Writing 20 bytes to @0xc, from @0x3fff40dc. Clearing 0..35(35) first.
[00:39:21]Guru Meditation Error: Core 1 panic'ed (StoreProhibited). Exception was unhandled.
[00:39:21]
[00:39:21]Core 1 register dump:
[00:39:21]PC : 0x400909a0 PS : 0x00060130 A0 : 0x800d91d8 A1 : 0x3ffcf640
WARNING Decoded 0x400909a0: memset at /builds/idf/crosstool-NG/.build/xtensa-esp32-elf/src/newlib/newlib/libc/machine/xtensa/memset.S:150
[00:39:21]A2 : 0x0000000c A3 : 0x00000000 A4 : 0x00000023 A5 : 0x0000000c
[00:39:21]A6 : 0x00000014 A7 : 0x00000002 A8 : 0x800e7c91 A9 : 0x3ffcf5c0
[00:39:21]A10 : 0x00000005 A11 : 0x3f400f31 A12 : 0x00000060 A13 : 0x3f400f38
[00:39:21]A14 : 0x3ffcf744 A15 : 0x00000000 SAR : 0x00000004 EXCCAUSE: 0x0000001d
[00:39:21]EXCVADDR: 0x0000000c LBEG : 0x400909a0 LEND : 0x400909ab LCOUNT : 0x00000001
[00:39:21]
[00:39:21]
[00:39:21]Backtrace:0x4009099d:0x3ffcf6400x400d91d5:0x3ffcf650 0x400da588:0x3ffcf680 0x400dc07a:0x3ffcf6d0 0x40205e89:0x3ffcf700 0x400dfa61:0x3ffcf720 0x40205e51:0x3ffcf740 0x400de711:0x3ffcf760 0x40206235:0x3ffcf780 0x402062f5:0x3ffcf7a0 0x400e718a:0x3ffcf7c0 0x400e935e:0x3ffcf7f0 0x400f4762:0x3ffcf8d0
WARNING Found stack trace! Trying to decode it
WARNING Decoded 0x4009099d: memset at /builds/idf/crosstool-NG/.build/xtensa-esp32-elf/src/newlib/newlib/libc/machine/xtensa/memset.S:143
WARNING Decoded 0x400d91d5: esphome::bedjet::BedjetCodec::decode_notify(unsigned char const, unsigned short) at /config/esphome/.esphome/build/bedjet/src/esphome/components/bedjet/bedjet_codec.cpp:99
WARNING Decoded 0x400da588: esphome::bedjet::BedJetHub::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t) at /config/esphome/.esphome/build/bedjet/src/esphome/components/bedjet/bedjet_hub.cpp:378
WARNING Decoded 0x400dc07a: esphome::ble_client::BLEClient::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t) at /config/esphome/.esphome/build/bedjet/src/esphome/components/ble_client/ble_client.cpp:58 (discriminator 2)
WARNING Decoded 0x40205e89: esphome::esp32_ble_tracker::ESP32BLETracker::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t) at /config/esphome/.esphome/build/bedjet/src/esphome/components/esp32_ble_tracker/esp32_ble_tracker.cpp:346 (discriminator 2)
WARNING Decoded 0x400dfa61: non-virtual thunk to esphome::esp32_ble_tracker::ESP32BLETracker::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t)
WARNING Decoded 0x40205e51: esphome::esp32_ble::ESP32BLE::real_gattc_eventhandler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t) at /config/esphome/.esphome/build/bedjet/src/esphome/components/esp32_ble/ble.cpp:208 (discriminator 2)
WARNING Decoded 0x400de711: esphome::esp32_ble::ESP32BLE::loop() at /config/esphome/.esphome/build/bedjet/src/esphome/components/esp32_ble/ble.cpp:158
WARNING Decoded 0x40206235: esphome::Component::call_loop() at /config/esphome/.esphome/build/bedjet/src/esphome/core/component.cpp:76
WARNING Decoded 0x402062f5: esphome::Component::call() at /config/esphome/.esphome/build/bedjet/src/esphome/core/component.cpp:98
WARNING Decoded 0x400e718a: esphome::Application::setup() at /config/esphome/.esphome/build/bedjet/src/esphome/core/application.cpp:52 (discriminator 2)
WARNING Decoded 0x400e935e: setup() at /config/esphome/.esphome/build/bedjet/src/main.cpp:290
WARNING Decoded 0x400f4762: loopTask(void*) at /data/cache/platformio/packages/framework-arduinoespressif32/cores/esp32/main.cpp:42
[00:39:22]
[00:39:22]
[00:39:22]
[00:39:22]
[00:39:22]ELF file SHA256: 0000000000000000
[00:39:22]
[00:39:22]Rebooting...
[00:39:22]ets Jul 29 2019 12:21:46
[00:39:22]
[00:39:22]rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
[00:39:22]configsip: 0, SPIWP:0xee
[00:39:22]clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
[00:39:22]mode:DIO, clock div:2
[00:39:22]load:0x3fff0030,len:1184
[00:39:22]load:0x40078000,len:13132
[00:39:22]load:0x40080400,len:3036
[00:39:22]entry 0x400805e4
[00:39:22][I][logger:258]: Log initialized
(after crashing 2 times it connected)
i reflashed and now it works
i reflashed and now it works
Reflashed from my branch, and it stopped crashing?
The 0xC memory address does not look normal to me, and almost certainly highlights the root of this bug. I expect it to be more similar to the other address 0x3fff40dc.
@nochlab1 that is helpful - I have a few more log statements to verify my suspicions, if you wouldn't mind rebuilding and redeploying from the same branch, and report back what logs you get.
I suspect that this is a race condition between the component setup order: BLEClient is setup using AFTER_BLUETOOTH, while BedJet is setup with AFTER_WIFI. BLEClient gets setup first, and then BedJet later. Normally that's probably not a problem, but if the BedJet is actively broadcasting notification packets (while there's no client listening to those packets), then as soon as BLEClient is initialized, it will start trying to dispatch these gatt events, including the notify packet. But if BedJet hasn't been initialized yet, it will be trying to handle a packet on an incomplete component, so the memory address will be uninitialized (null / 0), and trying to access the status packet buffer on that, results in a memory address of 0xc
which is invalid, hence the crash you're seeing.
@nochlab1 that is helpful - I have a few more log statements to verify my suspicions, if you wouldn't mind rebuilding and redeploying from the same branch, and report back what logs you get.
I suspect that this is a race condition between the component setup order: BLEClient is setup using AFTER_BLUETOOTH, while BedJet is setup with AFTER_WIFI. BLEClient gets setup first, and then BedJet later. Normally that's probably not a problem, but if the BedJet is actively broadcasting notification packets (while there's no client listening to those packets), then as soon as BLEClient is initialized, it will start trying to dispatch these gatt events, including the notify packet. But if BedJet hasn't been initialized yet, it will be trying to handle a packet on an incomplete component, so the memory address will be uninitialized (null / 0), and trying to access the status packet buffer on that, results in a memory address of
0xc
which is invalid, hence the crash you're seeing.
HARDWARE: ESP32 240MHz, 320KB RAM, 4MB Flash
(side point esphome version v2022.9.0 works normally)
Whoops, my mistake. Should have tested it first 😳 Try now.
Linking /data/bedjet/.pioenvs/bedjet/firmware.elf
/data/cache/platformio/packages/toolchain-xtensa-esp32/bin/../lib/gcc/xtensa-esp32-elf/8.4.0/../../../../xtensa-esp32-elf/bin/ld: /data/bedjet/.pioenvs/bedjet/src/main.cpp.o:(.literal._Z5setupv+0xf8): undefined reference to vtable for esphome::bedjet::BedJetHub' /data/cache/platformio/packages/toolchain-xtensa-esp32/bin/../lib/gcc/xtensa-esp32-elf/8.4.0/../../../../xtensa-esp32-elf/bin/ld: /data/bedjet/.pioenvs/bedjet/src/main.cpp.o:(.literal._Z5setupv+0xfc): undefined reference to
vtable for esphome::bedjet::BedJetHub'
/data/cache/platformio/packages/toolchain-xtensa-esp32/bin/../lib/gcc/xtensa-esp32-elf/8.4.0/../../../../xtensa-esp32-elf/bin/ld: /data/bedjet/.pioenvs/bedjet/src/main.cpp.o:(.literal._Z5setupv+0x10c): undefined reference to vtable for esphome::bedjet::BedJetClimate' /data/cache/platformio/packages/toolchain-xtensa-esp32/bin/../lib/gcc/xtensa-esp32-elf/8.4.0/../../../../xtensa-esp32-elf/bin/ld: /data/bedjet/.pioenvs/bedjet/src/main.cpp.o:(.literal._Z5setupv+0x110): undefined reference to
vtable for esphome::bedjet::BedJetClimate'
/data/cache/platformio/packages/toolchain-xtensa-esp32/bin/../lib/gcc/xtensa-esp32-elf/8.4.0/../../../../xtensa-esp32-elf/bin/ld: /data/bedjet/.pioenvs/bedjet/src/main.cpp.o:(.literal._Z5setupv+0x114): undefined reference to vtable for esphome::bedjet::BedJetClimate' /data/cache/platformio/packages/toolchain-xtensa-esp32/bin/../lib/gcc/xtensa-esp32-elf/8.4.0/../../../../xtensa-esp32-elf/bin/ld: /data/bedjet/.pioenvs/bedjet/src/main.cpp.o:(.literal._Z5setupv+0x128): undefined reference to
vtable for esphome::bedjet::BedJetFan'
/data/cache/platformio/packages/toolchain-xtensa-esp32/bin/../lib/gcc/xtensa-esp32-elf/8.4.0/../../../../xtensa-esp32-elf/bin/ld: /data/bedjet/.pioenvs/bedjet/src/main.cpp.o:(.literal._Z5setupv+0x12c): undefined reference to vtable for esphome::bedjet::BedJetFan' /data/cache/platformio/packages/toolchain-xtensa-esp32/bin/../lib/gcc/xtensa-esp32-elf/8.4.0/../../../../xtensa-esp32-elf/bin/ld: /data/bedjet/.pioenvs/bedjet/src/main.cpp.o:(.literal._Z5setupv+0x130): undefined reference to
vtable for esphome::bedjet::BedJetFan'
/data/cache/platformio/packages/toolchain-xtensa-esp32/bin/../lib/gcc/xtensa-esp32-elf/8.4.0/../../../../xtensa-esp32-elf/bin/ld: /data/bedjet/.pioenvs/bedjet/src/main.cpp.o:(.literal._Z5setupv+0x194): undefined reference to esphome::bedjet::BedJetHub::register_child(esphome::bedjet::BedJetClient*)' /data/cache/platformio/packages/toolchain-xtensa-esp32/bin/../lib/gcc/xtensa-esp32-elf/8.4.0/../../../../xtensa-esp32-elf/bin/ld: /data/bedjet/.pioenvs/bedjet/src/main.cpp.o: in function
esphome::bedjet::BedJetHub::BedJetHub()':
/config/esphome/.esphome/build/bedjet/src/esphome/components/bedjet/bedjet_hub.h:36: undefined reference to esphome::bedjet::BedJetHub::register_child(esphome::bedjet::BedJetClient*)' /data/cache/platformio/packages/toolchain-xtensa-esp32/bin/../lib/gcc/xtensa-esp32-elf/8.4.0/../../../../xtensa-esp32-elf/bin/ld: /data/bedjet/.pioenvs/bedjet/src/main.cpp.o: in function
setup()':
/config/esphome/.esphome/build/bedjet/src/main.cpp:269: undefined reference to `esphome::bedjet::BedJetHub::register_child(esphome::bedjet::BedJetClient*)'
collect2: error: ld returned 1 exit status
*** [/data/bedjet/.pioenvs/bedjet/firmware.elf] Error 1
========================= [FAILED] Took 34.96 seconds =========================
That looks like a build cache issue. What version of esphome are you building with (my test branch is based on dev from last week, but I tested the build with the current release, and it succeeded)? If you're still on 2022.9, that might be why this fails to link.
You could install the beta or dev version of the addon, and just stop 22.9 and start beta or dev, and try to rebuild. That way if you need to go back to 22.9, you can switch back.
I suspect that this is a race condition between the component setup order: BLEClient is setup using AFTER_BLUETOOTH, while BedJet is setup with AFTER_WIFI. BLEClient gets setup first, and then BedJet later. Normally that's probably not a problem, but if the BedJet is actively broadcasting notification packets (while there's no client listening to those packets), then as soon as BLEClient is initialized, it will start trying to dispatch these gatt events, including the notify packet. But if BedJet hasn't been initialized yet, it will be trying to handle a packet on an incomplete component, so the memory address will be uninitialized (null / 0), and trying to access the status packet buffer on that, results in a memory address of
0xc
which is invalid, hence the crash you're seeing.
Thinking through it, that would certainly explain it. I'll try to build/flash my bedjet ESP32 today w/ your branch and get back to you. Do you want me to first try "stock" 2023.03.02
but with some custom setup_priority
values on the two components to serve as a control of this theory, @jhansche ?
The current test branch logs should be able to prove the theory, and the fix would likely be updating BedJet's setup priority to setup_priority::DATA
. The main reason to test the logging first before making changes to setup_priority, is because if that's the problem, then fixing setup_priority would prevent the crash, but it's already a race condition. So getting the logs when the crash is occurring is more meaningful than just not getting a crash.
If the current test branch does not log the BedJetHub::setup
debug log line before crashing, then that is very likely the root cause, because that is when the codec_
pointer is initialized. If you see the BedJetHub::setup line get logged, then it most likely will not crash.
If you see the log line and it crashes, then we have to go back to the drawing board.
-- And if this is what's causing it, then the actual problem leading to the crash is that the BedJet unit is still broadcasting notify packets while there's no client associated, so when BLEClient initializes, it's immediately getting packets that the BedJet component hasn't requested yet. If the unit were reset or power cycled before esphome starts up, then that situation wouldn't happen, and it won't crash. This is likely why I haven't observed it myself.
We might be able to emulate that bad state by power cycling the esp32 while it's connected to the BedJet unit. In that case the BedJet doesn't know that the client has disappeared, so when esphome starts back up, it'll still be broadcasting the BLE notify events.
I've done some isolated experiments, and that theory appears to hold true. Because calling an instance method on a pointer does not dereference that pointer, it is possible to call a method on a null pointer (officially this is considered undefined behavior, but there's no actual enforcement that prevents it from happening). That experiment also confirms my theory about why your logs shows the address of &this->buf_
being 0xC
.
I think I'm going to just move forward with the setup_priority change. I've seen enough to convince me that this is the bug.
As promised, here's my results:
Prep:
# Confirm on stock 2023.03.02 release
pip install esphome --upgrade
# Confirm build_root cache is empty
esphome clean projects/bedjet.yaml
Below are (lightly) edited outputs. The first I had logger set to INFO
, second was after I switched to DEBUG
.
Linking .pioenvs/bedjet-controller/firmware.elf
RAM: [== ] 17.8% (used 58272 bytes from 327680 bytes)
Flash: [======= ] 74.7% (used 1370841 bytes from 1835008 bytes)
<...>
INFO Successfully uploaded program.
INFO Starting log output from /dev/ttyUSB0 with baud rate 115200
[15:56:24]\xa5\xd9\xe92
[15:56:24]load:0x3fff0030,len:6660
[15:56:24]load:0x40078000,len:14944
[15:56:24]ho 0 tail 12 room 4
[15:56:24]load:0x40080400,len:3816
[15:56:24]entry 0x40080698
[15:56:24]I (28) boot: ESP-IDF 4.4.4 2nd stage bootloader
[15:56:24]I (28) boot: compile time 15:55:50
[15:56:24]I (28) boot: chip revision: v1.0
[15:56:24]I (31) boot_comm: chip revision: 1, min. bootloader chip revision: 0
[15:56:24]I (38) boot.esp32: SPI Speed : 40MHz
[15:56:24]I (43) boot.esp32: SPI Mode : DIO
[15:56:24]I (47) boot.esp32: SPI Flash Size : 4MB
[15:56:24]I (52) boot: Enabling RNG early entropy source...
[15:56:24]I (57) boot: Partition Table:
[15:56:24]I (61) boot: ## Label Usage Type ST Offset Length
[15:56:24]I (68) boot: 0 otadata OTA data 01 00 00009000 00002000
[15:56:24]I (76) boot: 1 phy_init RF data 01 01 0000b000 00001000
[15:56:24]I (83) boot: 2 app0 OTA app 00 10 00010000 001c0000
[15:56:24]I (91) boot: 3 app1 OTA app 00 11 001d0000 001c0000
[15:56:24]I (98) boot: 4 nvs WiFi data 01 02 00390000 0006d000
[15:56:24]I (106) boot: End of partition table
[15:56:24]I (110) boot: No factory image, trying OTA 0
[15:56:24]I (115) boot_comm: chip revision: 1, min. application chip revision: 0
[15:56:24]I (122) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=3453ch (214332) map
[15:56:24]I (208) esp_image: segment 1: paddr=00044564 vaddr=3ffbdb60 size=053f8h ( 21496) load
[15:56:24]I (217) esp_image: segment 2: paddr=00049964 vaddr=40080000 size=066b4h ( 26292) load
[15:56:24]I (228) esp_image: segment 3: paddr=00050020 vaddr=400d0020 size=f93e4h (1020900) map
[15:56:24]I (598) esp_image: segment 4: paddr=0014940c vaddr=400866b4 size=16d18h ( 93464) load
[15:56:24]I (650) boot: Loaded app from partition at offset 0x10000
[15:56:24]I (686) boot: Set actual ota_seq=1 in otadata[0]
[15:56:24]I (687) boot: Disabling RNG early entropy source...
[15:56:24]I (697) cpu_start: Pro cpu up.
[15:56:24]I (698) cpu_start: Starting app cpu, entry point is 0x40082308
[15:56:24]I (0) cpu_start: App cpu up.
[15:56:25]I (714) cpu_start: Pro cpu start user code
[15:56:25]I (714) cpu_start: cpu freq: 160000000
[15:56:25]I (714) cpu_start: Application information:
[15:56:25]I (718) cpu_start: Project name: bedjet-controller
[15:56:25]I (724) cpu_start: App version: 2023.3.2
[15:56:25]I (729) cpu_start: Compile time: Apr 11 2023 15:55:37
[15:56:25]I (735) cpu_start: ELF file SHA256: 93154bdb1ea08ab7...
[15:56:25]I (741) cpu_start: ESP-IDF: 4.4.4
[15:56:25]I (746) heap_init: Initializing. RAM available for dynamic allocation:
[15:56:25]I (753) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
[15:56:25]I (759) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
[15:56:25]I (765) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
[15:56:25]I (772) heap_init: At 3FFCBF00 len 00014100 (80 KiB): DRAM
[15:56:25]I (778) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
[15:56:25]I (784) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
[15:56:25]I (791) heap_init: At 4009D3CC len 00002C34 (11 KiB): IRAM
[15:56:25]I (798) spi_flash: detected chip: winbond
[15:56:25]I (801) spi_flash: flash io: dio
[15:56:25]I (810) cpu_start: Starting scheduler on PRO CPU.
[15:56:25]I (0) cpu_start: Starting scheduler on APP CPU.
[15:56:25][I][logger:258]: Log initialized
[15:56:25][I][esp-idf:000]: I (211) gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
[15:56:25]
[15:56:25][I][app:029]: Running through setup()...
[15:56:25][I][esp-idf:000]: I (230) BTDM_INIT: BT controller compile version [8020d24]
[15:56:25]
[15:56:25][I][esp-idf:000]: I (1275) system_api: Base MAC address is not set
[15:56:25]
[15:56:25][I][esp-idf:000]: I (1276) system_api: read default base MAC address from EFUSE
[15:56:25]
[15:56:25][I][esp-idf:000]: I (1278) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
[15:56:25]
[15:56:25][I][esp-idf:000]: I (1915) wifi:
[15:56:25][I][esp-idf:000]: wifi driver task: 3ffe365c, prio:23, stack:6656, core=0
[15:56:25][I][esp-idf:000]:
[15:56:25]
[15:56:25][I][esp-idf:000]: I (1923) wifi:
[15:56:25][I][esp-idf:000]: wifi firmware version: 6567a16
[15:56:25][I][esp-idf:000]:
[15:56:25]
[15:56:25][I][esp-idf:000]: I (1924) wifi:
[15:56:25][I][esp-idf:000]: wifi certification version: v7.0
[15:56:25][I][esp-idf:000]:
[15:56:25]
[15:56:25][I][esp-idf:000]: I (1929) wifi:
[15:56:26][I][esp-idf:000]: config NVS flash: enabled
[15:56:26][I][esp-idf:000]:
[15:56:26]
[15:56:26][I][esp-idf:000]: I (1939) wifi:
[15:56:26][I][esp-idf:000]: config nano formating: disabled
[15:56:26][I][esp-idf:000]:
[15:56:26]
[15:56:26][I][esp-idf:000]: I (1950) wifi:
[15:56:26][I][esp-idf:000]: Init data frame dynamic rx buffer num: 32
[15:56:26][I][esp-idf:000]:
[15:56:26]
[15:56:26][I][esp-idf:000]: I (1970) wifi:
[15:56:26][I][esp-idf:000]: Init management frame dynamic rx buffer num: 32
[15:56:26][I][esp-idf:000]:
[15:56:26]
[15:56:26][I][esp-idf:000]: I (1980) wifi:
[15:56:26][I][esp-idf:000]: Init management short buffer num: 32
[15:56:26][I][esp-idf:000]:
[15:56:26]
[15:56:26][I][esp-idf:000]: I (1991) wifi:
[15:56:26][I][esp-idf:000]: Init dynamic tx buffer num: 32
[15:56:26][I][esp-idf:000]:
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2011) wifi:
[15:56:26][I][esp-idf:000]: Init static rx buffer size: 1600
[15:56:26][I][esp-idf:000]:
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2021) wifi:
[15:56:26][I][esp-idf:000]: Init static rx buffer num: 10
[15:56:26][I][esp-idf:000]:
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2031) wifi:
[15:56:26][I][esp-idf:000]: Init dynamic rx buffer num: 32
[15:56:26][I][esp-idf:000]:
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2043) wifi_init: rx ba win: 6
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2043) wifi_init: tcpip mbox: 32
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2052) wifi_init: udp mbox: 6
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2052) wifi_init: tcp mbox: 6
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2062) wifi_init: tcp tx win: 5744
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2072) wifi_init: tcp rx win: 5744
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2072) wifi_init: tcp mss: 1440
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2083) wifi_init: WiFi IRAM OP enabled
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2093) wifi_init: WiFi RX IRAM OP enabled
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2097) wifi:
[15:56:26][I][esp-idf:000]: mode : sta (ES:P3:2M:AC:09:30)
[15:56:26][I][esp-idf:000]:
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2114) wifi:
[15:56:26][I][esp-idf:000]: enable tsf
[15:56:26][I][esp-idf:000]:
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2124) wifi:
[15:56:26][I][esp-idf:000]: Set ps type: 1
[15:56:26]
[15:56:26][I][esp-idf:000]:
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2135) wifi:
[15:56:26][I][esp-idf:000]: Error! Should use default active scan time parameter for WiFi scan when Bluetooth is enabled!!!!!!
[15:56:26]
[15:56:26][I][esp-idf:000]:
[15:56:26]
[15:56:26][I][esp-idf:000]: I (2148) wifi:
[15:56:26][I][esp-idf:000]: Set ps type: 1
[15:56:26]
[15:56:26][I][esp-idf:000]:
[15:56:26]
[15:56:26][W][esp32_ble_tracker:119]: Too many BLE events to process. Some devices may not show up.
[15:56:26][I][esp-idf:000]: E (2173) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2174) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2175) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2185) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2195) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2205) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2206) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2216) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2226) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2236) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2247) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2257) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2257) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2267) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2277) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2287) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2298) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2298) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2308) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2318) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2328) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2339) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2339) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2349) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2359) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2369) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2380) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2390) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2391) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2400) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2410) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2421) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2431) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2441) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2441) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2451) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2462) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2472) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2482) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2482) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2492) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2503) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2513) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2523) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2523) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2533) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2544) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2554) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2564) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2574) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2574) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2584) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2595) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2605) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2615) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2625) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2626) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2636) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2646) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2656) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2666) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2667) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2677) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2687) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2697) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2707) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2708) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2718) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2728) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2738) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2748) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2759) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2759) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2769) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2779) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2789) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2800) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2800) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2810) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2820) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: E (2830) BT_BTM: BTM_BleScan scan not active
[15:56:26]
[15:56:26]
[15:56:26][I][esp-idf:000]: W (2841) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:26]
[15:56:26]
[15:56:28][I][wifi:445]: - 'myWiFiNetWorkName' (Wi:Fi:AP:AD:DY:02) ▂▄▆█
[15:56:28][I][wifi:257]: WiFi Connecting to 'myWiFiNetWorkName'...
[15:56:29][I][esp-idf:000]: I (4953) wifi:
[15:56:29][I][esp-idf:000]: new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
[15:56:29][I][esp-idf:000]:
[15:56:29]
[15:56:30][I][esp-idf:000]: I (6509) wifi:
[15:56:30][I][esp-idf:000]: state: init -> auth (b0)
[15:56:30][I][esp-idf:000]:
[15:56:30]
[15:56:30][I][esp-idf:000]: I (6517) wifi:
[15:56:30][I][esp-idf:000]: state: auth -> assoc (0)
[15:56:30][I][esp-idf:000]:
[15:56:30]
[15:56:30][I][esp-idf:000]: I (6525) wifi:
[15:56:30][I][esp-idf:000]: state: assoc -> run (10)
[15:56:30][I][esp-idf:000]:
[15:56:30]
[15:56:30][I][esp-idf:000]: I (6570) wifi:
[15:56:30][I][esp-idf:000]: connected with myWiFiNetWorkName, aid = 26, channel 1, BW20, bssid = Wi:Fi:AP:AD:DY:02
[15:56:30][I][esp-idf:000]:
[15:56:30]
[15:56:30][I][esp-idf:000]: I (6571) wifi:
[15:56:30][I][esp-idf:000]: security: WPA2-PSK, phy: bgn, rssi: -48
[15:56:30][I][esp-idf:000]:
[15:56:30]
[15:56:30][I][esp-idf:000]: I (6574) wifi:
[15:56:30][I][esp-idf:000]: pm start, type: 1
[15:56:30]
[15:56:30][I][esp-idf:000]:
[15:56:30]
[15:56:30][I][esp-idf:000]: I (6649) wifi:
[15:56:30][I][esp-idf:000]: AP's beacon interval = 102400 us, DTIM period = 1
[15:56:30][I][esp-idf:000]:
[15:56:30]
[15:56:31][I][esp32_ble_client:196]: [0] [BE:DJ:ET:DE:VI:CE] Connected
[15:56:31][I][bedjet:217]: [BE:DJ:ET:DE:VI:CE] Discovered service characteristics:
[15:56:31][I][bedjet:218]: - Command char: 0x33
[15:56:31][I][bedjet:219]: - Status char: 0x2a
[15:56:31][I][bedjet:220]: - config descriptor: 0x2b
[15:56:31][I][bedjet:221]: - Name char: 0x2d
[15:56:31]
[15:56:31]assert failed: virtual void esphome::bedjet::BedJetHub::gattc_event_handler(esp_gattc_cb_event_t, esp_gatt_if_t, esp_ble_gattc_cb_param_t*) bedjet_hub.cpp:378 (this->codec_ != nullptr)
[15:56:31]
[15:56:31]
[15:56:31]Backtrace: 0x40082c42:0x3ffd0b30 0x400911c1:0x3ffd0b50 0x400978b5:0x3ffd0b70 0x400d4402:0x3ffd0c90 0x400d608a:0x3ffd0ce0 0x401c2165:0x3ffd0d10 0x400d9175:0x3ffd0d30 0x401c212d:0x3ffd0d50 0x400d7efd:0x3ffd0d70 0x401c2c1d:0x3ffd0d90 0x401c2d09:0x3ffd0db0 0x400e5c6e:0x3ffd0dd0 0x400e8dad:0x3ffd0e00 0x400d740f:0x3ffd0ee0
WARNING Found stack trace! Trying to decode it
WARNING Decoded 0x40082c42: panic_abort at /home/karl/.platformio/packages/framework-espidf/components/esp_system/panic.c:408
WARNING Decoded 0x400911c1: esp_system_abort at /home/karl/.platformio/packages/framework-espidf/components/esp_system/esp_system.c:137
WARNING Decoded 0x400978b5: __assert_func at /home/karl/.platformio/packages/framework-espidf/components/newlib/assert.c:85
WARNING Decoded 0x400d4402: esphome::bedjet::BedJetHub::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/components/bedjet/bedjet_hub.cpp:378 (discriminator 1)
WARNING Decoded 0x400d608a: esphome::ble_client::BLEClient::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/components/ble_client/ble_client.cpp:58 (discriminator 2)
WARNING Decoded 0x401c2165: esphome::esp32_ble_tracker::ESP32BLETracker::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/components/esp32_ble_tracker/esp32_ble_tracker.cpp:346 (discriminator 2)
WARNING Decoded 0x400d9175: non-virtual thunk to esphome::esp32_ble_tracker::ESP32BLETracker::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*)
WARNING Decoded 0x401c212d: esphome::esp32_ble::ESP32BLE::real_gattc_event_handler_(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/components/esp32_ble/ble.cpp:208 (discriminator 2)
WARNING Decoded 0x400d7efd: esphome::esp32_ble::ESP32BLE::loop() at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/components/esp32_ble/ble.cpp:158
WARNING Decoded 0x401c2c1d: esphome::Component::call_loop() at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/core/component.cpp:76
WARNING Decoded 0x401c2d09: esphome::Component::call() at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/core/component.cpp:98
WARNING Decoded 0x400e5c6e: esphome::Application::setup() at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/core/application.cpp:52 (discriminator 2)
WARNING Decoded 0x400e8dad: setup() at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/projects/bedjet.yaml:254
WARNING Decoded 0x400d740f: esphome::loop_task(void*) at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/components/esp32/core.cpp:72
[15:56:31]
[15:56:31]
[15:56:31]
[15:56:31]
[15:56:31]ELF file SHA256: 93154bdb1ea08ab7
[15:56:31]
[15:56:31]Rebooting...
[15:56:31]ets Jun 8 2016 00:22:57
[15:56:31]
[15:56:31]rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
[15:56:31]configsip: 0, SPIWP:0xee
[15:56:31]clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
[15:56:31]mode:DIO, clock div:2
[15:56:31]load:0x3fff0030,len:6660
[15:56:31]load:0x40078000,len:14944
[15:56:31]ho 0 tail 12 room 4
[15:56:31]load:0x40080400,len:3816
[15:56:31]entry 0x40080698
[15:56:31]I (29) boot: ESP-IDF 4.4.4 2nd stage bootloader
[15:56:31]I (29) boot: compile time 15:55:50
[15:56:31]I (29) boot: chip revision: v1.0
[15:56:31]I (32) boot_comm: chip revision: 1, min. bootloader chip revision: 0
[15:56:31]I (39) boot.esp32: SPI Speed : 40MHz
[15:56:31]I (44) boot.esp32: SPI Mode : DIO
[15:56:31]I (48) boot.esp32: SPI Flash Size : 4MB
[15:56:31]I (53) boot: Enabling RNG early entropy source...
[15:56:31]I (58) boot: Partition Table:
[15:56:31]I (62) boot: ## Label Usage Type ST Offset Length
[15:56:31]I (69) boot: 0 otadata OTA data 01 00 00009000 00002000
[15:56:31]I (76) boot: 1 phy_init RF data 01 01 0000b000 00001000
[15:56:31]I (84) boot: 2 app0 OTA app 00 10 00010000 001c0000
[15:56:31]I (91) boot: 3 app1 OTA app 00 11 001d0000 001c0000
[15:56:31]I (99) boot: 4 nvs WiFi data 01 02 00390000 0006d000
[15:56:31]I (106) boot: End of partition table
[15:56:31]I (111) boot_comm: chip revision: 1, min. application chip revision: 0
[15:56:31]I (118) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=3453ch (214332) map
[15:56:31]I (204) esp_image: segment 1: paddr=00044564 vaddr=3ffbdb60 size=053f8h ( 21496) load
[15:56:31]I (213) esp_image: segment 2: paddr=00049964 vaddr=40080000 size=066b4h ( 26292) load
[15:56:31]I (224) esp_image: segment 3: paddr=00050020 vaddr=400d0020 size=f93e4h (1020900) map
[15:56:32]I (593) esp_image: segment 4: paddr=0014940c vaddr=400866b4 size=16d18h ( 93464) load
[15:56:32]I (646) boot: Loaded app from partition at offset 0x10000
[15:56:32]I (646) boot: Disabling RNG early entropy source...
[15:56:32]I (658) cpu_start: Pro cpu up.
[15:56:32]I (658) cpu_start: Starting app cpu, entry point is 0x40082308
[15:56:32]I (644) cpu_start: App cpu up.
[15:56:32]I (674) cpu_start: Pro cpu start user code
[15:56:32]I (674) cpu_start: cpu freq: 160000000
[15:56:32]I (675) cpu_start: Application information:
[15:56:32]I (679) cpu_start: Project name: bedjet-controller
[15:56:32]I (685) cpu_start: App version: 2023.3.2
[15:56:32]I (690) cpu_start: Compile time: Apr 11 2023 15:55:37
[15:56:32]I (696) cpu_start: ELF file SHA256: 93154bdb1ea08ab7...
[15:56:32]I (702) cpu_start: ESP-IDF: 4.4.4
[15:56:32]I (707) heap_init: Initializing. RAM available for dynamic allocation:
[15:56:32]I (714) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
[15:56:32]I (720) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
[15:56:32]I (726) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
[15:56:32]I (732) heap_init: At 3FFCBF00 len 00014100 (80 KiB): DRAM
[15:56:32]I (738) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
[15:56:32]I (745) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
[15:56:32]I (751) heap_init: At 4009D3CC len 00002C34 (11 KiB): IRAM
[15:56:32]I (759) spi_flash: detected chip: winbond
[15:56:32]I (762) spi_flash: flash io: dio
[15:56:32]I (771) cpu_start: Starting scheduler on PRO CPU.
[15:56:32]I (0) cpu_start: Starting scheduler on APP CPU.
[15:56:32][I][logger:258]: Log initialized
[15:56:32][I][esp-idf:000]: I (211) gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
[15:56:32]
[15:56:32][I][app:029]: Running through setup()...
[15:56:32][I][esp-idf:000]: I (230) BTDM_INIT: BT controller compile version [8020d24]
[15:56:32]
[15:56:32][I][esp-idf:000]: I (1236) system_api: Base MAC address is not set
[15:56:32]
[15:56:32][I][esp-idf:000]: I (1237) system_api: read default base MAC address from EFUSE
[15:56:32]
[15:56:32][I][esp-idf:000]: I (1239) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
[15:56:32]
[15:56:33][I][esp-idf:000]: I (1871) wifi:
[15:56:33][I][esp-idf:000]: wifi driver task: 3ffe365c, prio:23, stack:6656, core=0
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: I (1879) wifi:
[15:56:33][I][esp-idf:000]: wifi firmware version: 6567a16
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: I (1880) wifi:
[15:56:33][I][esp-idf:000]: wifi certification version: v7.0
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: I (1885) wifi:
[15:56:33][I][esp-idf:000]: config NVS flash: enabled
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: I (1895) wifi:
[15:56:33][I][esp-idf:000]: config nano formating: disabled
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: I (1906) wifi:
[15:56:33][I][esp-idf:000]: Init data frame dynamic rx buffer num: 32
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: I (1926) wifi:
[15:56:33][I][esp-idf:000]: Init management frame dynamic rx buffer num: 32
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: I (1936) wifi:
[15:56:33][I][esp-idf:000]: Init management short buffer num: 32
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: I (1946) wifi:
[15:56:33][I][esp-idf:000]: Init dynamic tx buffer num: 32
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: I (1967) wifi:
[15:56:33][I][esp-idf:000]: Init static rx buffer size: 1600
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: I (1977) wifi:
[15:56:33][I][esp-idf:000]: Init static rx buffer num: 10
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: I (1987) wifi:
[15:56:33][I][esp-idf:000]: Init dynamic rx buffer num: 32
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: I (1999) wifi_init: rx ba win: 6
[15:56:33]
[15:56:33][I][esp-idf:000]: I (1999) wifi_init: tcpip mbox: 32
[15:56:33]
[15:56:33][I][esp-idf:000]: I (2008) wifi_init: udp mbox: 6
[15:56:33]
[15:56:33][I][esp-idf:000]: I (2008) wifi_init: tcp mbox: 6
[15:56:33]
[15:56:33][I][esp-idf:000]: I (2018) wifi_init: tcp tx win: 5744
[15:56:33]
[15:56:33][I][esp-idf:000]: I (2028) wifi_init: tcp rx win: 5744
[15:56:33]
[15:56:33][I][esp-idf:000]: I (2028) wifi_init: tcp mss: 1440
[15:56:33]
[15:56:33][I][esp-idf:000]: I (2039) wifi_init: WiFi IRAM OP enabled
[15:56:33]
[15:56:33][I][esp-idf:000]: I (2049) wifi_init: WiFi RX IRAM OP enabled
[15:56:33]
[15:56:33][I][esp-idf:000]: I (2053) wifi:
[15:56:33][I][esp-idf:000]: mode : sta (ES:P3:2M:AC:09:30)
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: I (2070) wifi:
[15:56:33][I][esp-idf:000]: enable tsf
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: I (2080) wifi:
[15:56:33][I][esp-idf:000]: Set ps type: 1
[15:56:33]
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: W (2090) wifi:
[15:56:33][I][esp-idf:000]: Error! Should use default active scan time parameter for WiFi scan when Bluetooth is enabled!!!!!!
[15:56:33]
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:33][I][esp-idf:000]: I (2104) wifi:
[15:56:33][I][esp-idf:000]: Set ps type: 1
[15:56:33]
[15:56:33][I][esp-idf:000]:
[15:56:33]
[15:56:36][I][esp-idf:000]: E (4917) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (4918) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (4918) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (4918) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (4919) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (4924) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (4935) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (4945) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (4955) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (4965) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (4966) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (4976) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (4986) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (4996) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (5007) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (5017) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (5017) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (5027) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (5037) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (5047) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (5058) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (5058) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (5068) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (5078) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (5088) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (5099) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (5099) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (5109) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (5119) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (5129) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (5140) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (5150) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (5150) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (5160) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (5170) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (5180) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (5191) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (5201) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (5201) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (5211) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (5221) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (5232) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: E (5242) BT_BTM: BTM_BleScan scan not active
[15:56:36]
[15:56:36]
[15:56:36][I][esp-idf:000]: W (5242) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:36]
[15:56:36]
[15:56:37][I][esp-idf:000]: E (5254) BT_BTM: BTM_BleScan scan not active
[15:56:37]
[15:56:37]
[15:56:37][I][esp-idf:000]: W (6776) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:37]
[15:56:37]
[15:56:38][I][esp-idf:000]: E (6777) BT_BTM: BTM_BleScan scan not active
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: W (6777) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: E (6783) BT_BTM: BTM_BleScan scan not active
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: W (6784) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: E (6792) BT_BTM: BTM_BleScan scan not active
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: W (6802) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: E (6813) BT_BTM: BTM_BleScan scan not active
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: W (6828) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: E (6830) BT_BTM: BTM_BleScan scan not active
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: W (6833) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: E (6843) BT_BTM: BTM_BleScan scan not active
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: W (6854) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: E (6864) BT_BTM: BTM_BleScan scan not active
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: W (6874) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: E (6876) BT_BTM: BTM_BleScan scan not active
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: W (6884) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: E (6895) BT_BTM: BTM_BleScan scan not active
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: W (6905) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: E (6915) BT_BTM: BTM_BleScan scan not active
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: W (6915) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: E (6925) BT_BTM: BTM_BleScan scan not active
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: W (6936) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: E (6946) BT_BTM: BTM_BleScan scan not active
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: W (6956) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: E (6967) BT_BTM: BTM_BleScan scan not active
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: W (6967) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: E (6977) BT_BTM: BTM_BleScan scan not active
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: W (6987) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: E (6997) BT_BTM: BTM_BleScan scan not active
[15:56:38]
[15:56:38]
[15:56:38][I][esp-idf:000]: W (7007) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:56:38]
[15:56:38]
[15:56:39][I][esp-idf:000]: I (7838) esp_netif_handlers: sta ip: 10.13.30.126, mask: 255.255.255.0, gw: 10.13.30.1
[15:56:39]
[15:56:39][W][ota:103]: Last Boot was an unhandled reset, will proceed to safe mode in 8 restarts
[15:56:39][I][mqtt:176]: Connecting to MQTT...
[15:56:39][I][mqtt:216]: MQTT Connected!
[15:56:39][I][bedjet:073]: Restored previous saved state.
[15:56:39][I][app:062]: setup() finished successfully!
[15:56:39][I][app:102]: ESPHome version 2023.3.2 compiled on Apr 11 2023, 15:55:37
[15:56:39][I][app:104]: Project kquinsland.bedjet-controller version 1.3.17c1309
[15:56:39][W][ota:103]: Last Boot was an unhandled reset, will proceed to safe mode in 8 restarts
[15:56:40][I][esp-idf:000]: I (9458) wifi:
[15:56:40][I][esp-idf:000]: <ba-add>idx:1 (ifx:0, Wi:Fi:AP:AD:DY:02), tid:6, ssn:2, winSize:64
[15:56:40][I][esp-idf:000]:
[15:56:40]
[15:56:40][I][esp32_ble_client:196]: [0] [BE:DJ:ET:DE:VI:CE] Connected
[15:56:40][I][bedjet:217]: [BE:DJ:ET:DE:VI:CE] Discovered service characteristics:
[15:56:40][I][bedjet:218]: - Command char: 0x33
[15:56:40][I][bedjet:219]: - Status char: 0x2a
[15:56:40][I][bedjet:220]: - config descriptor: 0x2b
[15:56:40][I][bedjet:221]: - Name char: 0x2d
And with DEBUG
in the mix
Linking .pioenvs/bedjet-controller/firmware.elf
RAM: [== ] 17.8% (used 58272 bytes from 327680 bytes)
Flash: [======== ] 75.4% (used 1384009 bytes from 1835008 bytes)
Building .pioenvs/bedjet-controller/firmware.bin
Creating esp32 image...
<...>
Hash of data verified.
Leaving...
Hard resetting via RTS pin...
INFO Successfully uploaded program.
INFO Starting log output from /dev/ttyUSB0 with baud rate 115200
[15:58:55]%=\xb1 clock div:2
[15:58:55]load:0x3fff0030,len:6660
[15:58:55]load:0x40078000,len:14944
[15:58:55]ho 0 tail 12 room 4
[15:58:55]load:0x40080400,len:3816
[15:58:55]entry 0x40080698
[15:58:55]I (28) boot: ESP-IDF 4.4.4 2nd stage bootloader
[15:58:55]I (28) boot: compile time 15:58:21
[15:58:55]I (28) boot: chip revision: v1.0
[15:58:55]I (31) boot_comm: chip revision: 1, min. bootloader chip revision: 0
[15:58:55]I (38) boot.esp32: SPI Speed : 40MHz
[15:58:55]I (43) boot.esp32: SPI Mode : DIO
[15:58:55]I (47) boot.esp32: SPI Flash Size : 4MB
[15:58:55]I (52) boot: Enabling RNG early entropy source...
[15:58:55]I (57) boot: Partition Table:
[15:58:55]I (61) boot: ## Label Usage Type ST Offset Length
[15:58:55]I (68) boot: 0 otadata OTA data 01 00 00009000 00002000
[15:58:55]I (76) boot: 1 phy_init RF data 01 01 0000b000 00001000
[15:58:55]I (83) boot: 2 app0 OTA app 00 10 00010000 001c0000
[15:58:55]I (91) boot: 3 app1 OTA app 00 11 001d0000 001c0000
[15:58:55]I (98) boot: 4 nvs WiFi data 01 02 00390000 0006d000
[15:58:55]I (106) boot: End of partition table
[15:58:55]I (110) boot: No factory image, trying OTA 0
[15:58:55]I (115) boot_comm: chip revision: 1, min. application chip revision: 0
[15:58:55]I (122) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=35798h (219032) map
[15:58:55]I (210) esp_image: segment 1: paddr=000457c0 vaddr=3ffbdb60 size=053f8h ( 21496) load
[15:58:55]I (218) esp_image: segment 2: paddr=0004abc0 vaddr=40080000 size=05458h ( 21592) load
[15:58:55]I (228) esp_image: segment 3: paddr=00050020 vaddr=400d0020 size=fb4f8h (1029368) map
[15:58:56]I (600) esp_image: segment 4: paddr=0014b520 vaddr=40085458 size=17f74h ( 98164) load
[15:58:56]I (655) boot: Loaded app from partition at offset 0x10000
[15:58:56]I (691) boot: Set actual ota_seq=1 in otadata[0]
[15:58:56]I (691) boot: Disabling RNG early entropy source...
[15:58:56]I (702) cpu_start: Pro cpu up.
[15:58:56]I (702) cpu_start: Starting app cpu, entry point is 0x40082308
[15:58:56]I (0) cpu_start: App cpu up.
[15:58:56]I (718) cpu_start: Pro cpu start user code
[15:58:56]I (719) cpu_start: cpu freq: 160000000
[15:58:56]I (719) cpu_start: Application information:
[15:58:56]I (723) cpu_start: Project name: bedjet-controller
[15:58:56]I (729) cpu_start: App version: 2023.3.2
[15:58:56]I (734) cpu_start: Compile time: Apr 11 2023 15:58:08
[15:58:56]I (740) cpu_start: ELF file SHA256: 926220af10994685...
[15:58:56]I (746) cpu_start: ESP-IDF: 4.4.4
[15:58:56]I (751) heap_init: Initializing. RAM available for dynamic allocation:
[15:58:56]I (758) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
[15:58:56]I (764) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
[15:58:56]I (770) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
[15:58:56]I (776) heap_init: At 3FFCBF00 len 00014100 (80 KiB): DRAM
[15:58:56]I (782) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
[15:58:56]I (789) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
[15:58:56]I (795) heap_init: At 4009D3CC len 00002C34 (11 KiB): IRAM
[15:58:56]I (803) spi_flash: detected chip: winbond
[15:58:56]I (806) spi_flash: flash io: dio
[15:58:56]I (815) cpu_start: Starting scheduler on PRO CPU.
[15:58:56]I (0) cpu_start: Starting scheduler on APP CPU.
[15:58:56][I][logger:258]: Log initialized
[15:58:56][C][status_led:014]: Setting up Status LED...
[15:58:56][D][esp-idf:000]: I (211) gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
[15:58:56]
[15:58:56][C][ota:469]: There have been 3 suspected unsuccessful boot attempts.
[15:58:56][D][esp32.preferences:113]: Saving 1 preferences to flash...
[15:58:56][D][esp32.preferences:142]: Saving 1 preferences to flash: 0 cached, 1 written, 0 failed
[15:58:56][I][app:029]: Running through setup()...
[15:58:56][D][binary_sensor:034]: 'BedJet Controller Status': Sending initial state OFF
[15:58:56][C][esp32_ble:026]: Setting up BLE...
[15:58:56][D][esp-idf:000]: I (240) BTDM_INIT: BT controller compile version [8020d24]
[15:58:56]
[15:58:56][D][esp-idf:000]: I (1308) system_api: Base MAC address is not set
[15:58:56]
[15:58:56][D][esp-idf:000]: I (1317) system_api: read default base MAC address from EFUSE
[15:58:56]
[15:58:56][D][esp-idf:000]: I (1340) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
[15:58:56]
[15:58:57][D][esp32_ble:042]: BLE setup complete
[15:58:57][D][esp32_ble_tracker:246]: Starting scan...
[15:58:57][C][wifi:037]: Setting up WiFi...
[15:58:57][C][wifi:038]: Local MAC: ES:P3:2M:AC:09:30
[15:58:57][D][esp-idf:000]: I (1978) wifi:
[15:58:57][D][esp-idf:000]: wifi driver task: 3ffe37d0, prio:23, stack:6656, core=0
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][esp-idf:000]: I (1985) wifi:
[15:58:57][D][esp-idf:000]: wifi firmware version: 6567a16
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][esp-idf:000]: I (1992) wifi:
[15:58:57][D][esp-idf:000]: wifi certification version: v7.0
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2003) wifi:
[15:58:57][D][esp-idf:000]: config NVS flash: enabled
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2013) wifi:
[15:58:57][D][esp-idf:000]: config nano formating: disabled
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2023) wifi:
[15:58:57][D][esp-idf:000]: Init data frame dynamic rx buffer num: 32
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2033) wifi:
[15:58:57][D][esp-idf:000]: Init management frame dynamic rx buffer num: 32
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2054) wifi:
[15:58:57][D][esp-idf:000]: Init management short buffer num: 32
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2064) wifi:
[15:58:57][D][esp-idf:000]: Init dynamic tx buffer num: 32
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2075) wifi:
[15:58:57][D][esp-idf:000]: Init static rx buffer size: 1600
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2085) wifi:
[15:58:57][D][esp-idf:000]: Init static rx buffer num: 10
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2105) wifi:
[15:58:57][D][esp-idf:000]: Init dynamic rx buffer num: 32
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2106) wifi_init: rx ba win: 6
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2115) wifi_init: tcpip mbox: 32
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2115) wifi_init: udp mbox: 6
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2125) wifi_init: tcp mbox: 6
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2136) wifi_init: tcp tx win: 5744
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2136) wifi_init: tcp rx win: 5744
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2146) wifi_init: tcp mss: 1440
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2156) wifi_init: WiFi IRAM OP enabled
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2156) wifi_init: WiFi RX IRAM OP enabled
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2170) wifi:
[15:58:57][D][esp-idf:000]: mode : sta (ES:P3:2M:AC:09:30)
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2177) wifi:
[15:58:57][D][esp-idf:000]: enable tsf
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][esp-idf:000]: I (2187) wifi:
[15:58:57][D][esp-idf:000]: Set ps type: 1
[15:58:57]
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][wifi:386]: Starting scan...
[15:58:57][D][esp-idf:000]: W (2208) wifi:
[15:58:57][D][esp-idf:000]: Error! Should use default active scan time parameter for WiFi scan when Bluetooth is enabled!!!!!!
[15:58:57]
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][text_sensor:067]: 'BedJet Controller Uptime': Sending state '1s'
[15:58:57][D][sensor:127]: 'BedJet Controller Uptime (seconds)': Sending state 1.17200 s with 0 decimals of accuracy
[15:58:57][D][esp-idf:000]: I (2239) wifi:
[15:58:57][D][esp-idf:000]: Set ps type: 1
[15:58:57]
[15:58:57][D][esp-idf:000]:
[15:58:57]
[15:58:57][D][switch:056]: 'Enable BedJet connection': Sending state ON
[15:58:57][D][esp32_ble_client:048]: [0] [BE:DJ:ET:DE:VI:CE] Found device
[15:58:57][D][esp32_ble_tracker:214]: Pausing scan to make connection...
[15:58:57][D][esp32_ble_tracker:214]: Pausing scan to make connection...
[15:58:57][D][esp32_ble_tracker:214]: Pausing scan to make connection...
[15:58:57][D][esp-idf:000]: E (2279) BT_BTM: BTM_BleScan scan not active
[15:58:57]
[15:58:57]
[15:58:57][D][esp-idf:000]: W (2289) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:58:57]
[15:58:57]
[15:59:00][I][esp32_ble_client:196]: [0] [BE:DJ:ET:DE:VI:CE] Connected
[15:59:00][D][ble_client_lambda:133]: Connected to BLE device
[15:59:00][D][binary_sensor:036]: 'BedJet Connected': Sending state ON
[15:59:00][I][bedjet:217]: [BE:DJ:ET:DE:VI:CE] Discovered service characteristics:
[15:59:00][I][bedjet:218]: - Command char: 0x33
[15:59:00][I][bedjet:219]: - Status char: 0x2a
[15:59:00][I][bedjet:220]: - config descriptor: 0x2b
[15:59:00][I][bedjet:221]: - Name char: 0x2d
[15:59:00][D][bedjet:239]: [BE:DJ:ET:DE:VI:CE] Services complete: obtained char handles.
[15:59:00][D][bedjet:437]: [BE:DJ:ET:DE:VI:CE] wrote notify=true to status config 0x002b, for conn 0
[15:59:00][D][esp32_ble_tracker:246]: Starting scan...
[15:59:00]
[15:59:00]assert failed: virtual void esphome::bedjet::BedJetHub::gattc_event_handler(esp_gattc_cb_event_t, esp_gatt_if_t, esp_ble_gattc_cb_param_t*) bedjet_hub.cpp:378 (this->codec_ != nullptr)
[15:59:00]
[15:59:00]
[15:59:00]Backtrace: 0x40082c42:0x3ffd0b30 0x400911c1:0x3ffd0b50 0x400978b5:0x3ffd0b70 0x400d4a4e:0x3ffd0c90 0x400d695a:0x3ffd0ce0 0x401c4385:0x3ffd0d10 0x400d9d31:0x3ffd0d30 0x401c434d:0x3ffd0d50 0x400d8aa5:0x3ffd0d70 0x401c4d39:0x3ffd0d90 0x401c4e25:0x3ffd0db0 0x400e7bfa:0x3ffd0dd0 0x400eada9:0x3ffd0e00 0x400d7f2b:0x3ffd0ee0
WARNING Found stack trace! Trying to decode it
WARNING Decoded 0x40082c42: panic_abort at /home/karl/.platformio/packages/framework-espidf/components/esp_system/panic.c:408
WARNING Decoded 0x400911c1: esp_system_abort at /home/karl/.platformio/packages/framework-espidf/components/esp_system/esp_system.c:137
WARNING Decoded 0x400978b5: __assert_func at /home/karl/.platformio/packages/framework-espidf/components/newlib/assert.c:85
WARNING Decoded 0x400d4a4e: esphome::bedjet::BedJetHub::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/components/bedjet/bedjet_hub.cpp:378 (discriminator 1)
WARNING Decoded 0x400d695a: esphome::ble_client::BLEClient::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/components/ble_client/ble_client.cpp:58 (discriminator 2)
WARNING Decoded 0x401c4385: esphome::esp32_ble_tracker::ESP32BLETracker::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/components/esp32_ble_tracker/esp32_ble_tracker.cpp:346 (discriminator 2)
WARNING Decoded 0x400d9d31: non-virtual thunk to esphome::esp32_ble_tracker::ESP32BLETracker::gattc_event_handler(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*)
WARNING Decoded 0x401c434d: esphome::esp32_ble::ESP32BLE::real_gattc_event_handler_(esp_gattc_cb_event_t, unsigned char, esp_ble_gattc_cb_param_t*) at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/components/esp32_ble/ble.cpp:208 (discriminator 2)
WARNING Decoded 0x400d8aa5: esphome::esp32_ble::ESP32BLE::loop() at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/components/esp32_ble/ble.cpp:158
WARNING Decoded 0x401c4d39: esphome::Component::call_loop() at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/core/component.cpp:76
WARNING Decoded 0x401c4e25: esphome::Component::call() at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/core/component.cpp:98
WARNING Decoded 0x400e7bfa: esphome::Application::setup() at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/core/application.cpp:52 (discriminator 2)
WARNING Decoded 0x400eada9: setup() at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/projects/bedjet.yaml:254
WARNING Decoded 0x400d7f2b: esphome::loop_task(void*) at /home/karl/Projects/esphome/hardware/build-root/bedjet-controller/src/esphome/components/esp32/core.cpp:72
[15:59:00]
[15:59:00]
[15:59:00]
[15:59:00]
[15:59:00]ELF file SHA256: 926220af10994685
[15:59:00]
[15:59:00]Rebooting...
[15:59:00]ets Jun 8 2016 00:22:57
[15:59:00]
[15:59:00]rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
[15:59:00]configsip: 0, SPIWP:0xee
[15:59:00]clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
[15:59:00]mode:DIO, clock div:2
[15:59:00]load:0x3fff0030,len:6660
[15:59:00]load:0x40078000,len:14944
[15:59:00]ho 0 tail 12 room 4
[15:59:00]load:0x40080400,len:3816
[15:59:00]entry 0x40080698
[15:59:00]I (29) boot: ESP-IDF 4.4.4 2nd stage bootloader
[15:59:00]I (29) boot: compile time 15:58:21
[15:59:00]I (29) boot: chip revision: v1.0
[15:59:00]I (32) boot_comm: chip revision: 1, min. bootloader chip revision: 0
[15:59:00]I (39) boot.esp32: SPI Speed : 40MHz
[15:59:00]I (44) boot.esp32: SPI Mode : DIO
[15:59:00]I (48) boot.esp32: SPI Flash Size : 4MB
[15:59:00]I (53) boot: Enabling RNG early entropy source...
[15:59:00]I (58) boot: Partition Table:
[15:59:00]I (62) boot: ## Label Usage Type ST Offset Length
[15:59:00]I (69) boot: 0 otadata OTA data 01 00 00009000 00002000
[15:59:00]I (76) boot: 1 phy_init RF data 01 01 0000b000 00001000
[15:59:00]I (84) boot: 2 app0 OTA app 00 10 00010000 001c0000
[15:59:00]I (91) boot: 3 app1 OTA app 00 11 001d0000 001c0000
[15:59:00]I (99) boot: 4 nvs WiFi data 01 02 00390000 0006d000
[15:59:00]I (106) boot: End of partition table
[15:59:00]I (111) boot_comm: chip revision: 1, min. application chip revision: 0
[15:59:00]I (118) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=35798h (219032) map
[15:59:00]I (206) esp_image: segment 1: paddr=000457c0 vaddr=3ffbdb60 size=053f8h ( 21496) load
[15:59:00]I (214) esp_image: segment 2: paddr=0004abc0 vaddr=40080000 size=05458h ( 21592) load
[15:59:00]I (223) esp_image: segment 3: paddr=00050020 vaddr=400d0020 size=fb4f8h (1029368) map
[15:59:01]I (596) esp_image: segment 4: paddr=0014b520 vaddr=40085458 size=17f74h ( 98164) load
[15:59:01]I (651) boot: Loaded app from partition at offset 0x10000
[15:59:01]I (651) boot: Disabling RNG early entropy source...
[15:59:01]I (663) cpu_start: Pro cpu up.
[15:59:01]I (663) cpu_start: Starting app cpu, entry point is 0x40082308
[15:59:01]I (649) cpu_start: App cpu up.
[15:59:01]I (679) cpu_start: Pro cpu start user code
[15:59:01]I (679) cpu_start: cpu freq: 160000000
[15:59:01]I (679) cpu_start: Application information:
[15:59:01]I (684) cpu_start: Project name: bedjet-controller
[15:59:01]I (690) cpu_start: App version: 2023.3.2
[15:59:01]I (695) cpu_start: Compile time: Apr 11 2023 15:58:08
[15:59:01]I (701) cpu_start: ELF file SHA256: 926220af10994685...
[15:59:01]I (707) cpu_start: ESP-IDF: 4.4.4
[15:59:01]I (712) heap_init: Initializing. RAM available for dynamic allocation:
[15:59:01]I (719) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
[15:59:01]I (725) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
[15:59:01]I (731) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
[15:59:01]I (737) heap_init: At 3FFCBF00 len 00014100 (80 KiB): DRAM
[15:59:01]I (743) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
[15:59:01]I (749) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
[15:59:01]I (756) heap_init: At 4009D3CC len 00002C34 (11 KiB): IRAM
[15:59:01]I (763) spi_flash: detected chip: winbond
[15:59:01]I (767) spi_flash: flash io: dio
[15:59:01]I (775) cpu_start: Starting scheduler on PRO CPU.
[15:59:01]I (0) cpu_start: Starting scheduler on APP CPU.
[15:59:01][I][logger:258]: Log initialized
[15:59:01][C][status_led:014]: Setting up Status LED...
[15:59:01][D][esp-idf:000]: I (211) gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
[15:59:01]
[15:59:01][C][ota:469]: There have been 4 suspected unsuccessful boot attempts.
[15:59:01][D][esp32.preferences:113]: Saving 1 preferences to flash...
[15:59:01][D][esp32.preferences:142]: Saving 1 preferences to flash: 0 cached, 1 written, 0 failed
[15:59:01][I][app:029]: Running through setup()...
[15:59:01][D][binary_sensor:034]: 'BedJet Controller Status': Sending initial state OFF
[15:59:01][C][esp32_ble:026]: Setting up BLE...
[15:59:01][D][esp-idf:000]: I (240) BTDM_INIT: BT controller compile version [8020d24]
[15:59:01]
[15:59:01][D][esp-idf:000]: I (1268) system_api: Base MAC address is not set
[15:59:01]
[15:59:01][D][esp-idf:000]: I (1277) system_api: read default base MAC address from EFUSE
[15:59:01]
[15:59:01][D][esp-idf:000]: I (1300) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
[15:59:01]
[15:59:02][D][esp32_ble:042]: BLE setup complete
[15:59:02][D][esp32_ble_tracker:246]: Starting scan...
[15:59:02][C][wifi:037]: Setting up WiFi...
[15:59:02][C][wifi:038]: Local MAC: ES:P3:2M:AC:09:30
[15:59:02][D][esp-idf:000]: I (1932) wifi:
[15:59:02][D][esp-idf:000]: wifi driver task: 3ffe3760, prio:23, stack:6656, core=0
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][esp-idf:000]: I (1939) wifi:
[15:59:02][D][esp-idf:000]: wifi firmware version: 6567a16
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][esp-idf:000]: I (1946) wifi:
[15:59:02][D][esp-idf:000]: wifi certification version: v7.0
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][esp-idf:000]: I (1957) wifi:
[15:59:02][D][esp-idf:000]: config NVS flash: enabled
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][esp-idf:000]: I (1967) wifi:
[15:59:02][D][esp-idf:000]: config nano formating: disabled
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][esp-idf:000]: I (1977) wifi:
[15:59:02][D][esp-idf:000]: Init data frame dynamic rx buffer num: 32
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][esp-idf:000]: I (1987) wifi:
[15:59:02][D][esp-idf:000]: Init management frame dynamic rx buffer num: 32
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2008) wifi:
[15:59:02][D][esp-idf:000]: Init management short buffer num: 32
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2018) wifi:
[15:59:02][D][esp-idf:000]: Init dynamic tx buffer num: 32
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2029) wifi:
[15:59:02][D][esp-idf:000]: Init static rx buffer size: 1600
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2039) wifi:
[15:59:02][D][esp-idf:000]: Init static rx buffer num: 10
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2059) wifi:
[15:59:02][D][esp-idf:000]: Init dynamic rx buffer num: 32
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2060) wifi_init: rx ba win: 6
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2069) wifi_init: tcpip mbox: 32
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2069) wifi_init: udp mbox: 6
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2079) wifi_init: tcp mbox: 6
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2090) wifi_init: tcp tx win: 5744
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2090) wifi_init: tcp rx win: 5744
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2100) wifi_init: tcp mss: 1440
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2110) wifi_init: WiFi IRAM OP enabled
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2110) wifi_init: WiFi RX IRAM OP enabled
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2124) wifi:
[15:59:02][D][esp-idf:000]: mode : sta (ES:P3:2M:AC:09:30)
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2131) wifi:
[15:59:02][D][esp-idf:000]: enable tsf
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][esp-idf:000]: I (2141) wifi:
[15:59:02][D][esp-idf:000]: Set ps type: 1
[15:59:02]
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][wifi:386]: Starting scan...
[15:59:02][D][esp-idf:000]: W (2162) wifi:
[15:59:02][D][esp-idf:000]: Error! Should use default active scan time parameter for WiFi scan when Bluetooth is enabled!!!!!!
[15:59:02]
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][text_sensor:067]: 'BedJet Controller Uptime': Sending state '1s'
[15:59:02][D][sensor:127]: 'BedJet Controller Uptime (seconds)': Sending state 1.16600 s with 0 decimals of accuracy
[15:59:02][D][text_sensor:067]: 'BedJet Controller Uptime': Sending state '1s'
[15:59:02][D][esp-idf:000]: I (2193) wifi:
[15:59:02][D][esp-idf:000]: Set ps type: 1
[15:59:02]
[15:59:02][D][esp-idf:000]:
[15:59:02]
[15:59:02][D][switch:056]: 'Enable BedJet connection': Sending state ON
[15:59:05][D][esp32_ble_client:048]: [0] [BE:DJ:ET:DE:VI:CE] Found device
[15:59:05][D][esp32_ble_tracker:214]: Pausing scan to make connection...
[15:59:05][D][esp32_ble_tracker:214]: Pausing scan to make connection...
[15:59:05][D][esp32_ble_tracker:214]: Pausing scan to make connection...
[15:59:05][D][esp32_ble_tracker:214]: Pausing scan to make connection...
[15:59:05][D][esp-idf:000]: E (5005) BT_BTM: BTM_BleScan scan not active
[15:59:05]
[15:59:05]
[15:59:05][D][esp-idf:000]: W (5015) BT_APPL: bta_dm_ble_scan stop scan failed, status=0x6
[15:59:05]
[15:59:05]
[15:59:05][D][wifi:401]: Found networks:
<...>
[15:59:08][I][mqtt:176]: Connecting to MQTT...
[15:59:08][I][mqtt:216]: MQTT Connected!
[15:59:08][C][sntp:028]: Setting up SNTP...
[15:59:08][D][bedjet:119]: BedJetHub::setup
[15:59:08][I][bedjet:073]: Restored previous saved state.
[15:59:08][D][climate:392]: 'BedJet Climate' - Sending state:
[15:59:08][D][climate:395]: Mode: OFF
[15:59:08][D][climate:397]: Action: OFF
[15:59:08][D][climate:403]: Custom Fan Mode: 20%
[15:59:08][D][climate:406]: Preset: NONE
[15:59:08][D][climate:415]: Current Temperature: nan°C
[15:59:08][D][climate:421]: Target Temperature: 32.00°C
[15:59:08][D][mqtt.fan:122]: 'BedJet Fan' Sending state OFF.
[15:59:08][I][app:062]: setup() finished successfully!
[15:59:08][D][bedjet:098]: [BedJet Fan] update()
[15:59:08][D][bedjet:102]: [BedJet Fan] update_status result=false
[15:59:08][D][bedjet:344]: [BedJet Climate] update()
[15:59:08][D][bedjet:348]: [BedJet Climate] update_status result=false
[15:59:08][D][bedjet:509]: [BE:DJ:ET:DE:VI:CE] Not connected, will not send status.
<...>
[15:59:08][I][esp32_ble_client:196]: [0] [BE:DJ:ET:DE:VI:CE] Connected
[15:59:08][D][ble_client_lambda:133]: Connected to BLE device
[15:59:08][D][binary_sensor:036]: 'BedJet Connected': Sending state ON
[15:59:08][I][bedjet:217]: [BE:DJ:ET:DE:VI:CE] Discovered service characteristics:
[15:59:08][I][bedjet:218]: - Command char: 0x33
[15:59:08][I][bedjet:219]: - Status char: 0x2a
[15:59:08][I][bedjet:220]: - config descriptor: 0x2b
[15:59:09][I][bedjet:221]: - Name char: 0x2d
[15:59:09][D][bedjet:239]: [BE:DJ:ET:DE:VI:CE] Services complete: obtained char handles.
[15:59:09][D][bedjet:437]: [BE:DJ:ET:DE:VI:CE] wrote notify=true to status config 0x002b, for conn 0
[15:59:09][D][esp32_ble_tracker:246]: Starting scan...
[15:59:09][I][app:102]: ESPHome version 2023.3.2 compiled on Apr 11 2023, 15:58:08
[15:59:09][I][app:104]: Project kquinsland.bedjet-controller version 1.3.17c1309
[15:59:09][C][status_led:019]: Status LED:
[15:59:09][C][status_led:020]: Pin: GPIO2
[15:59:09][C][wifi:504]: WiFi:
<...>
[15:59:09][D][bedjet:379]: codec = 0x3ffd255c
[15:59:09][D][bedjet:096]: Writing 20 bytes to @0x3ffeb888, on @0x3ffeb87c. Clearing 0..35(35) first.
<...>
[15:59:09][D][bedjet:272]: [BEDJET-VICE] Write to handle 0x002b status=0
<...>
[15:59:09][C][esp32_ble:214]: ESP32 BLE:
[15:59:09][C][esp32_ble_tracker:591]: BLE Tracker:
[15:59:09][C][esp32_ble_tracker:592]: Scan Duration: 300 s
[15:59:09][C][esp32_ble_tracker:593]: Scan Interval: 1000.0 ms
[15:59:09][C][esp32_ble_tracker:594]: Scan Window: 300.0 ms
[15:59:09][C][esp32_ble_tracker:595]: Scan Type: ACTIVE
[15:59:09][C][esp32_ble_tracker:596]: Continuous Scanning: True
[15:59:09][D][bedjet:272]: [BEDJET-VICE] Write to handle 0x002b status=0
[15:59:09][C][ble_client:027]: BLE Client:
[15:59:09][C][ble_client:028]: Address: BE:DJ:ET:DE:VI:CE
<...>
[15:59:09][D][bedjet:512]: [BEDJET-VICE] Notifying 2 children of latest status @0x3ffeb888.
[15:59:09][D][climate:392]: 'BedJet Climate' - Sending state:
[15:59:09][D][climate:395]: Mode: OFF
[15:59:09][D][climate:397]: Action: IDLE
[15:59:09][D][climate:400]: Fan Mode: OFF
[15:59:09][D][climate:403]: Custom Fan Mode: 20%
[15:59:09][D][climate:415]: Current Temperature: 22.00°C
[15:59:09][D][climate:421]: Target Temperature: 32.00°C
<...>
[15:59:09][C][bedjet:489]: BedJet Hub 'BEDJET-VICE'
[15:59:09][C][bedjet:490]: ble_client.app_id: 1
[15:59:09][C][bedjet:491]: ble_client.conn_id: 0
[15:59:09][C][bedjet:492]: Update Interval: 15.0s
[15:59:09][C][bedjet:493]: Child components (2):
[15:59:09][C][bedjet:495]: - BedJet Climate
[15:59:09][C][bedjet:495]: - BedJet Fan
[15:59:09][C][bedjet:039]: BedJet Climate 'BedJet Climate'
[15:59:09][C][bedjet:042]: Supported modes:
[15:59:09][C][bedjet:044]: - OFF
[15:59:09][C][bedjet:044]: - HEAT
[15:59:09][C][bedjet:044]: - FAN_ONLY
[15:59:09][C][bedjet:044]: - DRY
[15:59:09][C][bedjet:049]: - BedJet heating mode: HEAT
[15:59:09][C][bedjet:052]: Supported fan modes:
[15:59:09][C][bedjet:057]: - 10% (c)
[15:59:09][C][bedjet:057]: - 100% (c)
[15:59:09][C][bedjet:057]: - 15% (c)
[15:59:09][C][bedjet:057]: - 20% (c)
[15:59:09][C][bedjet:057]: - 25% (c)
[15:59:09][C][bedjet:057]: - 30% (c)
[15:59:09][C][bedjet:057]: - 35% (c)
[15:59:09][C][bedjet:057]: - 40% (c)
[15:59:09][C][bedjet:057]: - 45% (c)
[15:59:09][C][bedjet:057]: - 5% (c)
[15:59:09][C][bedjet:057]: - 50% (c)
[15:59:09][C][bedjet:057]: - 55% (c)
[15:59:09][C][bedjet:057]: - 60% (c)
[15:59:09][C][bedjet:057]: - 65% (c)
[15:59:09][C][bedjet:057]: - 70% (c)
[15:59:09][C][bedjet:057]: - 75% (c)
[15:59:09][C][bedjet:057]: - 80% (c)
[15:59:09][C][bedjet:057]: - 85% (c)
[15:59:09][C][bedjet:057]: - 90% (c)
[15:59:09][C][bedjet:057]: - 95% (c)
[15:59:09][C][bedjet:060]: Supported presets:
[15:59:09][C][bedjet:062]: - BOOST
[15:59:09][C][bedjet:065]: - EXT HT (c)
[15:59:09][C][bedjet:065]: - M1 (c)
[15:59:09][C][bedjet:065]: - M2 (c)
[15:59:09][C][bedjet:065]: - M3 (c)
[15:59:09][C][bedjet:011]: BedJet Fan 'BedJet Fan'
[15:59:09][C][bedjet:154]: Speed: YES
[15:59:09][C][bedjet:155]: Speed count: 20
<...>
[15:59:11][D][esp-idf:000]: I (11206) wifi:
[15:59:11][D][esp-idf:000]: <ba-add>idx:1 (ifx:0, Wi:Fi:AP:AD:DY:02), tid:6, ssn:2, winSize:64
[15:59:11][D][esp-idf:000]:
[15:59:11]
[15:59:11][D][sntp:078]: Synchronized time: 2023-04-11 15:59:11
[15:59:21][D][bedjet:512]: [BEDJET-VICE] Notifying 2 children of latest status @0x3ffeb888.
[15:59:21][D][climate:392]: 'BedJet Climate' - Sending state:
[15:59:21][D][climate:395]: Mode: OFF
[15:59:21][D][climate:397]: Action: IDLE
[15:59:21][D][climate:400]: Fan Mode: OFF
[15:59:21][D][climate:403]: Custom Fan Mode: 20%
[15:59:21][D][climate:415]: Current Temperature: 22.00°C
[15:59:21][D][climate:421]: Target Temperature: 32.00°C
[15:59:24][D][bedjet:379]: codec = 0x3ffd255c
[15:59:24][D][bedjet:096]: Writing 20 bytes to @0x3ffeb888, on @0x3ffeb87c. Clearing 0..35(35) first.
[15:59:36][D][bedjet:512]: [BEDJET-VICE] Notifying 2 children of latest status @0x3ffeb888.
[15:59:36][D][climate:392]: 'BedJet Climate' - Sending state:
[15:59:36][D][climate:395]: Mode: OFF
[15:59:36][D][climate:397]: Action: IDLE
[15:59:36][D][climate:400]: Fan Mode: OFF
[15:59:36][D][climate:403]: Custom Fan Mode: 20%
[15:59:36][D][climate:415]: Current Temperature: 21.50°C
[15:59:36][D][climate:421]: Target Temperature: 32.00°C
[15:59:39][D][bedjet:379]: codec = 0x3ffd255c
[15:59:39][D][bedjet:096]: Writing 20 bytes to @0x3ffeb888, on @0x3ffeb87c. Clearing 0..35(35) first.
[15:59:42][D][bedjet:098]: [BedJet Fan] update()
[15:59:42][D][bedjet:102]: [BedJet Fan] update_status result=true
[15:59:43][D][esp32.preferences:113]: Saving 1 preferences to flash...
[15:59:43][D][esp32.preferences:142]: Saving 1 preferences to flash: 1 cached, 0 written, 0 failed
<...>
[15:59:43][D][sensor:127]: 'BedJet Controller Uptime (seconds)': Sending state 42.24000 s with 0 decimals of accuracy
[15:59:44][D][bedjet:344]: [BedJet Climate] update()
[15:59:44][D][climate:392]: 'BedJet Climate' - Sending state:
[15:59:44][D][climate:395]: Mode: OFF
[15:59:44][D][climate:397]: Action: IDLE
[15:59:44][D][climate:400]: Fan Mode: OFF
[15:59:44][D][climate:403]: Custom Fan Mode: 20%
[15:59:44][D][climate:415]: Current Temperature: 22.00°C
[15:59:44][D][climate:421]: Target Temperature: 32.00°C
[15:59:44][D][climate:392]: 'BedJet Climate' - Sending state:
[15:59:44][D][climate:395]: Mode: OFF
[15:59:44][D][climate:397]: Action: IDLE
[15:59:44][D][climate:400]: Fan Mode: OFF
[15:59:44][D][climate:403]: Custom Fan Mode: 20%
[15:59:44][D][climate:415]: Current Temperature: 22.00°C
[15:59:44][D][climate:421]: Target Temperature: 32.00°C
[15:59:44][D][bedjet:348]: [BedJet Climate] update_status result=true
[15:59:45][D][text_sensor:067]: 'BedJet Controller Uptime': Sending state '42s'
[15:59:51][D][bedjet:512]: [BEDJET-VICE] Notifying 2 children of latest status @0x3ffeb888.
[15:59:51][D][climate:392]: 'BedJet Climate' - Sending state:
[15:59:51][D][climate:395]: Mode: OFF
[15:59:51][D][climate:397]: Action: IDLE
[15:59:51][D][climate:400]: Fan Mode: OFF
[15:59:51][D][climate:403]: Custom Fan Mode: 20%
[15:59:51][D][climate:415]: Current Temperature: 22.00°C
[15:59:51][D][climate:421]: Target Temperature: 32.00°C
[15:59:55][D][bedjet:379]: codec = 0x3ffd255c
[15:59:55][D][bedjet:096]: Writing 20 bytes to @0x3ffeb888, on @0x3ffeb87c. Clearing 0..35(35) first.
<...>
# Pattern like this repeats;
[16:11:37][D][bedjet:379]: codec = 0x3ffd255c
[16:11:37][D][bedjet:096]: Writing 20 bytes to @0x3ffeb888, on @0x3ffeb87c. Clearing 0..35(35) first.
[16:11:42][D][bedjet:098]: [BedJet Fan] update()
[16:11:42][D][bedjet:102]: [BedJet Fan] update_status result=true
<...>
[16:11:52][D][bedjet:379]: codec = 0x3ffd255c
[16:11:52][D][bedjet:096]: Writing 20 bytes to @0x3ffeb888, on @0x3ffeb87c. Clearing 0..35(35) first.
[16:12:06][D][bedjet:512]: [BEDJET-VICE] Notifying 2 children of latest status @0x3ffeb888.
It looks like your hunch was correct; the only crashes are at the failed assert()
checks for null pointers you added: https://github.com/esphome/esphome/compare/dev...jhansche:esphome:test/3807
Great, thanks for testing that.
I've created a draft PR mentioned above. Switching the external component to that PR should test the fix, which no longer has the extra logging or assertions. https://github.com/esphome/esphome/pull/4677 Like I said it might be harder to verify with certainty that it's totally fixed, since the only confirmation is "it doesn't crash", and it already only crashes from a race condition, so only sometimes. But it should at least work. If it does then I'll mark it ready for review and try to get some eyes on it.
I tested the PR on my own BedJet and it appears to work fine. And it's already approved, so will likely be merged soon for the next release.
Thanks to everyone here for all the logs and help tracking this down.
Reading through this. Can ESP32 not work properly with a BedJet while also being a Bluetooth Proxy?
This is explained in the BLE proxy docs.
It should work, but I have not tested it explicitly. It largely depends on whether the proxied device needs a connection or not. There's a limit on the number of devices that esp32 can connect to at one time. But if it's just passive BLE scanning, there's no limit.
I am able to connect to two separate BedJet units with a single esp32, so I know that it can connect to multiple devices.
But I don't see how you arrived at your conclusion by reading through this. This issue has nothing to do with BLE proxy. If you're having a specific problem then I suggest you open a new issue with relevant information for your issue.
Will do, thanks.
The problem
Not connected, will not send status.
Which version of ESPHome has the issue?
2022.11.1
What type of installation are you using?
Home Assistant Add-on
Which version of Home Assistant has the issue?
2022.11.2
What platform are you using?
ESP32
Board
Node-MCU
Component causing the issue
Bedjet
Example YAML snippet
No response
Anything in the logs that might be useful for us?
Additional information