Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

ESP32C6 unsafe/racy code when starting comisoning window (CON-870) #719

Closed
damian-kurek-wizzdev opened this issue Nov 6, 2023 · 3 comments
Closed

ESP32C6 unsafe/racy code when starting comisoning window (CON-870) #719

damian-kurek-wizzdev opened this issue Nov 6, 2023 · 3 comments

Comments

@damian-kurek-wizzdev
Copy link

Describe the bug
My code is working fine on esp32 but on c6 I get unsafe/racy error while opening the commissioning window.

chip::CommissioningWindowManager& commissionMgr = chip::Server::GetInstance().GetCommissioningWindowManager();
constexpr auto kTimeoutSeconds = chip::System::Clock::Seconds16(600*3);
if (!commissionMgr.IsCommissioningWindowOpen())
{
    /* After removing last fabric, this example does Fnot remove the Wi-Fi credentials
     * and still has IP connectivity so, only advertising on DNS-SD.
     */
    CHIP_ERROR err = commissionMgr.OpenBasicCommissioningWindow(kTimeoutSeconds,
                                                                chip::CommissioningWindowAdvertisement::kAllSupported);
    if (err != CHIP_NO_ERROR)
    {
        ESP_LOGE(TAG, "Failed to open commissioning window, err:%" CHIP_ERROR_FORMAT, err.Format());
    }
}

Environment

  • ESP-Matter Commit Id: main
  • ESP-IDF Commit Id: 5.1.1
  • SoC (eg: ESP32 or ESP32-C3): ESP32-C6
  • Host Machine OS: Ubuntu
  • Commissioner app and versions if present: -
  • Commissioner's logs if present: -

Any additional details

  • Device Logs (Please attach the log file):

I (11987) chip[DL]: IP_EVENT_GOT_IP6
I (11987) chip[DL]: IPv6 addr available. Ready on WIFI_STA_DEF interface: fe80:0000:0000:0000:424c:caff:fe45:35e4
E (11987) MatterThermostatDriver: Interface IP Address changed
I (11997) chip[DIS]: Updating services using commissioning mode 0
I (11997) chip[DIS]: CHIP minimal mDNS started advertising.
I (12007) chip[DIS]: Updating services using commissioning mode 0
I (12017) chip[DIS]: CHIP minimal mDNS started advertising.
I (12507) NtpTime: sntp_sync_time Time synchronized - 1699264772 sec
W (12507) NtpTime: Setting utc timestamp of device startup in us ld
W (12507) NtpTime: Setting utc timestamp of device startup in ms ld
I (16397) chip[DIS]: Updating services using commissioning mode 0
E (16397) chip[DL]: Chip stack locking error at 'src/inet/UDPEndPointImplLwIP.cpp:213'. Code is unsafe/racy
E (16397) chip[-]: chipDie chipDie chipDie

abort() was called at PC 0x420b03dd on core 0
0x420b03dd: chip::Platform::Internal::AssertChipStackLockedByCurrentThread(char const*, int) at /data/build_matter/esp-idf/chip/../../../mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/config/esp32/third_party/connectedhomeip/src/lib/support/CodeUtils.h:508
(inlined by) chipDie at /data/build_matter/esp-idf/chip/../../../mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/config/esp32/third_party/connectedhomeip/src/lib/support/CodeUtils.h:518
(inlined by) chip::Platform::Internal::AssertChipStackLockedByCurrentThread(char const*, int) at /data/build_matter/esp-idf/chip/../../../mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/config/esp32/third_party/connectedhomeip/src/platform/LockTracker.cpp:36

Stack dump detected
Core 0 register dump:
MEPC : 0x408005e0 RA : 0x4080913c SP : 0x40840830 GP : 0x40814120
0x408005e0: panic_abort at /data/mill-esp32/main/externals/esp-idf/components/esp_system/panic.c:452

0x4080913c: __ubsan_include at /data/mill-esp32/main/externals/esp-idf/components/esp_system/ubsan.c:313

TP : 0x407eb1e8 T0 : 0x37363534 T1 : 0x7271706f T2 : 0x33323130
S0/FP : 0x4084086c S1 : 0x40840850 A0 : 0x4084086c A1 : 0x4084084e
A2 : 0x00000000 A3 : 0x40840899 A4 : 0x00000001 A5 : 0x40828000
A6 : 0x00000000 A7 : 0x76757473 S2 : 0x00000000 S3 : 0x40822358
S4 : 0x420aca78 S5 : 0x00000000 S6 : 0x00000001 S7 : 0x00000020
0x420aca78: chip::BitMapObjectPool<mdns::Minimal::ServerBase::EndpointInfo, 30u>::ReleaseObject(mdns::Minimal::ServerBase::EndpointInfo*) at /data/build_matter/esp-idf/chip/../../../mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/config/esp32/third_party/connectedhomeip/src/lib/support/Pool.h:231
(inlined by) chip::BitMapObjectPool<mdns::Minimal::ServerBase::EndpointInfo, 30u>::ReleaseObject(void*, void*) at /data/build_matter/esp-idf/chip/../../../mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/config/esp32/third_party/connectedhomeip/src/lib/support/Pool.h:278

S8 : 0x00000003 S9 : 0x00000000 S10 : 0x00000000 S11 : 0x00000000
T3 : 0x6e6d6c6b T4 : 0x6a696867 T5 : 0x66656463 T6 : 0x62613938
MSTATUS : 0x00001881 MTVEC : 0x40800001 MCAUSE : 0x00000007 MTVAL : 0x00000000
0x40800001: _vector_table at ??:?

MHARTID : 0x00000000

Backtrace:

panic_abort (details=details@entry=0x4084086c "abort() was called at PC 0x420b03dd on core 0") at /data/mill-esp32/main/externals/esp-idf/components/esp_system/panic.c:452
452 ((volatile int ) 0) = 0; // NOLINT(clang-analyzer-core.NullDereference) should be an invalid operation on targets
#0 panic_abort (details=details@entry=0x4084086c "abort() was called at PC 0x420b03dd on core 0") at /data/mill-esp32/main/externals/esp-idf/components/esp_system/panic.c:452
#1 0x4080913c in esp_system_abort (details=details@entry=0x4084086c "abort() was called at PC 0x420b03dd on core 0") at /data/mill-esp32/main/externals/esp-idf/components/esp_system/port/esp_system_chip.c:84
#2 0x4080cda0 in abort () at /data/mill-esp32/main/externals/esp-idf/components/newlib/abort.c:38
#3 0x420b03e0 in chipAbort () at ../../../mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/config/esp32/third_party/connectedhomeip/src/lib/support/CodeUtils.h:508
#4 chipDie () at ../../../mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/config/esp32/third_party/connectedhomeip/src/lib/support/CodeUtils.h:518
#5 chip::Platform::Internal::AssertChipStackLockedByCurrentThread (file=file@entry=0x421b4710 "", line=line@entry=213) at ../../../mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/config/esp32/third_party/connectedhomeip/src/platform/LockTracker.cpp:36
#6 0x420cf90a in chip::Inet::UDPEndPointImplLwIP::CloseImpl (this=0x40823f08 <chip::DeviceLayer::Internal::GenericConnectivityManagerImpl_UDPchip::DeviceLayer::ConnectivityManagerImpl::_UDPEndPointManager()::sUDPEndPointManagerImpl+120>) at ../../../mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/config/esp32/third_party/connectedhomeip/src/inet/UDPEndPointImplLwIP.cpp:213
#7 0x420cf9b4 in chip::Inet::UDPEndPointImplLwIP::Free (this=0x40823f08 <chip::DeviceLayer::Internal::GenericConnectivityManagerImpl_UDPchip::DeviceLayer::ConnectivityManagerImpl::_UDPEndPointManager()::sUDPEndPointManagerImpl+120>) at ../../../mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/config/esp32/third_party/connectedhomeip/src/inet/UDPEndPointImplLwIP.cpp:244
#8 0x420aca8a in chip::BitMapObjectPool<mdns::Minimal::ServerBase::EndpointInfo, 30u>::ReleaseObject (element=0x40822374 chip::Dnssd::GlobalMinimalMdnsServer::Instance()::_instance+36, this=0x40822358 chip::Dnssd::GlobalMinimalMdnsServer::Instance()::_instance+8) at ../../../mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/config/esp32/third_party/connectedhomeip/src/lib/support/Pool.h:234
#9 chip::BitMapObjectPool<mdns::Minimal::ServerBase::EndpointInfo, 30u>::ReleaseObject (element=0x40822374 chip::Dnssd::GlobalMinimalMdnsServer::Instance()::_instance+36, this=0x40822358 chip::Dnssd::GlobalMinimalMdnsServer::Instance()::_instance+8) at ../../../mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/config/esp32/third_party/connectedhomeip/src/lib/support/Pool.h:229
#10 chip::BitMapObjectPool<mdns::Minimal::ServerBase::EndpointInfo, 30u>::ReleaseObject (context=0x40822358 chip::Dnssd::GlobalMinimalMdnsServer::Instance()::_instance+8, object=0x40822374 chip::Dnssd::GlobalMinimalMdnsServer::Instance()::_instance+36) at ../../../mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/config/esp32/third_party/connectedhomeip/src/lib/support/Pool.h:278
#11 0x420ae42a in chip::internal::StaticAllocatorBitmap::ForEachActiveObjectInner (this=0x40822358 chip::Dnssd::GlobalMinimalMdnsServer::Instance()::_instance+8, context=0x40822358 chip::Dnssd::GlobalMinimalMdnsServer::Instance()::_instance+8, lambda=0x420aca78 <chip::BitMapObjectPool<mdns::Minimal::ServerBase::EndpointInfo, 30u>::ReleaseObject(void, void)>) at ../../../mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/config/esp32/third_party/connectedhomeip/src/lib/support/Pool.cpp:122
#12 0x420aae86 in chip::Dnssd::(anonymous namespace)::AdvertiserMinMdns::Init (this=this@entry=0x40821e28 <chip::Dnssd::(anonymous namespace)::gAdvertiser>, udpEndPointManager=0x40823e90 <chip::DeviceLayer::Internal::GenericConnectivityManagerImpl_UDPchip::DeviceLayer::ConnectivityManagerImpl::_UDPEndPointManager()::sUDPEndPointManagerImpl>) at ../../../mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/config/esp32/third_party/connectedhomeip/src/lib/dnssd/Advertiser_ImplMinimalMdns.cpp:352
#13 0x4204ebda in chip::app::DnssdServer::StartServer (this=0x4081a0d0 chip::app::DnssdServer::Instance()::instance, mode=chip::Dnssd::CommissioningMode::kDisabled) at /data/mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/src/app/server/Dnssd.cpp:384
#14 0x4204eca8 in chip::app::DnssdServer::StartServer (this=) at /data/mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/src/app/server/Dnssd.cpp:348
#15 0x4204dd9c in chip::CommissioningWindowManager::StopAdvertisement (this=this@entry=0x4081ffd8 chip::Server::sServer+8816, aShuttingDown=aShuttingDown@entry=false) at /data/mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/src/app/server/CommissioningWindowManager.cpp:476
#16 0x4204e19c in chip::CommissioningWindowManager::Cleanup (this=this@entry=0x4081ffd8 chip::Server::sServer+8816) at /data/mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/src/app/server/CommissioningWindowManager.cpp:117
#17 0x4204e444 in chip::CommissioningWindowManager::OpenBasicCommissioningWindow (this=0x4081ffd8 chip::Server::sServer+8816, commissioningTimeout=..., commissioningTimeout@entry=..., advertisementMode=advertisementMode@entry=chip::CommissioningWindowAdvertisement::kAllSupported) at /data/mill-esp32/main/externals/esp-matter/esp-matter/connectedhomeip/connectedhomeip/src/app/server/CommissioningWindowManager.cpp:298
#18 0x4202cd9e in matter_thermostat_driver::MatterThermostatDriver::startComisioningWindow (this=) at /data/mill-esp32/main/src/matter/matter_thermostat_driver.cpp:131
#19 0x42019140 in delayed_call::runLoop () at /data/mill-esp32/main/src/common/misc/os/delayed_call.cpp:126
#20 0x00000000 in ?? ()
Backtrace stopped: frame did not save the PC
ELF file SHA256: b1ccc32564dcc087

Rebooting...
ESP-ROM:esp32c6-20220919
Build:Sep 19 2022
rst:0xc (SW_CPU),boot:0xc (SPI_FAST_FLASH_BOOT)
Saved PC:0x4001975a
0x4001975a: software_reset_cpu in ROM

SPIWP:0xee
mode:DIO, clock div:2
load:0x4086c410,len:0xcb4
load:0x4086e610,len:0x2b20
load:0x40875728,len:0x133c
SHA-256 comparison failed:
Calculated: 19d6de0ed0a26a0754d7d35f068dc3c8cfd7af31f9dda29cfc09743ca67b572c
Expected: ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff
Attempting to boot anyway...
entry 0x4086c410
@github-actions github-actions bot changed the title ESP32C6 unsafe/racy code when starting comisoning window ESP32C6 unsafe/racy code when starting comisoning window (CON-870) Nov 6, 2023
@shubhamdp
Copy link
Contributor

@damian-kurek-wizzdev Take a look at https://docs.espressif.com/projects/esp-matter/en/latest/esp32/faq.html#a1-11-chip-stack-locking-error-code-is-unsafe-racy

@damian-kurek-wizzdev
Copy link
Author

damian-kurek-wizzdev commented Nov 6, 2023 •
edited
Loading

@shubhamdp Thanks for it. It went past it, but now it fails on nvs read for parameter iteration-count. Returning NVS_NOT_FOUND error.
The core of the code is the same and nvs storage is working on esp32 and esp32c6.
And it looks like on c6 it automatically starts the commissioning window when on esp32 it does not do it.

@damian-kurek-wizzdev
Copy link
Author

I cleared cache and it started working. Probably some compilation error.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@shubhamdp @damian-kurek-wizzdev