From c64885462160146a079df648737bdc37ca3fb578 Mon Sep 17 00:00:00 2001 From: jthomp007c Date: Mon, 10 Nov 2025 21:49:27 +0000 Subject: [PATCH 1/2] LLAMA-17349 : extra debug for closing fds Reason for change: Seems we have a stale file descriptor, adding much debug to find it Test Procedure: for dev purposes only Risks: DO NOT MERGE Priority: P1 Signed-off-by: Jason Thomson --- CMakeLists.txt | 6 +++--- src/ble/ctrlm_ble_rcu_interface.cpp | 4 ++++ src/ble/hal/blercu/bluez/blegattcharacteristic.cpp | 2 ++ src/ble/hal/blercu/bluez/blegattnotifypipe.cpp | 2 ++ src/ble/hal/utils/fwimagefile.cpp | 1 + src/ble/hal/utils/hcisocket.cpp | 3 +++ src/ctrlm_ir_controller.cpp | 3 +++ src/input_event/ctrlm_input_event_writer.cpp | 1 + src/voice/ctrlm_voice_obj.cpp | 7 +++++++ src/voice/ctrlm_voice_obj_generic.cpp | 1 + src/voice/ipc/ctrlm_voice_ipc_iarm_thunder.cpp | 2 ++ 11 files changed, 29 insertions(+), 3 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index 61dbb8e0..ab2fa54f 100755 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -223,9 +223,9 @@ if(ENABLE_NETWORKED_STANDBY_MODE) add_compile_definitions(NETWORKED_STANDBY_MODE_ENABLED) endif() -if(FDC_ENABLED) - add_compile_definitions(FDC_ENABLED) -endif() +#if(FDC_ENABLED) +add_compile_definitions(FDC_ENABLED) +#endif() if(IP_ENABLED) add_compile_definitions(CTRLM_NETWORK_IP CTRLM_IP_HAL_LOG_ENABLED) diff --git a/src/ble/ctrlm_ble_rcu_interface.cpp b/src/ble/ctrlm_ble_rcu_interface.cpp index 6abecad1..b9b29424 100644 --- a/src/ble/ctrlm_ble_rcu_interface.cpp +++ b/src/ble/ctrlm_ble_rcu_interface.cpp @@ -1516,6 +1516,7 @@ static int OpenKeyInputDevice(uint64_t ieee_address) return input_fd; } } + XLOGD_INFO("closing fd <%d>", input_fd); close(input_fd); if (NULL != evdev) { libevdev_free(evdev); @@ -1644,6 +1645,7 @@ void *KeyMonitorThread(void *data) if (rcuKeypressFds.end() != rcuKeypressFds.find(device_changed_msg->address)) { if (rcuKeypressFds[device_changed_msg->address] >= 0) { + XLOGD_INFO("closing fd <%d>", rcuKeypressFds[device_changed_msg->address]); close(rcuKeypressFds[device_changed_msg->address]); } rcuKeypressFds.erase(device_changed_msg->address); @@ -1657,6 +1659,7 @@ void *KeyMonitorThread(void *data) if (rcu.second >= 0) { XLOGD_INFO("Closing key input device for RCU <%s> so key monitor thread can reopen...", rcu.first.toString().c_str()); + XLOGD_INFO("closing fd <%d>", rcu.second); close(rcu.second); rcu.second = -1; } @@ -1675,6 +1678,7 @@ void *KeyMonitorThread(void *data) for (auto &rcu : rcuKeypressFds) { if (rcu.second >= 0) { + XLOGD_INFO("closing fd <%d>", rcu.second); close(rcu.second); rcu.second = -1; } diff --git a/src/ble/hal/blercu/bluez/blegattcharacteristic.cpp b/src/ble/hal/blercu/bluez/blegattcharacteristic.cpp index e79849c9..1afeacc1 100644 --- a/src/ble/hal/blercu/bluez/blegattcharacteristic.cpp +++ b/src/ble/hal/blercu/bluez/blegattcharacteristic.cpp @@ -573,6 +573,7 @@ void BleGattCharacteristicBluez::enablePipeNotifications(const Slot", pipeFd); close(pipeFd); XLOGD_ERROR("invalid MTU size on the notify pipe (%hd bytes)", mtu); @@ -589,6 +590,7 @@ void BleGattCharacteristicBluez::enablePipeNotifications(const Slot(pipeFd, mtu, m_uuid); //BleGattNotifyPipe dups the pipe, so close the original here. + XLOGD_INFO("closing fd <%d>", pipeFd); close(pipeFd); if (!m_notifyPipe || !m_notifyPipe->isValid()) { diff --git a/src/ble/hal/blercu/bluez/blegattnotifypipe.cpp b/src/ble/hal/blercu/bluez/blegattnotifypipe.cpp index 6f54af37..2bade0b3 100644 --- a/src/ble/hal/blercu/bluez/blegattnotifypipe.cpp +++ b/src/ble/hal/blercu/bluez/blegattnotifypipe.cpp @@ -221,9 +221,11 @@ void BleGattNotifyPipe::shutdown() ThreadJoin(&m_notifyThread, 2); } if (FD_SIGNAL(m_exitEventFds) > -1) { + XLOGD_INFO("closing fd <%d>", FD_SIGNAL(m_exitEventFds)); close(FD_SIGNAL(m_exitEventFds)); } if (FD_RECV(m_exitEventFds) > -1) { + XLOGD_INFO("closing fd <%d>", FD_RECV(m_exitEventFds)); close(FD_RECV(m_exitEventFds)); } diff --git a/src/ble/hal/utils/fwimagefile.cpp b/src/ble/hal/utils/fwimagefile.cpp index 8f7454cd..f59cd6b8 100644 --- a/src/ble/hal/utils/fwimagefile.cpp +++ b/src/ble/hal/utils/fwimagefile.cpp @@ -94,6 +94,7 @@ FwImageFile::FwImageFile(const string &filePath) // check the file header / contents m_valid = checkFile(); if (!m_valid) { + XLOGD_INFO("closing fd <%d>", m_fd); close(m_fd); m_fd = -1; } diff --git a/src/ble/hal/utils/hcisocket.cpp b/src/ble/hal/utils/hcisocket.cpp index 4c96b72f..0b57851e 100644 --- a/src/ble/hal/utils/hcisocket.cpp +++ b/src/ble/hal/utils/hcisocket.cpp @@ -434,6 +434,7 @@ HciSocketImpl::HciSocketImpl(uint hciDeviceId, int netNsFd) // setup the hci socket if (!setSocketFilter(sockFd) || !bindSocket(sockFd, hciDeviceId)) { + XLOGD_INFO("closing <%d>", sockFd); close(sockFd); return; } @@ -462,9 +463,11 @@ HciSocketImpl::~HciSocketImpl() ctrlm_utils_thread_join(&m_socketThread, 2); } if (FD_SIGNAL(m_exitEventFds) > -1) { + XLOGD_INFO("closing <%d>", FD_SIGNAL(m_exitEventFds)); close(FD_SIGNAL(m_exitEventFds)); } if (FD_RECV(m_exitEventFds) > -1) { + XLOGD_INFO("closing <%d>", FD_RECV(m_exitEventFds)); close(FD_RECV(m_exitEventFds)); } diff --git a/src/ctrlm_ir_controller.cpp b/src/ctrlm_ir_controller.cpp index db978c7c..70e1539d 100644 --- a/src/ctrlm_ir_controller.cpp +++ b/src/ctrlm_ir_controller.cpp @@ -348,6 +348,7 @@ static int ctrlm_ir_open_key_input_device(vector names) { } } } + XLOGD_INFO("closing fd <%d>", input_fd); close(input_fd); if (NULL != evdev) { libevdev_free(evdev); @@ -468,6 +469,7 @@ void* ctrlm_ir_key_monitor_thread(void *data) { XLOGD_ERROR("error = <%d>, <%s>, closing and reopening device...", errsv, strerror(errsv)); input_device_retry_cnt = 0; if (input_device_fd >= 0) { + XLOGD_INFO("closing fd <%d>", input_device_fd); close(input_device_fd); input_device_fd = -1; } @@ -521,6 +523,7 @@ void* ctrlm_ir_key_monitor_thread(void *data) { ctrlm_timeout_destroy(&g_retry_input_open_timer_tag); if (input_device_fd >= 0) { + XLOGD_INFO("closing fd <%d>", input_device_fd); close(input_device_fd); } return NULL; diff --git a/src/input_event/ctrlm_input_event_writer.cpp b/src/input_event/ctrlm_input_event_writer.cpp index c463a78e..3347ce69 100644 --- a/src/input_event/ctrlm_input_event_writer.cpp +++ b/src/input_event/ctrlm_input_event_writer.cpp @@ -73,6 +73,7 @@ void ctrlm_input_event_writer::shutdown(void) { return; } ioctl(fd_, UI_DEV_DESTROY); + XLOGD_INFO("closing fd <%d>", fd_); close(fd_); fd_ = -1; initialized_ = false; diff --git a/src/voice/ctrlm_voice_obj.cpp b/src/voice/ctrlm_voice_obj.cpp index 2491ae9a..c8c7ee13 100644 --- a/src/voice/ctrlm_voice_obj.cpp +++ b/src/voice/ctrlm_voice_obj.cpp @@ -284,10 +284,12 @@ ctrlm_voice_t::~ctrlm_voice_t() { for(uint32_t group = VOICE_SESSION_GROUP_DEFAULT; group < VOICE_SESSION_GROUP_QTY; group++) { ctrlm_voice_session_t *session = &this->voice_session[group]; if(session->audio_pipe[PIPE_READ] >= 0) { + XLOGD_INFO("closing fd <%d>", session->audio_pipe[PIPE_READ]); close(session->audio_pipe[PIPE_READ]); session->audio_pipe[PIPE_READ] = -1; } if(session->audio_pipe[PIPE_WRITE] >= 0) { + XLOGD_INFO("closing fd <%d>", session->audio_pipe[PIPE_WRITE]); close(session->audio_pipe[PIPE_WRITE]); session->audio_pipe[PIPE_WRITE] = -1; } @@ -1489,7 +1491,9 @@ ctrlm_voice_session_response_status_t ctrlm_voice_t::voice_session_req(ctrlm_net XLOGD_TELEMETRY("Failed to acquire voice session"); this->voice_session_notify_abort(network_id, controller_id, 0, CTRLM_VOICE_SESSION_ABORT_REASON_BUSY); if(create_pipe) { + XLOGD_INFO("closing fd <%d>", fds[PIPE_WRITE]); close(fds[PIPE_WRITE]); + XLOGD_INFO("closing fd <%d>", fds[PIPE_READ]); close(fds[PIPE_READ]); } return(VOICE_SESSION_RESPONSE_BUSY); @@ -1803,11 +1807,13 @@ bool ctrlm_voice_t::voice_session_data(ctrlm_network_id_t network_id, ctrlm_cont } else { if(session->audio_pipe[PIPE_READ] >= 0) { XLOGD_INFO("Closing previous pipe - READ fd <%d>", session->audio_pipe[PIPE_READ]); + XLOGD_INFO("closing fd <%d>", session->audio_pipe[PIPE_READ]); close(session->audio_pipe[PIPE_READ]); session->audio_pipe[PIPE_READ] = -1; } if(session->audio_pipe[PIPE_WRITE] >= 0) { XLOGD_INFO("Closing previous pipe - WRITE fd <%d>", session->audio_pipe[PIPE_WRITE]); + XLOGD_INFO("closing fd <%d>", session->audio_pipe[PIPE_WRITE]); close(session->audio_pipe[PIPE_WRITE]); session->audio_pipe[PIPE_WRITE] = -1; } @@ -1925,6 +1931,7 @@ void ctrlm_voice_t::voice_session_end(ctrlm_voice_session_t *session, ctrlm_voic if(session->audio_pipe[PIPE_WRITE] >= 0) { XLOGD_INFO("Close write pipe - fd <%d>", session->audio_pipe[PIPE_WRITE]); + XLOGD_INFO("closing fd <%d>", session->audio_pipe[PIPE_WRITE]); close(session->audio_pipe[PIPE_WRITE]); session->audio_pipe[PIPE_WRITE] = -1; } diff --git a/src/voice/ctrlm_voice_obj_generic.cpp b/src/voice/ctrlm_voice_obj_generic.cpp index 340b295d..977bf04a 100644 --- a/src/voice/ctrlm_voice_obj_generic.cpp +++ b/src/voice/ctrlm_voice_obj_generic.cpp @@ -123,6 +123,7 @@ void ctrlm_voice_generic_t::voice_sdk_close() { if(session->audio_pipe[PIPE_WRITE] >= 0) { // close the audio input source XLOGD_WARN("Closing audio write pipe <%d>", session->audio_pipe[PIPE_WRITE]); + XLOGD_INFO("closing fd <%d>", session->audio_pipe[PIPE_WRITE]); close(session->audio_pipe[PIPE_WRITE]); session->audio_pipe[PIPE_WRITE] = -1; } diff --git a/src/voice/ipc/ctrlm_voice_ipc_iarm_thunder.cpp b/src/voice/ipc/ctrlm_voice_ipc_iarm_thunder.cpp index ad9cc5db..a45a0a17 100644 --- a/src/voice/ipc/ctrlm_voice_ipc_iarm_thunder.cpp +++ b/src/voice/ipc/ctrlm_voice_ipc_iarm_thunder.cpp @@ -736,6 +736,7 @@ IARM_Result_t ctrlm_voice_ipc_iarm_thunder_t::voice_session_request(void *data) XLOGD_ERROR("zero length audio data <%s>", str_audio_file.c_str()); result = false; } + XLOGD_INFO("closing fd <%d>", audio_fd); close(audio_fd); } } @@ -765,6 +766,7 @@ IARM_Result_t ctrlm_voice_ipc_iarm_thunder_t::voice_session_request(void *data) voice_status != VOICE_SESSION_RESPONSE_AVAILABLE_PAR_VOICE) { XLOGD_ERROR("Failed opening voice session <%s>", ctrlm_voice_session_response_status_str(voice_status)); if(fd >= 0) { + XLOGD_INFO("closing fd <%d>", fd); close(fd); } result = false; From 7fc038c1afdd5d22d6f9a71252d5d6c0e27553c7 Mon Sep 17 00:00:00 2001 From: jthomp007c Date: Mon, 10 Nov 2025 21:49:27 +0000 Subject: [PATCH 2/2] LLAMA-17349 : extra debug for closing fds Reason for change: Seems we have a stale file descriptor, adding much debug to find it Test Procedure: for dev purposes only Risks: DO NOT MERGE Priority: P1 Signed-off-by: Jason Thomson --- src/ble/ctrlm_ble_rcu_interface.cpp | 3 ++- src/ble/hal/blercu/bluez/blegattnotifypipe.cpp | 1 + src/ble/hal/utils/hcisocket.cpp | 3 ++- src/ctrlm_ir_controller.cpp | 2 ++ src/factory/ctrlmf_ws.c | 2 ++ 5 files changed, 9 insertions(+), 2 deletions(-) diff --git a/src/ble/ctrlm_ble_rcu_interface.cpp b/src/ble/ctrlm_ble_rcu_interface.cpp index b9b29424..993622e1 100644 --- a/src/ble/ctrlm_ble_rcu_interface.cpp +++ b/src/ble/ctrlm_ble_rcu_interface.cpp @@ -21,7 +21,7 @@ #include "ctrlm_ble_rcu_interface.h" #include "ctrlm_ble_utils.h" #include "ctrlm_voice_obj.h" - +#include #define CTRLM_BLE_KEY_MSG_QUEUE_MSG_MAX (10) #define CTRLM_BLE_KEY_MSG_QUEUE_MSG_SIZE_MAX (sizeof(ctrlm_ble_key_queue_device_changed_msg_t)) @@ -1600,6 +1600,7 @@ void *KeyMonitorThread(void *data) sem_post(&metadata->m_keyThreadSem); XLOGD_INFO("Enter main loop for new key monitor thread"); + XLOGD_INFO("TID <%d>", (int)gettid()); do { // Needs to be reinitialized before each call to select() because select() will modify these variables FD_ZERO(&rfds); diff --git a/src/ble/hal/blercu/bluez/blegattnotifypipe.cpp b/src/ble/hal/blercu/bluez/blegattnotifypipe.cpp index 2bade0b3..77f5a07c 100644 --- a/src/ble/hal/blercu/bluez/blegattnotifypipe.cpp +++ b/src/ble/hal/blercu/bluez/blegattnotifypipe.cpp @@ -312,6 +312,7 @@ void *NotifyThread(void *data) XLOGD_INFO("Enter main loop for bluez notification pipe (%d) for %s", notifyPipe->m_pipeFd, notifyPipe->m_uuid.toString().c_str()); + XLOGD_INFO("TID <%d>", (int)gettid()); do { // Needs to be reinitialized before each call to select() because select() will modify these variables FD_ZERO(&rfds); diff --git a/src/ble/hal/utils/hcisocket.cpp b/src/ble/hal/utils/hcisocket.cpp index 0b57851e..5da9122d 100644 --- a/src/ble/hal/utils/hcisocket.cpp +++ b/src/ble/hal/utils/hcisocket.cpp @@ -31,7 +31,7 @@ // #include "linux/containerhelpers.h" #include "ctrlm_log_ble.h" - +#include using namespace std; @@ -1061,6 +1061,7 @@ void *SocketThread(void *data) sem_post(&socketImpl->m_socketThreadSem); XLOGD_INFO("Enter main loop for HCI socket thread"); + XLOGD_INFO("TID <%d>", (int)gettid()); do { if (FD_RECV(socketImpl->m_exitEventFds) < 0 || socketImpl->m_hciSocket < 0) { XLOGD_ERROR("one of the fds is invalid, exiting thread"); diff --git a/src/ctrlm_ir_controller.cpp b/src/ctrlm_ir_controller.cpp index 70e1539d..65329f73 100644 --- a/src/ctrlm_ir_controller.cpp +++ b/src/ctrlm_ir_controller.cpp @@ -28,6 +28,7 @@ #include "ctrlm_config_types.h" #include "ctrlm_config_default.h" #include "ctrlm_network.h" +#include "unistd.h" #include @@ -377,6 +378,7 @@ static gboolean ctrlm_ir_retry_input_open(gpointer user_data) { void* ctrlm_ir_key_monitor_thread(void *data) { XLOGD_INFO("Enter..."); + XLOGD_INFO("TID <%d>", (int)gettid()); ctrlm_ir_controller_t *ir_controller = (ctrlm_ir_controller_t *)data; diff --git a/src/factory/ctrlmf_ws.c b/src/factory/ctrlmf_ws.c index ea175c06..f3ea51d2 100644 --- a/src/factory/ctrlmf_ws.c +++ b/src/factory/ctrlmf_ws.c @@ -131,6 +131,8 @@ void *ctrlmf_ws_main(void *param) { return(NULL); } ctrlmf_ws_thread_state_t state; + + XLOGD_INFO("TID <%d>", (int)gettid()); state.audio_frames = params.audio_frames; state.audio_frame_qty = params.audio_frame_qty;