From 6d82ccae3e8ef32190658ba40d4bb9b0e83a2968 Mon Sep 17 00:00:00 2001 From: admin Date: Mon, 2 Mar 2026 03:26:03 +0800 Subject: [PATCH] chore(logging): trim firmware logs and remove runtime diagnostics scaffolding --- .../src/control_plane_lifecycle.c | 14 --- components/domain/include/domain.h | 34 ------ .../internal/voice_interaction_internal.h | 3 - .../domain/src/domain_runtime_contracts.c | 76 ------------ components/domain/src/image_generation.c | 15 --- components/domain/src/printer_protocol.c | 13 -- components/domain/src/printer_protocol_jobs.c | 5 - .../domain/src/printer_protocol_worker.c | 5 - components/domain/src/voice_interaction.c | 114 +++++------------- .../domain/src/voice_interaction_common.c | 68 +---------- .../domain/src/voice_interaction_marker.c | 87 ++----------- .../domain/src/voice_interaction_tasks.c | 17 --- components/domain/src/voice_interaction_ws.c | 31 ++--- .../domain/src/voice_interaction_ws_audio.c | 2 +- .../src/voice_interaction_ws_protocol.c | 54 ++------- components/platform/CMakeLists.txt | 1 - components/platform/include/platform.h | 34 ------ components/platform/src/runtime_diagnostics.c | 81 ------------- components/platform/src/wifi_manager.c | 55 +++------ sdkconfig.defaults | 2 + 20 files changed, 81 insertions(+), 630 deletions(-) delete mode 100644 components/platform/src/runtime_diagnostics.c diff --git a/components/control_plane/src/control_plane_lifecycle.c b/components/control_plane/src/control_plane_lifecycle.c index d7094c0..9cf75a3 100644 --- a/components/control_plane/src/control_plane_lifecycle.c +++ b/components/control_plane/src/control_plane_lifecycle.c @@ -45,7 +45,6 @@ static void lifecycle_set_state_locked(control_plane_lifecycle_state_t state, s_status.last_error = last_error; s_status.last_transition_ms = esp_timer_get_time() / 1000; strlcpy(s_status.last_stage, stage != NULL ? stage : "unknown", sizeof(s_status.last_stage)); - domain_diag_set_gauge(DOMAIN_DIAG_GAUGE_LIFECYCLE_STATE, (int32_t)state); } const char *control_plane_lifecycle_state_str(control_plane_lifecycle_state_t state) { @@ -125,7 +124,6 @@ static esp_err_t lifecycle_run_step_with_retry(const char *stage, lifecycle_step return rc; } - domain_diag_counter_add(DOMAIN_DIAG_COUNTER_LIFECYCLE_START_RETRY, 1); vTaskDelay(pdMS_TO_TICKS(domain_policy_lifecycle_retry_backoff_ms(attempt))); } @@ -133,11 +131,8 @@ static esp_err_t lifecycle_run_step_with_retry(const char *stage, lifecycle_step } esp_err_t control_plane_lifecycle_start(void) { - domain_diag_counter_add(DOMAIN_DIAG_COUNTER_LIFECYCLE_START_ATTEMPT, 1); if (!lifecycle_lock_take(1000)) { - domain_diag_counter_add(DOMAIN_DIAG_COUNTER_LIFECYCLE_START_FAILED, 1); - domain_diag_record_error("lifecycle_start", ESP_ERR_TIMEOUT, "lifecycle lock timeout"); return ESP_ERR_TIMEOUT; } @@ -188,7 +183,6 @@ esp_err_t control_plane_lifecycle_start(void) { xSemaphoreGive(s_lock); } - domain_diag_counter_add(DOMAIN_DIAG_COUNTER_LIFECYCLE_START_SUCCESS, 1); ESP_LOGI(TAG, "control-plane lifecycle started"); return ESP_OK; @@ -208,8 +202,6 @@ start_failed: xSemaphoreGive(s_lock); } - domain_diag_counter_add(DOMAIN_DIAG_COUNTER_LIFECYCLE_START_FAILED, 1); - domain_diag_record_error("lifecycle_start", rc, failed_stage); ESP_LOGE(TAG, "control-plane lifecycle start failed at stage=%s, rc=0x%x", failed_stage, @@ -218,11 +210,8 @@ start_failed: } esp_err_t control_plane_lifecycle_stop(void) { - domain_diag_counter_add(DOMAIN_DIAG_COUNTER_LIFECYCLE_STOP_ATTEMPT, 1); if (!lifecycle_lock_take(1000)) { - domain_diag_counter_add(DOMAIN_DIAG_COUNTER_LIFECYCLE_STOP_FAILED, 1); - domain_diag_record_error("lifecycle_stop", ESP_ERR_TIMEOUT, "lifecycle lock timeout"); return ESP_ERR_TIMEOUT; } @@ -266,11 +255,8 @@ esp_err_t control_plane_lifecycle_stop(void) { } if (first_err == ESP_OK) { - domain_diag_counter_add(DOMAIN_DIAG_COUNTER_LIFECYCLE_STOP_SUCCESS, 1); ESP_LOGI(TAG, "control-plane lifecycle stopped"); } else { - domain_diag_counter_add(DOMAIN_DIAG_COUNTER_LIFECYCLE_STOP_FAILED, 1); - domain_diag_record_error("lifecycle_stop", first_err, "control-plane stop failed"); ESP_LOGE(TAG, "control-plane lifecycle stop failed, rc=0x%x", (unsigned)first_err); } diff --git a/components/domain/include/domain.h b/components/domain/include/domain.h index e498ad3..bbcaa13 100644 --- a/components/domain/include/domain.h +++ b/components/domain/include/domain.h @@ -33,40 +33,6 @@ uint32_t domain_policy_image_download_timeout_default_ms(void); uint32_t domain_policy_image_download_timeout_min_ms(void); uint32_t domain_policy_image_download_timeout_max_ms(void); -// ---------- domain_diagnostics ---------- -typedef enum { - DOMAIN_DIAG_COUNTER_LIFECYCLE_START_ATTEMPT = 0, - DOMAIN_DIAG_COUNTER_LIFECYCLE_START_SUCCESS, - DOMAIN_DIAG_COUNTER_LIFECYCLE_START_FAILED, - DOMAIN_DIAG_COUNTER_LIFECYCLE_START_RETRY, - DOMAIN_DIAG_COUNTER_LIFECYCLE_STOP_ATTEMPT, - DOMAIN_DIAG_COUNTER_LIFECYCLE_STOP_SUCCESS, - DOMAIN_DIAG_COUNTER_LIFECYCLE_STOP_FAILED, - DOMAIN_DIAG_COUNTER_WIFI_CONNECT_SUCCESS, - DOMAIN_DIAG_COUNTER_WIFI_CONNECT_FAILED, - DOMAIN_DIAG_COUNTER_WIFI_CONNECT_TIMEOUT, - DOMAIN_DIAG_COUNTER_PRINTER_JOB_SUBMITTED, - DOMAIN_DIAG_COUNTER_PRINTER_JOB_SUCCESS, - DOMAIN_DIAG_COUNTER_PRINTER_JOB_FAILED, - DOMAIN_DIAG_COUNTER_PRINTER_JOB_CANCELED, - DOMAIN_DIAG_COUNTER_IMAGE_GENERATE_ATTEMPT, - DOMAIN_DIAG_COUNTER_IMAGE_GENERATE_SUCCESS, - DOMAIN_DIAG_COUNTER_IMAGE_GENERATE_FAILED, - DOMAIN_DIAG_COUNTER_IMAGE_GENERATE_TIMEOUT, - DOMAIN_DIAG_COUNTER_MAX, -} domain_diag_counter_t; - -typedef enum { - DOMAIN_DIAG_GAUGE_LIFECYCLE_STATE = 0, - DOMAIN_DIAG_GAUGE_STATUS_POLL_PAUSE_DEPTH, - DOMAIN_DIAG_GAUGE_PRINTER_QUEUE_DEPTH, - DOMAIN_DIAG_GAUGE_MAX, -} domain_diag_gauge_t; - -void domain_diag_counter_add(domain_diag_counter_t counter, uint32_t delta); -void domain_diag_set_gauge(domain_diag_gauge_t gauge, int32_t value); -void domain_diag_record_error(const char *source, esp_err_t code, const char *message); - // ---------- raster_tools ---------- esp_err_t raster_tools_render_text_384(const char *text, uint8_t scale, diff --git a/components/domain/internal/voice_interaction_internal.h b/components/domain/internal/voice_interaction_internal.h index 71952bf..0e5fbfd 100644 --- a/components/domain/internal/voice_interaction_internal.h +++ b/components/domain/internal/voice_interaction_internal.h @@ -78,7 +78,6 @@ typedef struct { bool stop_requested; bool ws_text_shutdown; bool ws_text_busy; - bool ws_low_stack_warned; bool response_first_sentence_checked; voice_dialog_state_t dialog_state; @@ -102,8 +101,6 @@ void voice_fill_err(char *err, size_t err_len, const char *msg); void voice_set_last_error_locked(const char *msg); bool voice_lock(uint32_t timeout_ms); void voice_unlock(void); -void voice_log_status_snapshot(const char *stage); -void voice_log_heap_snapshot(const char *stage); void voice_wait_audio_playback_done(uint32_t timeout_ms, const char *stage); void voice_close_audio_with_drain(uint32_t timeout_ms, const char *stage); diff --git a/components/domain/src/domain_runtime_contracts.c b/components/domain/src/domain_runtime_contracts.c index ab916d1..c8fb78c 100644 --- a/components/domain/src/domain_runtime_contracts.c +++ b/components/domain/src/domain_runtime_contracts.c @@ -2,62 +2,6 @@ #include "platform.h" -static runtime_diag_counter_t to_platform_counter(domain_diag_counter_t counter) { - switch (counter) { - case DOMAIN_DIAG_COUNTER_LIFECYCLE_START_ATTEMPT: - return RUNTIME_DIAG_COUNTER_LIFECYCLE_START_ATTEMPT; - case DOMAIN_DIAG_COUNTER_LIFECYCLE_START_SUCCESS: - return RUNTIME_DIAG_COUNTER_LIFECYCLE_START_SUCCESS; - case DOMAIN_DIAG_COUNTER_LIFECYCLE_START_FAILED: - return RUNTIME_DIAG_COUNTER_LIFECYCLE_START_FAILED; - case DOMAIN_DIAG_COUNTER_LIFECYCLE_START_RETRY: - return RUNTIME_DIAG_COUNTER_LIFECYCLE_START_RETRY; - case DOMAIN_DIAG_COUNTER_LIFECYCLE_STOP_ATTEMPT: - return RUNTIME_DIAG_COUNTER_LIFECYCLE_STOP_ATTEMPT; - case DOMAIN_DIAG_COUNTER_LIFECYCLE_STOP_SUCCESS: - return RUNTIME_DIAG_COUNTER_LIFECYCLE_STOP_SUCCESS; - case DOMAIN_DIAG_COUNTER_LIFECYCLE_STOP_FAILED: - return RUNTIME_DIAG_COUNTER_LIFECYCLE_STOP_FAILED; - case DOMAIN_DIAG_COUNTER_WIFI_CONNECT_SUCCESS: - return RUNTIME_DIAG_COUNTER_WIFI_CONNECT_SUCCESS; - case DOMAIN_DIAG_COUNTER_WIFI_CONNECT_FAILED: - return RUNTIME_DIAG_COUNTER_WIFI_CONNECT_FAILED; - case DOMAIN_DIAG_COUNTER_WIFI_CONNECT_TIMEOUT: - return RUNTIME_DIAG_COUNTER_WIFI_CONNECT_TIMEOUT; - case DOMAIN_DIAG_COUNTER_PRINTER_JOB_SUBMITTED: - return RUNTIME_DIAG_COUNTER_PRINTER_JOB_SUBMITTED; - case DOMAIN_DIAG_COUNTER_PRINTER_JOB_SUCCESS: - return RUNTIME_DIAG_COUNTER_PRINTER_JOB_SUCCESS; - case DOMAIN_DIAG_COUNTER_PRINTER_JOB_FAILED: - return RUNTIME_DIAG_COUNTER_PRINTER_JOB_FAILED; - case DOMAIN_DIAG_COUNTER_PRINTER_JOB_CANCELED: - return RUNTIME_DIAG_COUNTER_PRINTER_JOB_CANCELED; - case DOMAIN_DIAG_COUNTER_IMAGE_GENERATE_ATTEMPT: - return RUNTIME_DIAG_COUNTER_IMAGE_GENERATE_ATTEMPT; - case DOMAIN_DIAG_COUNTER_IMAGE_GENERATE_SUCCESS: - return RUNTIME_DIAG_COUNTER_IMAGE_GENERATE_SUCCESS; - case DOMAIN_DIAG_COUNTER_IMAGE_GENERATE_FAILED: - return RUNTIME_DIAG_COUNTER_IMAGE_GENERATE_FAILED; - case DOMAIN_DIAG_COUNTER_IMAGE_GENERATE_TIMEOUT: - return RUNTIME_DIAG_COUNTER_IMAGE_GENERATE_TIMEOUT; - default: - return RUNTIME_DIAG_COUNTER_MAX; - } -} - -static runtime_diag_gauge_t to_platform_gauge(domain_diag_gauge_t gauge) { - switch (gauge) { - case DOMAIN_DIAG_GAUGE_LIFECYCLE_STATE: - return RUNTIME_DIAG_GAUGE_LIFECYCLE_STATE; - case DOMAIN_DIAG_GAUGE_STATUS_POLL_PAUSE_DEPTH: - return RUNTIME_DIAG_GAUGE_STATUS_POLL_PAUSE_DEPTH; - case DOMAIN_DIAG_GAUGE_PRINTER_QUEUE_DEPTH: - return RUNTIME_DIAG_GAUGE_PRINTER_QUEUE_DEPTH; - default: - return RUNTIME_DIAG_GAUGE_MAX; - } -} - uint32_t domain_policy_lifecycle_start_retry_count(void) { return runtime_policy_lifecycle_start_retry_count(); } @@ -97,23 +41,3 @@ uint32_t domain_policy_image_download_timeout_min_ms(void) { uint32_t domain_policy_image_download_timeout_max_ms(void) { return runtime_policy_image_download_timeout_max_ms(); } - -void domain_diag_counter_add(domain_diag_counter_t counter, uint32_t delta) { - runtime_diag_counter_t mapped = to_platform_counter(counter); - if (mapped >= RUNTIME_DIAG_COUNTER_MAX) { - return; - } - runtime_diag_counter_add(mapped, delta); -} - -void domain_diag_set_gauge(domain_diag_gauge_t gauge, int32_t value) { - runtime_diag_gauge_t mapped = to_platform_gauge(gauge); - if (mapped >= RUNTIME_DIAG_GAUGE_MAX) { - return; - } - runtime_diag_set_gauge(mapped, value); -} - -void domain_diag_record_error(const char *source, esp_err_t code, const char *message) { - runtime_diag_record_error(source, code, message); -} diff --git a/components/domain/src/image_generation.c b/components/domain/src/image_generation.c index 88da384..e16753d 100644 --- a/components/domain/src/image_generation.c +++ b/components/domain/src/image_generation.c @@ -845,11 +845,9 @@ esp_err_t image_generation_generate_png(const image_generation_request_t *req, image_generation_result_t *out_result, char *err, size_t err_len) { - runtime_diag_counter_add(RUNTIME_DIAG_COUNTER_IMAGE_GENERATE_ATTEMPT, 1); if (req == NULL || out_result == NULL || req->prompt == NULL || req->prompt[0] == '\0') { image_generation_fill_err(err, err_len, "prompt is required"); - runtime_diag_counter_add(RUNTIME_DIAG_COUNTER_IMAGE_GENERATE_FAILED, 1); return ESP_ERR_INVALID_ARG; } @@ -879,12 +877,6 @@ esp_err_t image_generation_generate_png(const image_generation_request_t *req, "image generate stage failed, rc=0x%x, msg=%s", (unsigned)gen_rc, (err != NULL && err[0] != '\0') ? err : "model invoke failed"); - if (gen_rc == ESP_ERR_TIMEOUT) { - runtime_diag_counter_add(RUNTIME_DIAG_COUNTER_IMAGE_GENERATE_TIMEOUT, 1); - } else { - runtime_diag_counter_add(RUNTIME_DIAG_COUNTER_IMAGE_GENERATE_FAILED, 1); - } - runtime_diag_record_error("image_generate", gen_rc, err != NULL ? err : "model invoke failed"); image_generation_result_free(out_result); return gen_rc; } @@ -900,12 +892,6 @@ esp_err_t image_generation_generate_png(const image_generation_request_t *req, "image download stage failed, rc=0x%x, msg=%s", (unsigned)dl_rc, (err != NULL && err[0] != '\0') ? err : "download failed"); - if (dl_rc == ESP_ERR_TIMEOUT) { - runtime_diag_counter_add(RUNTIME_DIAG_COUNTER_IMAGE_GENERATE_TIMEOUT, 1); - } else { - runtime_diag_counter_add(RUNTIME_DIAG_COUNTER_IMAGE_GENERATE_FAILED, 1); - } - runtime_diag_record_error("image_download", dl_rc, err != NULL ? err : "download failed"); image_generation_result_free(out_result); return dl_rc; } @@ -919,7 +905,6 @@ esp_err_t image_generation_generate_png(const image_generation_request_t *req, (long long)(t_gen_done_ms - t0_ms), (long long)(t_dl_done_ms - t_gen_done_ms), (long long)(t_dl_done_ms - t0_ms)); - runtime_diag_counter_add(RUNTIME_DIAG_COUNTER_IMAGE_GENERATE_SUCCESS, 1); return ESP_OK; } diff --git a/components/domain/src/printer_protocol.c b/components/domain/src/printer_protocol.c index 7757c8d..e52bbfc 100644 --- a/components/domain/src/printer_protocol.c +++ b/components/domain/src/printer_protocol.c @@ -172,8 +172,6 @@ printer_status_poll_pause_token_t printer_protocol_status_poll_pause_acquire(voi } s_status_poll_pause_tokens[slot] = token; - runtime_diag_set_gauge(RUNTIME_DIAG_GAUGE_STATUS_POLL_PAUSE_DEPTH, - (int32_t)status_poll_pause_depth_locked()); xSemaphoreGive(s_mutex); return token; } @@ -199,8 +197,6 @@ void printer_protocol_status_poll_pause_release(printer_status_poll_pause_token_ } } - runtime_diag_set_gauge(RUNTIME_DIAG_GAUGE_STATUS_POLL_PAUSE_DEPTH, - (int32_t)status_poll_pause_depth_locked()); xSemaphoreGive(s_mutex); *token = 0; } @@ -281,8 +277,6 @@ esp_err_t printer_protocol_init(void) { xSemaphoreGive(s_mutex); } - runtime_diag_set_gauge(RUNTIME_DIAG_GAUGE_STATUS_POLL_PAUSE_DEPTH, 0); - runtime_diag_set_gauge(RUNTIME_DIAG_GAUGE_PRINTER_QUEUE_DEPTH, 0); s_protocol_initialized = true; s_protocol_stopping = false; @@ -345,8 +339,6 @@ esp_err_t printer_protocol_stop(uint32_t timeout_ms) { xSemaphoreGive(s_mutex); } - runtime_diag_set_gauge(RUNTIME_DIAG_GAUGE_STATUS_POLL_PAUSE_DEPTH, 0); - if (s_evt != NULL) { xEventGroupSetBits(s_evt, EVT_SHUTDOWN); } @@ -396,9 +388,6 @@ esp_err_t printer_protocol_stop(uint32_t timeout_ms) { s_protocol_initialized = false; s_protocol_stopping = false; - runtime_diag_set_gauge(RUNTIME_DIAG_GAUGE_STATUS_POLL_PAUSE_DEPTH, 0); - runtime_diag_set_gauge(RUNTIME_DIAG_GAUGE_PRINTER_QUEUE_DEPTH, 0); - platform_printer_deinit(); ESP_LOGI(TAG, "printer protocol stopped"); @@ -439,6 +428,4 @@ void printer_protocol_get_runtime_status(printer_runtime_status_t *out_status) { : 0; xSemaphoreGive(s_mutex); } - - runtime_diag_set_gauge(RUNTIME_DIAG_GAUGE_PRINTER_QUEUE_DEPTH, (int32_t)out_status->queue_depth); } diff --git a/components/domain/src/printer_protocol_jobs.c b/components/domain/src/printer_protocol_jobs.c index d3e43b9..0bd76e8 100644 --- a/components/domain/src/printer_protocol_jobs.c +++ b/components/domain/src/printer_protocol_jobs.c @@ -177,8 +177,6 @@ esp_err_t printer_protocol_submit_raster_job_ex(const uint8_t *raster, density != NULL ? density : "中等", ignore_precheck, (unsigned)queue_depth); - runtime_diag_counter_add(RUNTIME_DIAG_COUNTER_PRINTER_JOB_SUBMITTED, 1); - runtime_diag_set_gauge(RUNTIME_DIAG_GAUGE_PRINTER_QUEUE_DEPTH, (int32_t)queue_depth); return ESP_OK; } @@ -320,7 +318,6 @@ esp_err_t printer_protocol_cancel_job(uint32_t job_id, char *err, size_t err_len xSemaphoreGive(s_mutex); if (canceled_finalized) { - runtime_diag_counter_add(RUNTIME_DIAG_COUNTER_PRINTER_JOB_CANCELED, 1); } return ESP_OK; } @@ -357,7 +354,5 @@ size_t printer_protocol_cleanup_jobs(bool include_success, bool include_failed, } xSemaphoreGive(s_mutex); - runtime_diag_set_gauge(RUNTIME_DIAG_GAUGE_PRINTER_QUEUE_DEPTH, - s_job_queue != NULL ? (int32_t)uxQueueMessagesWaiting(s_job_queue) : 0); return removed; } diff --git a/components/domain/src/printer_protocol_worker.c b/components/domain/src/printer_protocol_worker.c index c9af53a..12843c2 100644 --- a/components/domain/src/printer_protocol_worker.c +++ b/components/domain/src/printer_protocol_worker.c @@ -211,16 +211,13 @@ void printer_protocol_worker_task(void *arg) { if (ok) { s_jobs[idx].state = PRINT_JOB_STATE_SUCCESS; s_jobs[idx].error[0] = 0; - runtime_diag_counter_add(RUNTIME_DIAG_COUNTER_PRINTER_JOB_SUCCESS, 1); } else if (s_jobs[idx].cancel_requested || printer_protocol_is_stopping()) { s_jobs[idx].state = PRINT_JOB_STATE_CANCELED; if (s_jobs[idx].error[0] == 0) { strlcpy(s_jobs[idx].error, "job canceled", sizeof(s_jobs[idx].error)); } - runtime_diag_counter_add(RUNTIME_DIAG_COUNTER_PRINTER_JOB_CANCELED, 1); } else { s_jobs[idx].state = PRINT_JOB_STATE_FAILED; - runtime_diag_counter_add(RUNTIME_DIAG_COUNTER_PRINTER_JOB_FAILED, 1); } int64_t duration_ms = 0; @@ -244,8 +241,6 @@ void printer_protocol_worker_task(void *arg) { free(s_jobs[idx].data); s_jobs[idx].data = NULL; - runtime_diag_set_gauge(RUNTIME_DIAG_GAUGE_PRINTER_QUEUE_DEPTH, - (int32_t)uxQueueMessagesWaiting(s_job_queue)); xSemaphoreGive(s_mutex); } diff --git a/components/domain/src/voice_interaction.c b/components/domain/src/voice_interaction.c index 8e414d8..b2a6abb 100644 --- a/components/domain/src/voice_interaction.c +++ b/components/domain/src/voice_interaction.c @@ -65,7 +65,7 @@ static bool voice_wait_worker_tasks_exit(uint32_t timeout_ms) { if (voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { ESP_LOGW(TAG, - "[stage] worker_task_exit_timeout: uplink_alive=%d heartbeat_alive=%d ws_text_alive=%d", + "worker_task_exit_timeout: uplink_alive=%d heartbeat_alive=%d ws_text_alive=%d", s_voice.uplink_task != NULL, s_voice.heartbeat_task != NULL, s_voice.ws_text_task != NULL); @@ -118,10 +118,9 @@ esp_err_t voice_interaction_init(void) { esp_err_t voice_interaction_start_with_timeout(uint32_t timeout_ms, char *err, size_t err_len) { uint32_t connect_timeout_ms = clamp_timeout_ms(timeout_ms, VOICE_START_CONNECT_TIMEOUT_MS, 1000, 30000); - ESP_LOGI(TAG, "[stage] session_start_enter"); if (!s_voice.ready) { voice_fill_err(err, err_len, "voice interaction not initialized"); - ESP_LOGW(TAG, "[stage] session_start_abort: not initialized"); + ESP_LOGW(TAG, "session_start_abort: not initialized"); return ESP_ERR_INVALID_STATE; } @@ -129,20 +128,13 @@ esp_err_t voice_interaction_start_with_timeout(uint32_t timeout_ms, char *err, s strlen(CONFIG_TQ_VOICE_WORKSPACE_ID) == 0 || strlen(CONFIG_TQ_VOICE_APP_ID) == 0) { voice_fill_err(err, err_len, "voice API key/workspace/app_id is missing"); - ESP_LOGW(TAG, "[stage] session_start_abort: config missing"); + ESP_LOGW(TAG, "session_start_abort: config missing"); return ESP_ERR_INVALID_STATE; } - ESP_LOGI(TAG, - "[stage] session_config_ok: ws_uri=%s sample_rate=%d frame_ms=%d bitrate_kbps=%d ws_stack=%d", - CONFIG_TQ_VOICE_WS_URI, - CONFIG_TQ_VOICE_SAMPLE_RATE, - CONFIG_TQ_VOICE_OPUS_FRAME_MS, - CONFIG_TQ_VOICE_OPUS_BITRATE_KBPS, - VOICE_WS_TASK_STACK); if (!voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { voice_fill_err(err, err_len, "voice lock timeout"); - ESP_LOGW(TAG, "[stage] session_start_abort: lock timeout"); + ESP_LOGW(TAG, "session_start_abort: lock timeout"); return ESP_ERR_TIMEOUT; } bool already_active = s_voice.session_active; @@ -152,13 +144,11 @@ esp_err_t voice_interaction_start_with_timeout(uint32_t timeout_ms, char *err, s if (already_active) { if (ws_connected && started) { - ESP_LOGI(TAG, "[stage] session_start_skip: already active"); - voice_log_status_snapshot("already_active"); return ESP_OK; } ESP_LOGW(TAG, - "[stage] session_start_recover: active=%d ws_connected=%d started=%d", + "session_start_recover: active=%d ws_connected=%d started=%d", already_active, ws_connected, started); @@ -167,13 +157,11 @@ esp_err_t voice_interaction_start_with_timeout(uint32_t timeout_ms, char *err, s voice_interaction_ws_init_cjson_hooks(); - ESP_LOGI(TAG, "[stage] opus_setup_begin"); esp_err_t opus_setup_err = voice_setup_opus(err, err_len); if (opus_setup_err != ESP_OK) { ESP_LOGE(TAG, "voice opus setup failed: %s", esp_err_to_name(opus_setup_err)); goto exit_err; } - ESP_LOGI(TAG, "[stage] opus_setup_ok"); if (voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { voice_make_uuid(s_voice.task_id); @@ -188,7 +176,6 @@ esp_err_t voice_interaction_start_with_timeout(uint32_t timeout_ms, char *err, s s_voice.stop_requested = false; s_voice.tap_active = false; s_voice.speech_active = false; - s_voice.ws_low_stack_warned = false; s_voice.response_first_sentence_checked = false; s_voice.uplink_task_with_caps = false; s_voice.heartbeat_task_with_caps = false; @@ -196,10 +183,6 @@ esp_err_t voice_interaction_start_with_timeout(uint32_t timeout_ms, char *err, s s_voice.ws_text_shutdown = false; s_voice.ws_text_busy = false; s_voice.last_event_ms = voice_now_ms(); - ESP_LOGI(TAG, - "[stage] session_context_prepared: task_id=%s device_uuid=%s", - s_voice.task_id, - s_voice.device_uuid); voice_unlock(); } @@ -222,54 +205,47 @@ esp_err_t voice_interaction_start_with_timeout(uint32_t timeout_ms, char *err, s #endif }; - ESP_LOGI(TAG, "[stage] ws_init_begin"); esp_websocket_client_handle_t ws = esp_websocket_client_init(&ws_cfg); if (ws == NULL) { voice_fill_err(err, err_len, "websocket init failed"); - ESP_LOGE(TAG, "[stage] ws_init_failed"); + ESP_LOGE(TAG, "ws_init_failed"); goto exit_err; } - ESP_LOGI(TAG, "[stage] ws_init_ok"); size_t auth_len = strlen(CONFIG_TQ_VOICE_API_KEY) + 8; char *auth_value = (char *)voice_malloc_prefer_psram(auth_len); if (auth_value == NULL) { voice_fill_err(err, err_len, "no memory for auth header"); - ESP_LOGE(TAG, "[stage] ws_auth_header_alloc_failed"); + ESP_LOGE(TAG, "ws_auth_header_alloc_failed"); esp_websocket_client_destroy(ws); goto exit_err; } snprintf(auth_value, auth_len, "Bearer %s", CONFIG_TQ_VOICE_API_KEY); esp_websocket_client_append_header(ws, "Authorization", auth_value); free(auth_value); - ESP_LOGI(TAG, "[stage] ws_auth_header_set"); - ESP_LOGI(TAG, "[stage] ws_register_events_begin"); esp_err_t reg_err = esp_websocket_register_events(ws, WEBSOCKET_EVENT_ANY, voice_websocket_event_handler, NULL); if (reg_err != ESP_OK) { voice_fill_err(err, err_len, "websocket register events failed"); - ESP_LOGE(TAG, "[stage] ws_register_events_failed: %s", esp_err_to_name(reg_err)); + ESP_LOGE(TAG, "ws_register_events_failed: %s", esp_err_to_name(reg_err)); esp_websocket_client_destroy(ws); goto exit_err; } - ESP_LOGI(TAG, "[stage] ws_register_events_ok"); - ESP_LOGI(TAG, "[stage] ws_start_begin"); esp_err_t ws_start_err = esp_websocket_client_start(ws); if (ws_start_err != ESP_OK) { voice_fill_err(err, err_len, "websocket start failed"); - ESP_LOGE(TAG, "[stage] ws_start_failed: %s", esp_err_to_name(ws_start_err)); + ESP_LOGE(TAG, "ws_start_failed: %s", esp_err_to_name(ws_start_err)); esp_websocket_client_destroy(ws); goto exit_err; } - ESP_LOGI(TAG, "[stage] ws_start_ok"); if (!voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { voice_fill_err(err, err_len, "voice lock timeout"); - ESP_LOGE(TAG, "[stage] session_start_abort: lock timeout after ws_start"); + ESP_LOGE(TAG, "session_start_abort: lock timeout after ws_start"); esp_websocket_client_stop(ws); esp_websocket_client_destroy(ws); goto exit_err; @@ -282,12 +258,10 @@ esp_err_t voice_interaction_start_with_timeout(uint32_t timeout_ms, char *err, s s_voice.ws_text_shutdown = false; s_voice.ws_text_busy = false; voice_unlock(); - voice_log_status_snapshot("session_marked_active"); - voice_log_heap_snapshot("before_create_uplink"); if (!voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { voice_fill_err(err, err_len, "voice lock timeout"); - ESP_LOGE(TAG, "[stage] session_start_abort: lock timeout before ws_text_task create"); + ESP_LOGE(TAG, "session_start_abort: lock timeout before ws_text_task create"); (void)voice_interaction_stop(NULL, 0); return ESP_ERR_TIMEOUT; } @@ -298,12 +272,11 @@ esp_err_t voice_interaction_start_with_timeout(uint32_t timeout_ms, char *err, s voice_unlock(); if (ws_text_queue == NULL) { voice_fill_err(err, err_len, "create ws text queue failed"); - ESP_LOGE(TAG, "[stage] ws_text_queue_create_failed"); + ESP_LOGE(TAG, "ws_text_queue_create_failed"); (void)voice_interaction_stop(NULL, 0); return ESP_ERR_NO_MEM; } - ESP_LOGI(TAG, "[stage] ws_text_task_create_begin"); BaseType_t ok = voice_create_task_prefer_psram(voice_ws_text_task, "voice_ws_text", VOICE_HEARTBEAT_TASK_STACK, @@ -312,13 +285,11 @@ esp_err_t voice_interaction_start_with_timeout(uint32_t timeout_ms, char *err, s &s_voice.ws_text_task_with_caps); if (ok != pdPASS) { voice_fill_err(err, err_len, "create ws text task failed"); - ESP_LOGE(TAG, "[stage] ws_text_task_create_failed"); + ESP_LOGE(TAG, "ws_text_task_create_failed"); (void)voice_interaction_stop(NULL, 0); return ESP_ERR_NO_MEM; } - ESP_LOGI(TAG, "[stage] ws_text_task_create_ok"); - ESP_LOGI(TAG, "[stage] uplink_task_create_begin"); ok = voice_create_task_prefer_psram(voice_uplink_task, "voice_uplink", VOICE_UPLINK_TASK_STACK, @@ -327,15 +298,11 @@ esp_err_t voice_interaction_start_with_timeout(uint32_t timeout_ms, char *err, s &s_voice.uplink_task_with_caps); if (ok != pdPASS) { voice_fill_err(err, err_len, "create uplink task failed"); - ESP_LOGE(TAG, "[stage] uplink_task_create_failed"); - voice_log_heap_snapshot("uplink_create_failed"); + ESP_LOGE(TAG, "uplink_task_create_failed"); (void)voice_interaction_stop(NULL, 0); return ESP_ERR_NO_MEM; } - ESP_LOGI(TAG, "[stage] uplink_task_create_ok"); - voice_log_heap_snapshot("after_create_uplink"); - ESP_LOGI(TAG, "[stage] heartbeat_task_create_begin"); ok = voice_create_task_prefer_psram(voice_heartbeat_task, "voice_hb", VOICE_HEARTBEAT_TASK_STACK, @@ -344,15 +311,11 @@ esp_err_t voice_interaction_start_with_timeout(uint32_t timeout_ms, char *err, s &s_voice.heartbeat_task_with_caps); if (ok != pdPASS) { voice_fill_err(err, err_len, "create heartbeat task failed"); - ESP_LOGE(TAG, "[stage] heartbeat_task_create_failed"); - voice_log_heap_snapshot("heartbeat_create_failed"); + ESP_LOGE(TAG, "heartbeat_task_create_failed"); (void)voice_interaction_stop(NULL, 0); return ESP_ERR_NO_MEM; } - ESP_LOGI(TAG, "[stage] heartbeat_task_create_ok"); - voice_log_heap_snapshot("after_create_heartbeat"); - ESP_LOGI(TAG, "[stage] wait_ws_connected_begin: timeout_ms=%u", (unsigned)connect_timeout_ms); int64_t deadline = voice_now_ms() + connect_timeout_ms; while (voice_now_ms() < deadline) { bool connected = false; @@ -368,7 +331,7 @@ esp_err_t voice_interaction_start_with_timeout(uint32_t timeout_ms, char *err, s if (!voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { voice_fill_err(err, err_len, "voice lock timeout"); - ESP_LOGE(TAG, "[stage] wait_ws_connected_abort: lock timeout"); + ESP_LOGE(TAG, "wait_ws_connected_abort: lock timeout"); (void)voice_interaction_stop(NULL, 0); return ESP_ERR_TIMEOUT; } @@ -376,18 +339,15 @@ esp_err_t voice_interaction_start_with_timeout(uint32_t timeout_ms, char *err, s voice_unlock(); if (!connected) { voice_fill_err(err, err_len, "websocket connect timeout"); - ESP_LOGE(TAG, "[stage] wait_ws_connected_timeout"); - voice_log_status_snapshot("wait_ws_connected_timeout"); + ESP_LOGE(TAG, "wait_ws_connected_timeout"); (void)voice_interaction_stop(NULL, 0); return ESP_ERR_TIMEOUT; } - ESP_LOGI(TAG, "[stage] wait_ws_connected_ok"); - voice_log_status_snapshot("session_start_exit_ok"); return ESP_OK; exit_err: - ESP_LOGE(TAG, "[stage] session_start_exit_err: %s", (err != NULL && err[0] != '\0') ? err : "unknown"); + ESP_LOGE(TAG, "session_start_exit_err: %s", (err != NULL && err[0] != '\0') ? err : "unknown"); voice_release_runtime_resources(); voice_close_audio_with_drain(VOICE_AUDIO_DRAIN_WAIT_MS, "session_start_exit_err_close"); return ESP_FAIL; @@ -399,24 +359,22 @@ esp_err_t voice_interaction_start(char *err, size_t err_len) { esp_err_t voice_interaction_stop_with_timeout(uint32_t timeout_ms, char *err, size_t err_len) { uint32_t worker_exit_timeout_ms = clamp_timeout_ms(timeout_ms, 1500, 500, 10000); - ESP_LOGI(TAG, "[stage] session_stop_enter"); if (!s_voice.ready) { voice_fill_err(err, err_len, "voice interaction not initialized"); - ESP_LOGW(TAG, "[stage] session_stop_abort: not initialized"); + ESP_LOGW(TAG, "session_stop_abort: not initialized"); return ESP_ERR_INVALID_STATE; } if (!voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { voice_fill_err(err, err_len, "voice lock timeout"); - ESP_LOGW(TAG, "[stage] session_stop_abort: lock timeout"); + ESP_LOGW(TAG, "session_stop_abort: lock timeout"); return ESP_ERR_TIMEOUT; } if (!s_voice.session_active) { voice_unlock(); voice_close_audio_with_drain(VOICE_AUDIO_DRAIN_WAIT_MS, "session_stop_skip_close"); - ESP_LOGI(TAG, "[stage] session_stop_skip: not active"); return ESP_OK; } @@ -431,12 +389,11 @@ esp_err_t voice_interaction_stop_with_timeout(uint32_t timeout_ms, char *err, si s_voice.tap_active = false; s_voice.speech_active = false; voice_unlock(); - voice_log_status_snapshot("session_stop_requested"); if (ws_connected) { (void)voice_send_directive("finish-task", "Stop", true); if (!voice_wait_ws_text_idle(VOICE_WS_SEND_TIMEOUT_MS + 1200)) { - ESP_LOGW(TAG, "[stage] ws_text_idle_timeout_before_shutdown"); + ESP_LOGW(TAG, "ws_text_idle_timeout_before_shutdown"); } } voice_close_audio_with_drain(VOICE_AUDIO_DRAIN_WAIT_ON_STOP_MS, "session_stop_close"); @@ -460,7 +417,7 @@ esp_err_t voice_interaction_stop_with_timeout(uint32_t timeout_ms, char *err, si voice_set_last_error_locked("worker exit timeout"); voice_unlock(); } - ESP_LOGW(TAG, "[stage] session_stop_abort: workers still alive"); + ESP_LOGW(TAG, "session_stop_abort: workers still alive"); return ESP_ERR_TIMEOUT; } @@ -470,13 +427,11 @@ esp_err_t voice_interaction_stop_with_timeout(uint32_t timeout_ms, char *err, si } if (ws != NULL) { - ESP_LOGI(TAG, "[stage] ws_stop_destroy_begin"); esp_websocket_unregister_events(ws, WEBSOCKET_EVENT_ANY, voice_websocket_event_handler); esp_websocket_client_stop(ws); esp_websocket_client_destroy(ws); - ESP_LOGI(TAG, "[stage] ws_stop_destroy_ok"); } if (voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { @@ -502,11 +457,9 @@ esp_err_t voice_interaction_stop_with_timeout(uint32_t timeout_ms, char *err, si s_voice.playback_deadline_ms = 0; voice_unlock(); } - voice_log_status_snapshot("session_stop_cleared"); voice_release_runtime_resources(); voice_close_audio_with_drain(VOICE_AUDIO_DRAIN_WAIT_MS, "session_stop_exit_close"); - ESP_LOGI(TAG, "[stage] session_stop_exit_ok"); return ESP_OK; } @@ -539,7 +492,7 @@ esp_err_t voice_interaction_try_send_speech(char *err, size_t err_len) { esp_err_t send_err = voice_send_directive("continue-task", "SendSpeech", true); if (send_err != ESP_OK) { voice_fill_err(err, err_len, "send speech failed"); - ESP_LOGW(TAG, "[stage] send_speech_failed: rc=0x%x", (unsigned)send_err); + ESP_LOGW(TAG, "send_speech_failed: rc=0x%x", (unsigned)send_err); return send_err; } @@ -569,16 +522,15 @@ esp_err_t voice_interaction_try_send_speech(char *err, size_t err_len) { } esp_err_t voice_interaction_tap_start(char *err, size_t err_len) { - ESP_LOGI(TAG, "[stage] tap_start_enter"); if (!voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { voice_fill_err(err, err_len, "voice lock timeout"); - ESP_LOGW(TAG, "[stage] tap_start_abort: lock timeout"); + ESP_LOGW(TAG, "tap_start_abort: lock timeout"); return ESP_ERR_TIMEOUT; } if (!s_voice.session_active || !s_voice.ws_connected || !s_voice.started) { ESP_LOGW(TAG, - "[stage] tap_start_abort: session_active=%d ws_connected=%d started=%d", + "tap_start_abort: session_active=%d ws_connected=%d started=%d", s_voice.session_active, s_voice.ws_connected, s_voice.started); @@ -588,24 +540,22 @@ esp_err_t voice_interaction_tap_start(char *err, size_t err_len) { } voice_unlock(); - voice_log_heap_snapshot("tap_start_before_audio_open"); esp_err_t audio_err = voice_open_audio_for_dialog(err, err_len); if (audio_err != ESP_OK) { - voice_log_heap_snapshot("tap_start_audio_open_failed"); return audio_err; } if (!voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { voice_fill_err(err, err_len, "voice lock timeout"); voice_audio_close(); - ESP_LOGW(TAG, "[stage] tap_start_abort: lock timeout after audio open"); + ESP_LOGW(TAG, "tap_start_abort: lock timeout after audio open"); return ESP_ERR_TIMEOUT; } if (!s_voice.session_active || !s_voice.ws_connected || !s_voice.started) { ESP_LOGW(TAG, - "[stage] tap_start_abort_after_audio_open: session_active=%d ws_connected=%d started=%d", + "tap_start_abort_after_audio_open: session_active=%d ws_connected=%d started=%d", s_voice.session_active, s_voice.ws_connected, s_voice.started); @@ -619,7 +569,6 @@ esp_err_t voice_interaction_tap_start(char *err, size_t err_len) { s_voice.tap_active = true; s_voice.speech_active = false; voice_unlock(); - ESP_LOGI(TAG, "[stage] tap_start_marked_active: listening=%d", listening); if (!listening) { esp_err_t req_rc = voice_send_directive("continue-task", "RequestToSpeak", true); @@ -630,7 +579,7 @@ esp_err_t voice_interaction_tap_start(char *err, size_t err_len) { voice_unlock(); } voice_fill_err(err, err_len, "request to speak failed"); - ESP_LOGW(TAG, "[stage] tap_start_abort: request_to_speak failed rc=0x%x", (unsigned)req_rc); + ESP_LOGW(TAG, "tap_start_abort: request_to_speak failed rc=0x%x", (unsigned)req_rc); return req_rc; } } else { @@ -646,21 +595,19 @@ esp_err_t voice_interaction_tap_start(char *err, size_t err_len) { } } - voice_log_status_snapshot("tap_start_exit_ok"); return ESP_OK; } esp_err_t voice_interaction_tap_cancel(char *err, size_t err_len) { - ESP_LOGI(TAG, "[stage] tap_cancel_enter"); if (!voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { voice_fill_err(err, err_len, "voice lock timeout"); - ESP_LOGW(TAG, "[stage] tap_cancel_abort: lock timeout"); + ESP_LOGW(TAG, "tap_cancel_abort: lock timeout"); return ESP_ERR_TIMEOUT; } if (!s_voice.session_active || !s_voice.ws_connected || !s_voice.started) { ESP_LOGW(TAG, - "[stage] tap_cancel_abort: session_active=%d ws_connected=%d started=%d", + "tap_cancel_abort: session_active=%d ws_connected=%d started=%d", s_voice.session_active, s_voice.ws_connected, s_voice.started); @@ -673,7 +620,6 @@ esp_err_t voice_interaction_tap_cancel(char *err, size_t err_len) { s_voice.tap_active = false; s_voice.speech_active = false; voice_unlock(); - voice_log_status_snapshot("tap_cancel_marked_inactive"); esp_err_t stop_err = ESP_OK; if (should_send_stop) { diff --git a/components/domain/src/voice_interaction_common.c b/components/domain/src/voice_interaction_common.c index 6ff16b7..9117273 100644 --- a/components/domain/src/voice_interaction_common.c +++ b/components/domain/src/voice_interaction_common.c @@ -47,50 +47,6 @@ void voice_unlock(void) { } } -void voice_log_status_snapshot(const char *stage) { - if (!voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { - ESP_LOGW(TAG, "[stage] %s: status snapshot lock timeout", stage); - return; - } - - ESP_LOGI(TAG, - "[stage] %s: active=%d ws=%d started=%d tap=%d speech=%d state=%s up=%" PRIu32 - " down=%" PRIu32 " err=%s", - stage, - s_voice.session_active, - s_voice.ws_connected, - s_voice.started, - s_voice.tap_active, - s_voice.speech_active, - voice_interaction_dialog_state_str(s_voice.dialog_state), - s_voice.upstream_packets, - s_voice.downstream_packets, - s_voice.last_error[0] != '\0' ? s_voice.last_error : "-"); - voice_unlock(); -} - -void voice_log_heap_snapshot(const char *stage) { - size_t free_8bit = heap_caps_get_free_size(MALLOC_CAP_8BIT); - size_t free_internal = heap_caps_get_free_size(MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT); - size_t free_dma = heap_caps_get_free_size(MALLOC_CAP_DMA | MALLOC_CAP_8BIT); - size_t free_spiram = heap_caps_get_free_size(MALLOC_CAP_SPIRAM | MALLOC_CAP_8BIT); - size_t largest_8bit = heap_caps_get_largest_free_block(MALLOC_CAP_8BIT); - size_t largest_internal = heap_caps_get_largest_free_block(MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT); - size_t largest_dma = heap_caps_get_largest_free_block(MALLOC_CAP_DMA | MALLOC_CAP_8BIT); - size_t largest_spiram = heap_caps_get_largest_free_block(MALLOC_CAP_SPIRAM | MALLOC_CAP_8BIT); - ESP_LOGI(TAG, - "[stage] %s heap: free8=%u free_internal=%u free_dma=%u free_spiram=%u largest8=%u largest_internal=%u largest_dma=%u largest_spiram=%u", - stage, - (unsigned)free_8bit, - (unsigned)free_internal, - (unsigned)free_dma, - (unsigned)free_spiram, - (unsigned)largest_8bit, - (unsigned)largest_internal, - (unsigned)largest_dma, - (unsigned)largest_spiram); -} - void voice_wait_audio_playback_done(uint32_t timeout_ms, const char *stage) { if (!voice_audio_is_open() || timeout_ms == 0) { return; @@ -122,22 +78,11 @@ void voice_wait_audio_playback_done(uint32_t timeout_ms, const char *stage) { !started || dialog_state != VOICE_DIALOG_STATE_RESPONDING; if (codec_tail_done && downstream_quiet && remote_not_responding) { - ESP_LOGI(TAG, - "[stage] %s: audio_drain_done now=%" PRId64 " play_deadline=%" PRId64 " last_down=%" PRId64, - stage != NULL ? stage : "audio_drain", - now_ms, - playback_deadline_ms, - last_downstream_ms); return; } vTaskDelay(pdMS_TO_TICKS(30)); } - - ESP_LOGI(TAG, - "[stage] %s: audio_drain_timeout timeout_ms=%u", - stage != NULL ? stage : "audio_drain", - (unsigned)timeout_ms); } void voice_close_audio_with_drain(uint32_t timeout_ms, const char *stage) { @@ -205,10 +150,9 @@ BaseType_t voice_create_task_prefer_psram(TaskFunction_t task_fn, if (out_with_caps != NULL) { *out_with_caps = true; } - ESP_LOGI(TAG, "[stage] task_create_psram_ok: name=%s stack=%u", name, (unsigned)stack_size); return pdPASS; } - ESP_LOGW(TAG, "[stage] task_create_psram_failed: name=%s stack=%u", name, (unsigned)stack_size); + ESP_LOGW(TAG, "task_create_psram_failed: name=%s stack=%u", name, (unsigned)stack_size); #endif rc = xTaskCreate(task_fn, @@ -217,10 +161,8 @@ BaseType_t voice_create_task_prefer_psram(TaskFunction_t task_fn, NULL, priority, out_task); - if (rc == pdPASS) { - ESP_LOGI(TAG, "[stage] task_create_internal_ok: name=%s stack=%u", name, (unsigned)stack_size); - } else { - ESP_LOGE(TAG, "[stage] task_create_internal_failed: name=%s stack=%u", name, (unsigned)stack_size); + if (rc != pdPASS) { + ESP_LOGE(TAG, "task_create_internal_failed: name=%s stack=%u", name, (unsigned)stack_size); } return rc; } @@ -445,14 +387,12 @@ esp_err_t voice_open_audio_for_dialog(char *err, size_t err_len) { .input_gain_db = (float)CONFIG_TQ_VOICE_CODEC_MIC_GAIN_DB, }; - ESP_LOGI(TAG, "[stage] audio_open_begin"); esp_err_t open_err = voice_audio_open(&audio_cfg, err, err_len); if (open_err != ESP_OK) { - ESP_LOGE(TAG, "[stage] audio_open_failed: %s", esp_err_to_name(open_err)); + ESP_LOGE(TAG, "audio_open_failed: %s", esp_err_to_name(open_err)); return open_err; } - ESP_LOGI(TAG, "[stage] audio_open_ok"); return ESP_OK; } diff --git a/components/domain/src/voice_interaction_marker.c b/components/domain/src/voice_interaction_marker.c index c5df2ca..6c33885 100644 --- a/components/domain/src/voice_interaction_marker.c +++ b/components/domain/src/voice_interaction_marker.c @@ -87,22 +87,6 @@ static void voice_marker_image_generation_record_success(const char *prompt, portEXIT_CRITICAL(&s_marker_image_gen_lock); } -static void voice_log_text_preview(const char *stage, const char *text) { - if (stage == NULL || text == NULL || text[0] == '\0') { - return; - } - - size_t len = strlen(text); - const int preview = 240; - ESP_LOGI(TAG, - "[stage] %s: len=%u text=%.*s%s", - stage, - (unsigned)len, - preview, - text, - (len > (size_t)preview) ? "..." : ""); -} - static bool voice_is_space_char(char c) { return isspace((unsigned char)c) != 0; } @@ -243,10 +227,6 @@ static void voice_try_preview_marker_png(const voice_image_generation_task_arg_t preview_err, sizeof(preview_err)); if (preview_rc == ESP_OK) { - ESP_LOGI(TAG, - "[stage] marker_image_preview_ok: dialog_id=%s png_bytes=%u", - task_arg->dialog_id[0] != '\0' ? task_arg->dialog_id : "-", - (unsigned)png_len); return; } @@ -255,7 +235,7 @@ static void voice_try_preview_marker_png(const voice_image_generation_task_arg_t } ESP_LOGW(TAG, - "[stage] marker_image_preview_failed: dialog_id=%s rc=0x%x msg=%s", + "marker_image_preview_failed: dialog_id=%s rc=0x%x msg=%s", task_arg->dialog_id[0] != '\0' ? task_arg->dialog_id : "-", (unsigned)preview_rc, preview_err[0] != '\0' ? preview_err : "preview failed"); @@ -277,11 +257,6 @@ static esp_err_t voice_submit_marker_generated_image(const voice_image_generatio uint8_t *raster = NULL; size_t raster_len = 0; char decode_err[128] = {0}; - ESP_LOGI(TAG, - "[stage] marker_image_print_decode_start: dialog_id=%s request_id=%s png_bytes=%u", - task_arg->dialog_id[0] != '\0' ? task_arg->dialog_id : "-", - result->request_id[0] != '\0' ? result->request_id : "-", - (unsigned)result->png_len); esp_err_t decode_rc = raster_tools_convert_png_to_raster_384(result->png, result->png_len, true, @@ -299,19 +274,13 @@ static esp_err_t voice_submit_marker_generated_image(const voice_image_generatio err_len, decode_err[0] != '\0' ? decode_err : "decode generated image failed"); ESP_LOGW(TAG, - "[stage] marker_image_print_decode_failed: dialog_id=%s rc=0x%x msg=%s", + "marker_image_print_decode_failed: dialog_id=%s rc=0x%x msg=%s", task_arg->dialog_id[0] != '\0' ? task_arg->dialog_id : "-", (unsigned)decode_rc, err != NULL && err[0] != '\0' ? err : "decode generated image failed"); return decode_rc; } - ESP_LOGI(TAG, - "[stage] marker_image_print_decode_done: dialog_id=%s raster_size=%ux%u raster_bytes=%u", - task_arg->dialog_id[0] != '\0' ? task_arg->dialog_id : "-", - (unsigned)raster_width, - (unsigned)raster_height, - (unsigned)raster_len); uint32_t job_id = 0; char submit_err[128] = {0}; @@ -332,16 +301,11 @@ static esp_err_t voice_submit_marker_generated_image(const voice_image_generatio err_len, submit_err[0] != '\0' ? submit_err : "submit print job failed"); ESP_LOGW(TAG, - "[stage] marker_image_print_submit_failed: dialog_id=%s rc=0x%x msg=%s", + "marker_image_print_submit_failed: dialog_id=%s rc=0x%x msg=%s", task_arg->dialog_id[0] != '\0' ? task_arg->dialog_id : "-", (unsigned)submit_rc, err != NULL && err[0] != '\0' ? err : "submit print job failed"); } else { - ESP_LOGI(TAG, - "[stage] marker_image_print_submit_ok: dialog_id=%s request_id=%s job_id=%u", - task_arg->dialog_id[0] != '\0' ? task_arg->dialog_id : "-", - result->request_id[0] != '\0' ? result->request_id : "-", - (unsigned)job_id); } free(raster); @@ -370,21 +334,10 @@ static void voice_image_generation_task(void *arg) { printer_status_poll_pause_token_t status_poll_pause_token = 0; char gen_err[160] = {0}; - ESP_LOGI(TAG, - "[stage] marker_image_gen_start: dialog_id=%s prompt_len=%u", - task_arg->dialog_id[0] != '\0' ? task_arg->dialog_id : "-", - (unsigned)strlen(task_arg->prompt)); status_poll_pause_token = printer_protocol_status_poll_pause_acquire(); esp_err_t rc = image_generation_generate_png(&req, &result, gen_err, sizeof(gen_err)); printer_protocol_status_poll_pause_release(&status_poll_pause_token); if (rc == ESP_OK) { - ESP_LOGI(TAG, - "[stage] marker_image_gen_done: dialog_id=%s request_id=%s size=%ux%u png_bytes=%u", - task_arg->dialog_id[0] != '\0' ? task_arg->dialog_id : "-", - result.request_id[0] != '\0' ? result.request_id : "-", - (unsigned)result.width, - (unsigned)result.height, - (unsigned)result.png_len); char submit_err[160] = {0}; esp_err_t submit_rc = voice_submit_marker_generated_image(task_arg, @@ -397,14 +350,14 @@ static void voice_image_generation_task(void *arg) { voice_now_ms()); } else { ESP_LOGW(TAG, - "[stage] marker_image_print_failed: dialog_id=%s rc=0x%x msg=%s", + "marker_image_print_failed: dialog_id=%s rc=0x%x msg=%s", task_arg->dialog_id[0] != '\0' ? task_arg->dialog_id : "-", (unsigned)submit_rc, submit_err[0] != '\0' ? submit_err : "marker image print failed"); } } else { ESP_LOGW(TAG, - "[stage] marker_image_gen_failed: dialog_id=%s rc=0x%x msg=%s", + "marker_image_gen_failed: dialog_id=%s rc=0x%x msg=%s", task_arg->dialog_id[0] != '\0' ? task_arg->dialog_id : "-", (unsigned)rc, gen_err[0] != '\0' ? gen_err : "image generation failed"); @@ -425,30 +378,22 @@ static void voice_schedule_marker_image_generation(const char *prompt, const cha size_t prompt_len = strlen(prompt); if (prompt_len > VOICE_IMAGE_MARKER_PROMPT_MAX_LEN) { ESP_LOGW(TAG, - "[stage] marker_image_gen_skip: prompt too long, len=%u", + "marker_image_gen_skip: prompt too long, len=%u", (unsigned)prompt_len); return; } - uint32_t repeat_remain_ms = 0; if (!voice_marker_image_generation_try_acquire(prompt, dialog_id, voice_now_ms(), - &repeat_remain_ms)) { - if (repeat_remain_ms > 0) { - ESP_LOGI(TAG, - "[stage] marker_image_gen_skip: duplicate prompt suppressed, remain_ms=%u", - (unsigned)repeat_remain_ms); - } else { - ESP_LOGI(TAG, "[stage] marker_image_gen_skip: previous marker task running"); - } + NULL)) { return; } voice_image_generation_task_arg_t *task_arg = (voice_image_generation_task_arg_t *)calloc(1, sizeof(*task_arg)); if (task_arg == NULL) { - ESP_LOGW(TAG, "[stage] marker_image_gen_skip: no memory for task arg"); + ESP_LOGW(TAG, "marker_image_gen_skip: no memory for task arg"); voice_marker_image_generation_release(); return; } @@ -465,16 +410,11 @@ static void voice_schedule_marker_image_generation(const char *prompt, const cha VOICE_IMAGE_GEN_TASK_PRIO, NULL); if (ok != pdPASS) { - ESP_LOGW(TAG, "[stage] marker_image_gen_skip: create task failed"); + ESP_LOGW(TAG, "marker_image_gen_skip: create task failed"); voice_marker_image_generation_release(); free(task_arg); return; } - - ESP_LOGI(TAG, - "[stage] marker_image_gen_queued: dialog_id=%s prompt=%s", - task_arg->dialog_id[0] != '\0' ? task_arg->dialog_id : "-", - task_arg->prompt); } void voice_marker_try_trigger_image_generation(const char *dialog_id, const char *final_text) { @@ -497,17 +437,10 @@ void voice_marker_try_trigger_image_generation(const char *dialog_id, const char templated_prompt, sizeof(templated_prompt)); if (templated_prompt[0] == '\0') { - ESP_LOGW(TAG, "[stage] marker_image_gen_skip: build prompt failed"); + ESP_LOGW(TAG, "marker_image_gen_skip: build prompt failed"); return; } - ESP_LOGI(TAG, - "[stage] marker_image_gen_detected: first_sentence=%s", - first_sentence); - ESP_LOGI(TAG, - "[stage] marker_image_gen_subject: keyword=%s", - marker_subject); - voice_log_text_preview("marker_image_gen_prompt_templated", templated_prompt); voice_schedule_marker_image_generation(templated_prompt, dialog_id); } diff --git a/components/domain/src/voice_interaction_tasks.c b/components/domain/src/voice_interaction_tasks.c index 7ae03f8..1ffccaa 100644 --- a/components/domain/src/voice_interaction_tasks.c +++ b/components/domain/src/voice_interaction_tasks.c @@ -3,26 +3,11 @@ #include #include "esp_audio_enc.h" -#include "esp_log.h" - -static const char *TAG = "voice_interaction"; void voice_uplink_task(void *arg) { (void)arg; - bool low_stack_warned = false; - UBaseType_t start_hwm = uxTaskGetStackHighWaterMark(NULL); - ESP_LOGI(TAG, "[stage] uplink_task_started: stack_hwm_words=%u", (unsigned)start_hwm); - while (true) { - if (!low_stack_warned) { - UBaseType_t hwm = uxTaskGetStackHighWaterMark(NULL); - if (hwm < 256) { - low_stack_warned = true; - ESP_LOGW(TAG, "[stage] uplink_task_low_stack: hwm_words=%u", (unsigned)hwm); - } - } - bool active = false; bool connected = false; bool started = false; @@ -88,7 +73,6 @@ void voice_uplink_task(void *arg) { s_voice.speech_active = false; s_voice.dialog_state = VOICE_DIALOG_STATE_IDLE; s_voice.last_event_ms = voice_now_ms(); - ESP_LOGW(TAG, "[stage] uplink_detected_ws_disconnected"); } voice_unlock(); } @@ -139,7 +123,6 @@ void voice_heartbeat_task(void *arg) { } if (connected && started) { - ESP_LOGI(TAG, "[stage] heartbeat_send"); (void)voice_send_directive("continue-task", "HeartBeat", true); } diff --git a/components/domain/src/voice_interaction_ws.c b/components/domain/src/voice_interaction_ws.c index 6ec0111..be323eb 100644 --- a/components/domain/src/voice_interaction_ws.c +++ b/components/domain/src/voice_interaction_ws.c @@ -135,13 +135,11 @@ static esp_err_t voice_send_text_immediate(const char *text, int len) { s_voice.speech_active = false; s_voice.dialog_state = VOICE_DIALOG_STATE_IDLE; s_voice.last_event_ms = voice_now_ms(); - ESP_LOGW(TAG, "[stage] ws_state_reconciled: transport disconnected"); } voice_unlock(); } if (ws == NULL || !connected || !transport_connected) { - ESP_LOGW(TAG, "[stage] ws_send_text skipped: ws=%p connected=%d len=%d", (void *)ws, connected, len); return ESP_ERR_INVALID_STATE; } @@ -150,10 +148,9 @@ static esp_err_t voice_send_text_immediate(const char *text, int len) { len, pdMS_TO_TICKS(VOICE_WS_SEND_TIMEOUT_MS)); if (ret < 0) { - ESP_LOGW(TAG, "[stage] ws_send_text failed: len=%d", len); + ESP_LOGW(TAG, "ws_send_text failed: len=%d", len); return ESP_FAIL; } - ESP_LOGI(TAG, "[stage] ws_send_text ok: len=%d", len); return ESP_OK; } @@ -209,12 +206,6 @@ esp_err_t voice_send_directive(const char *action, } esp_err_t err = voice_send_text(text, (int)strlen(text)); - ESP_LOGI(TAG, - "[stage] directive: action=%s directive=%s with_dialog_id=%d result=%s", - action, - directive, - with_dialog_id, - esp_err_to_name(err)); cJSON_free(text); return err; } @@ -293,7 +284,7 @@ static void voice_handle_text_chunk(esp_websocket_event_data_t *data) { s_voice.text_agg = (uint8_t *)voice_calloc_prefer_psram(1, (size_t)data->payload_len + 1); if (s_voice.text_agg == NULL) { - ESP_LOGW(TAG, "[stage] text_agg_alloc_failed: len=%d", data->payload_len); + ESP_LOGW(TAG, "text_agg_alloc_failed: len=%d", data->payload_len); return; } s_voice.text_agg_size = (size_t)data->payload_len; @@ -336,7 +327,7 @@ static void voice_handle_binary_chunk(esp_websocket_event_data_t *data) { s_voice.bin_agg = (uint8_t *)voice_malloc_prefer_psram((size_t)data->payload_len); if (s_voice.bin_agg == NULL) { - ESP_LOGW(TAG, "[stage] bin_agg_alloc_failed: len=%d", data->payload_len); + ESP_LOGW(TAG, "bin_agg_alloc_failed: len=%d", data->payload_len); return; } s_voice.bin_agg_size = (size_t)data->payload_len; @@ -374,16 +365,9 @@ void voice_websocket_event_handler(void *handler_args, (void)handler_args; (void)base; - UBaseType_t ws_hwm = uxTaskGetStackHighWaterMark(NULL); - if (!s_voice.ws_low_stack_warned && ws_hwm < 256) { - s_voice.ws_low_stack_warned = true; - ESP_LOGW(TAG, "[stage] ws_task_low_stack: hwm_words=%u", (unsigned)ws_hwm); - } - esp_websocket_event_data_t *data = (esp_websocket_event_data_t *)event_data; switch ((esp_websocket_event_id_t)event_id) { case WEBSOCKET_EVENT_CONNECTED: { - ESP_LOGI(TAG, "[stage] ws_connected"); if (voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { s_voice.ws_connected = true; s_voice.last_event_ms = voice_now_ms(); @@ -396,16 +380,15 @@ void voice_websocket_event_handler(void *handler_args, voice_unlock(); } if (start_msg != NULL) { - esp_err_t send_err = voice_send_text(start_msg, (int)strlen(start_msg)); - ESP_LOGI(TAG, "[stage] start_message_sent: result=%s", esp_err_to_name(send_err)); + (void)voice_send_text(start_msg, (int)strlen(start_msg)); cJSON_free(start_msg); } else { - ESP_LOGE(TAG, "[stage] start_message_build_failed"); + ESP_LOGE(TAG, "start_message_build_failed"); } break; } case WEBSOCKET_EVENT_DISCONNECTED: - ESP_LOGW(TAG, "[stage] ws_disconnected"); + ESP_LOGW(TAG, "ws_disconnected"); if (voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { s_voice.ws_connected = false; s_voice.started = false; @@ -428,7 +411,7 @@ void voice_websocket_event_handler(void *handler_args, } break; case WEBSOCKET_EVENT_ERROR: - ESP_LOGW(TAG, "[stage] ws_error"); + ESP_LOGW(TAG, "ws_error"); if (voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { voice_set_last_error_locked("websocket error"); s_voice.last_event_ms = voice_now_ms(); diff --git a/components/domain/src/voice_interaction_ws_audio.c b/components/domain/src/voice_interaction_ws_audio.c index b99f363..c3fb3b4 100644 --- a/components/domain/src/voice_interaction_ws_audio.c +++ b/components/domain/src/voice_interaction_ws_audio.c @@ -85,7 +85,7 @@ void voice_ws_audio_handle_downstream_packet(const uint8_t *data, size_t len) { } } else { ESP_LOGW(TAG, - "[stage] audio_downstream_write_failed: rc=0x%x err=%s samples=%u", + "audio_downstream_write_failed: rc=0x%x err=%s samples=%u", (unsigned)write_err, audio_err[0] != '\0' ? audio_err : "-", (unsigned)samples); diff --git a/components/domain/src/voice_interaction_ws_protocol.c b/components/domain/src/voice_interaction_ws_protocol.c index 1e710f5..572c0dc 100644 --- a/components/domain/src/voice_interaction_ws_protocol.c +++ b/components/domain/src/voice_interaction_ws_protocol.c @@ -58,16 +58,13 @@ static void voice_response_finalize_task(void *arg) { (void)arg; uint32_t playback_wait_ms = voice_calc_response_finalize_wait_ms(); - ESP_LOGI(TAG, - "[stage] responding_ended_local_playback_wait: timeout_ms=%u", - (unsigned)playback_wait_ms); voice_wait_audio_playback_done(playback_wait_ms, "responding_ended_local_playback"); esp_err_t local_end_rc = voice_send_directive_with_retry("continue-task", "LocalRespondingEnded", true); if (local_end_rc != ESP_OK) { ESP_LOGW(TAG, - "[stage] responding_ended_local_end_failed: rc=0x%x", + "responding_ended_local_end_failed: rc=0x%x", (unsigned)local_end_rc); } @@ -75,7 +72,7 @@ static void voice_response_finalize_task(void *arg) { voice_send_directive_with_retry("finish-task", "Stop", true); if (stop_rc != ESP_OK) { ESP_LOGW(TAG, - "[stage] responding_ended_stop_failed: rc=0x%x", + "responding_ended_stop_failed: rc=0x%x", (unsigned)stop_rc); } @@ -96,7 +93,6 @@ static void voice_schedule_response_finalize(void) { portEXIT_CRITICAL(&s_response_finalize_lock); if (!should_start) { - ESP_LOGI(TAG, "[stage] responding_ended_finalize_skip: task already running"); return; } @@ -110,9 +106,8 @@ static void voice_schedule_response_finalize(void) { portENTER_CRITICAL(&s_response_finalize_lock); s_response_finalize_running = false; portEXIT_CRITICAL(&s_response_finalize_lock); - ESP_LOGW(TAG, "[stage] responding_ended_finalize_start_failed"); + ESP_LOGW(TAG, "responding_ended_finalize_start_failed"); } else { - ESP_LOGI(TAG, "[stage] responding_ended_finalize_task_started"); } } @@ -141,22 +136,6 @@ static bool voice_get_json_bool(cJSON *obj, const char *name, bool *out_value) { return true; } -static void voice_log_final_text(const char *stage, const char *text) { - if (stage == NULL || text == NULL || text[0] == '\0') { - return; - } - - size_t len = strlen(text); - const int preview = 240; - ESP_LOGI(TAG, - "[stage] %s: len=%u text=%.*s%s", - stage, - (unsigned)len, - preview, - text, - (len > (size_t)preview) ? "..." : ""); -} - static void voice_handle_output_event(cJSON *output) { const char *event_name = voice_get_json_str(output, "event"); if (event_name == NULL) { @@ -168,11 +147,6 @@ static void voice_handle_output_event(cJSON *output) { if (strcmp(event_name, "DialogStateChanged") == 0) { state = voice_get_json_str(output, "state"); } - ESP_LOGI(TAG, - "[stage] ws_event_output: event=%s dialog_id=%s state=%s", - event_name, - dialog_id != NULL ? dialog_id : "-", - state != NULL ? state : "-"); bool finished = false; bool has_finished = voice_get_json_bool(output, "finished", &finished); @@ -180,14 +154,11 @@ static void voice_handle_output_event(cJSON *output) { bool should_check_marker_in_first_sentence = false; bool should_try_send_speech = false; if (has_finished && finished) { - if (strcmp(event_name, "SpeechContent") == 0) { - voice_log_final_text("asr_final_text", voice_get_json_str(output, "text")); - } else if (strcmp(event_name, "RespondingContent") == 0) { + if (strcmp(event_name, "RespondingContent") == 0) { const char *final_text = voice_get_json_str(output, "text"); if (final_text == NULL || final_text[0] == '\0') { final_text = voice_get_json_str(output, "spoken"); } - voice_log_final_text("response_final_text", final_text); responding_final_text = final_text; if (responding_final_text != NULL && responding_final_text[0] != '\0' && voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { @@ -211,7 +182,6 @@ static void voice_handle_output_event(cJSON *output) { s_voice.started = true; s_voice.dialog_state = VOICE_DIALOG_STATE_IDLE; s_voice.response_first_sentence_checked = false; - ESP_LOGI(TAG, "[stage] session_started: dialog_id=%s", s_voice.dialog_id); } else if (strcmp(event_name, "DialogStateChanged") == 0) { if (state != NULL) { voice_dialog_state_t prev_state = s_voice.dialog_state; @@ -235,15 +205,8 @@ static void voice_handle_output_event(cJSON *output) { } } } - ESP_LOGI(TAG, - "[stage] dialog_state_changed: state=%s current=%s", - state != NULL ? state : "-", - voice_interaction_dialog_state_str(s_voice.dialog_state)); } else if (strcmp(event_name, "SpeechEnded") == 0) { s_voice.speech_active = false; - ESP_LOGI(TAG, "[stage] speech_ended: stop uplink"); - } else if (strcmp(event_name, "RespondingEnded") == 0) { - ESP_LOGI(TAG, "[stage] responding_ended: schedule_local_playback_finalize"); } else if (strcmp(event_name, "Stopped") == 0) { s_voice.started = false; s_voice.tap_active = false; @@ -251,12 +214,11 @@ static void voice_handle_output_event(cJSON *output) { s_voice.dialog_state = VOICE_DIALOG_STATE_IDLE; s_voice.response_first_sentence_checked = false; should_close_audio = true; - ESP_LOGI(TAG, "[stage] session_stopped_by_server"); } else if (strcmp(event_name, "Error") == 0) { const char *error_msg = voice_get_json_str(output, "error_message"); if (error_msg != NULL) { voice_set_last_error_locked(error_msg); - ESP_LOGW(TAG, "[stage] server_error: %s", error_msg); + ESP_LOGW(TAG, "server_error: %s", error_msg); } s_voice.dialog_state = VOICE_DIALOG_STATE_IDLE; s_voice.tap_active = false; @@ -280,7 +242,7 @@ static void voice_handle_output_event(cJSON *output) { esp_err_t rc = voice_interaction_try_send_speech(speech_err, sizeof(speech_err)); if (rc != ESP_OK && rc != ESP_ERR_INVALID_STATE) { ESP_LOGW(TAG, - "[stage] auto_send_speech_failed: rc=0x%x err=%s", + "auto_send_speech_failed: rc=0x%x err=%s", (unsigned)rc, speech_err[0] != '\0' ? speech_err : "-"); } @@ -320,7 +282,7 @@ void voice_ws_protocol_handle_text_message(const char *text, size_t len) { cJSON *status_msg = cJSON_GetObjectItemCaseSensitive(header, "status_message"); if (cJSON_IsNumber(status_code) && status_code->valueint >= 400) { ESP_LOGW(TAG, - "[stage] ws_header_error: status_code=%d status_message=%s", + "ws_header_error: status_code=%d status_message=%s", status_code->valueint, (cJSON_IsString(status_msg) && status_msg->valuestring != NULL) ? status_msg->valuestring : "-"); if (voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { @@ -338,7 +300,7 @@ void voice_ws_protocol_handle_text_message(const char *text, size_t len) { voice_handle_output_event(output); } else if (header_event != NULL && strcmp(header_event, "task-failed") == 0) { const char *error_msg = voice_get_json_str(header, "error_message"); - ESP_LOGW(TAG, "[stage] ws_task_failed: %s", error_msg != NULL ? error_msg : "task failed"); + ESP_LOGW(TAG, "ws_task_failed: %s", error_msg != NULL ? error_msg : "task failed"); if (voice_lock(VOICE_STATUS_LOCK_TIMEOUT_MS)) { voice_set_last_error_locked(error_msg != NULL ? error_msg : "task failed"); s_voice.started = false; diff --git a/components/platform/CMakeLists.txt b/components/platform/CMakeLists.txt index 3bcb5ca..4123ef4 100644 --- a/components/platform/CMakeLists.txt +++ b/components/platform/CMakeLists.txt @@ -10,7 +10,6 @@ idf_component_register( "src/platform_mic_key.c" "src/voice_audio.c" "src/runtime_policy.c" - "src/runtime_diagnostics.c" INCLUDE_DIRS "include" PRIV_INCLUDE_DIRS diff --git a/components/platform/include/platform.h b/components/platform/include/platform.h index 32e555d..1d17d67 100644 --- a/components/platform/include/platform.h +++ b/components/platform/include/platform.h @@ -150,40 +150,6 @@ uint32_t runtime_policy_image_download_timeout_default_ms(void); uint32_t runtime_policy_image_download_timeout_min_ms(void); uint32_t runtime_policy_image_download_timeout_max_ms(void); -// ---------- runtime_diagnostics ---------- -typedef enum { - RUNTIME_DIAG_COUNTER_LIFECYCLE_START_ATTEMPT = 0, - RUNTIME_DIAG_COUNTER_LIFECYCLE_START_SUCCESS, - RUNTIME_DIAG_COUNTER_LIFECYCLE_START_FAILED, - RUNTIME_DIAG_COUNTER_LIFECYCLE_START_RETRY, - RUNTIME_DIAG_COUNTER_LIFECYCLE_STOP_ATTEMPT, - RUNTIME_DIAG_COUNTER_LIFECYCLE_STOP_SUCCESS, - RUNTIME_DIAG_COUNTER_LIFECYCLE_STOP_FAILED, - RUNTIME_DIAG_COUNTER_WIFI_CONNECT_SUCCESS, - RUNTIME_DIAG_COUNTER_WIFI_CONNECT_FAILED, - RUNTIME_DIAG_COUNTER_WIFI_CONNECT_TIMEOUT, - RUNTIME_DIAG_COUNTER_PRINTER_JOB_SUBMITTED, - RUNTIME_DIAG_COUNTER_PRINTER_JOB_SUCCESS, - RUNTIME_DIAG_COUNTER_PRINTER_JOB_FAILED, - RUNTIME_DIAG_COUNTER_PRINTER_JOB_CANCELED, - RUNTIME_DIAG_COUNTER_IMAGE_GENERATE_ATTEMPT, - RUNTIME_DIAG_COUNTER_IMAGE_GENERATE_SUCCESS, - RUNTIME_DIAG_COUNTER_IMAGE_GENERATE_FAILED, - RUNTIME_DIAG_COUNTER_IMAGE_GENERATE_TIMEOUT, - RUNTIME_DIAG_COUNTER_MAX, -} runtime_diag_counter_t; - -typedef enum { - RUNTIME_DIAG_GAUGE_LIFECYCLE_STATE = 0, - RUNTIME_DIAG_GAUGE_STATUS_POLL_PAUSE_DEPTH, - RUNTIME_DIAG_GAUGE_PRINTER_QUEUE_DEPTH, - RUNTIME_DIAG_GAUGE_MAX, -} runtime_diag_gauge_t; - -void runtime_diag_counter_add(runtime_diag_counter_t counter, uint32_t delta); -void runtime_diag_set_gauge(runtime_diag_gauge_t gauge, int32_t value); -void runtime_diag_record_error(const char *source, esp_err_t code, const char *message); - #ifdef __cplusplus } #endif diff --git a/components/platform/src/runtime_diagnostics.c b/components/platform/src/runtime_diagnostics.c deleted file mode 100644 index eb1670b..0000000 --- a/components/platform/src/runtime_diagnostics.c +++ /dev/null @@ -1,81 +0,0 @@ -#include "platform.h" - -#include - -#include "esp_timer.h" -#include "freertos/FreeRTOS.h" -#include "freertos/semphr.h" - -static SemaphoreHandle_t s_lock; -typedef struct { - uint64_t counters[RUNTIME_DIAG_COUNTER_MAX]; - int32_t gauges[RUNTIME_DIAG_GAUGE_MAX]; - int64_t last_error_ms; - esp_err_t last_error_code; - char last_error_source[32]; - char last_error_message[96]; -} runtime_diag_state_t; - -static runtime_diag_state_t s_snapshot; - -static void runtime_diag_ensure_lock(void) { - if (s_lock == NULL) { - s_lock = xSemaphoreCreateMutex(); - } -} - -void runtime_diag_counter_add(runtime_diag_counter_t counter, uint32_t delta) { - if (counter < 0 || counter >= RUNTIME_DIAG_COUNTER_MAX || delta == 0) { - return; - } - - runtime_diag_ensure_lock(); - if (s_lock == NULL) { - return; - } - - if (xSemaphoreTake(s_lock, pdMS_TO_TICKS(50)) != pdTRUE) { - return; - } - s_snapshot.counters[counter] += delta; - xSemaphoreGive(s_lock); -} - -void runtime_diag_set_gauge(runtime_diag_gauge_t gauge, int32_t value) { - if (gauge < 0 || gauge >= RUNTIME_DIAG_GAUGE_MAX) { - return; - } - - runtime_diag_ensure_lock(); - if (s_lock == NULL) { - return; - } - - if (xSemaphoreTake(s_lock, pdMS_TO_TICKS(50)) != pdTRUE) { - return; - } - s_snapshot.gauges[gauge] = value; - xSemaphoreGive(s_lock); -} - -void runtime_diag_record_error(const char *source, esp_err_t code, const char *message) { - runtime_diag_ensure_lock(); - if (s_lock == NULL) { - return; - } - - if (xSemaphoreTake(s_lock, pdMS_TO_TICKS(100)) != pdTRUE) { - return; - } - - s_snapshot.last_error_ms = esp_timer_get_time() / 1000; - s_snapshot.last_error_code = code; - strlcpy(s_snapshot.last_error_source, - source != NULL ? source : "unknown", - sizeof(s_snapshot.last_error_source)); - strlcpy(s_snapshot.last_error_message, - message != NULL ? message : "unknown", - sizeof(s_snapshot.last_error_message)); - - xSemaphoreGive(s_lock); -} diff --git a/components/platform/src/wifi_manager.c b/components/platform/src/wifi_manager.c index bcab015..cbadc1e 100644 --- a/components/platform/src/wifi_manager.c +++ b/components/platform/src/wifi_manager.c @@ -150,21 +150,6 @@ static esp_err_t wifi_manager_load_credentials(wifi_sta_credentials_t *out_creds return ESP_OK; } -static void wifi_manager_record_connect_result(esp_err_t err, const char *stage) { - if (err == ESP_OK) { - runtime_diag_counter_add(RUNTIME_DIAG_COUNTER_WIFI_CONNECT_SUCCESS, 1); - return; - } - - if (err == ESP_ERR_TIMEOUT) { - runtime_diag_counter_add(RUNTIME_DIAG_COUNTER_WIFI_CONNECT_TIMEOUT, 1); - } else { - runtime_diag_counter_add(RUNTIME_DIAG_COUNTER_WIFI_CONNECT_FAILED, 1); - } - - runtime_diag_record_error("wifi_connect", err, stage); -} - static void wifi_event_handler(void *arg, esp_event_base_t event_base, int32_t event_id, @@ -373,14 +358,12 @@ static esp_err_t wifi_manager_scan_get_handler(httpd_req_t *req) { esp_err_t err = esp_wifi_scan_start(&scan_cfg, true); if (err != ESP_OK) { - runtime_diag_record_error("wifi_scan", err, "esp_wifi_scan_start failed"); return wifi_manager_send_prov_json(req, false, "scan_failed"); } uint16_t ap_count = 0; err = esp_wifi_scan_get_ap_num(&ap_count); if (err != ESP_OK) { - runtime_diag_record_error("wifi_scan", err, "esp_wifi_scan_get_ap_num failed"); return wifi_manager_send_prov_json(req, false, "scan_failed"); } @@ -399,7 +382,6 @@ static esp_err_t wifi_manager_scan_get_handler(httpd_req_t *req) { err = esp_wifi_scan_get_ap_records(&fetch_num, records); if (err != ESP_OK) { free(records); - runtime_diag_record_error("wifi_scan", err, "esp_wifi_scan_get_ap_records failed"); return wifi_manager_send_prov_json(req, false, "scan_failed"); } ap_count = fetch_num; @@ -494,25 +476,21 @@ static esp_err_t wifi_manager_connect_sta(const wifi_sta_credentials_t *creds, b err = esp_wifi_set_mode(keep_softap ? WIFI_MODE_APSTA : WIFI_MODE_STA); if (err != ESP_OK) { - wifi_manager_record_connect_result(err, "set mode failed"); return err; } err = esp_wifi_set_config(WIFI_IF_STA, &wifi_config); if (err != ESP_OK) { - wifi_manager_record_connect_result(err, "set sta config failed"); return err; } err = esp_wifi_start(); if (err != ESP_OK && err != ESP_ERR_INVALID_STATE) { - wifi_manager_record_connect_result(err, "wifi start failed"); return err; } err = esp_wifi_connect(); if (err != ESP_OK && err != ESP_ERR_WIFI_CONN) { - wifi_manager_record_connect_result(err, "wifi connect failed"); return err; } ESP_LOGI(TAG, "trying to connect to SSID:%s", creds->ssid); @@ -533,18 +511,15 @@ static esp_err_t wifi_manager_connect_sta(const wifi_sta_credentials_t *creds, b ESP_LOGW(TAG, "failed to set WIFI_PS_NONE, rc=0x%x", (unsigned)ps_rc); } s_ready = true; - wifi_manager_record_connect_result(ESP_OK, "connect success"); return ESP_OK; } if (bits & WIFI_FAIL_BIT) { ESP_LOGW(TAG, "failed to connect to SSID:%s", creds->ssid); - wifi_manager_record_connect_result(ESP_FAIL, "connect failed after retries"); return ESP_FAIL; } ESP_LOGW(TAG, "Wi-Fi connect timeout, SSID:%s", creds->ssid); - wifi_manager_record_connect_result(ESP_ERR_TIMEOUT, "connect timeout"); return ESP_ERR_TIMEOUT; } @@ -555,6 +530,12 @@ static esp_err_t wifi_manager_prov_index_get_handler(httpd_req_t *req) { return httpd_resp_send(req, (const char *)s_provision_page_start, page_len); } +static esp_err_t wifi_manager_prov_favicon_get_handler(httpd_req_t *req) { + httpd_resp_set_status(req, "204 No Content"); + httpd_resp_set_hdr(req, "Cache-Control", "max-age=86400"); + return httpd_resp_send(req, NULL, 0); +} + static esp_err_t wifi_manager_prov_submit_post_handler(httpd_req_t *req) { if (req->content_len <= 0 || req->content_len >= WIFI_PROV_HTTP_BODY_MAX_LEN) { return wifi_manager_send_prov_json(req, false, "invalid_payload"); @@ -597,7 +578,6 @@ static esp_err_t wifi_manager_prov_submit_post_handler(httpd_req_t *req) { err = wifi_manager_save_credentials(&creds); if (err != ESP_OK) { - runtime_diag_record_error("wifi_provision", err, "save credentials failed"); s_ready = false; (void)esp_wifi_disconnect(); return wifi_manager_send_prov_json(req, false, "save_failed"); @@ -638,6 +618,19 @@ static esp_err_t wifi_manager_start_prov_http_server(void) { return err; } + const httpd_uri_t favicon_uri = { + .uri = "/favicon.ico", + .method = HTTP_GET, + .handler = wifi_manager_prov_favicon_get_handler, + .user_ctx = NULL, + }; + err = httpd_register_uri_handler(s_prov_httpd, &favicon_uri); + if (err != ESP_OK) { + httpd_stop(s_prov_httpd); + s_prov_httpd = NULL; + return err; + } + const httpd_uri_t scan_uri = { .uri = "/scan", .method = HTTP_GET, @@ -790,20 +783,17 @@ esp_err_t wifi_manager_start(void) { esp_err_t err = esp_netif_init(); if (err != ESP_OK && err != ESP_ERR_INVALID_STATE) { - runtime_diag_record_error("wifi_start", err, "esp_netif_init failed"); return err; } err = esp_event_loop_create_default(); if (err != ESP_OK && err != ESP_ERR_INVALID_STATE) { - runtime_diag_record_error("wifi_start", err, "event loop init failed"); return err; } if (s_sta_netif == NULL) { s_sta_netif = esp_netif_create_default_wifi_sta(); if (s_sta_netif == NULL) { - runtime_diag_record_error("wifi_start", ESP_ERR_NO_MEM, "create sta netif failed"); return ESP_ERR_NO_MEM; } } @@ -811,7 +801,6 @@ esp_err_t wifi_manager_start(void) { if (s_ap_netif == NULL) { s_ap_netif = esp_netif_create_default_wifi_ap(); if (s_ap_netif == NULL) { - runtime_diag_record_error("wifi_start", ESP_ERR_NO_MEM, "create ap netif failed"); return ESP_ERR_NO_MEM; } } @@ -819,13 +808,11 @@ esp_err_t wifi_manager_start(void) { wifi_init_config_t cfg = WIFI_INIT_CONFIG_DEFAULT(); err = esp_wifi_init(&cfg); if (err != ESP_OK && err != ESP_ERR_INVALID_STATE) { - runtime_diag_record_error("wifi_start", err, "esp_wifi_init failed"); return err; } err = esp_wifi_set_storage(WIFI_STORAGE_RAM); if (err != ESP_OK) { - runtime_diag_record_error("wifi_start", err, "esp_wifi_set_storage RAM failed"); return err; } @@ -836,7 +823,6 @@ esp_err_t wifi_manager_start(void) { NULL, &s_wifi_event_inst); if (err != ESP_OK) { - runtime_diag_record_error("wifi_start", err, "register WIFI event failed"); return err; } } @@ -848,7 +834,6 @@ esp_err_t wifi_manager_start(void) { NULL, &s_ip_event_inst); if (err != ESP_OK) { - runtime_diag_record_error("wifi_start", err, "register IP event failed"); return err; } } @@ -870,7 +855,6 @@ esp_err_t wifi_manager_start(void) { err = wifi_manager_run_softap_provisioning(); if (err != ESP_OK) { - runtime_diag_record_error("wifi_start", err, "SoftAP provisioning failed"); (void)wifi_manager_stop(); } @@ -949,7 +933,6 @@ esp_err_t wifi_manager_stop(void) { s_started = false; if (first_err != ESP_OK) { - runtime_diag_record_error("wifi_stop", first_err, "wifi stop failed"); } return first_err; diff --git a/sdkconfig.defaults b/sdkconfig.defaults index 0979546..e7486f6 100644 --- a/sdkconfig.defaults +++ b/sdkconfig.defaults @@ -14,6 +14,8 @@ CONFIG_LWIP_TCP_SND_BUF_DEFAULT=57344 CONFIG_LWIP_TCP_WND_DEFAULT=262144 CONFIG_LWIP_TCP_RECVMBOX_SIZE=192 CONFIG_LWIP_TCPIP_RECVMBOX_SIZE=256 +CONFIG_LOG_DEFAULT_LEVEL_WARN=y +CONFIG_BOOTLOADER_LOG_LEVEL_WARN=y CONFIG_TQ_WIFI_PROV_SOFTAP_SSID="TalkingQ-Setup" CONFIG_TQ_WIFI_PROV_SOFTAP_PASSWORD="" CONFIG_TQ_WIFI_PROV_SOFTAP_CHANNEL=1