LLAMA-17349 : extra debug for closing fds

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)

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 <unistd.h>
 
 #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))
@@ -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);
@@ -1599,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);
@@ -1644,6 +1646,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 +1660,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 +1679,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;
                             }

src/ble/hal/blercu/bluez/blegattcharacteristic.cpp

@@ -573,6 +573,7 @@ void BleGattCharacteristicBluez::enablePipeNotifications(const Slot<const std::v
             }
 
             if (mtu < 23) {
+                XLOGD_INFO("closing fd <%d>", pipeFd);
                 close(pipeFd);
 
                 XLOGD_ERROR("invalid MTU size on the notify pipe (%hd bytes)", mtu);
@@ -589,6 +590,7 @@ void BleGattCharacteristicBluez::enablePipeNotifications(const Slot<const std::v
             m_notifyPipe = make_shared<BleGattNotifyPipe>(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()) {

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));
     }
 
@@ -310,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);

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;
     }

src/ble/hal/utils/hcisocket.cpp

@@ -31,7 +31,7 @@
 // #include "linux/containerhelpers.h"
 
 #include "ctrlm_log_ble.h"
-
+#include <unistd.h>
 
 
 using namespace std;
@@ -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));
     }
 
@@ -1058,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");

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 <fcntl.h>
 
@@ -348,6 +349,7 @@ static int ctrlm_ir_open_key_input_device(vector<string> names) {
                         }
                      }
                   }
+                  XLOGD_INFO("closing fd <%d>", input_fd);
                   close(input_fd);
                   if (NULL != evdev) {
                      libevdev_free(evdev);
@@ -376,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;
 
@@ -468,6 +471,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 +525,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;

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;

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;

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;
     }

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;
             }

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;