Skip to content

Glitch during ESP32-C6 Startup #11230

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.

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

Closed
1 task done
def1149 opened this issue Apr 8, 2025 · 9 comments
Closed
1 task done

Glitch during ESP32-C6 Startup #11230

def1149 opened this issue Apr 8, 2025 · 9 comments
Assignees
Labels
Area: Zigbee Issues and Feature Request about Zigbee Status: Awaiting triage Issue is waiting for triage

Comments

@def1149
Copy link

def1149 commented Apr 8, 2025

Board

Adafruit ESP32-C6 Feather

Device Description

Nothing attached

Hardware Configuration

Nothing attached

Version

v3.2.0

IDE Name

Arduino 2.3.5

Operating System

Windows 11

Flash frequency

40 MHz

PSRAM enabled

no

Upload speed

921600

Description

Occasionally, expected Zigbee data transmission is missing in Home Assistant

To debug:
Using the Espressif Sleepy Temperature sensor example with modifications to log events of note and running in ESP32 debug mode

I created a test temperature generator that monotonically increases the temperature by 0.5C every wake-up cycle and I plot the values in Home Assistant. I expect to see a consistent stair-step pattern on the graph. Occasionally the pattern demonstrates missing values

The ESP32-C6 seems to experience an error on startup during initialization after awakening from sleep.

Image

This is the annotated (####) corresponding log output.

12:37:07.236 -> Going to sleep now                               #### end of previous connection cycle
12:37:17.981 -> ========== Before Setup Start ===========        #### wakeup for this connection and start of good cycle 
12:37:17.981 -> Chip Info:
12:37:17.981 -> ------------------------------------------
12:37:17.981 ->   Model             : ESP32-C6
12:37:17.981 ->   Package           : 1
12:37:17.981 ->   Revision          : 0.01
12:37:17.981 ->   Cores             : 1
12:37:17.981 ->   CPU Frequency     : 80 MHz
12:37:17.981 ->   XTAL Frequency    : 40
12:37:17.981 ->   Features Bitfield : 0x00000052
12:37:17.981 ->   Embedded Flash    : No
12:37:17.981 ->   Embedded PSRAM    : No
12:37:17.981 ->   2.4GHz WiFi       : Yes
12:37:17.981 ->   Classic BT        : No
12:37:17.981 ->   BT Low Energy     : Yes
12:37:17.981 ->   IEEE 802.15.4     : Yes
12:37:17.981 -> ------------------------------------------
12:37:17.981 -> INTERNAL Memory Info:
12:37:17.981 -> ------------------------------------------
12:37:17.981 ->   Total Size        :   439236 B ( 428.9 KB)
12:37:17.981 ->   Free Bytes        :   404120 B ( 394.6 KB)
12:37:17.981 ->   Allocated Bytes   :    28132 B (  27.5 KB)
12:37:17.981 ->   Minimum Free Bytes:   399396 B ( 390.0 KB)
12:37:17.981 ->   Largest Free Block:   368628 B ( 360.0 KB)
12:37:17.981 -> ------------------------------------------
12:37:17.981 -> Flash Info:
12:37:17.981 -> ------------------------------------------
12:37:17.981 ->   Chip Size         :  4194304 B (4 MB)
12:37:17.981 ->   Block Size        :    65536 B (  64.0 KB)
12:37:17.981 ->   Sector Size       :     4096 B (   4.0 KB)
12:37:17.981 ->   Page Size         :      256 B (   0.2 KB)
12:37:17.981 ->   Bus Speed         : 40 MHz
12:37:17.981 ->   Bus Mode          : QIO
12:37:17.981 -> ------------------------------------------
12:37:17.981 -> Partitions Info:
12:37:17.981 -> ------------------------------------------
12:37:17.981 ->                 nvs : addr: 0x00009000, size:    20.0 KB, type: DATA, subtype: NVS
12:37:17.981 ->             otadata : addr: 0x0000E000, size:     8.0 KB, type: DATA, subtype: OTA
12:37:17.981 ->                app0 : addr: 0x00010000, size:  1280.0 KB, type:  APP, subtype: OTA_0
12:37:18.007 ->                app1 : addr: 0x00150000, size:  1280.0 KB, type:  APP, subtype: OTA_1
12:37:18.007 ->              spiffs : addr: 0x00290000, size:  1388.0 KB, type: DATA, subtype: SPIFFS
12:37:18.007 ->          zb_storage : addr: 0x003EB000, size:    16.0 KB, type: DATA, subtype: FAT
12:37:18.007 ->              zb_fct : addr: 0x003EF000, size:     4.0 KB, type: DATA, subtype: FAT
12:37:18.007 ->            coredump : addr: 0x003F0000, size:    64.0 KB, type: DATA, subtype: COREDUMP
12:37:18.007 -> ------------------------------------------
12:37:18.007 -> Software Info:
12:37:18.007 -> ------------------------------------------
12:37:18.007 ->   Compile Date/Time : Apr  7 2025 14:39:39
12:37:18.007 ->   Compile Host OS   : windows
12:37:18.007 ->   ESP-IDF Version   : v5.4.1-1-g2f7dcd862a-dirty
12:37:18.007 ->   Arduino Version   : 3.2.0
12:37:18.007 -> ------------------------------------------
12:37:18.007 -> Board Info:
12:37:18.007 -> ------------------------------------------
12:37:18.007 ->   Arduino Board     : ADAFRUIT_FEATHER_ESP32C6
12:37:18.007 ->   Arduino Variant   : adafruit_feather_esp32c6
12:37:18.007 ->   Arduino FQBN      : esp32:esp32:adafruit_feather_esp32c6:UploadSpeed=921600,CDCOnBoot=cdc,CPUFreq=80,FlashFreq=80,FlashMode=qio,PartitionScheme=zigbee,DebugLevel=debug,EraseFlash=none,JTAGAdapter=default,ZigbeeMode=ed
12:37:18.007 -> ============ Before Setup End ============
12:37:18.118 -> [   872][I][esp32-hal-periman.c:141] perimanSetPinBus(): Pin 12 already has type USB_DM (38) with bus 0x408132b4
12:37:18.118 -> [   873][I][esp32-hal-periman.c:141] perimanSetPinBus(): Pin 13 already has type USB_DP (39) with bus 0x408132b4
12:37:23.117 -> Restart = 5
12:37:23.117 -> [  5875][D][ZigbeeCore.cpp:97] addEndpoint(): Endpoint: 10, Device ID: 0x0302
12:37:23.117 -> Starting Zigbee
12:37:23.117 -> [  5875][D][ZigbeeCore.cpp:145] zigbeeInit(): Initialize Zigbee stack
12:37:23.117 -> [  5897][D][ZigbeeCore.cpp:152] zigbeeInit(): Register all Zigbee EPs in list
12:37:23.117 -> [  5900][I][ZigbeeCore.cpp:160] zigbeeInit(): List of registered Zigbee EPs:
12:37:23.117 -> [  5901][I][ZigbeeCore.cpp:162] zigbeeInit(): Device type: Temperature Sensor, Endpoint: 10, Device ID: 0x0302
12:37:23.117 -> [  5913][I][ZigbeeCore.cpp:241] esp_zb_app_signal_handler(): Zigbee stack initialized
12:37:23.155 -> [  5914][D][ZigbeeCore.cpp:242] esp_zb_app_signal_handler(): Zigbee channel mask: 0x00000800
12:37:23.431 -> [  6189][I][ZigbeeCore.cpp:248] esp_zb_app_signal_handler(): Device started up in non factory-reset mode
12:37:23.431 -> [  6190][I][ZigbeeCore.cpp:261] esp_zb_app_signal_handler(): Device rebooted
12:37:23.431 -> [  6192][D][ZigbeeCore.cpp:512] searchBindings(): Requesting binding table for address 0xe3d9
12:37:23.431 -> [  6194][D][ZigbeeCore.cpp:452] bindingTableCb(): Binding table callback for address 0xe3d9 with status 0
12:37:23.431 -> [  6195][D][ZigbeeCore.cpp:455] bindingTableCb(): Binding table info: total 3, index 0, count 3
12:37:23.431 -> [  6196][D][ZigbeeCore.cpp:465] bindingTableCb(): Binding table record: src_endp 10, dst_endp 1, cluster_id 0x0405, dst_addr_mode 3
12:37:23.431 -> [  6198][D][ZigbeeCore.cpp:482] bindingTableCb(): Device bound to EP 10 -> device endpoint: 1, short addr: 0x0000, ieee addr: F0:82:C0:FF:FE:6B:DB:EC
12:37:23.431 -> [  6199][D][ZigbeeCore.cpp:465] bindingTableCb(): Binding table record: src_endp 10, dst_endp 1, cluster_id 0x0001, dst_addr_mode 3
12:37:23.431 -> [  6200][D][ZigbeeCore.cpp:482] bindingTableCb(): Device bound to EP 10 -> device endpoint: 1, short addr: 0x0000, ieee addr: F0:82:C0:FF:FE:6B:DB:EC
12:37:23.431 -> [  6202][D][ZigbeeCore.cpp:465] bindingTableCb(): Binding table record: src_endp 10, dst_endp 1, cluster_id 0x0402, dst_addr_mode 3
12:37:23.431 -> [  6203][D][ZigbeeCore.cpp:482] bindingTableCb(): Device bound to EP 10 -> device endpoint: 1, short addr: 0x0000, ieee addr: F0:82:C0:FF:FE:6B:DB:EC
12:37:23.431 -> [  6204][D][ZigbeeCore.cpp:503] bindingTableCb(): Filling bounded devices finished
12:37:23.431 -> [  6196][D][ZigbeeCore.cpp:465] bindingTableCb(): Binding table record: src_endp 10, dst_endp 1, cluster_id 0x0405, dst_addr_mode 3
12:37:23.431 -> [  6198][D][ZigbeeCore.cpp:482] bindingTableCb(): Device bound to EP 10 -> device endpoint: 1, short addr: 0x0000, ieee addr: F0:82:C0:FF:FE:6B:DB:EC
12:37:23.431 -> [  6199][D][ZigbeeCore.cpp:465] bindingTableCb(): Binding table record: src_endp 10, dst_endp 1, cluster_id 0x0001, dst_addr_mode 3
12:37:23.431 -> [  6200][D][ZigbeeCore.cpp:482] bindingTableCb(): Device bound to EP 10 -> device endpoint: 1, short addr: 0x0000, ieee addr: F0:82:C0:FF:FE:6B:DB:EC
12:37:23.431 -> [  6202][D][ZigbeeCore.cpp:465] bindingTableCb(): Binding table record: src_endp 10, dst_endp 1, cluster_id 0x0402, dst_addr_mode 3
12:37:23.431 -> [  6203][D][ZigbeeCore.cpp:482] bindingTableCb(): Device bound to EP 10 -> device endpoint: 1, short addr: 0x0000, ieee addr: F0:82:C0:FF:FE:6B:DB:EC
12:37:23.431 -> [  6204][D][ZigbeeCore.cpp:503] bindingTableCb(): Filling bounded devices finished
12:37:23.431 -> Started in 331 mS
12:37:23.431 -> Connecting to network
12:37:23.431 -> 
12:37:23.431 -> Successfully connected to Zigbee network in 0 mS
12:37:24.415 -> =========== After Setup Start ============
12:37:24.415 -> INTERNAL Memory Info:
12:37:24.415 -> ------------------------------------------
12:37:24.415 ->   Total Size        :   439236 B ( 428.9 KB)
12:37:24.415 ->   Free Bytes        :   372440 B ( 363.7 KB)
12:37:24.415 ->   Allocated Bytes   :    58868 B (  57.5 KB)
12:37:24.415 ->   Minimum Free Bytes:   372440 B ( 363.7 KB)
12:37:24.415 ->   Largest Free Block:   344052 B ( 336.0 KB)
12:37:24.448 -> ------------------------------------------
12:37:24.448 -> GPIO Info:
12:37:24.448 -> ------------------------------------------
12:37:24.448 ->   GPIO : BUS_TYPE[bus/unit][chan]
12:37:24.448 ->   --------------------------------------  
12:37:24.448 ->      9 : GPIO
12:37:24.448 ->     12 : USB_DM
12:37:24.448 ->     13 : USB_DP
12:37:24.448 ->     16 : UART_TX[0]
12:37:24.448 ->     17 : UART_RX[0]
12:37:24.448 ->     20 : GPIO
12:37:24.448 -> ============ After Setup End =============
12:37:24.448 -> Check for Button
12:37:24.448 -> Measure 
12:37:24.448 -> [  7242][D][ZigbeeTempSensor.cpp:81] setTemperature(): Setting temperature to 4900
12:37:24.448 -> [  7244][D][ZigbeeTempSensor.cpp:134] setHumidity(): Setting humidity to 0
12:37:24.491 -> Report 
12:37:24.491 -> Reported 1, temperature: 49.00°C, Humidity: 0.00%
12:37:24.659 -> Going to sleep now                                  #### end of good cycle
12:37:35.371 -> =========== Before Setup Start ===========          #### start of glitch cycle
12:37:35.371 -> Chip Info:
12:37:35.371 -> ------------------------------------------
12:37:35.371 ->   Model             : ESP32-C6
12:37:35.371 ->   Package           : 1
12:37:35.371 ->   Revision          : 0.01
12:37:35.371 ->   Cores             : 1
12:37:35.371 ->   CPU Frequency     : 80 MHz
12:37:35.371 ->   XTAL Frequency    : 40
12:37:35.371 ->   Features Bitfield : 0x00000052
12:37:35.371 ->   Embedded Flash    : No
12:37:35.371 ->   Embedded PSRAM    : No
12:37:35.371 ->   2.4GHz WiFi       : Yes
12:37:35.371 ->   Classic BT        : No
12:37:35.371 ->   BT Low Energy     : Yes
12:37:35.371 ->   IEEE 802.15.4     : Yes
12:37:35.371 -> ------------------------------------------
12:37:35.371 -> INTERNAL Memory Info:
12:37:35.371 -> ------------------------------------------
12:37:35.371 ->   Total Size        :   439236 B ( 428.9 KB)
12:37:35.371 ->   Free Bytes        :   404120 B ( 394.6 KB)
12:37:35.371 ->   Allocated Bytes   :    28132 B (  27.5 KB)
12:37:35.371 ->   Minimum Free Bytes:   399396 B ( 390.0 KB)
12:37:35.371 ->   Largest Free Block:   368628 B ( 360.0 KB)
12:37:35.371 -> ------------------------------------------
12:37:35.371 -> Flash Info:
12:37:35.371 -> ------------------------------------------
12:37:35.371 ->   Chip Size         :  4194304 B (4 MB)
12:37:35.371 ->   Block Size        :    65536 B (  64.0 KB)
12:37:35.371 ->   Sector Size       :     4096 B (   4.0 KB)
12:37:35.371 ->   Page Size         :      256 B (   0.2 KB)
12:37:35.371 ->   Bus Speed         : 40 MHz
12:37:35.371 ->   Bus Mode          : QIO
12:37:35.371 -> ------------------------------------------
12:37:35.371 -> Partitions Info:
12:37:35.371 -> ------------------------------------------       #### glitch What happened?
12:37:35.371 ->                 nvs : addr: 0x00009000, size:    =========== Before Setup Start ===========           
12:40:11.691 -> Chip Info:                                       #### start of next good cycle after 2:26 delay???                                      
12:40:11.691 -> ------------------------------------------
12:40:11.691 ->   Model             : ESP32-C6
12:40:11.691 ->   Package           : 1
12:40:11.691 ->   Revision          : 0.01
12:40:11.691 ->   Cores             : 1
12:40:11.691 ->   CPU Frequency     : 80 MHz
12:40:11.691 ->   XTAL Frequency    : 40
12:40:11.691 ->   Features Bitfield : 0x00000052
12:40:11.691 ->   Embedded Flash    : No
12:40:11.691 ->   Embedded PSRAM    : No
12:40:11.691 ->   2.4GHz WiFi       : Yes
12:40:11.691 ->   Classic BT        : No
12:40:11.691 ->   BT Low Energy     : Yes
12:40:11.691 ->   IEEE 802.15.4     : Yes
12:40:11.691 -> ------------------------------------------
12:40:11.691 -> INTERNAL Memory Info:
12:40:11.691 -> ------------------------------------------
12:40:11.691 ->   Total Size        :   439236 B ( 428.9 KB)
12:40:11.691 ->   Free Bytes        :   404120 B ( 394.6 KB)
12:40:11.691 ->   Allocated Bytes   :    28132 B (  27.5 KB)
12:40:11.691 ->   Minimum Free Bytes:   399396 B ( 390.0 KB)96 B ( 390.0 KB)

Sketch

// Copyright 2024 Espressif Systems (Shanghai) PTE LTD
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
//     http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.

/**
 * @brief This example demonstrates Zigbee temperature and humidity sensor Sleepy device.
 *
 * The example demonstrates how to use Zigbee library to create an end device temperature and humidity sensor.
 * The sensor is a Zigbee end device, which is reporting data to the Zigbee network.
 *
 * Proper Zigbee mode must be selected in Tools->Zigbee mode
 * and also the correct partition scheme must be selected in Tools->Partition Scheme.
 *
 * Please check the README.md for instructions and more detailed description.
 *
 * Created by Jan Procházka (https://github.com/P-R-O-C-H-Y/)
 */

#ifndef ZIGBEE_MODE_ED
#error "Zigbee end device mode is not selected in Tools->Zigbee mode"
#endif

#include "Zigbee.h"
#include <rom/rtc.h>

/* Zigbee temperature + humidity sensor configuration */
#define TEMP_SENSOR_ENDPOINT_NUMBER 10

#define uS_TO_S_FACTOR 1000000ULL /* Conversion factor for micro seconds to seconds */
#define TIME_TO_SLEEP  10         /* Sleep for 55s will + 5s delay for establishing connection => data reported every 1 minute */

uint8_t button = BOOT_PIN;
long start = 0; 
float wakeup = 0.0;
RTC_DATA_ATTR float fakeTemp = -30.0;
RTC_DATA_ATTR float lastStat = 0.0;
RTC_DATA_ATTR long bigCycle = 0;
ZigbeeTempSensor zbTempSensor = ZigbeeTempSensor(TEMP_SENSOR_ENDPOINT_NUMBER);

/************************ Temp sensor *****************************/
void meausureAndSleep() {
  // Measure temperature sensor value
  Serial.printf("Measure \r\n");
  float temperature = fakeTemp;// temperatureRead();

  // Use temperature value as humidity value to demonstrate both temperature and humidity
  float humidity = lastStat; //temperature;

  // Update temperature and humidity values in Temperature sensor EP
  zbTempSensor.setTemperature(temperature);
  zbTempSensor.setHumidity(humidity);
 
  zbTempSensor.setBatteryPercentage((int)wakeup );

  zbTempSensor.reportBatteryPercentage();

  Serial.printf("Report \r\n");
  // Report temperature and humidity values
  bool reported = zbTempSensor.report();

  Serial.printf("Reported %D, temperature: %.2f°C, Humidity: %.2f%%\r\n", reported, temperature, humidity);

  // Add small delay to allow the data to be sent before going to sleep
  delay(200);

  fakeTemp = fakeTemp+0.5;   // Monotonically increase the temperature to force Home Assistant to record the temp as it doesn't record if unchanged 
  if(fakeTemp > 80.0) {
    fakeTemp = -30.0;
  }
  if (!reported) {
    lastStat = 15.0;
  }
  // Put device to deep sleep
  Serial.println("Going to sleep now");
  esp_sleep_enable_timer_wakeup((TIME_TO_SLEEP * uS_TO_S_FACTOR)-(millis()-start));
  esp_deep_sleep_start();
}


/********************* Arduino functions **************************/
void setup() {
  start = millis();
  wakeup = (float)rtc_get_reset_reason(0);

  lastStat = 0.0;
  Serial.begin(115200);
  delay(5000);
  Serial.printf("Cycle: %D Restart: %D\r\n",(int)wakeup,bigCycle);
  bigCycle++;
  // Init button switch
  pinMode(button, INPUT_PULLUP);

  // Configure the wake up source and set to wake up every 5 seconds
  //esp_sleep_enable_timer_wakeup(TIME_TO_SLEEP * uS_TO_S_FACTOR);

  // Optional: set Zigbee device name and model
  zbTempSensor.setManufacturerAndModel("Espressif", "SleepyZigbeeTempSensor");

  // Set minimum and maximum temperature measurement value (10-50°C is default range for chip temperature measurement)
  zbTempSensor.setMinMaxValue(-30, 80);    

  // Set tolerance for temperature measurement in °C (lowest possible value is 0.01°C)
  zbTempSensor.setTolerance(0.1);

  // Set power source to battery and set battery percentage to measured value (now 100% for demonstration)
  // The value can be also updated by calling zbTempSensor.setBatteryPercentage(percentage) anytime
  zbTempSensor.setPowerSource(ZB_POWER_SOURCE_BATTERY, 100);


  // Add humidity cluster to the temperature sensor device with min, max and tolerance values
  zbTempSensor.addHumiditySensor(0, 100, 1);

  // Add endpoint to Zigbee Core
  Zigbee.addEndpoint(&zbTempSensor);

  // Create a custom Zigbee configuration for End Device with keep alive 10s to avoid interference with reporting data
  esp_zb_cfg_t zigbeeConfig = ZIGBEE_DEFAULT_ED_CONFIG();
  zigbeeConfig.nwk_cfg.zed_cfg.keep_alive = 10000;

  // For battery powered devices, it can be better to set timeout for Zigbee Begin to lower value to save battery
  // If the timeout has been reached, the network channel mask will be reset and the device will try to connect again after reset (scanning all channels)
  Zigbee.setTimeout(5000);  // Set timeout for Zigbee Begin to 10s (default is 30s)

  // When all EPs are registered, start Zigbee in End Device mode
  long t1 = millis();
  Serial.println("Starting Zigbee");
  if(!Zigbee.begin(&zigbeeConfig, false)) {
    
      Serial.println("Zigbee failed to start!");
      Serial.println("Going to sleep now for 30 seconds");
      esp_sleep_enable_timer_wakeup(30 * uS_TO_S_FACTOR);
      esp_deep_sleep_start();
  }

  Serial.printf("Started in %d mS\r\n",millis()-t1);
  Serial.println("Connecting to network");

  t1 = millis();
  int n = 0;
  while (!Zigbee.connected()) {
    n++;
    Serial.print(".");
    delay(100);
    if (n>100) {
      lastStat = 10.0;
      Serial.println("Zigbee failed to Connect!");
      Serial.println("Going to sleep for 20 seconds");
      esp_sleep_enable_timer_wakeup(20 * uS_TO_S_FACTOR);
      esp_deep_sleep_start();
      //Serial.println("Rebooting...");
      //ESP.restart();  // If Zigbee failed to start, reboot the device and try again
    }
  }
  Serial.println();
  Serial.printf("Successfully connected to Zigbee network in %d mS\r\n",millis()-t1);

  // Delay approx 1s (may be adjusted) to allow establishing proper connection with coordinator, needed for sleepy devices
  delay(1000);
}

void loop() {
  // Checking button for factory reset
   Serial.printf("Check for Button\r\n");
  if (digitalRead(button) == LOW) {  // Push button pressed
    // Key debounce handling
    delay(100);
    int startTime = millis();
    while (digitalRead(button) == LOW) {
      delay(50);
      if ((millis() - startTime) > 10000) {
        // If key pressed for more than 10secs, factory reset Zigbee and reboot
        Serial.println("Resetting Zigbee to factory and rebooting in 1s.");
        delay(1000);
        // Optional set reset in factoryReset to false, to not restart device after erasing nvram, but set it to endless sleep manually instead
        Zigbee.factoryReset(false);
        Serial.println("Going to endless sleep, press RESET button or power off/on the device to wake up");
        esp_sleep_disable_wakeup_source(ESP_SLEEP_WAKEUP_TIMER);
        esp_deep_sleep_start();
      }
    }
  }

  // Call the function to measure temperature and put the device to sleep
  meausureAndSleep();
}

Debug Message

See above

Other Steps to Reproduce

Program an ESP32-C6 with the script and enroll it as a Zigbee ZHA device on Home Assistant 2025.4.1
Use a history card to graph the temperature values reported by the device

I have checked existing issues, online documentation and the Troubleshooting Guide

  • I confirm I have checked existing issues, online documentation and Troubleshooting guide.
@def1149 def1149 added the Status: Awaiting triage Issue is waiting for triage label Apr 8, 2025
@SuGlider SuGlider added the Area: Zigbee Issues and Feature Request about Zigbee label Apr 8, 2025
@P-R-O-C-H-Y P-R-O-C-H-Y self-assigned this Apr 9, 2025
@P-R-O-C-H-Y
Copy link
Member

Hi @def1149, How often this glitch happens? If its reproducible, can you try to set Core Debug Level to "Error" only or disable, to see if its related to the printing to UART/USB or if its something related to Zigbee.

@def1149
Copy link
Author

def1149 commented Apr 9, 2025

@P-R-O-C-H-Y I have noticed other unexplainable "flat" spots in the HA temperature plots of other sensors I've created to monitor freezers where temperatures naturally cycle higher and lower, using both C6 and H2 processors. When I couldn't find a cause in my code, I modified the example code to create a situation to more easily identify any missing data points, and logged while running the code. I've seen the glitch in the log previously and repeated the testing before opening the issue.

It's not clear that this is a Zigbee problem because the glitch occurs during startup before any application code executes. I don't know what executes during board startup.

I will repeat this test on a different board with error level logging

@lbernstone
Copy link
Contributor

Do you get the issue if you remove all the button logic?

Please post code that matches the output.
Why are you forcing millis and wakeup_reason into incorrect types? (this is definitely not the problem, but is going to bite you in the long run)
Use serial.flush to wait for output to finish rather than delays

@def1149
Copy link
Author

def1149 commented Apr 9, 2025

@lbernstone

Do you get the issue if you remove all the button logic?

Please post code that matches the output. Why are you forcing millis and wakeup_reason into incorrect types? (this is definitely not the problem, but is going to bite you in the long run) Use serial.flush to wait for output to finish rather than delays

I haven't tried removing button logic, but I'm not activating that while testing so I doubt that it's an issue.

"It's not clear that this is a Zigbee problem because the glitch occurs during startup before any application code executes. I don't know what executes during board startup."

The posted code was used to create the log

I'm not using delays for serial output, but to ensure the Zigbee stack has time to complete the transactions as there doesn't seem to be a function that returns something like transaction complete that I can wait on. I know that without a delay after reporting that data will sometimes not be transmitted even though zbTempSensor.report() returns true

I'm using humidity and batteryPercentage to send some status values to help with debugging when I run with all logging and serial output disabled. I'm often running multiple test devices distributed at various distances from the controller to asses performance at low signal levels and can't hook up a PC to log output all of them. There doesn't seem to be an easy way to add additional "debug data clusters" to an endpoint to capture and transfer additional debug data to Home Assistant during testing.

I'll be adding support for this device to my testing to capture and log data to a microSD card

https://www.sparkfun.com/sparkfun-qwiic-openlog.html

Some of these tests have to run for hours or days to expose intermittent issues

@def1149
Copy link
Author

def1149 commented Apr 9, 2025

Additional failure recorded as directed with Error level logging enabled, see ### annotations
`
14:07:33.952 -> Cycle: 814 Restart: 5
14:07:33.999 -> Starting Zigbee
14:07:34.276 -> Started in 323 mS
14:07:34.276 -> Connecting to network
14:07:34.276 ->
14:07:34.311 -> Successfully connected to Zigbee network in 0 mS
14:07:35.291 -> Check for Button
14:07:35.291 -> Measure
14:07:35.291 -> Report
14:07:35.291 -> Reported 1, temperature: 45.00°C, Humidity: 0.00%
14:07:35.510 -> Going to sleep nowCycle: 815 Restart: 5
14:07:50.532 -> Starting Zigbee ####
14:07:52.323 -> �[0;31mE (7724) ESP_ZIGBEE_CORE: In BDB commissioning, an error occurred (for example: the device has already been running)�[0m
14:07:52.371 -> Started in 1836 mS
14:07:52.371 -> Connecting to network
14:07:52.371 ->
14:07:52.371 -> Successfully connected to Zigbee network in 0 mS
14:07:53.333 -> Check for Button
14:07:53.333 -> Measure
14:07:53.333 -> Report
14:07:53.333 -> Reported 1, temperature: 45.50°C, Humidity: 0.00%
14:07:53.549 -> Going to sleep now
14:08:08.525 -> Cycle: 816 Restart: 5
14:08:08.525 -> Starting Zigbee
14:08:08.883 -> Started in 320 mS
14:08:08.883 -> Connecting to network
14:08:08.883 ->
14:08:08.883 -> Successfully connected to Zigbee network in 0 mS
14:08:09.850 -> Check for Button
14:08:09.850 -> Measure
14:08:09.888 -> Report
14:08:09.888 -> Reported 1, temperature: 46.00°C, Humidity: 0.00%
14:08:10.062 -> Going to sleep now
14:08:25.085 -> Cycle: 817 Restart: 5
14:08:25.085 -> Starting Zigbee
14:08:26.123 -> Started in 1057 mS
14:08:26.123 -> Connecting to network
14:08:26.123 ->
14:08:26.123 -> Successfully connected to Zigbee network in 0 mS
14:08:27.129 -> Check for Button
14:08:27.129 -> Measure
14:08:27.129 -> Report
14:08:27.129 -> Reported 1, temperature: 46.50°C, Humidity: 0.00%
14:08:27.358 -> Going to sleep now
14:08:42.352 -> Cycle: 818 Restart: 5
14:08:42.352 -> Starting Zigbee
14:08:47.395 -> [ 10047][E][ZigbeeCore.cpp:51] begin(): ZigbeeCore begin failed or timeout ####
14:08:47.395 -> Zigbee failed to start!
14:08:47.395 -> Going to sleep now for 30 seconds
14:09:22.279 -> Cycle: 819 Restart: 5
14:09:22.279 -> Starting Zigbee
14:09:27.336 -> [ 10047][E][ZigbeeCore.cpp:51] begin(): ZigbeeCore begin failed or timeout ####
14:09:27.336 -> Zigbee failed to start!
14:09:27.336 -> Going to sleep now for 30 seconds
14:10:02.203 -> Cycle: 820 Restart: 5
14:10:02.203 -> Starting Zigbee
14:10:04.717 -> Started in 2518 mS
14:10:04.717 -> Connecting to network
14:10:04.717 ->
14:10:04.717 -> Successfully connected to Zigbee network in 0 mS
14:10:05.703 -> Check for Button
14:10:05.703 -> Measure
14:10:05.703 -> Report
14:10:05.703 -> Reported 1, temperature: 47.00°C, Humidity: 0.00%
14:10:05.925 -> Going to sleep now
14:10:20.885 -> Cycle: 821 Restart: 5
14:10:20.928 -> Starting Zigbee
14:10:21.224 -> Started in 313 mS
14:10:21.224 -> Connecting to network
14:10:21.224 ->
14:10:21.224 -> Successfully connected to Zigbee network in 0 mS
14:10:22.245 -> Check for Button
14:10:22.245 -> Measure
14:10:22.245 -> Report
14:10:22.245 -> Reported 1, temperature: 47.50°C, Humidity: 0.00%
14:10:22.439 -> Going to sleep now
``
A similar-looking graphical view of data loss

Image

During a three hour run there were two occurences

Image

@P-R-O-C-H-Y
Copy link
Member

P-R-O-C-H-Y commented Apr 10, 2025

I cannot see the reason of failure which is described in the issue header. But in this last log you send, it seems that the Zigbee does not want to start. Are you using Zigbee debug libs for EndDevice or normal once? If not, can you please use the ones with Debug, so maybe we can have more logs.

But overall, 2 failures during 3 hours of reporting every 30s, its approx 0,5% mistake. Which to be honest is not bad.

@def1149
Copy link
Author

def1149 commented Apr 10, 2025

There may be multiple causes for a failure to report. My strategy will shift from trying to identify and correct the cause to detecting and recovering as best I can. It's likely that any H/W, library, or my code issues will be sorted out over time. Thanks

@def1149 def1149 closed this as completed Apr 10, 2025
@def1149 def1149 reopened this Apr 10, 2025
@def1149
Copy link
Author

def1149 commented Apr 10, 2025

@P-R-O-C-H-Y After running more tests and spending time digging through the ZHA debug log I have three instances where no errors were produced in the EP application but three datapoints in a row were missed in Home Assistant. The missing values are not in the ZHA log.

The test app ( based on the sleepy temperature sensor example) is sending temperature values about every 16 seconds.
These values are artificially created starting at -30 and continuing up to 80 by adding 0,5 for each cycle. I do this because Home Assistant will not record duplicates received sequentially. A temperature sensor chip could produce duplicate values. And I chart the received in HA so missing values are easy to spot. See previous entries in this case. The ZHA logs are very detailed and I don't understand most of it, but did find data from my device Nwk ID x0544.

I've attached an annotated ZHA debug log using >>>> to mark the start of key entries

At about 15:23:05 in the log is an entry that starts a series of records for temperature value 59.5
The next reported temperature value occurs starting at about 15:24:08 with a value 61.5.
Reports for values 60.0, 60.5, and 61.0 are missing

I expect that wireless protocols will experience data loss, it but as far as I understand it Zigbee uses a protocol that uses ACKS to confirm receipt of data, so I would expect an error to be signaled on the EP if it doesn't get an ACK from the coordinator.

m4152305.log

@def1149
Copy link
Author

def1149 commented Apr 13, 2025

After a lot of tweaking of EP code for my ESP32-C6 Zigbee temperature sensor to detect and capture problems at key points (to minimize any logging impact), and sending log data via serial to separate ESP32 with an SD card. I've found three categories of data missing in HA.

  1. HA does not record successive duplicate values. When this happens, I see the last seen date/time update.
  2. Occasionally the EP fails to connect. I added intelligent retries with retry interval backoff to not flood the air with messages to prevent message storms.
  3. The EP thinks it delivered the data, but it's missing in HA and there's no trace of the transaction in the ZHA debug logs, or there's signs of some kind error but the EP did not see an error. Not much I can do to investigate this with my minimal Zigbee stack and ZHA knowledge.

The occasional glitching when the C6 wakes up from deep sleep appears to be due to something that happens in the startup code when Verbose logging is enabled. I didn't see it when log level was reduced to Error.

At this point, I can create reliable enough Zigbee/ZHA sensors using the ESP32- C6/H2 so I'm replacing my power hungry Wi-Fi sensors and MQTT.

@def1149 def1149 closed this as completed Apr 13, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Area: Zigbee Issues and Feature Request about Zigbee Status: Awaiting triage Issue is waiting for triage
Projects
None yet
Development

No branches or pull requests

4 participants