diff --git a/esphome/components/zigbee_proxy/__init__.py b/esphome/components/zigbee_proxy/__init__.py index 310781e73b..2ba4cbc6ed 100644 --- a/esphome/components/zigbee_proxy/__init__.py +++ b/esphome/components/zigbee_proxy/__init__.py @@ -1,5 +1,5 @@ import esphome.codegen as cg -from esphome.components import uart +from esphome.components import uart, usb_uart import esphome.config_validation as cv from esphome.const import CONF_ID, CONF_POWER_SAVE_MODE, CONF_WIFI import esphome.final_validate as fv @@ -11,6 +11,17 @@ CONF_BUFFER_SIZE = "buffer_size" CONF_INITIAL_TIMEOUT = "initial_timeout" CONF_MIN_TIMEOUT = "min_timeout" CONF_MAX_TIMEOUT = "max_timeout" +CONF_USB_UART_ID = "usb_uart_id" + +# Default ACK timeout values calibrated for hardware UART (460800 baud, ~2-5 ms round-trip) +_DEFAULT_HW_INITIAL_TIMEOUT = 1600 +_DEFAULT_HW_MIN_TIMEOUT = 400 +_DEFAULT_HW_MAX_TIMEOUT = 3200 + +# Optimized ACK timeout values for USB CDC ACM paths (~20-30 ms round-trip) +_DEFAULT_USB_INITIAL_TIMEOUT = 200 +_DEFAULT_USB_MIN_TIMEOUT = 50 +_DEFAULT_USB_MAX_TIMEOUT = 500 zigbee_proxy_ns = cg.esphome_ns.namespace("zigbee_proxy") ZigbeeProxy = zigbee_proxy_ns.class_("ZigbeeProxy", cg.Component, uart.UARTDevice) @@ -36,13 +47,13 @@ CONFIG_SCHEMA = cv.All( esp8266=512, default=1024, ), - cv.Optional(CONF_INITIAL_TIMEOUT, default=1600): cv.int_range( - min=100, max=10000 - ), - cv.Optional(CONF_MIN_TIMEOUT, default=400): cv.int_range(min=100, max=5000), - cv.Optional(CONF_MAX_TIMEOUT, default=3200): cv.int_range( - min=500, max=10000 - ), + # When usb_uart_id is present the component selects USB-optimized ACK + # timeout defaults (~20-30 ms round-trip) instead of the hardware UART + # defaults (~2-5 ms round-trip). Explicit timeout keys always win. + cv.Optional(CONF_USB_UART_ID): cv.use_id(usb_uart.USBUartChannel), + cv.Optional(CONF_INITIAL_TIMEOUT): cv.int_range(min=100, max=10000), + cv.Optional(CONF_MIN_TIMEOUT): cv.int_range(min=100, max=5000), + cv.Optional(CONF_MAX_TIMEOUT): cv.int_range(min=500, max=10000), } ) .extend(cv.COMPONENT_SCHEMA) @@ -59,11 +70,31 @@ async def to_code(config): cg.add_define("USE_ZIGBEE_PROXY") + # Request UART to wake the main loop when data arrives for low-latency processing + uart.request_wake_loop_on_rx() + # Set buffer size via define for compile-time allocation if CONF_BUFFER_SIZE in config: cg.add_define("ZIGBEE_PROXY_BUFFER_SIZE", config[CONF_BUFFER_SIZE]) - # Set timeout values - cg.add(var.set_initial_timeout(config[CONF_INITIAL_TIMEOUT])) - cg.add(var.set_min_timeout(config[CONF_MIN_TIMEOUT])) - cg.add(var.set_max_timeout(config[CONF_MAX_TIMEOUT])) + # Select timeout defaults based on UART transport type. + # USB CDC ACM has higher round-trip latency (~20-30 ms) than hardware UART + # (~2-5 ms), so the adaptive ACK timeout algorithm needs different starting + # points to avoid unnecessary stalls at boot. + is_usb = CONF_USB_UART_ID in config + initial_timeout = config.get( + CONF_INITIAL_TIMEOUT, + _DEFAULT_USB_INITIAL_TIMEOUT if is_usb else _DEFAULT_HW_INITIAL_TIMEOUT, + ) + min_timeout = config.get( + CONF_MIN_TIMEOUT, + _DEFAULT_USB_MIN_TIMEOUT if is_usb else _DEFAULT_HW_MIN_TIMEOUT, + ) + max_timeout = config.get( + CONF_MAX_TIMEOUT, + _DEFAULT_USB_MAX_TIMEOUT if is_usb else _DEFAULT_HW_MAX_TIMEOUT, + ) + + cg.add(var.set_initial_timeout(initial_timeout)) + cg.add(var.set_min_timeout(min_timeout)) + cg.add(var.set_max_timeout(max_timeout)) diff --git a/esphome/components/zigbee_proxy/ash_protocol.cpp b/esphome/components/zigbee_proxy/ash_protocol.cpp index f49b4eeeda..46752ea385 100644 --- a/esphome/components/zigbee_proxy/ash_protocol.cpp +++ b/esphome/components/zigbee_proxy/ash_protocol.cpp @@ -5,8 +5,7 @@ #include "esphome/core/log.h" #include "esphome/core/helpers.h" -namespace esphome { -namespace zigbee_proxy { +namespace esphome::zigbee_proxy { static const char *const TAG = "zigbee_proxy"; @@ -128,7 +127,7 @@ void ZigbeeProxy::parse_control_byte_(uint8_t control) { uint32_t rtt = millis() - this->ack_timer_start_; this->update_adaptive_timeout_(rtt); this->clear_tx_buffer_(); - ESP_LOGD(TAG, "ACK received (piggybacked in DATA), RTT: %u ms", rtt); + ESP_LOGV(TAG, "ACK received (piggybacked in DATA), RTT: %u ms", rtt); } // Increment RX sequence and send ACK (ack_num = next expected frame) @@ -157,7 +156,7 @@ void ZigbeeProxy::parse_control_byte_(uint8_t control) { uint32_t rtt = millis() - this->ack_timer_start_; this->update_adaptive_timeout_(rtt); this->clear_tx_buffer_(); - ESP_LOGD(TAG, "ACK received for frame %d, RTT: %u ms", this->tx_pending_frame_num_, rtt); + ESP_LOGV(TAG, "ACK received for frame %d, RTT: %u ms", this->tx_pending_frame_num_, rtt); } break; @@ -347,8 +346,8 @@ size_t ZigbeeProxy::build_frame_(uint8_t *output, const uint8_t *data, size_t le } // Add control byte with stuffing (reserved: FLAG, ESCAPE, XON, XOFF, SUB, CAN) - if (control == ASH_FLAG_BYTE || control == ASH_ESCAPE_BYTE || control == 0x11 || control == 0x13 || - control == 0x18 || control == 0x1A) { + if (control == ASH_FLAG_BYTE || control == ASH_ESCAPE_BYTE || control == 0x11 || control == 0x13 || control == 0x18 || + control == 0x1A) { output[pos++] = ASH_ESCAPE_BYTE; output[pos++] = control ^ ASH_XOR_BYTE; } else { @@ -365,8 +364,8 @@ size_t ZigbeeProxy::build_frame_(uint8_t *output, const uint8_t *data, size_t le // Add data payload with stuffing for (size_t i = 0; i < length; i++) { uint8_t byte = data[i]; - if (byte == ASH_FLAG_BYTE || byte == ASH_ESCAPE_BYTE || byte == 0x11 || byte == 0x13 || - byte == 0x18 || byte == 0x1A) { + if (byte == ASH_FLAG_BYTE || byte == ASH_ESCAPE_BYTE || byte == 0x11 || byte == 0x13 || byte == 0x18 || + byte == 0x1A) { output[pos++] = ASH_ESCAPE_BYTE; output[pos++] = byte ^ ASH_XOR_BYTE; } else { @@ -389,8 +388,8 @@ size_t ZigbeeProxy::build_frame_(uint8_t *output, const uint8_t *data, size_t le output[pos++] = crc_high; } - if (crc_low == ASH_FLAG_BYTE || crc_low == ASH_ESCAPE_BYTE || crc_low == 0x11 || crc_low == 0x13 || - crc_low == 0x18 || crc_low == 0x1A) { + if (crc_low == ASH_FLAG_BYTE || crc_low == ASH_ESCAPE_BYTE || crc_low == 0x11 || crc_low == 0x13 || crc_low == 0x18 || + crc_low == 0x1A) { output[pos++] = ASH_ESCAPE_BYTE; output[pos++] = crc_low ^ ASH_XOR_BYTE; } else { @@ -403,7 +402,6 @@ size_t ZigbeeProxy::build_frame_(uint8_t *output, const uint8_t *data, size_t le return pos; } -} // namespace zigbee_proxy -} // namespace esphome +} // namespace esphome::zigbee_proxy #endif // USE_ZIGBEE_PROXY diff --git a/esphome/components/zigbee_proxy/ash_protocol.h b/esphome/components/zigbee_proxy/ash_protocol.h index 890ff2064a..8d7246eaa4 100644 --- a/esphome/components/zigbee_proxy/ash_protocol.h +++ b/esphome/components/zigbee_proxy/ash_protocol.h @@ -3,8 +3,7 @@ #include #include -namespace esphome { -namespace zigbee_proxy { +namespace esphome::zigbee_proxy { // ASH Protocol Constants static constexpr uint8_t ASH_FLAG_BYTE = 0x7E; // Frame delimiter @@ -86,5 +85,4 @@ enum class EzspError : uint8_t { EXCEEDED_MAXIMUM_ACK_TIMEOUT_COUNT = 0x51, }; -} // namespace zigbee_proxy -} // namespace esphome +} // namespace esphome::zigbee_proxy diff --git a/esphome/components/zigbee_proxy/ezsp_commands.h b/esphome/components/zigbee_proxy/ezsp_commands.h index 3131d0bad5..8d86c4c197 100644 --- a/esphome/components/zigbee_proxy/ezsp_commands.h +++ b/esphome/components/zigbee_proxy/ezsp_commands.h @@ -3,8 +3,7 @@ #include #include -namespace esphome { -namespace zigbee_proxy { +namespace esphome::zigbee_proxy { // EZSP Protocol Versions static constexpr uint8_t EZSP_MIN_VERSION = 8; // Minimum supported version @@ -54,5 +53,4 @@ static constexpr size_t NETWORK_PARAMS_EXT_PAN_ID_OFFSET = 2; static constexpr size_t NETWORK_PARAMS_PAN_ID_OFFSET = 10; static constexpr size_t NETWORK_PARAMS_CHANNEL_OFFSET = 13; -} // namespace zigbee_proxy -} // namespace esphome +} // namespace esphome::zigbee_proxy diff --git a/esphome/components/zigbee_proxy/zigbee_proxy.cpp b/esphome/components/zigbee_proxy/zigbee_proxy.cpp index a6636da030..ce31772ea3 100644 --- a/esphome/components/zigbee_proxy/zigbee_proxy.cpp +++ b/esphome/components/zigbee_proxy/zigbee_proxy.cpp @@ -11,8 +11,7 @@ #include "esphome/components/wifi/wifi_component.h" #endif -namespace esphome { -namespace zigbee_proxy { +namespace esphome::zigbee_proxy { static const char *const TAG = "zigbee_proxy"; @@ -44,8 +43,8 @@ void ZigbeeProxy::loop() { // Check for boot sequence timeout if (this->boot_sequence_active_) { - uint32_t elapsed = millis() - this->setup_time_; - if (elapsed > 10000) { // 10 second timeout for entire boot sequence + uint32_t total_elapsed = millis() - this->boot_start_time_; + if (total_elapsed > 10000) { // 10 second timeout for entire boot sequence ESP_LOGE(TAG, "Boot sequence timeout (state: %d)", static_cast(this->boot_state_)); this->boot_state_ = BootState::FAILED; this->boot_sequence_active_ = false; @@ -53,6 +52,11 @@ void ZigbeeProxy::loop() { if (this->ash_state_ != AshState::CONNECTED) { this->ash_state_ = AshState::FAILED; } + } else if (this->boot_state_ == BootState::WAIT_RSTACK && (millis() - this->setup_time_) > ASH_RESET_TIMEOUT) { + // RST was sent before USB device finished enumeration — retry + ESP_LOGD(TAG, "No RSTACK received within %u ms, retrying RST", ASH_RESET_TIMEOUT); + this->setup_time_ = millis(); + this->send_rst_frame_(); } } @@ -114,14 +118,14 @@ void ZigbeeProxy::zigbee_proxy_request(api::APIConnection *api_connection, const ESP_LOGW(TAG, "Another client is already subscribed"); return; } - ESP_LOGI(TAG, "Client subscribed"); + ESP_LOGD(TAG, "Client subscribed"); this->api_connection_ = api_connection; this->client_reset_session_(); break; case api::enums::ZIGBEE_PROXY_REQUEST_TYPE_UNSUBSCRIBE: if (this->api_connection_ == api_connection) { - ESP_LOGI(TAG, "Client unsubscribed"); + ESP_LOGD(TAG, "Client unsubscribed"); this->api_connection_ = nullptr; } break; @@ -177,12 +181,12 @@ void ZigbeeProxy::set_timeout_config(uint32_t initial_ms, uint32_t min_ms, uint3 this->timeout_config_.min_timeout_ms = min_ms; this->timeout_config_.max_timeout_ms = max_ms; this->timeout_config_.current_timeout_ms = initial_ms; - ESP_LOGI(TAG, "Timeout config updated: initial=%u, min=%u, max=%u", initial_ms, min_ms, max_ms); + ESP_LOGV(TAG, "Timeout config updated: initial=%u, min=%u, max=%u", initial_ms, min_ms, max_ms); } // ASH Protocol State Machine void ZigbeeProxy::reset_ash_protocol_() { - ESP_LOGI(TAG, "Resetting ASH protocol"); + ESP_LOGV(TAG, "Resetting ASH protocol"); this->ash_state_ = AshState::CONNECTING; this->tx_sequence_ = 0; this->rx_sequence_ = 0; @@ -190,6 +194,7 @@ void ZigbeeProxy::reset_ash_protocol_() { this->tx_retry_count_ = 0; this->parsing_state_ = ParsingState::WAIT_FLAG_START; this->setup_time_ = millis(); + this->boot_start_time_ = this->setup_time_; // Start boot sequence this->boot_state_ = BootState::WAIT_RSTACK; @@ -200,28 +205,20 @@ void ZigbeeProxy::reset_ash_protocol_() { } void ZigbeeProxy::send_rst_frame_() { - // Send CANCEL bytes (0x1A) to clear NCP's receive buffer before RST - // This is required by ASH protocol to ensure NCP ignores any partial frames - // Note: 0x1A is ASH_CAN (cancel), NOT 0x18 which is ASH_SUB (substitute) + // Build a combined buffer: 32 CAN bytes followed immediately by the RST frame, + // sent as a single write_array call. This ensures correct byte ordering and + // minimizes the number of USB bulk transfers (all bytes fit in one USB FS packet). static constexpr uint8_t ASH_CAN_BYTE = 0x1A; - for (int i = 0; i < 32; i++) { - this->write_byte(ASH_CAN_BYTE); - } + static constexpr size_t CAN_COUNT = 32; + static constexpr size_t MAX_RST_FRAME_SIZE = 8; + uint8_t combined[CAN_COUNT + MAX_RST_FRAME_SIZE]; + memset(combined, ASH_CAN_BYTE, CAN_COUNT); + size_t rst_len = this->build_frame_(combined + CAN_COUNT, nullptr, 0, AshFrameType::RST); + + ESP_LOGV(TAG, "RST frame bytes (%u): %s", rst_len, format_hex_pretty(combined + CAN_COUNT, rst_len).c_str()); + this->write_array(combined, CAN_COUNT + rst_len); this->flush(); - - // Small delay to allow NCP to process CANCEL bytes - delay(10); - - // Now send the RST frame - uint8_t frame[8]; - size_t length = this->build_frame_(frame, nullptr, 0, AshFrameType::RST); - - // Debug: log exact bytes being sent - ESP_LOGV(TAG, "RST frame bytes (%u): %s", length, format_hex_pretty(frame, length).c_str()); - - this->write_array(frame, length); - this->flush(); - ESP_LOGD(TAG, "Sent RST frame (with 32 CAN bytes prefix)"); + ESP_LOGV(TAG, "Sent RST frame (with %u CAN bytes prefix)", CAN_COUNT); } void ZigbeeProxy::handle_rstack_frame_(const uint8_t *data, size_t length) { @@ -232,24 +229,27 @@ void ZigbeeProxy::handle_rstack_frame_(const uint8_t *data, size_t length) { if (this->boot_state_ == BootState::WAIT_RSTACK) { // Initial RSTACK - start boot sequence - ESP_LOGI(TAG, "Received RSTACK, starting EZSP initialization"); + ESP_LOGV(TAG, "Received RSTACK, starting EZSP initialization"); this->ash_state_ = AshState::CONNECTED; - // Small delay to let NCP settle and clear any pending data - delay(50); - - // Drain any garbage bytes from UART buffer - while (this->available()) { - uint8_t byte; - this->read_byte(&byte); - ESP_LOGV(TAG, "Draining post-RSTACK byte: 0x%02X", byte); + // Non-blocking drain: give the NCP 10 ms to settle and flush any stale bytes. + // yield() lets the USB task deliver buffered bytes into the ring buffer so they + // can be consumed here rather than contaminating the next EZSP exchange. + uint32_t drain_deadline = millis() + 10; + while (millis() < drain_deadline) { + while (this->available()) { + uint8_t discard; + this->read_byte(&discard); + ESP_LOGV(TAG, "Draining post-RSTACK byte: 0x%02X", discard); + } + yield(); } this->boot_state_ = BootState::SEND_VERSION; this->advance_boot_state_(); } else if (this->boot_state_ == BootState::WAIT_FINAL_RSTACK) { // Final RSTACK after harvesting - boot complete - ESP_LOGI(TAG, "Boot sequence complete, NCP reset to clean state"); + ESP_LOGV(TAG, "Boot sequence complete, NCP reset to clean state"); this->ash_state_ = AshState::CONNECTED; this->boot_state_ = BootState::COMPLETE; this->boot_sequence_active_ = false; @@ -258,7 +258,7 @@ void ZigbeeProxy::handle_rstack_frame_(const uint8_t *data, size_t length) { this->check_wifi_zigbee_conflict_(); } else if (this->ash_state_ == AshState::CONNECTING) { // RSTACK during connecting (triggered by client RST forwarding) - ESP_LOGI(TAG, "Received RSTACK, NCP ready"); + ESP_LOGV(TAG, "Received RSTACK, NCP ready"); this->ash_state_ = AshState::CONNECTED; // Forward to client if subscribed if (this->api_connection_ != nullptr) { @@ -266,7 +266,7 @@ void ZigbeeProxy::handle_rstack_frame_(const uint8_t *data, size_t length) { } } else if (this->api_connection_ != nullptr) { // Client is subscribed, forward RSTACK - ESP_LOGI(TAG, "Forwarding RSTACK to client"); + ESP_LOGV(TAG, "Forwarding RSTACK to client"); this->ash_state_ = AshState::CONNECTED; this->forward_ncp_rstack_to_client_(this->rx_buffer_.data() + 1, this->rx_buffer_index_ - 3); } else { @@ -276,7 +276,7 @@ void ZigbeeProxy::handle_rstack_frame_(const uint8_t *data, size_t length) { void ZigbeeProxy::handle_error_frame_(const uint8_t *data, size_t length) { if (length < 1) { - ESP_LOGE(TAG, "ERROR frame too short"); + ESP_LOGE(TAG, "Frame too short"); return; } @@ -313,14 +313,14 @@ void ZigbeeProxy::handle_error_frame_(const uint8_t *data, size_t length) { break; } - ESP_LOGE(TAG, "NCP ERROR: %s (0x%02X)", error_str, error_code); + ESP_LOGE(TAG, "NCP error: %s (0x%02X)", error_str, error_code); if (this->api_connection_ != nullptr) { // Forward error to client this->forward_ncp_error_to_client_(data, length); } else { // No client, attempt recovery ourselves - ESP_LOGI(TAG, "Attempting recovery..."); + ESP_LOGV(TAG, "Attempting recovery"); this->reset_ash_protocol_(); } } @@ -420,7 +420,7 @@ void ZigbeeProxy::handle_retransmission_() { this->tx_retry_count_++; if (this->tx_retry_count_ > ASH_MAX_RETRIES) { - ESP_LOGE(TAG, "Max retries exceeded, entering FAILED state"); + ESP_LOGE(TAG, "Max retries exceeded"); this->ash_state_ = AshState::FAILED; this->clear_tx_buffer_(); return; @@ -439,7 +439,7 @@ void ZigbeeProxy::handle_retransmission_() { // Sequence: RST -> RSTACK -> version() -> networkInit() -> stackStatus -> getNetworkParameters() -> RST -> RSTACK void ZigbeeProxy::start_boot_sequence_() { - ESP_LOGI(TAG, "Starting boot sequence to harvest network info"); + ESP_LOGV(TAG, "Starting boot sequence to harvest network info"); this->boot_state_ = BootState::WAIT_RSTACK; this->boot_sequence_active_ = true; this->ezsp_sequence_ = 0; @@ -464,7 +464,7 @@ void ZigbeeProxy::advance_boot_state_() { break; case BootState::SEND_FINAL_RST: - ESP_LOGI(TAG, "Sending final RST to reset NCP to clean state"); + ESP_LOGV(TAG, "Sending final RST to reset NCP to clean state"); this->boot_state_ = BootState::WAIT_FINAL_RSTACK; this->send_rst_frame_(); break; @@ -531,10 +531,10 @@ void ZigbeeProxy::handle_boot_data_frame_(const uint8_t *data, size_t length) { // Some NCPs proceed directly without stackStatusHandler callback if (payload_length >= 1) { uint8_t status = payload[0]; - ESP_LOGD(TAG, "networkInit response: status=0x%02X", status); + ESP_LOGV(TAG, "networkInit response: status=0x%02X", status); // Proceed to getNetworkParameters regardless of status // getNetworkParameters will tell us if there's actually a network - ESP_LOGI(TAG, "networkInit complete, querying network parameters"); + ESP_LOGV(TAG, "networkInit complete, querying network parameters"); this->boot_state_ = BootState::SEND_GET_NETWORK_PARAMS; this->advance_boot_state_(); } @@ -564,7 +564,7 @@ void ZigbeeProxy::send_ezsp_version_() { EZSP_MAX_VERSION // Desired protocol version }; - ESP_LOGD(TAG, "Sending EZSP version command (legacy format, requesting v%d)", EZSP_MAX_VERSION); + ESP_LOGV(TAG, "Sending EZSP version command (legacy format, requesting v%d)", EZSP_MAX_VERSION); this->send_data_frame_(cmd, sizeof(cmd), false); } @@ -579,7 +579,7 @@ void ZigbeeProxy::send_network_init_() { EZSP_NETWORK_INIT & 0xFF, // Frame ID 0x00, 0x00 // networkInitStruct bitmask (default) }; - ESP_LOGD(TAG, "Sending EZSP networkInit command (legacy format)"); + ESP_LOGV(TAG, "Sending EZSP networkInit command (legacy format)"); this->send_data_frame_(cmd, sizeof(cmd), false); } @@ -590,7 +590,7 @@ void ZigbeeProxy::send_get_network_params_() { EZSP_FRAME_CONTROL_COMMAND, // Frame control EZSP_GET_NETWORK_PARAMETERS & 0xFF // Frame ID }; - ESP_LOGD(TAG, "Sending EZSP getNetworkParameters command (legacy format)"); + ESP_LOGV(TAG, "Sending EZSP getNetworkParameters command (legacy format)"); this->send_data_frame_(cmd, sizeof(cmd), false); } @@ -618,7 +618,7 @@ void ZigbeeProxy::handle_version_response_(const uint8_t *data, size_t length) { if (ncp_version == this->ezsp_requested_version_) { // NCP accepted our requested version - treat as success - ESP_LOGI(TAG, "NCP accepted EZSP v%d", ncp_version); + ESP_LOGV(TAG, "NCP accepted EZSP v%d", ncp_version); this->ezsp_version_ = ncp_version; // Proceed to networkInit this->boot_state_ = BootState::SEND_NETWORK_INIT; @@ -627,7 +627,7 @@ void ZigbeeProxy::handle_version_response_(const uint8_t *data, size_t length) { } // NCP doesn't support our version - re-negotiate - ESP_LOGI(TAG, "NCP supports EZSP v%d, re-negotiating", ncp_version); + ESP_LOGV(TAG, "NCP supports EZSP v%d, re-negotiating", ncp_version); this->ezsp_requested_version_ = ncp_version; // Re-send version command with NCP's supported version @@ -638,7 +638,7 @@ void ZigbeeProxy::handle_version_response_(const uint8_t *data, size_t length) { 0x00, // Frame ID (version) ncp_version // Use NCP's version }; - ESP_LOGD(TAG, "Re-sending EZSP version command (requesting v%d)", ncp_version); + ESP_LOGV(TAG, "Re-sending EZSP version command (requesting v%d)", ncp_version); this->send_data_frame_(cmd, sizeof(cmd), false); // Stay in WAIT_VERSION state return; @@ -655,7 +655,7 @@ void ZigbeeProxy::handle_version_response_(const uint8_t *data, size_t length) { uint8_t stack_type = data[1]; uint16_t stack_version = data[2] | (static_cast(data[3]) << 8); - ESP_LOGI(TAG, "NCP EZSP version: %d, stack type: %d, stack version: 0x%04X", this->ezsp_version_, stack_type, + ESP_LOGD(TAG, "NCP EZSP version: %d, stack type: %d, stack version: 0x%04X", this->ezsp_version_, stack_type, stack_version); if (this->ezsp_version_ < EZSP_MIN_VERSION) { @@ -677,16 +677,16 @@ void ZigbeeProxy::handle_stack_status_(const uint8_t *data, size_t length) { } uint8_t status = data[0]; - ESP_LOGD(TAG, "Stack status: 0x%02X", status); + ESP_LOGV(TAG, "Stack status: 0x%02X", status); // Check for network up status if (status == static_cast(EmberStatus::NETWORK_UP) || status == static_cast(EmberStatus::SUCCESS)) { - ESP_LOGI(TAG, "Network is up, querying parameters"); + ESP_LOGV(TAG, "Network is up, querying parameters"); this->boot_state_ = BootState::SEND_GET_NETWORK_PARAMS; this->advance_boot_state_(); } else if (status == static_cast(EmberStatus::NOT_JOINED)) { // No network configured - that's fine, we just won't have network info - ESP_LOGI(TAG, "No network configured on NCP"); + ESP_LOGD(TAG, "No network configured on NCP"); this->boot_state_ = BootState::SEND_FINAL_RST; this->advance_boot_state_(); } else { @@ -700,8 +700,13 @@ void ZigbeeProxy::handle_stack_status_(const uint8_t *data, size_t length) { void ZigbeeProxy::handle_network_params_response_(const uint8_t *data, size_t length) { // getNetworkParameters response: // [status] [nodeType] [extendedPanId (8)] [panId (2)] [radioTxPower] [radioChannel] ... + // A 1-byte response (status only) is normal when the NCP has no network configured. if (length < 14) { - ESP_LOGW(TAG, "Network params response too short: %u bytes", length); + if (length == 1) { + ESP_LOGD(TAG, "NCP has no network configured (status=0x%02X)", data[0]); + } else { + ESP_LOGW(TAG, "getNetworkParameters response unexpected length: %u bytes", length); + } this->boot_state_ = BootState::SEND_FINAL_RST; this->advance_boot_state_(); return; @@ -727,8 +732,8 @@ void ZigbeeProxy::handle_network_params_response_(const uint8_t *data, size_t le this->network_info_.valid = true; - ESP_LOGI(TAG, - "Network info harvested:\n" + ESP_LOGD(TAG, + "Network info:\n" " Extended PAN ID: %02X%02X%02X%02X%02X%02X%02X%02X\n" " PAN ID: 0x%04X\n" " Channel: %u", @@ -756,7 +761,7 @@ bool ZigbeeProxy::set_ieee_address_(const uint8_t *new_address) { if (changed) { memcpy(this->network_info_.ieee_address.data(), new_address, ZIGBEE_IEEE_ADDR_SIZE); this->network_info_.valid = true; - ESP_LOGI(TAG, "IEEE address updated: %02X:%02X:%02X:%02X:%02X:%02X:%02X:%02X", new_address[7], new_address[6], + ESP_LOGD(TAG, "IEEE address updated: %02X:%02X:%02X:%02X:%02X:%02X:%02X:%02X", new_address[7], new_address[6], new_address[5], new_address[4], new_address[3], new_address[2], new_address[1], new_address[0]); this->send_network_info_changed_msg_(); return true; @@ -768,7 +773,7 @@ bool ZigbeeProxy::set_ieee_address_(const uint8_t *new_address) { void ZigbeeProxy::send_network_info_changed_msg_(api::APIConnection *conn) { // This would send network info to the API client // For now, we'll log it - ESP_LOGD(TAG, "Network info changed notification"); + ESP_LOGV(TAG, "Network info changed notification"); } // WiFi/Zigbee channel conflict detection @@ -822,7 +827,7 @@ void ZigbeeProxy::check_wifi_zigbee_conflict_() { " Recommendation: %s", wifi_channel, zigbee_channel, recommendation); } else { - ESP_LOGI(TAG, "No WiFi/Zigbee channel conflict (WiFi: %u, Zigbee: %u)", wifi_channel, zigbee_channel); + ESP_LOGV(TAG, "No WiFi/Zigbee channel conflict (WiFi: %u, Zigbee: %u)", wifi_channel, zigbee_channel); } #endif } @@ -854,7 +859,7 @@ void ZigbeeProxy::check_bootloader_mode_(const uint8_t *data, size_t length) { // Reset bootloader state if we see normal traffic if (this->bootloader_state_ != BootloaderState::NORMAL && this->ash_state_ == AshState::CONNECTED) { - ESP_LOGI(TAG, "NCP returned to normal operation"); + ESP_LOGV(TAG, "NCP returned to normal operation"); this->bootloader_state_ = BootloaderState::NORMAL; } } @@ -881,7 +886,7 @@ void ZigbeeProxy::client_reset_session_() { this->client_escape_next_byte_ = false; this->client_ash_state_ = AshState::DISCONNECTED; this->client_parsing_state_ = ParsingState::WAIT_FLAG_START; - ESP_LOGD(TAG, "Client ASH session reset"); + ESP_LOGV(TAG, "Client ASH session reset"); } void ZigbeeProxy::send_to_client_(const uint8_t *data, size_t length) { @@ -893,9 +898,7 @@ void ZigbeeProxy::send_to_client_(const uint8_t *data, size_t length) { this->api_connection_->send_zigbee_proxy_frame(this->outgoing_proto_msg_); } -void ZigbeeProxy::client_send_raw_frame_(const uint8_t *frame, size_t length) { - this->send_to_client_(frame, length); -} +void ZigbeeProxy::client_send_raw_frame_(const uint8_t *frame, size_t length) { this->send_to_client_(frame, length); } void ZigbeeProxy::client_send_ack_frame_(uint8_t ack_num) { uint8_t frame[8]; @@ -910,13 +913,13 @@ void ZigbeeProxy::client_send_rstack_frame_(uint8_t reset_code) { uint8_t frame[16]; size_t length = this->build_frame_(frame, payload, sizeof(payload), AshFrameType::RSTACK); this->client_send_raw_frame_(frame, length); - ESP_LOGD(TAG, "Sent client RSTACK (code=0x%02X)", reset_code); + ESP_LOGV(TAG, "Sent client RSTACK (code=0x%02X)", reset_code); } void ZigbeeProxy::client_send_data_frame_(const uint8_t *data, size_t length) { uint8_t frame[MAX_ASH_FRAME_SIZE]; - size_t frame_length = this->build_frame_(frame, data, length, AshFrameType::DATA, - this->client_tx_sequence_, this->client_rx_sequence_); + size_t frame_length = + this->build_frame_(frame, data, length, AshFrameType::DATA, this->client_tx_sequence_, this->client_rx_sequence_); this->client_tx_sequence_ = (this->client_tx_sequence_ + 1) & ASH_MAX_SEQUENCE; this->client_send_raw_frame_(frame, frame_length); ESP_LOGV(TAG, "Sent client DATA frame, payload %u bytes", length); @@ -927,7 +930,7 @@ void ZigbeeProxy::client_send_error_frame_(uint8_t error_code) { uint8_t frame[16]; size_t length = this->build_frame_(frame, payload, sizeof(payload), AshFrameType::ERROR); this->client_send_raw_frame_(frame, length); - ESP_LOGD(TAG, "Sent client ERROR (code=0x%02X)", error_code); + ESP_LOGV(TAG, "Sent client ERROR (code=0x%02X)", error_code); } void ZigbeeProxy::forward_ncp_data_to_client_(const uint8_t *payload, size_t length) { @@ -944,14 +947,14 @@ void ZigbeeProxy::forward_ncp_rstack_to_client_(const uint8_t *data, size_t leng this->client_tx_sequence_ = 0; this->client_rx_sequence_ = 0; this->client_ash_state_ = AshState::CONNECTED; - ESP_LOGD(TAG, "Forwarded RSTACK to client"); + ESP_LOGV(TAG, "Forwarded RSTACK to client"); } void ZigbeeProxy::forward_ncp_error_to_client_(const uint8_t *data, size_t length) { uint8_t frame[16]; size_t frame_length = this->build_frame_(frame, data, length, AshFrameType::ERROR); this->client_send_raw_frame_(frame, frame_length); - ESP_LOGD(TAG, "Forwarded ERROR to client"); + ESP_LOGV(TAG, "Forwarded ERROR to client"); } void ZigbeeProxy::client_parse_byte_(uint8_t byte) { @@ -1105,8 +1108,9 @@ void ZigbeeProxy::client_parse_control_byte_(uint8_t control) { case AshFrameType::RST: // Client wants to reset - forward RST to NCP // Don't use reset_ash_protocol_() as that enters boot sequence - ESP_LOGI(TAG, "Client RST → forwarding to NCP"); + ESP_LOGV(TAG, "Client RST → forwarding to NCP"); this->ash_state_ = AshState::CONNECTING; + this->setup_time_ = millis(); // Reset timeout reference for RSTACK wait this->tx_sequence_ = 0; this->rx_sequence_ = 0; this->tx_buffer_pending_ = false; @@ -1128,7 +1132,6 @@ void ZigbeeProxy::client_parse_control_byte_(uint8_t control) { } } -} // namespace zigbee_proxy -} // namespace esphome +} // namespace esphome::zigbee_proxy #endif // USE_ZIGBEE_PROXY diff --git a/esphome/components/zigbee_proxy/zigbee_proxy.h b/esphome/components/zigbee_proxy/zigbee_proxy.h index 638ec9e98c..b4193aaca3 100644 --- a/esphome/components/zigbee_proxy/zigbee_proxy.h +++ b/esphome/components/zigbee_proxy/zigbee_proxy.h @@ -12,8 +12,7 @@ #include -namespace esphome { -namespace zigbee_proxy { +namespace esphome::zigbee_proxy { // Timeout configuration structure struct TimeoutConfig { @@ -183,7 +182,8 @@ class ZigbeeProxy : public uart::UARTDevice, public Component { api::APIConnection *api_connection_{nullptr}; // Current subscribed client // NCP-side (right) 32-bit values - uint32_t setup_time_{0}; // Time when setup() was called + uint32_t setup_time_{0}; // Time when last RST frame was sent + uint32_t boot_start_time_{0}; // Time when the boot sequence began (for overall timeout) uint32_t ack_timer_start_{0}; // Time when ACK timer started uint32_t last_rtt_ms_{0}; // Last measured round-trip time @@ -203,8 +203,8 @@ class ZigbeeProxy : public uart::UARTDevice, public Component { uint8_t last_ack_sent_{0}; // Last ACK number sent // Client-side (left) 8-bit values - uint8_t client_tx_sequence_{0}; // Client-facing TX sequence (proxy → client) - uint8_t client_rx_sequence_{0}; // Client-facing RX sequence (client → proxy) + uint8_t client_tx_sequence_{0}; // Client-facing TX sequence (proxy → client) + uint8_t client_rx_sequence_{0}; // Client-facing RX sequence (client → proxy) // NCP-side enums and booleans AshState ash_state_{AshState::DISCONNECTED}; @@ -220,16 +220,15 @@ class ZigbeeProxy : public uart::UARTDevice, public Component { uint8_t ezsp_sequence_{0}; // EZSP frame sequence number uint8_t ezsp_requested_version_{0}; // Version we last requested (for re-negotiation) - bool tx_buffer_pending_{false}; // True if waiting for ACK from NCP - bool escape_next_byte_{false}; // True if next NCP byte should be unescaped - bool client_escape_next_byte_{false}; // True if next client byte should be unescaped - bool network_info_ready_{false}; // True when network info retrieved - bool boot_sequence_active_{false}; // True during boot-time init + bool tx_buffer_pending_{false}; // True if waiting for ACK from NCP + bool escape_next_byte_{false}; // True if next NCP byte should be unescaped + bool client_escape_next_byte_{false}; // True if next client byte should be unescaped + bool network_info_ready_{false}; // True when network info retrieved + bool boot_sequence_active_{false}; // True during boot-time init }; extern ZigbeeProxy *global_zigbee_proxy; // NOLINT(cppcoreguidelines-avoid-non-const-global-variables) -} // namespace zigbee_proxy -} // namespace esphome +} // namespace esphome::zigbee_proxy #endif // USE_ZIGBEE_PROXY