lboue commented 7 months ago

Boot loop with Matter Fan Control Example

Hello,

I am facing a bootlop with the Matter Fan Control Example from this repo.

Build an flash

cd matter-esp32-dcmotor
source ./scripts/flash_factory_dac_provider.sh
idf.py flash -b 115200
idf.py monitor

Boot log

E (1930) chip[DL]: Long dispatch time: 865 ms, for event type 2
I (1930) chip[DL]: Starting ESP WiFi layer
I (1940) wifi:mode : sta (d4:d4:da:98:21:14)
I (1940) wifi:enable tsf
W (1940) wifi:Haven't to connect to a suitable AP now!
I (1940) chip[DL]: Done driving station state, nothing else to do...
W (1950) wifi:Haven't to connect to a suitable AP now!
I (1950) chip[DL]: Done driving station state, nothing else to do...
I (1960) chip[SVR]: Initializing subscription resumption storage...
I (1970) chip[SVR]: Server initializing...
I (1980) chip[TS]: Last Known Good Time: 2023-10-14T01:16:48
I (1980) chip[DMG]: AccessControl: initializing
I (1980) chip[DMG]: Examples::AccessControlDelegate::Init
I (1990) chip[DMG]: AccessControl: setting
I (2000) chip[DMG]: DefaultAclStorage: initializing
I (2000) chip[DMG]: DefaultAclStorage: 0 entries loaded
I (2030) chip[ZCL]: Using ZAP configuration...
I (2030) esp_matter_cluster: Cluster plugin init common callback
I (2030) chip[DMG]: AccessControlCluster: initializing
I (2040) chip[ZCL]: 0x3f406a6b ep 0 clus 0x0000_0030 attr 0x0000_0000 not supported
I (2050) chip[ZCL]: Initiating Admin Commissioning cluster.
I (2060) chip[DIS]: Updating services using commissioning mode 1
I (2060) chip[DIS]: CHIP minimal mDNS started advertising.
I (2070) chip[DIS]: Advertise commission parameter vendorID=65522 productID=32772 discriminator=1234/04 cm=1
I (2080) chip[DIS]: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 2D4AAAA84A6E7EDA.
I (2090) chip[DIS]: mDNS service published: _matterc._udp
I (2090) chip[IN]: CASE Server enabling CASE session setups
I (2100) chip[SVR]: Joining Multicast groups
I (2110) chip[SVR]: Server Listening...
I (2110) esp_matter_core: Dynamic endpoint 0 added
I (2120) chip[DL]: WIFI_EVENT_STA_START
W (2120) wifi:Haven't to connect to a suitable AP now!
I (2130) logger: [CSystem::matter_set_min_endpoint_id] Set minimum endpoint id as 1 [system.cpp:315]
I (2130) chip[DL]: Done driving station state, nothing else to do...
I (2140) logger: [CSystem::initialize] Matter started [system.cpp:88]
ets Jun  8 2016 00:22:57

rst:0x8 (TG1WDT_SYS_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 188777542, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:6024
load:0x40078000,len:15044
load:0x40080400,len:4
0x40080400: _init at ??:?

load:0x40080404,len:3756
entry 0x4008062c
I (59) boot: ESP-IDF v5.1.1-577-g6b1f40b9bf 2nd stage bootloader
I (59) boot: compile time Feb 25 2024 14:51:58
I (61) boot: Multicore bootloader
I (66) boot: chip revision: v1.0
I (69) boot.esp32: SPI Speed      : 40MHz
I (74) boot.esp32: SPI Mode       : DIO
I (79) boot.esp32: SPI Flash Size : 4MB
W (83) boot.esp32: PRO CPU has been reset by WDT.
W (88) boot.esp32: WDT reset info: PRO CPU PC=0x40091a99
0x40091a99: _frxt_task_coproc_state at /home/user/tools/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/portasm.S:698

W (94) boot.esp32: WDT reset info: APP CPU PC=0x40081739
0x40081739: panicHandler at /home/user/tools/esp-idf/components/esp_system/port/panic_handler.c:217

system.cpp#L88

Full log

boot_esp32_fan_dac.log

YOGYUI commented 7 months ago

bool CSystem::initialize()
{
    /*  *** */
     // start matter
    ret = esp_matter::start(matter_event_callback);
    if (ret != ESP_OK) {
        GetLogger(eLogType::Error)->Log("Failed to start matter (ret: %d)", ret);
        return false;
    }
    // prevent endpoint id increment when board reset
    matter_set_min_endpoint_id(1);
    GetLogger(eLogType::Info)->Log("Matter started");

    CDevice *dev = new CDeviceFanControlDCMotor();
    if (dev && dev->matter_add_endpoint()) {
        m_device_list.push_back(dev);
        dev->matter_update_all_attribute_values();
    } else {
        return false;
    }

    GetMemory()->Initialize();

    GetLogger(eLogType::Info)->Log("System Initialized");
    print_system_info();

    return true;
}

@lboue I guess that crash had occurred when creating CDeviceFanControlMotor instance but I'm not sure. (There are no logs after calling esp_matter::start()) I'll look further as soon as possible with my esp32 devkit.

lboue commented 7 months ago

Yes, I'll take a look at it myself. I will add some log message CDeviceFanControlMotor . Thanks.

lboue commented 7 months ago

I don't know exactly why, but I don't have this boot loop issue since I change Motor pin to GPIO21: #define GPIO_PIN_MOTOR_PWM 21

I (2152) logger: Checking m_motor_pwm_driver: TRUE
I (2162) NimBLE:  adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=40 adv_itvl_max=40
I (2162) gpio: GPIO[21]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
I (2172) NimBLE: 
I (2182) logger: ----- END: Checking m_motor_pwm_driver -----
I (2192) chip[DL]: CHIPoBLE advertising started
I (2202) logger: [CSystem::matter_event_callback] Commissioning window opened [system.cpp:391]
I (2212) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000003's Attribute 0x00000001 is 0 **********
I (2222) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000004's Attribute 0x00000000 is 128 **********
I (2232) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000004's Attribute 0x0000FFFC is <invalid type: 0> **********
I (2242) esp_matter_core: Dynamic endpoint 1 added
I (2252) logger: [CSystem::matter_update_attribute] Try to update matter attribute (endpoint: 1, cluster: 0x0202, attribute: 0x0000, value: 0) [system.cpp:353]
I (2262) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000000 is 0 **********
I (2282) logger: [CDeviceFanControlDCMotor::matter_on_change_attribute_value] cluster: FanControl(0x0202), attribute: FanMode(0x0000), value: 0 [device_fanctrl_dcmotor.cpp:122]
I (2302) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000000 is 0 **********
I (2302) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000002 is 0 **********
I (2322) logger: [CDeviceFanControlDCMotor::matter_on_change_attribute_value] cluster: FanControl(0x0202), attribute: PercentSetting(0x0002), value: 0 [device_fanctrl_dcmotor.cpp:144]
I (2332) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000002 is 0 **********
I (2342) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000000 is 0 **********
I (2362) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x0000FFFC is 0 **********
I (2372) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000003 is 0 **********
I (2382) logger: [CDeviceFanControlDCMotor::matter_on_change_attribute_value] cluster: FanControl(0x0202), attribute: PercentCurrent(0x0003), value: 0 [device_fanctrl_dcmotor.cpp:152]
I (2402) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x0000FFFC is 0 **********
I (2412) logger: [CSystem::matter_update_attribute] Try to update matter attribute (endpoint: 1, cluster: 0x0202, attribute: 0x0002, value: 0) [system.cpp:353]
I (2422) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000002 is 0 **********
I (2432) logger: [CDeviceFanControlDCMotor::matter_on_change_attribute_value] cluster: FanControl(0x0202), attribute: PercentSetting(0x0002), value: 0 [device_fanctrl_dcmotor.cpp:144]
I (2452) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000002 is 0 **********
I (2462) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000000 is 0 **********
I (2472) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x0000FFFC is 0 **********
I (2492) logger: [CSystem::matter_update_attribute] Try to update matter attribute (endpoint: 1, cluster: 0x0202, attribute: 0x0003, value: 0) [system.cpp:353]
I (2502) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000003 is 0 **********
I (2512) logger: [CDeviceFanControlDCMotor::matter_on_change_attribute_value] cluster: FanControl(0x0202), attribute: PercentCurrent(0x0003), value: 0 [device_fanctrl_dcmotor.cpp:152]
I (2532) logger: [CSystem::initialize] System Initialized [system.cpp:100]
I (2542) logger: [CSystem::print_system_info] System Info [system.cpp:248]
I (2542) logger: ----- ESP32 -----
I (2552) logger: Project Name: yogyui-matter-esp32-dcmotor
I (2552) logger: App Version: 1.0.0.0
I (2562) logger: CPU Core(s): 2
I (2562) logger: Revision: 1.0
I (2572) logger: Flash Size: 4 MB (embedded)
I (2572) logger: Heap Free Size: 79208

YOGYUI commented 7 months ago

@lboue That's very interesting (and also embarrassing...) when I had flashed firmware with no change (GPIO 16 as PWM output), there was no problem like below

I (2228) logger: [CSystem::matter_set_min_endpoint_id] Set minimum endpoint id as 1 [system.cpp:315]
I (2228) chip[DL]: Done driving station state, nothing else to do...
I (2238) logger: [CSystem::initialize] Matter started [system.cpp:88]
I (2258) gpio: GPIO[16]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
I (2278) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000003's Attribute 0x00000001 is 0 **********
I (2278) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000004's Attribute 0x00000000 is 128 **********
I (2288) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000004's Attribute 0x0000FFFC is <invalid type: 0> **********
I (2308) esp_matter_core: Dynamic endpoint 1 added
I (2308) logger: [CSystem::matter_update_attribute] Try to update matter attribute (endpoint: 1, cluster: 0x0202, attribute: 0x0000, value: 0) [system.cpp:353]
I (2328) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000000 is 0 **********
I (2338) logger: [CDeviceFanControlDCMotor::matter_on_change_attribute_value] cluster: FanControl(0x0202), attribute: FanMode(0x0000), value: 0 [device_fanctrl_dcmotor.cpp:118]
I (2358) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000000 is 0 **********
I (2368) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000002 is 0 **********
I (2378) logger: [CDeviceFanControlDCMotor::matter_on_change_attribute_value] cluster: FanControl(0x0202), attribute: PercentSetting(0x0002), value: 0 [device_fanctrl_dcmotor.cpp:140]
I (2398) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000002 is 0 **********
I (2408) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000000 is 0 **********
I (2418) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x0000FFFC is 0 **********
I (2428) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000003 is 0 **********
I (2438) logger: [CDeviceFanControlDCMotor::matter_on_change_attribute_value] cluster: FanControl(0x0202), attribute: PercentCurrent(0x0003), value: 0 [device_fanctrl_dcmotor.cpp:148]
I (2458) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x0000FFFC is 0 **********
I (2468) logger: [CSystem::matter_update_attribute] Try to update matter attribute (endpoint: 1, cluster: 0x0202, attribute: 0x0002, value: 0) [system.cpp:353]
I (2488) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000002 is 0 **********
I (2498) logger: [CDeviceFanControlDCMotor::matter_on_change_attribute_value] cluster: FanControl(0x0202), attribute: PercentSetting(0x0002), value: 0 [device_fanctrl_dcmotor.cpp:140]
I (2508) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000002 is 0 **********
I (2528) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000000 is 0 **********
I (2538) esp_matter_attribute: ********** R : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x0000FFFC is 0 **********
I (2548) logger: [CSystem::matter_update_attribute] Try to update matter attribute (endpoint: 1, cluster: 0x0202, attribute: 0x0003, value: 0) [system.cpp:353]
I (2558) esp_matter_attribute: ********** W : Endpoint 0x0001's Cluster 0x00000202's Attribute 0x00000003 is 0 **********
I (2578) logger: [CDeviceFanControlDCMotor::matter_on_change_attribute_value] cluster: FanControl(0x0202), attribute: PercentCurrent(0x0003), value: 0 [device_fanctrl_dcmotor.cpp:148]
I (2588) logger: [CSystem::initialize] System Initialized [system.cpp:100]
I (2598) logger: [CSystem::print_system_info] System Info [system.cpp:248]
I (2608) logger: ----- ESP32 -----
I (2608) logger: Project Name: yogyui-matter-esp32-dcmotor
I (2618) logger: App Version: 1.0.0.0
I (2618) logger: CPU Core(s): 2
I (2628) logger: Revision: 1.1
I (2628) logger: Flash Size: 4 MB (external)
I (2628) logger: Heap Free Size: 155040
I (2638) logger: ----- Network -----
I (2638) logger: IPv4 Address: 0.0.0.0
I (2648) logger: Gateway: 0.0.0.0
I (2648) logger: MAC Address: D8:BC:38:40:97:B0
I (2658) logger: ----- Matter -----
I (2658) logger: Vendor ID: 0xFFF2
I (2668) logger: Product ID: 0x8001
I (2668) logger: Setup Discriminator: 3841
I (2668) main_task: Returned from app_main()

I'm glad that problem is solved easily, but it's worth debugging why this happened.

lboue commented 7 months ago

@lboue That's very interesting (and also embarrassing...) when I had flashed firmware with no change (GPIO 16 as PWM output), there was no problem like below

I'm glad that problem is solved easily, but it's worth debugging why this happened.

Which board type did you flash? I tried with 2 ESP32-PICO boards:

I didn't find GPIO16 in ESP32-PICO schematic.

YOGYUI commented 7 months ago

@lboue I used ESP32-WROOM32E-32D with download kit. GPIO pin number should be modified following hardware limitation :)

YOGYUI / matter-esp32-dcmotor