From 4518662763987203f23642f0051b62e575683e05 Mon Sep 17 00:00:00 2001 From: Deepthi Date: Fri, 16 Oct 2026 09:39:20 +0000 Subject: [PATCH 01/10] Implement per-process Unix datagram socket replacing UDP broadcast Signed-off-by: Deepthi --- docs/API_DOCUMENTATION.md | 22 +++--- docs/QUICK_REFERENCE.md | 18 +++-- docs/TROUBLESHOOTING.md | 23 +++--- src/include/rdk_dynamic_logger.h | 3 +- src/rdk_dynamic_logger.c | 97 ++++++++++++++++++----- unittests/rdkLoggerDynamic.cpp | 96 +++++++++++----------- utils/rdklogctrl.c | 131 +++++++++++++++++++++++-------- 7 files changed, 263 insertions(+), 127 deletions(-) diff --git a/docs/API_DOCUMENTATION.md b/docs/API_DOCUMENTATION.md index 3b3368eb..5a07c1bb 100644 --- a/docs/API_DOCUMENTATION.md +++ b/docs/API_DOCUMENTATION.md @@ -328,21 +328,22 @@ The `rdklogctrl` command-line utility allows runtime modification of log levels: ```bash # Set log level for a module -rdklogctrl +rdklogctrl # Examples -rdklogctrl myapp LOG.RDK.NETWORK DEBUG -rdklogctrl receiver LOG.RDK.AUDIO INFO -rdklogctrl player LOG.RDK.VIDEO ERROR +rdklogctrl "$(pidof -s myapp)" LOG.RDK.NETWORK DEBUG +rdklogctrl "$(pidof -s receiver)" LOG.RDK.AUDIO INFO +rdklogctrl "$(pidof -s player)" LOG.RDK.VIDEO ERROR # Disable specific log level (using ~ prefix) -rdklogctrl myapp LOG.RDK.NETWORK ~DEBUG +rdklogctrl "$(pidof -s myapp)" LOG.RDK.NETWORK ~DEBUG ``` **Parameters**: -- `app_name`: Process name as shown by `ps` command +- `pid`: Process ID of the target application; `rdklogctrl` resolves its name from `/proc` - `module_name`: Module name (must match debug.ini format) - `log_level`: FATAL, ERROR, WARN, NOTICE, INFO, DEBUG, TRACE, NONE +Each logger listens on `/tmp/.logger/.` using a Unix datagram socket restricted to the process owner. ### Programmatic Runtime Control @@ -401,19 +402,19 @@ For backward compatibility with legacy RDK components: **Usage**: ```bash -rdklogctrl +rdklogctrl ``` **Examples**: ```bash # Enable debug logging for network module -rdklogctrl receiver LOG.RDK.NETWORK DEBUG +rdklogctrl "$(pidof -s receiver)" LOG.RDK.NETWORK DEBUG # Disable all logging for test module -rdklogctrl myapp LOG.RDK.TEST NONE +rdklogctrl "$(pidof -s myapp)" LOG.RDK.TEST NONE # Turn off only error logs (keep others) -rdklogctrl player LOG.RDK.AUDIO ~ERROR +rdklogctrl "$(pidof -s player)" LOG.RDK.AUDIO ~ERROR ``` ### rdklogmilestone - Milestone Utility @@ -762,4 +763,3 @@ int main() { --- **Note**: This documentation covers RDK Logger API version as implemented in the current codebase. For the most up-to-date information, refer to the source code and header files. - diff --git a/docs/QUICK_REFERENCE.md b/docs/QUICK_REFERENCE.md index d2ab5d36..284da69b 100644 --- a/docs/QUICK_REFERENCE.md +++ b/docs/QUICK_REFERENCE.md @@ -74,17 +74,21 @@ LOG.RDK.TEST=NONE ## Runtime Control ### rdklogctrl Command +Socket URI: `unix:///tmp/.logger/.` ```bash # Set log level for module -rdklogctrl +rdklogctrl + +# Example for PID 1122 +rdklogctrl 1122 LOG.RDK.RTMESS DEBUG # Examples -rdklogctrl myapp LOG.RDK.NETWORK DEBUG -rdklogctrl receiver LOG.RDK.AUDIO INFO -rdklogctrl player LOG.RDK.VIDEO ERROR +rdklogctrl "$(pidof -s myapp)" LOG.RDK.NETWORK DEBUG +rdklogctrl "$(pidof -s receiver)" LOG.RDK.AUDIO INFO +rdklogctrl "$(pidof -s player)" LOG.RDK.VIDEO ERROR # Disable specific level (~ prefix) -rdklogctrl myapp LOG.RDK.NETWORK ~DEBUG +rdklogctrl "$(pidof -s myapp)" LOG.RDK.NETWORK ~DEBUG # Available levels FATAL ERROR WARN NOTICE INFO DEBUG TRACE NONE @@ -307,7 +311,7 @@ int main() { APP_PID=$! # Change log level -rdklogctrl myapp LOG.RDK.TEST DEBUG +rdklogctrl "$APP_PID" LOG.RDK.TEST DEBUG # Check if change took effect (application should show more logs) @@ -333,4 +337,4 @@ kill $APP_PID - `rdklogctrl` - Runtime log control utility - `rdklogmilestone` - Milestone logging utility -This quick reference provides the most commonly needed information for day-to-day RDK Logger usage. \ No newline at end of file +This quick reference provides the most commonly needed information for day-to-day RDK Logger usage. diff --git a/docs/TROUBLESHOOTING.md b/docs/TROUBLESHOOTING.md index 259fb529..b5c144aa 100644 --- a/docs/TROUBLESHOOTING.md +++ b/docs/TROUBLESHOOTING.md @@ -135,7 +135,7 @@ find /etc -name "*log4c*" 2>/dev/null **Problem:** Changes don't take effect ```bash # Command appears to work but no change -rdklogctrl myapp LOG.RDK.NETWORK DEBUG +rdklogctrl "$(pidof -s myapp)" LOG.RDK.NETWORK DEBUG ``` **Debugging:** @@ -143,10 +143,10 @@ rdklogctrl myapp LOG.RDK.NETWORK DEBUG **Step 1: Verify process name** ```bash # Check exact process name -ps aux | grep myapp +pgrep -o myapp # Use exact name from ps output -rdklogctrl "myapp_process_name" LOG.RDK.NETWORK DEBUG +rdklogctrl "$(pidof -s myapp)" LOG.RDK.NETWORK DEBUG ``` **Step 2: Check process accessibility** @@ -155,13 +155,13 @@ rdklogctrl "myapp_process_name" LOG.RDK.NETWORK DEBUG ps -ef | grep myapp # Check if process accepts socket connections -netstat -tlnp | grep :12035 +ss -xlp | grep '/tmp/.logger/' ``` **Step 3: Test with simple module** ```bash # Try with a known module first -rdklogctrl myapp LOG.RDK.DEFAULT INFO +rdklogctrl "$(pidof -s myapp)" LOG.RDK.DEFAULT INFO ``` #### Issue: Dynamic logging not persistent @@ -486,14 +486,11 @@ void debug_config_loading() { #### Network Debugging for rdklogctrl ```bash -# Check if dynamic logger port is listening -netstat -tlnp | grep :12035 +# List per-process dynamic logger sockets +ss -xlpn | grep '/tmp/.logger/' -# Test socket connection -telnet localhost 12035 - -# Monitor network traffic -tcpdump -i lo port 12035 +# Verify socket ownership and permissions +ls -l /tmp/.logger ``` ### Quick Reference Checklist @@ -511,4 +508,4 @@ When troubleshooting RDK Logger issues: 9. **✓ Use debugging tools (valgrind, gdb, strace)** 10. **✓ Enable log4c debugging if needed** -This troubleshooting guide should help resolve most common issues with RDK Logger implementation and usage. \ No newline at end of file +This troubleshooting guide should help resolve most common issues with RDK Logger implementation and usage. diff --git a/src/include/rdk_dynamic_logger.h b/src/include/rdk_dynamic_logger.h index d5e016a8..53d4b572 100644 --- a/src/include/rdk_dynamic_logger.h +++ b/src/include/rdk_dynamic_logger.h @@ -28,9 +28,8 @@ #define RDK_DYNAMIC_LOG_COMPONENT_NAME_MAX 64 typedef struct { - // Adjusting sizes for legacy UDP datagram limits + // The encoded wire packet remains capped by RDK_DYNAMIC_LOG_PACKET_MAX. uint8_t signature[4]; - uint8_t message_length; uint8_t log_level; char app_name[RDK_DYNAMIC_LOG_APP_NAME_MAX + 1]; char component_name[RDK_DYNAMIC_LOG_COMPONENT_NAME_MAX + 1]; diff --git a/src/rdk_dynamic_logger.c b/src/rdk_dynamic_logger.c index 666b73f7..3f21139b 100644 --- a/src/rdk_dynamic_logger.c +++ b/src/rdk_dynamic_logger.c @@ -22,25 +22,52 @@ */ #include +#include #include -#include #include #include #include #include +#include #include +#include +#include #include "rdk_dynamic_logger.h" #include "rdk_debug_priv.h" -#define DL_PORT 12035 +#define DL_SOCKET_DIR "/tmp/.logger" #define DL_SIGNATURE "COMC" #define DL_SIGNATURE_LEN 4 static int g_dl_socket = -1; +static char g_dl_socket_path[sizeof(((struct sockaddr_un *)0)->sun_path)]; +static pid_t g_dl_socket_pid = -1; static pthread_mutex_t g_dl_request_mutex = PTHREAD_MUTEX_INITIALIZER; extern char *__progname; +static int rdk_dyn_log_make_socket_path(char *path, size_t path_size) +{ + struct stat dir_stat; + int length; + + if (__progname == NULL || __progname[0] == '\0') + return -1; + + if (mkdir(DL_SOCKET_DIR, 01777) == -1 && errno != EEXIST) + return -1; + if (lstat(DL_SOCKET_DIR, &dir_stat) == -1 || !S_ISDIR(dir_stat.st_mode) || + (dir_stat.st_uid != 0 && dir_stat.st_uid != geteuid()) || + ((dir_stat.st_mode & S_IWOTH) && !(dir_stat.st_mode & S_ISVTX))) + return -1; + + length = snprintf(path, path_size, DL_SOCKET_DIR "/%s.%ld", __progname, (long)getpid()); + if (length < 0 || (size_t)length >= path_size || strchr(__progname, '/') != NULL) + return -1; + + return 0; +} + static char * rdk_dyn_log_logLevelToString(rdk_LogLevel log_level) { switch(log_level){ @@ -86,7 +113,7 @@ void rdk_dyn_log_process_pending_request() { unsigned char packet[RDK_DYNAMIC_LOG_PACKET_MAX]; rdk_dynamic_log_message_t message = {0}; - struct sockaddr_in sender_addr; + struct sockaddr_un sender_addr; struct timeval tv; int numbytes, ret; size_t app_len, comp_len, comp_len_offset; @@ -96,11 +123,19 @@ void rdk_dyn_log_process_pending_request() if (pthread_mutex_trylock(&g_dl_request_mutex) != 0) return; + /* After fork/daemonize the inherited socket is named after the parent PID; rebind for ours. */ + if (g_dl_socket != -1 && g_dl_socket_pid != getpid()) { + close(g_dl_socket); + g_dl_socket = -1; + pthread_mutex_unlock(&g_dl_request_mutex); + rdk_dyn_log_init(); + return; + } + if(-1 == g_dl_socket) { pthread_mutex_unlock(&g_dl_request_mutex); return; } - memset(&sender_addr,0,sizeof(sender_addr)); while(1) { FD_ZERO(&rfds); FD_SET(g_dl_socket, &rfds); @@ -123,8 +158,7 @@ void rdk_dyn_log_process_pending_request() return; } - if (strcmp("127.0.0.1", inet_ntoa(sender_addr.sin_addr)) != 0 || - numbytes > (int)sizeof(packet) || + if (numbytes > (int)sizeof(packet) || numbytes < DL_SIGNATURE_LEN + 4 || (size_t)numbytes != (size_t)packet[DL_SIGNATURE_LEN] + DL_SIGNATURE_LEN + 1 || memcmp(packet, DL_SIGNATURE, DL_SIGNATURE_LEN) != 0) @@ -144,7 +178,6 @@ void rdk_dyn_log_process_pending_request() memset(&message, 0, sizeof(message)); memcpy(message.signature, packet, DL_SIGNATURE_LEN); - message.message_length = packet[DL_SIGNATURE_LEN]; message.log_level = packet[DL_SIGNATURE_LEN + 1]; memcpy(message.app_name, packet + DL_SIGNATURE_LEN + 3, app_len); memcpy(message.component_name, packet + comp_len_offset + 1, comp_len); @@ -155,38 +188,64 @@ void rdk_dyn_log_process_pending_request() void rdk_dyn_log_init() { - struct sockaddr_in my_addr; - int opt = 1; + struct sockaddr_un my_addr; + struct stat socket_stat; + socklen_t addr_len; + mode_t previous_umask; + int bind_result; pthread_mutex_lock(&g_dl_request_mutex); - if ((g_dl_socket = socket(AF_INET, SOCK_DGRAM, 0)) == -1) { + if (rdk_dyn_log_make_socket_path(g_dl_socket_path, sizeof(g_dl_socket_path)) != 0) { + fprintf(stderr, "%s() invalid or unavailable socket directory/path\n", __func__); + pthread_mutex_unlock(&g_dl_request_mutex); + return; + } + + if (lstat(g_dl_socket_path, &socket_stat) == 0) { + if (!S_ISSOCK(socket_stat.st_mode) || socket_stat.st_uid != geteuid() || + unlink(g_dl_socket_path) == -1) { + fprintf(stderr, "%s() socket path is already in use\n", __func__); + pthread_mutex_unlock(&g_dl_request_mutex); + return; + } + } else if (errno != ENOENT) { + fprintf(stderr, "%s() cannot inspect socket path: %s\n", __func__, strerror(errno)); + pthread_mutex_unlock(&g_dl_request_mutex); + return; + } + + if ((g_dl_socket = socket(AF_UNIX, SOCK_DGRAM, 0)) == -1) { fprintf(stderr, "%s() Socket creation failed. %s\n",__func__,strerror(errno)); pthread_mutex_unlock(&g_dl_request_mutex); return; } memset(&my_addr,0,sizeof(my_addr)); - my_addr.sin_family = AF_INET; - my_addr.sin_port = htons(DL_PORT); - my_addr.sin_addr.s_addr = inet_addr("127.255.255.255"); + my_addr.sun_family = AF_UNIX; + memcpy(my_addr.sun_path, g_dl_socket_path, strlen(g_dl_socket_path) + 1); + addr_len = (socklen_t)(offsetof(struct sockaddr_un, sun_path) + strlen(my_addr.sun_path) + 1); - if (-1 == setsockopt(g_dl_socket,SOL_SOCKET,SO_REUSEADDR,&opt,sizeof(int))) { - fprintf(stderr, "%s() setsockopt error %s\n",__func__,strerror(errno)); + previous_umask = umask(0177); + bind_result = bind(g_dl_socket, (struct sockaddr *)&my_addr, addr_len); + umask(previous_umask); + if (-1 == bind_result) { + fprintf(stderr, "%s() bind error %s\n",__func__,strerror(errno)); close(g_dl_socket); g_dl_socket = -1; pthread_mutex_unlock(&g_dl_request_mutex); return; } - if (-1 == bind(g_dl_socket, (struct sockaddr *)&my_addr, sizeof(struct sockaddr))) { - fprintf(stderr, "%s() bind error %s\n",__func__,strerror(errno)); + if (chmod(g_dl_socket_path, 0600) == -1) { + fprintf(stderr, "%s() socket permissions error %s\n",__func__,strerror(errno)); close(g_dl_socket); + unlink(g_dl_socket_path); g_dl_socket = -1; pthread_mutex_unlock(&g_dl_request_mutex); return; } - //fprintf(stderr, "%sg_dl_socket = %d __progname = %s \n",__func__,g_dl_socket,__progname); + g_dl_socket_pid = getpid(); pthread_mutex_unlock(&g_dl_request_mutex); } @@ -197,6 +256,8 @@ void rdk_dyn_log_deinit() { close(g_dl_socket); g_dl_socket = -1; + unlink(g_dl_socket_path); + g_dl_socket_path[0] = '\0'; } pthread_mutex_unlock(&g_dl_request_mutex); } diff --git a/unittests/rdkLoggerDynamic.cpp b/unittests/rdkLoggerDynamic.cpp index 12341cda..8498b3de 100644 --- a/unittests/rdkLoggerDynamic.cpp +++ b/unittests/rdkLoggerDynamic.cpp @@ -131,7 +131,7 @@ void* run_rdklogctrl(void* arg) { } char cmd[256]; - snprintf(cmd, sizeof(cmd), "./rdklogctrl rdk_logger_gtest %s %s", category_str, level_str); + snprintf(cmd, sizeof(cmd), "./rdklogctrl %ld %s %s", (long)getpid(), category_str, level_str); fprintf(stderr, "Executing command: %s\n", cmd); int ret = system(cmd); (void)ret; @@ -142,7 +142,7 @@ static void* run_log_messages(void* arg) { pthread_barrier_t* start_barrier = static_cast(arg); pthread_barrier_wait(start_barrier); for (int i = 0; i < 500; ++i) - rdk_logger_msg_printf(RDK_LOG_INFO, "LOG.RDK.TEST", "Concurrent test log\n"); + rdk_logger_msg_printf(RDK_LOG_INFO, "LOG.RDK.MEDIUM002", "Concurrent test log\n"); return NULL; } @@ -348,44 +348,34 @@ TEST(RdkDynamicLoggerTest, MessageProcessingViaSystem_negnone) { } -TEST(RdkDynamicLoggerTest, Critical001_AcceptsBoundaryComponentName) { - char conf_file[] = GTEST_DEBUG_INI_FILE; - ASSERT_EQ(rdk_logger_init(conf_file), RDK_SUCCESS); - - const char* component = "LOG.RDK.rdklogger_component_name_for_boundary_length_testing_123"; - ASSERT_EQ(strlen(component), 64U); - - rdklogctrl_args_t args; - args.category = CAT_BOUNDARY; - args.level = LVL_INFO; - - testing::internal::CaptureStderr(); - pthread_t client_thread; - ASSERT_EQ(0, pthread_create(&client_thread, nullptr, run_rdklogctrl, &args)); - usleep(500000); - rdk_logger_msg_printf(RDK_LOG_ERROR, "LOG.RDK.TESTMOD", "Process dynamic log request\n"); - ASSERT_EQ(0, pthread_join(client_thread, nullptr)); - - const std::string output = testing::internal::GetCapturedStderr(); - EXPECT_NE(output.find("for the component " + std::string(component) + ", is success"), std::string::npos); +// Runs a command, echoes its stdout+stderr to the test log, and returns the pclose status. +static int run_and_print(const std::string& command, std::string& output) { + FILE* pipe = popen((command + " 2>&1").c_str(), "r"); + if (pipe == nullptr) + return -1; + char chunk[256]; + while (fgets(chunk, sizeof(chunk), pipe) != nullptr) + output += chunk; + fprintf(stdout, "[%s]\n%s", command.c_str(), output.c_str()); + fflush(stdout); + return pclose(pipe); } -TEST(RdkDynamicLoggerTest, Critical001_RejectsComponentNameAboveBuffer) { - const char* output_path = "/tmp/rdklogctrl_critical001_test.txt"; - const std::string component = "LOG.RDK." + std::string(57, 'C'); +TEST(RdkDynamicLoggerTest, Critical001_RejectsOversizedComponentName) { + // 65 characters: one more than the 64-byte component limit + const std::string component = "LOG.RDK." + std::string(57, 'A'); ASSERT_EQ(component.size(), 65U); - const std::string command = "./rdklogctrl " + std::to_string(getpid()) + " " + - component + " INFO > " + output_path + " 2>&1"; - int status = system(command.c_str()); + + std::string output; + int status = run_and_print("./rdklogctrl " + std::to_string((long)getpid()) + " " + + component + " INFO", output); ASSERT_NE(status, -1); EXPECT_NE(status, 0); - std::ifstream output_file(output_path); - const std::string output((std::istreambuf_iterator(output_file)), - std::istreambuf_iterator()); - EXPECT_NE(output.find("packet field size"), std::string::npos); - remove(output_path); + EXPECT_NE(output.find("exceeds packet field size"), std::string::npos); } +// Medium_002: raises LOG.RDK.MEDIUM002 to INFO via rdklogctrl, then logs from two threads at once +// and checks all 1000 messages appear, i.e. concurrent RDK_LOG calls neither hang nor drop lines. TEST(RdkDynamicLoggerTest, Medium002_ConcurrentLogCallsComplete) { ASSERT_EQ(rdk_logger_init(GTEST_DEBUG_INI_FILE), RDK_SUCCESS); @@ -398,8 +388,11 @@ TEST(RdkDynamicLoggerTest, Medium002_ConcurrentLogCallsComplete) { pthread_t control_thread; pthread_t log_threads[2]; testing::internal::CaptureStdout(); + testing::internal::CaptureStderr(); ASSERT_EQ(pthread_create(&control_thread, nullptr, run_rdklogctrl, &args), 0); ASSERT_EQ(pthread_join(control_thread, nullptr), 0); + // Apply the queued level change before the threads start; otherwise early messages are filtered. + rdk_logger_msg_printf(RDK_LOG_INFO, "LOG.RDK.MEDIUM002", "Medium002 warm-up\n"); ASSERT_EQ(pthread_create(&log_threads[0], nullptr, run_log_messages, &start_barrier), 0); ASSERT_EQ(pthread_create(&log_threads[1], nullptr, run_log_messages, &start_barrier), 0); pthread_barrier_wait(&start_barrier); @@ -410,20 +403,33 @@ TEST(RdkDynamicLoggerTest, Medium002_ConcurrentLogCallsComplete) { const char* marker = "Medium002 INFO reconfiguration observed"; rdk_logger_msg_printf(RDK_LOG_INFO, "LOG.RDK.MEDIUM002", "%s\n", marker); const std::string output = testing::internal::GetCapturedStdout(); + const std::string errors = testing::internal::GetCapturedStderr(); + size_t concurrent_count = 0; + for (size_t pos = output.find("Concurrent test log"); pos != std::string::npos; + pos = output.find("Concurrent test log", pos + 1)) + ++concurrent_count; + printf("Medium002 concurrent log lines: %zu (expected 1000)\n", concurrent_count); + printf("Medium002 stderr:\n%s\n", errors.c_str()); + EXPECT_NE(errors.find("is success"), std::string::npos); + EXPECT_EQ(concurrent_count, 1000U); EXPECT_NE(output.find(marker), std::string::npos); } -TEST(RdkDynamicLoggerTest, Medium005_RdklogctrlRejectsOversizedModule) { - const char* output_path = "/tmp/rdklogctrl_medium005_test.txt"; +TEST(RdkDynamicLoggerTest, Medium005_RdklogctrlRejectsOversizedArguments) { + const std::string oversized_pid(200, '1'); const std::string oversized_module = "LOG.RDK." + std::string(200, 'B'); - const std::string command = "./rdklogctrl " + std::to_string(getpid()) + " " + - oversized_module + " DEBUG > " + output_path + " 2>&1"; - int status = system(command.c_str()); - ASSERT_NE(status, -1); - EXPECT_NE(status, 0); - std::ifstream output_file(output_path); - const std::string output((std::istreambuf_iterator(output_file)), - std::istreambuf_iterator()); - EXPECT_NE(output.find("packet field size"), std::string::npos); - remove(output_path); + const std::string commands[] = { + "./rdklogctrl " + oversized_pid + " LOG.RDK.TEST DEBUG", + "./rdklogctrl 1 " + oversized_module + " DEBUG" + }; + const std::string expected_errors[] = {"Invalid process ID", "packet field size"}; + + for (size_t index = 0; index < sizeof(commands) / sizeof(commands[0]); ++index) { + std::string output; + int status = run_and_print(commands[index], output); + ASSERT_NE(status, -1); + EXPECT_NE(status, 0); + EXPECT_NE(output.find(expected_errors[index]), std::string::npos); + } } + diff --git a/utils/rdklogctrl.c b/utils/rdklogctrl.c index 3d33060d..3fe5b57e 100644 --- a/utils/rdklogctrl.c +++ b/utils/rdklogctrl.c @@ -1,27 +1,26 @@ #include #include #include +#include #include +#include #include -#include -#include #include -#include -#include +#include #include #include "rdk_dynamic_logger.h" #define COMP_SIGNATURE "LOG.RDK." #define COMP_SIGNATURE_LEN 8 -#define DL_PORT 12035 +#define DL_SOCKET_DIR "/tmp/.logger" #define DL_SIGNATURE "COMC" #define DL_SIGNATURE_LEN 4 static void usage(const char* app_name) { - printf("usage: %s \n",app_name); + printf("usage: %s \n",app_name); printf("Parameters:\n"); - printf("app_name -> Application name, as per listed by 'ps' command\n"); + printf("pid -> Process ID of the application to update\n"); printf("module_name -> Module name.\n"); printf(" For RDK component, the 'Module name' is expected to start with 'LOG.RDK.' string\n"); printf(" For CPC component like 'Receiver', the module name can be either 'LOG.RDK.' or 'XREConnection', 'RmfMediaPlayer', etc.\n"); @@ -29,6 +28,41 @@ static void usage(const char* app_name) printf(" Possible values - FATAL, ERROR, WARN, NOTICE, INFO, DEBUG, TRACE, NONE\n"); } +static int process_name_for_pid(pid_t pid, char *process_name, size_t process_name_size) +{ + char proc_path[64]; + char command_line[RDK_DYNAMIC_LOG_APP_NAME_MAX + 2]; + char *argument_end; + char *base_name; + FILE *proc_file; + size_t bytes_read; + size_t name_length; + + if (snprintf(proc_path, sizeof(proc_path), "/proc/%ld/cmdline", (long)pid) >= (int)sizeof(proc_path)) + return -1; + + proc_file = fopen(proc_path, "rb"); + if (proc_file == NULL) + return -1; + + bytes_read = fread(command_line, 1, sizeof(command_line) - 1, proc_file); + fclose(proc_file); + argument_end = memchr(command_line, '\0', bytes_read); + if (argument_end == NULL || argument_end == command_line) + return -1; + + *argument_end = '\0'; + base_name = strrchr(command_line, '/'); + base_name = base_name == NULL ? command_line : base_name + 1; + name_length = strlen(base_name); + if (name_length == 0 || name_length >= process_name_size || + name_length > RDK_DYNAMIC_LOG_APP_NAME_MAX) + return -1; + + memcpy(process_name, base_name, name_length + 1); + return 0; +} + static int8_t validate_loglevel(const char* level) { char *loglevel = (char *)level; @@ -58,8 +92,16 @@ static int8_t validate_loglevel(const char* level) int main(int argc, char *argv[]) { - struct sockaddr_in dest_addr; - int sockfd, numbytes, optval = 1; + struct sockaddr_un dest_addr; + int sockfd, numbytes; + long parsed_pid; + char *pid_end; + const char *pid_character; + pid_t target_pid; + char process_name[RDK_DYNAMIC_LOG_APP_NAME_MAX + 1]; + char socket_path[sizeof(dest_addr.sun_path)]; + int socket_path_length; + socklen_t dest_addr_length; size_t app_len, comp_len, app_offset, component_length_offset; size_t component_offset, packet_length; int8_t level = -1; @@ -71,15 +113,28 @@ int main(int argc, char *argv[]) return -1; } - if(0 != strcmp("Receiver",argv[1])) { - if( (0 != strncmp(argv[2],COMP_SIGNATURE,COMP_SIGNATURE_LEN))) - { - printf("Invalid module name\n"); - usage(argv[0]); + for (pid_character = argv[1]; *pid_character != '\0'; ++pid_character) { + if (*pid_character < '0' || *pid_character > '9') { + fprintf(stderr, "Invalid process ID\n"); return -1; } } + errno = 0; + parsed_pid = strtol(argv[1], &pid_end, 10); + if (errno != 0 || pid_end == argv[1] || *pid_end != '\0' || + parsed_pid <= 0 || parsed_pid > INT_MAX) { + fprintf(stderr, "Invalid process ID\n"); + return -1; + } + target_pid = (pid_t)parsed_pid; + + comp_len = strlen(argv[2]); + if (comp_len == 0 || comp_len > RDK_DYNAMIC_LOG_COMPONENT_NAME_MAX) { + fprintf(stderr, "App or module name exceeds packet field size\n"); + return -1; + } + level = validate_loglevel(argv[3]); if(-1 == level) { printf("Invalid log level\n"); @@ -87,11 +142,22 @@ int main(int argc, char *argv[]) return -1; } - app_len = strlen(argv[1]); - comp_len = strlen(argv[2]); - if (app_len == 0 || comp_len == 0 || - app_len > RDK_DYNAMIC_LOG_APP_NAME_MAX || - comp_len > RDK_DYNAMIC_LOG_COMPONENT_NAME_MAX) { + if (process_name_for_pid(target_pid, process_name, sizeof(process_name)) != 0) { + fprintf(stderr, "Unable to resolve process ID %ld\n", parsed_pid); + return -1; + } + + if(0 != strcmp("Receiver",process_name)) { + if( (0 != strncmp(argv[2],COMP_SIGNATURE,COMP_SIGNATURE_LEN))) + { + printf("Invalid module name\n"); + usage(argv[0]); + return -1; + } + } + + app_len = strlen(process_name); + if (app_len == 0 || app_len > RDK_DYNAMIC_LOG_APP_NAME_MAX) { fprintf(stderr, "App or module name exceeds packet field size\n"); return -1; } @@ -113,29 +179,31 @@ int main(int argc, char *argv[]) } packet_length = component_offset + comp_len; - if ((sockfd = socket(AF_INET, SOCK_DGRAM, 0)) == -1) { - printf("socket: %s\n",strerror(errno)); + socket_path_length = snprintf(socket_path, sizeof(socket_path), DL_SOCKET_DIR "/%s.%ld", + process_name, parsed_pid); + if (socket_path_length < 0 || (size_t)socket_path_length >= sizeof(socket_path)) { + fprintf(stderr, "Process socket path is too long\n"); return -1; } - if(setsockopt(sockfd,SOL_SOCKET,SO_BROADCAST,(char *) &optval,sizeof(optval))){ - printf("Error setting socket to BROADCAST mode %s\n",strerror(errno)); + if ((sockfd = socket(AF_UNIX, SOCK_DGRAM, 0)) == -1) { + printf("socket: %s\n",strerror(errno)); return -1; } memset(&dest_addr,0,sizeof(dest_addr)); - dest_addr.sin_family = AF_INET; - dest_addr.sin_port=htons((unsigned short) DL_PORT); - dest_addr.sin_addr.s_addr=inet_addr("127.255.255.255"); + dest_addr.sun_family = AF_UNIX; + memcpy(dest_addr.sun_path, socket_path, (size_t)socket_path_length + 1); + dest_addr_length = (socklen_t)(offsetof(struct sockaddr_un, sun_path) + + (size_t)socket_path_length + 1); memcpy(message.signature, DL_SIGNATURE, DL_SIGNATURE_LEN); - message.message_length = (uint8_t)(app_len + comp_len + 3); message.log_level = (uint8_t)level; - memcpy(message.app_name, argv[1], app_len); + memcpy(message.app_name, process_name, app_len); memcpy(message.component_name, argv[2], comp_len); memcpy(packet, message.signature, DL_SIGNATURE_LEN); - packet[DL_SIGNATURE_LEN] = message.message_length; + packet[DL_SIGNATURE_LEN] = (uint8_t)(app_len + comp_len + 3); packet[DL_SIGNATURE_LEN + 1] = message.log_level; packet[DL_SIGNATURE_LEN + 2] = (uint8_t)app_len; memcpy(packet + app_offset, message.app_name, app_len); @@ -143,7 +211,7 @@ int main(int argc, char *argv[]) memcpy(packet + component_offset, message.component_name, comp_len); if ((numbytes=sendto(sockfd, packet, packet_length, 0, - (struct sockaddr *)&dest_addr, sizeof(dest_addr))) == -1) { + (struct sockaddr *)&dest_addr, dest_addr_length)) == -1) { printf("sendto: %s\n",strerror(errno)); close(sockfd); return -1; @@ -154,7 +222,8 @@ int main(int argc, char *argv[]) return -1; } - printf( "Sent message to update log level of %s for %s process\n", argv[2], argv[1]); + printf("Sent message to update log level of %s for PID %ld (%s)\n", + argv[2], parsed_pid, process_name); close(sockfd); return 0; } From 37a51b3dbccd2bcb35c8563efb504c42c6a7273e Mon Sep 17 00:00:00 2001 From: Deepthi Date: Fri, 16 Oct 2026 10:03:23 +0000 Subject: [PATCH 02/10] Address Copilot review comments Signed-off-by: Deepthi --- src/.Makefile.am.swp | Bin 0 -> 12288 bytes src/rdk_dynamic_logger.c | 29 +++++++++++++---------------- 2 files changed, 13 insertions(+), 16 deletions(-) create mode 100644 src/.Makefile.am.swp diff --git a/src/.Makefile.am.swp b/src/.Makefile.am.swp new file mode 100644 index 0000000000000000000000000000000000000000..4394eb11469d467809432835eb6d92ee49e373fb GIT binary patch literal 12288 zcmeI2-)|d55XZNuPe1{|8whFYL?V%5J4pkgtt{mDM>y3#B%j?VQl-=SZhhY7Zui(* z$Mp;R3y25)4+Q)lyzhv&kS|9j`Rm*(nB$!CFy z&J!KS!c_4oC?0bYR=fOMOk^S|JblTrG(`l6z$+2B!|oj(?7J;nrMvLahoe{8O^b;D z5g-CYfCvx)B0vO)01IX*zrV-WkEjIo6jeh#L_NR5 z*iWbl3Q+&N%h)fdpHbhVQq&*spg+{#c-CLVna|z1bP)j}Km>>Y5g-CYfCvzQ|CvA{ z$CvG=d64j+(`wS%_TY1K+k zN|6}P;)+!ANvU)*M87{8G+HiG*LJ&F8(uvJnUNQj!mv<0m0{7FTNqc3x&gYko0b$? zc5|zh*feW3*4#vu(1j9oh6r|0A9%|MHuzN%&g$KuKv;uvW~WB*2+F5CN$^t`qYd^h zzP5{PK_XLWxs_VwFjJ8*V5b5)G88Ho6w`hPH+0$e2Y^*;dPA?@!%-XRy)$^^^_qJiBnDwX zJj;y8bHEd2nk7<1E}%%}*2wY9is)vCb>n9U=)0@QjC3 zQPC!@q8~>uuXemftLL}Mhn4;1@-sbylrKP!Ek~amLY?7gvH_S|bi625Ds5qwy9!`p zt|uI!gd(#pq)_cr1)75@39=7liNDcNuuYj`Yx%}CagWaU@I6)z>5dC#hZXj mE63Lk@oHDcTZyDz7lEkl+vY+Kp;C!85fPVp-y~^JJ literal 0 HcmV?d00001 diff --git a/src/rdk_dynamic_logger.c b/src/rdk_dynamic_logger.c index 3f21139b..cce79a90 100644 --- a/src/rdk_dynamic_logger.c +++ b/src/rdk_dynamic_logger.c @@ -54,11 +54,16 @@ static int rdk_dyn_log_make_socket_path(char *path, size_t path_size) if (__progname == NULL || __progname[0] == '\0') return -1; - if (mkdir(DL_SOCKET_DIR, 01777) == -1 && errno != EEXIST) + if (mkdir(DL_SOCKET_DIR, 01777) == 0) { + /* mkdir honours the caller's umask; force the intended shared-directory mode. */ + if (chmod(DL_SOCKET_DIR, 01777) == -1) + return -1; + } else if (errno != EEXIST) { return -1; + } if (lstat(DL_SOCKET_DIR, &dir_stat) == -1 || !S_ISDIR(dir_stat.st_mode) || (dir_stat.st_uid != 0 && dir_stat.st_uid != geteuid()) || - ((dir_stat.st_mode & S_IWOTH) && !(dir_stat.st_mode & S_ISVTX))) + ((dir_stat.st_mode & (S_IWGRP | S_IWOTH)) && !(dir_stat.st_mode & S_ISVTX))) return -1; length = snprintf(path, path_size, DL_SOCKET_DIR "/%s.%ld", __progname, (long)getpid()); @@ -189,9 +194,7 @@ void rdk_dyn_log_process_pending_request() void rdk_dyn_log_init() { struct sockaddr_un my_addr; - struct stat socket_stat; socklen_t addr_len; - mode_t previous_umask; int bind_result; pthread_mutex_lock(&g_dl_request_mutex); @@ -201,15 +204,9 @@ void rdk_dyn_log_init() return; } - if (lstat(g_dl_socket_path, &socket_stat) == 0) { - if (!S_ISSOCK(socket_stat.st_mode) || socket_stat.st_uid != geteuid() || - unlink(g_dl_socket_path) == -1) { - fprintf(stderr, "%s() socket path is already in use\n", __func__); - pthread_mutex_unlock(&g_dl_request_mutex); - return; - } - } else if (errno != ENOENT) { - fprintf(stderr, "%s() cannot inspect socket path: %s\n", __func__, strerror(errno)); + /* Remove any stale entry; the sticky directory refuses to unlink entries owned by others. */ + if (unlink(g_dl_socket_path) == -1 && errno != ENOENT) { + fprintf(stderr, "%s() socket path is already in use: %s\n", __func__, strerror(errno)); pthread_mutex_unlock(&g_dl_request_mutex); return; } @@ -225,9 +222,7 @@ void rdk_dyn_log_init() memcpy(my_addr.sun_path, g_dl_socket_path, strlen(g_dl_socket_path) + 1); addr_len = (socklen_t)(offsetof(struct sockaddr_un, sun_path) + strlen(my_addr.sun_path) + 1); - previous_umask = umask(0177); bind_result = bind(g_dl_socket, (struct sockaddr *)&my_addr, addr_len); - umask(previous_umask); if (-1 == bind_result) { fprintf(stderr, "%s() bind error %s\n",__func__,strerror(errno)); close(g_dl_socket); @@ -256,7 +251,9 @@ void rdk_dyn_log_deinit() { close(g_dl_socket); g_dl_socket = -1; - unlink(g_dl_socket_path); + /* A forked child must not remove the parent's live socket. */ + if (g_dl_socket_pid == getpid()) + unlink(g_dl_socket_path); g_dl_socket_path[0] = '\0'; } pthread_mutex_unlock(&g_dl_request_mutex); From ae89655f06d4828e6f55bf51fd5fafc3f0dbe6e0 Mon Sep 17 00:00:00 2001 From: Deepthi Date: Fri, 16 Oct 2026 10:36:44 +0000 Subject: [PATCH 03/10] Address Copilot review comments Signed-off-by: Deepthi --- src/rdk_dynamic_logger.c | 40 +++++++++++++++++++++++++++++----------- utils/rdklogctrl.c | 4 ++-- 2 files changed, 31 insertions(+), 13 deletions(-) diff --git a/src/rdk_dynamic_logger.c b/src/rdk_dynamic_logger.c index cce79a90..6b8c36aa 100644 --- a/src/rdk_dynamic_logger.c +++ b/src/rdk_dynamic_logger.c @@ -1,4 +1,3 @@ -/* * If not stated otherwise in this file or this component's LICENSE file the * following copyright and licenses apply: * @@ -22,6 +21,7 @@ */ #include +#include #include #include #include @@ -54,15 +54,18 @@ static int rdk_dyn_log_make_socket_path(char *path, size_t path_size) if (__progname == NULL || __progname[0] == '\0') return -1; - if (mkdir(DL_SOCKET_DIR, 01777) == 0) { - /* mkdir honours the caller's umask; force the intended shared-directory mode. */ - if (chmod(DL_SOCKET_DIR, 01777) == -1) + /* Only root provisions the shared directory, so its owner is always root regardless of start order. */ + if (geteuid() == 0) { + if (mkdir(DL_SOCKET_DIR, 01777) == 0) { + /* mkdir honours the caller's umask; force the intended shared-directory mode. */ + if (chmod(DL_SOCKET_DIR, 01777) == -1) + return -1; + } else if (errno != EEXIST) { return -1; - } else if (errno != EEXIST) { - return -1; + } } if (lstat(DL_SOCKET_DIR, &dir_stat) == -1 || !S_ISDIR(dir_stat.st_mode) || - (dir_stat.st_uid != 0 && dir_stat.st_uid != geteuid()) || + dir_stat.st_uid != 0 || ((dir_stat.st_mode & (S_IWGRP | S_IWOTH)) && !(dir_stat.st_mode & S_ISVTX))) return -1; @@ -217,28 +220,43 @@ void rdk_dyn_log_init() return; } + /* Bind in a private (0700) directory so no one can queue packets before the socket is 0600. */ + char stage_dir[] = DL_SOCKET_DIR "/.stage.XXXXXX"; + char stage_path[sizeof(stage_dir) + 8]; + if (mkdtemp(stage_dir) == NULL) { + fprintf(stderr, "%s() staging directory error %s\n", __func__, strerror(errno)); + close(g_dl_socket); + g_dl_socket = -1; + pthread_mutex_unlock(&g_dl_request_mutex); + return; + } + snprintf(stage_path, sizeof(stage_path), "%s/s", stage_dir); + memset(&my_addr,0,sizeof(my_addr)); my_addr.sun_family = AF_UNIX; - memcpy(my_addr.sun_path, g_dl_socket_path, strlen(g_dl_socket_path) + 1); + memcpy(my_addr.sun_path, stage_path, strlen(stage_path) + 1); addr_len = (socklen_t)(offsetof(struct sockaddr_un, sun_path) + strlen(my_addr.sun_path) + 1); bind_result = bind(g_dl_socket, (struct sockaddr *)&my_addr, addr_len); if (-1 == bind_result) { fprintf(stderr, "%s() bind error %s\n",__func__,strerror(errno)); + rmdir(stage_dir); close(g_dl_socket); g_dl_socket = -1; pthread_mutex_unlock(&g_dl_request_mutex); return; } - if (chmod(g_dl_socket_path, 0600) == -1) { - fprintf(stderr, "%s() socket permissions error %s\n",__func__,strerror(errno)); + if (chmod(stage_path, 0600) == -1 || rename(stage_path, g_dl_socket_path) == -1) { + fprintf(stderr, "%s() socket publish error %s\n",__func__,strerror(errno)); close(g_dl_socket); - unlink(g_dl_socket_path); + unlink(stage_path); + rmdir(stage_dir); g_dl_socket = -1; pthread_mutex_unlock(&g_dl_request_mutex); return; } + rmdir(stage_dir); g_dl_socket_pid = getpid(); pthread_mutex_unlock(&g_dl_request_mutex); diff --git a/utils/rdklogctrl.c b/utils/rdklogctrl.c index 3fe5b57e..d065e527 100644 --- a/utils/rdklogctrl.c +++ b/utils/rdklogctrl.c @@ -31,7 +31,7 @@ static void usage(const char* app_name) static int process_name_for_pid(pid_t pid, char *process_name, size_t process_name_size) { char proc_path[64]; - char command_line[RDK_DYNAMIC_LOG_APP_NAME_MAX + 2]; + char command_line[PATH_MAX + 1]; char *argument_end; char *base_name; FILE *proc_file; @@ -210,7 +210,7 @@ int main(int argc, char *argv[]) packet[component_length_offset] = (uint8_t)comp_len; memcpy(packet + component_offset, message.component_name, comp_len); - if ((numbytes=sendto(sockfd, packet, packet_length, 0, + if ((numbytes=sendto(sockfd, packet, packet_length, MSG_DONTWAIT, (struct sockaddr *)&dest_addr, dest_addr_length)) == -1) { printf("sendto: %s\n",strerror(errno)); close(sockfd); From 175c0a7e4e9ca7f8b4b16a6a62a03d662b61de04 Mon Sep 17 00:00:00 2001 From: Deepthi Date: Fri, 16 Oct 2026 10:47:31 +0000 Subject: [PATCH 04/10] Address Copilot review comments Signed-off-by: Deepthi --- src/rdk_dynamic_logger.c | 16 +++++++--------- 1 file changed, 7 insertions(+), 9 deletions(-) diff --git a/src/rdk_dynamic_logger.c b/src/rdk_dynamic_logger.c index 6b8c36aa..129663d3 100644 --- a/src/rdk_dynamic_logger.c +++ b/src/rdk_dynamic_logger.c @@ -1,3 +1,4 @@ +/* * If not stated otherwise in this file or this component's LICENSE file the * following copyright and licenses apply: * @@ -54,18 +55,15 @@ static int rdk_dyn_log_make_socket_path(char *path, size_t path_size) if (__progname == NULL || __progname[0] == '\0') return -1; - /* Only root provisions the shared directory, so its owner is always root regardless of start order. */ - if (geteuid() == 0) { - if (mkdir(DL_SOCKET_DIR, 01777) == 0) { - /* mkdir honours the caller's umask; force the intended shared-directory mode. */ - if (chmod(DL_SOCKET_DIR, 01777) == -1) - return -1; - } else if (errno != EEXIST) { + if (mkdir(DL_SOCKET_DIR, 01777) == 0) { + /* mkdir honours the caller's umask; force the intended shared-directory mode. */ + if (chmod(DL_SOCKET_DIR, 01777) == -1) return -1; - } + } else if (errno != EEXIST) { + return -1; } if (lstat(DL_SOCKET_DIR, &dir_stat) == -1 || !S_ISDIR(dir_stat.st_mode) || - dir_stat.st_uid != 0 || + (dir_stat.st_uid != 0 && dir_stat.st_uid != geteuid()) || ((dir_stat.st_mode & (S_IWGRP | S_IWOTH)) && !(dir_stat.st_mode & S_ISVTX))) return -1; From 9aa06bdeee12cc772f67c7d733f6760f8dfb3069 Mon Sep 17 00:00:00 2001 From: Deepthi Date: Mon, 19 Oct 2026 05:55:37 +0000 Subject: [PATCH 05/10] Implement rdk_logger_get_logLevel functionality Signed-off-by: Deepthi --- include/rdk_logger.h | 8 +++++++ src/include/rdk_debug_priv.h | 1 + src/rdk_debug.c | 12 +++++++++++ src/rdk_debug_priv.c | 37 +++++++++++++++++++++++++++++++++ unittests/rdkEnableLogLevel.cpp | 18 ++++++++++++++++ 5 files changed, 76 insertions(+) diff --git a/include/rdk_logger.h b/include/rdk_logger.h index 942b6a26..b9ca1b74 100644 --- a/include/rdk_logger.h +++ b/include/rdk_logger.h @@ -343,6 +343,14 @@ bool rdk_logger_is_logLevel_enabled(const char *module, rdk_LogLevel level); */ bool rdk_logger_set_logLevel(const char *module, rdk_LogLevel logLevel); +/** + * @brief Get the effective log level for a module. + * @param module Module name. + * @param logLevel Receives the effective log level on success. + * @return TRUE if the level was retrieved, FALSE for invalid arguments or an unknown level. + */ +bool rdk_logger_get_logLevel(const char *module, rdk_LogLevel *logLevel); + /** * @brief Log a message for onboard logging. * @param module Module name. diff --git a/src/include/rdk_debug_priv.h b/src/include/rdk_debug_priv.h index 532ff83b..920db00d 100644 --- a/src/include/rdk_debug_priv.h +++ b/src/include/rdk_debug_priv.h @@ -32,6 +32,7 @@ void rdk_dbg_priv_deinit(void); rdk_Error rdk_dbg_priv_ext_init (const rdk_logger_ext_config_t* config); void rdk_dbg_priv_log_msg(rdk_LogLevel level, const char *module_name, const char* format, va_list args); bool rdk_dbg_priv_log_reconfig(const char *pModuleName, rdk_LogLevel level); +bool rdk_dbg_priv_log_get_level(const char *pModuleName, rdk_LogLevel *level); #ifdef __cplusplus } diff --git a/src/rdk_debug.c b/src/rdk_debug.c index 929fed89..8323e841 100644 --- a/src/rdk_debug.c +++ b/src/rdk_debug.c @@ -102,6 +102,18 @@ bool rdk_logger_set_logLevel(const char *module, rdk_LogLevel logLevel) return false; } +/** + * @brief Get the effective log level for a module. + * @param module Module name. + * @param logLevel Receives the effective log level on success. + * @return TRUE if the level was retrieved, FALSE for invalid arguments or an unknown level. + */ +bool rdk_logger_get_logLevel(const char *module, rdk_LogLevel *logLevel) +{ + return rdk_dbg_priv_log_get_level(module, logLevel); +} + + /** * @brief Enable or disable a log level for a module. * @param module Module name. diff --git a/src/rdk_debug_priv.c b/src/rdk_debug_priv.c index 5775c90a..55a3275f 100644 --- a/src/rdk_debug_priv.c +++ b/src/rdk_debug_priv.c @@ -684,6 +684,43 @@ bool rdk_dbg_priv_log_reconfig(const char *pModuleName, rdk_LogLevel logLevel) return ret; } +bool rdk_dbg_priv_log_get_level(const char *pModuleName, rdk_LogLevel *level) +{ + log4c_category_t* cat; + int priority; + + if (pModuleName == NULL || pModuleName[0] == '\0' || level == NULL) + return false; + + pthread_mutex_lock(&gLoggingMutex); + cat = log4c_category_get(pModuleName); + if (cat == NULL) { + pthread_mutex_unlock(&gLoggingMutex); + return false; + } + + priority = log4c_category_get_priority(cat); + if (priority == LOG4C_PRIORITY_NOTSET) + priority = gRootPriority; + + switch (priority) { + case LOG4C_PRIORITY_FATAL: *level = RDK_LOG_FATAL; break; + case LOG4C_PRIORITY_ERROR: *level = RDK_LOG_ERROR; break; + case LOG4C_PRIORITY_WARN: *level = RDK_LOG_WARN; break; + case LOG4C_PRIORITY_NOTICE: *level = RDK_LOG_NOTICE; break; + case LOG4C_PRIORITY_INFO: *level = RDK_LOG_INFO; break; + case LOG4C_PRIORITY_DEBUG: *level = RDK_LOG_DEBUG; break; + case LOG4C_PRIORITY_TRACE: *level = RDK_LOG_TRACE; break; + case LOG4C_PRIORITY_UNKNOWN: *level = RDK_LOG_NONE; break; + default: + pthread_mutex_unlock(&gLoggingMutex); + return false; + } + + pthread_mutex_unlock(&gLoggingMutex); + return true; +} + #define COMCAST_DATAED_BUFF_SIZE 40 /**************************************************************** * Wrapper function to retrieve module name diff --git a/unittests/rdkEnableLogLevel.cpp b/unittests/rdkEnableLogLevel.cpp index 83294306..7a9acf88 100644 --- a/unittests/rdkEnableLogLevel.cpp +++ b/unittests/rdkEnableLogLevel.cpp @@ -133,3 +133,21 @@ TEST(rdkEnableLogLevel, ONLYNOTICE_log_enabled) // ret = rdk_logger_deinit(); // ASSERT_EQ(ret,RDK_SUCCESS)<<"rdk_logger_deinit failed with return:\""< Date: Mon, 19 Oct 2026 07:27:28 +0000 Subject: [PATCH 06/10] Address Copilot review comments Signed-off-by: Deepthi --- src/rdk_debug_priv.c | 1 + 1 file changed, 1 insertion(+) diff --git a/src/rdk_debug_priv.c b/src/rdk_debug_priv.c index 55a3275f..b422168b 100644 --- a/src/rdk_debug_priv.c +++ b/src/rdk_debug_priv.c @@ -711,6 +711,7 @@ bool rdk_dbg_priv_log_get_level(const char *pModuleName, rdk_LogLevel *level) case LOG4C_PRIORITY_INFO: *level = RDK_LOG_INFO; break; case LOG4C_PRIORITY_DEBUG: *level = RDK_LOG_DEBUG; break; case LOG4C_PRIORITY_TRACE: *level = RDK_LOG_TRACE; break; + case LOG4C_PRIORITY_NONE: case LOG4C_PRIORITY_UNKNOWN: *level = RDK_LOG_NONE; break; default: pthread_mutex_unlock(&gLoggingMutex); From 65a835df2c584dcee7cf218bc7b158404990e00b Mon Sep 17 00:00:00 2001 From: udaykrishnag <33549128+udaykrishnag@users.noreply.github.com> Date: Mon, 19 Oct 2026 12:06:45 -0400 Subject: [PATCH 07/10] RDKEMW-24390: Mitigate Mythos Findings in RDK Logger --- src/.Makefile.am.swp | Bin 12288 -> 0 bytes 1 file changed, 0 insertions(+), 0 deletions(-) delete mode 100644 src/.Makefile.am.swp diff --git a/src/.Makefile.am.swp b/src/.Makefile.am.swp deleted file mode 100644 index 4394eb11469d467809432835eb6d92ee49e373fb..0000000000000000000000000000000000000000 GIT binary patch literal 0 HcmV?d00001 literal 12288 zcmeI2-)|d55XZNuPe1{|8whFYL?V%5J4pkgtt{mDM>y3#B%j?VQl-=SZhhY7Zui(* z$Mp;R3y25)4+Q)lyzhv&kS|9j`Rm*(nB$!CFy z&J!KS!c_4oC?0bYR=fOMOk^S|JblTrG(`l6z$+2B!|oj(?7J;nrMvLahoe{8O^b;D z5g-CYfCvx)B0vO)01IX*zrV-WkEjIo6jeh#L_NR5 z*iWbl3Q+&N%h)fdpHbhVQq&*spg+{#c-CLVna|z1bP)j}Km>>Y5g-CYfCvzQ|CvA{ z$CvG=d64j+(`wS%_TY1K+k zN|6}P;)+!ANvU)*M87{8G+HiG*LJ&F8(uvJnUNQj!mv<0m0{7FTNqc3x&gYko0b$? zc5|zh*feW3*4#vu(1j9oh6r|0A9%|MHuzN%&g$KuKv;uvW~WB*2+F5CN$^t`qYd^h zzP5{PK_XLWxs_VwFjJ8*V5b5)G88Ho6w`hPH+0$e2Y^*;dPA?@!%-XRy)$^^^_qJiBnDwX zJj;y8bHEd2nk7<1E}%%}*2wY9is)vCb>n9U=)0@QjC3 zQPC!@q8~>uuXemftLL}Mhn4;1@-sbylrKP!Ek~amLY?7gvH_S|bi625Ds5qwy9!`p zt|uI!gd(#pq)_cr1)75@39=7liNDcNuuYj`Yx%}CagWaU@I6)z>5dC#hZXj mE63Lk@oHDcTZyDz7lEkl+vY+Kp;C!85fPVp-y~^JJ From 9c3b6215142b0e5c6ff16475737f5871207ed005 Mon Sep 17 00:00:00 2001 From: Karunakaran A Date: Thu, 22 Oct 2026 02:23:16 +0000 Subject: [PATCH 08/10] Updated the rdklogger dynamic logging API and added new GetLevel() API Signed-off-by: Karunakaran A --- docs/API_DOCUMENTATION.md | 1 - docs/QUICK_REFERENCE.md | 1 - docs/README.md | 78 +++++++++--------- docs/TROUBLESHOOTING.md | 6 +- src/include/rdk_debug_priv.h | 6 +- src/include/rdk_dynamic_logger.h | 14 ++-- src/rdk_debug.c | 14 ++-- src/rdk_debug_priv.c | 41 +++++----- src/rdk_dynamic_logger.c | 134 ++++++++----------------------- utils/rdklogctrl.c | 93 +++++++-------------- 10 files changed, 144 insertions(+), 244 deletions(-) diff --git a/docs/API_DOCUMENTATION.md b/docs/API_DOCUMENTATION.md index 5a07c1bb..af2d60d9 100644 --- a/docs/API_DOCUMENTATION.md +++ b/docs/API_DOCUMENTATION.md @@ -343,7 +343,6 @@ rdklogctrl "$(pidof -s myapp)" LOG.RDK.NETWORK ~DEBUG - `pid`: Process ID of the target application; `rdklogctrl` resolves its name from `/proc` - `module_name`: Module name (must match debug.ini format) - `log_level`: FATAL, ERROR, WARN, NOTICE, INFO, DEBUG, TRACE, NONE -Each logger listens on `/tmp/.logger/.` using a Unix datagram socket restricted to the process owner. ### Programmatic Runtime Control diff --git a/docs/QUICK_REFERENCE.md b/docs/QUICK_REFERENCE.md index 284da69b..874d2060 100644 --- a/docs/QUICK_REFERENCE.md +++ b/docs/QUICK_REFERENCE.md @@ -74,7 +74,6 @@ LOG.RDK.TEST=NONE ## Runtime Control ### rdklogctrl Command -Socket URI: `unix:///tmp/.logger/.` ```bash # Set log level for module rdklogctrl diff --git a/docs/README.md b/docs/README.md index 94a8c9c2..29b81611 100644 --- a/docs/README.md +++ b/docs/README.md @@ -4,7 +4,7 @@ RDK Logger is a general-purpose logging framework for RDK middleware components On video platforms, RDK Logger serves as the logging backbone for middleware components such as the application manager, media pipeline, compositor, and Thunder plugin ecosystem. On broadband platforms, it fulfills the same role for protocol agents, platform management, and connectivity services. The same library binary and configuration model apply across all platform stacks, with the module naming convention (`LOG.RDK.`) providing the separation boundary between subsystems. -RDK Logger operates as a shared library (`librdkloggers`) that client processes link against. It uses Log4C as its underlying backend for log routing and formatting, and exposes a compact C API centered on the `RDK_LOG` macro. A companion command-line utility (`rdklogctrl`) communicates with running processes over a local UDP socket to change log levels at runtime without requiring a restart. +RDK Logger operates as a shared library (`librdkloggers`) that client processes link against. It uses Log4C as its underlying backend for log routing and formatting, and exposes a compact C API centered on the `RDK_LOG` macro. A companion command-line utility (`rdklogctrl`) communicates with running processes over a local unix socket to change log levels at runtime without requiring a restart. ```mermaid flowchart LR @@ -31,7 +31,7 @@ class SysLog VL - **Unified Logging API**: Provides the `RDK_LOG(level, module, format, ...)` macro as a single, consistent logging interface used by all RDK middleware components, replacing direct use of `printf`, `fprintf`, or `syslog`. - **Module-Specific Log Level Control**: Maintains independent log level configuration per component using the `LOG.RDK.` naming convention. Modules not explicitly configured inherit the default level set under `LOG.RDK.DEFAULT`. - **Three-Tier Configuration Override**: Resolves the active configuration file at startup using a priority chain — `/opt/debug.ini` (highest) → `/nvram/debug.ini` → `/etc/debug.ini` (default) — enabling field-level overrides without modifying the base system image. -- **Runtime Log Level Control**: The `rdklogctrl` utility sends UDP control messages to running processes on port 12035, enabling immediate log level changes per module without process restart. +- **Runtime Log Level Control**: The `rdklogctrl` utility sends control messages to specific running process, enabling immediate log level changes per module without process restart. - **Multiple Output Destinations**: Supports console (`stdout`/`stderr`), syslog daemon, systemd journal (when available), and rolling file appenders through a pluggable Log4C backend. - **Configurable Log Formats**: Six log message layouts are available, ranging from plain text to detailed formats including timestamps, thread IDs, module name, and log level. - **Milestone Logging**: Provides a dedicated `logMilestone()` API that records timestamped system lifecycle events (using `CLOCK_MONOTONIC_RAW`) to a dedicated milestones log file, separate from general component logs. @@ -43,7 +43,7 @@ class SysLog VL ## Design -RDK Logger follows a modular library architecture where the logging policy, output routing, and runtime control concerns are separated into distinct subsystems. The public API layer provides the `RDK_LOG` macro and initialization functions. A private implementation layer (`rdk_debug_priv.c`) handles Log4C backend integration, configuration parsing, and the actual message dispatch. A runtime control layer (`rdk_dynamic_logger.c`) implements a non-blocking UDP listener that processes log level change requests from the `rdklogctrl` utility. This separation allows the logging path to remain lightweight while control plane operations are handled independently. +RDK Logger follows a modular library architecture where the logging policy, output routing, and runtime control concerns are separated into distinct subsystems. The public API layer provides the `RDK_LOG` macro and initialization functions. A private implementation layer (`rdk_debug_priv.c`) handles Log4C backend integration, configuration parsing, and the actual message dispatch. A runtime control layer (`rdk_dynamic_logger.c`) implements a non-blocking unix socket listener that processes log level change requests from the `rdklogctrl` utility. This separation allows the logging path to remain lightweight while control plane operations are handled independently. The design prioritizes minimal overhead on the fast logging path. Level checks are performed first, and if the level is disabled for the given module, the call returns immediately without any formatting or I/O. Message formatting, timestamp generation, and backend dispatch only occur for messages that pass the level check. The Log4C backend manages output routing, file rotation, and integration with system logging facilities. @@ -51,7 +51,7 @@ Northbound integration is achieved through the `rdk_logger.h` public header and Southbound integration is handled by the Log4C library. RDK Logger registers custom layout types (formatters) and custom appender types (output backends) with Log4C before calling `log4c_init()`. The `log4crc` XML file controls how Log4C wires these layouts and appenders to log categories. This design allows the output format and destination to be changed by modifying `log4crc` rather than recompiling. -The runtime control IPC mechanism uses a UDP socket (port 12035, loopback broadcast `127.255.255.255`). When `rdklogctrl` is invoked, it constructs a structured binary message with a `"COMC"` signature, the target process name, the module name, and the new log level, then broadcasts it. Each running process that has initialized RDK Logger maintains a non-blocking UDP socket and calls `rdk_dyn_log_process_pending_request()` to drain any pending control messages. The receiving side validates the signature, verifies the target process name against `__progname`, and applies the level change atomically. +The runtime control IPC mechanism uses a unix socket. When `rdklogctrl` is invoked, it constructs a structured binary message with a `"COMC"` signature, the target process name, the module name, and the new log level, then broadcasts it. Each running process that has initialized RDK Logger maintains a non-blocking UNIX socket and calls `rdk_dyn_log_process_pending_request()` to drain any pending control messages. The receiving side validates the signature, verifies the target process name against `__progname`, and applies the level change atomically. Data persistence for standard log messages is delegated to Log4C appenders configured in `log4crc` (e.g., console/syslog/journal or Log4C file/rolling-file appenders). RDK Logger itself does not maintain a separate configuration cache beyond the Log4C category priority state applied at startup. Milestone log entries are persisted directly to a flat log file via `fopen`/`fprintf`. Onboarding log entries are appended to a separate file path and are suppressed once the device is marked as provisioned. @@ -75,7 +75,7 @@ flowchart TD end subgraph DynControl["Runtime Control (rdk_dynamic_logger.c)"] - UDPListener["UDP Listener\nPort 12035\nrdk_dyn_log_process_pending_request"] + SocketListener["unix Socket Listener\nrdk_dyn_log_process_pending_request"] end subgraph Subsystems["Logging Subsystems"] @@ -92,12 +92,12 @@ flowchart TD end subgraph Control["Runtime Control Tool"] - rdklogctrl["rdklogctrl utility\nUDP port 12035"] + rdklogctrl["rdklogctrl utility\nunix Socket"] end API --> Init Init --> ConfigParser - Init --> UDPListener + Init --> SocketListener API --> LevelFilter LevelFilter --> Formatter Formatter --> Appenders @@ -105,8 +105,8 @@ flowchart TD Log4C --> Console Log4C --> SysLog Log4C --> FileFS - UDPListener --> ConfigParser - rdklogctrl -->|UDP broadcast| UDPListener + SocketListener --> ConfigParser + rdklogctrl -->|Socket unicast| SocketListener Milestone --> FileFS Onboard --> FileFS ``` @@ -116,9 +116,9 @@ flowchart TD - **Threading Architecture**: Multi-threaded (library — runs in the context of the client process threads) - **Main Thread / Client Application Thread**: Issues `RDK_LOG()` calls from arbitrary client threads. Mutex (`gLoggingMutex`) serializes concurrent log message dispatch through the Log4C backend. - **Initialization Thread**: The first caller of `rdk_logger_init()` acquires `gInitMutex` to run the one-time initialization sequence. Subsequent callers find `isLogInited = true` and return immediately under the same mutex. -- **UDP Control Path**: The runtime control mechanism is non-blocking; `rdk_dyn_log_process_pending_request()` uses `select()` with a zero timeout and is called from within the client process's own event loop or logging path. The runtime control path requires no dedicated listener thread. +- **Control Path**: The runtime control mechanism is non-blocking; `rdk_dyn_log_process_pending_request()` uses `select()` with a zero timeout and is called from within the client process's own event loop or logging path. The runtime control path requires no dedicated listener thread. - **Synchronization**: Two `pthread_mutex_t` instances are used — `gInitMutex` guards the initialization state flag and `rdk_logger_ext_init` path; `gLoggingMutex` guards extended initialization of per-module appenders. The main logging path relies on Log4C's own thread safety for category priority checks. -- **Async / Event Dispatch**: All log messages are written synchronously within the calling thread. Runtime control updates apply immediately after `rdk_dbg_priv_log_reconfig()` updates the Log4C category priority. +- **Async / Event Dispatch**: All log messages are written synchronously within the calling thread. Runtime control updates apply immediately after `rdk_dbg_priv_set_level()` updates the Log4C category priority. ### Platform and Integration Requirements @@ -132,7 +132,7 @@ flowchart TD #### Initialization to Active State -The component transitions through the following states during its lifecycle: **Initializing** (mutex acquired, check `isLogInited` flag) → **LoadingConfig** (parse the selected debug.ini, populate Log4C category priorities) → **InitializingBackend** (register custom layouts and appenders, call `log4c_init()`) → **StartingDynamicControl** (open UDP socket on port 12035, bind to `127.255.255.255`) → **Active** (processing `RDK_LOG()` calls, servicing runtime control messages) → **Shutdown** (close UDP socket, release resources). +The component transitions through the following states during its lifecycle: **Initializing** (mutex acquired, check `isLogInited` flag) → **LoadingConfig** (parse the selected debug.ini, populate Log4C category priorities) → **InitializingBackend** (register custom layouts and appenders, call `log4c_init()`) → **StartingDynamicControl** → **Active** (processing `RDK_LOG()` calls, servicing runtime control messages) → **Shutdown** (close unix socket, release resources). ```mermaid sequenceDiagram @@ -170,20 +170,20 @@ sequenceDiagram PrivCore-->>Logger: RDK_SUCCESS Logger->>DynLog: rdk_dyn_log_init() - DynLog->>DynLog: socket(AF_INET, SOCK_DGRAM) bind port 12035 - DynLog-->>Logger: UDP listener ready + DynLog->>DynLog: socket(AF_INET, SOCK_DGRAM) bind /tmp/.logger.. + DynLog-->>Logger: Socket listener ready Note over Logger: isLogInited = true Logger-->>App: RDK_SUCCESS (Active) loop Runtime App->>Logger: RDK_LOG(level, module, format, ...) - Logger->>PrivCore: rdk_dbg_priv_log_msg() + Logger->>PrivCore: rdk_dbg_priv_log() end App->>Logger: rdk_logger_deinit() Logger->>DynLog: rdk_dyn_log_deinit() - DynLog->>DynLog: close UDP socket + DynLog->>DynLog: close unix socket Logger-->>App: RDK_SUCCESS ``` @@ -191,7 +191,7 @@ sequenceDiagram **State Change Triggers:** -- **Module Log Level Change via rdklogctrl**: When a valid UDP control message is received matching the process name and a recognized module name, `rdk_dbg_priv_log_reconfig()` updates the Log4C category priority for that module immediately. Subsequent `RDK_LOG()` calls for that module reflect the new level without any restart. +- **Module Log Level Change via rdklogctrl**: When a valid control message is received matching the process name and a recognized module name, `rdk_dbg_priv_set_level()` updates the Log4C category priority for that module immediately. Subsequent `RDK_LOG()` calls for that module reflect the new level without any restart. - **Invalid Control Message**: Messages that fail signature validation (`"COMC"` check) or have a mismatched process name are discarded; out-of-range log levels are rejected and reported to `stderr` by `rdk_dyn_log_validate_component_name()`. - **Configuration File Not Found**: If the selected debug.ini cannot be opened, `rdk_logger_parse_config()` returns `RDK_FAILURE`, initialization of RDK Logger fails, and `isLogInited` remains false. Log messages issued before a successful initialization are suppressed. @@ -226,7 +226,7 @@ sequenceDiagram PrivCore->>Log4C: log4c_category_set_priority per module PrivCore-->>Logger: RDK_SUCCESS Logger->>DynLog: rdk_dyn_log_init() - DynLog->>DynLog: socket and bind on port 12035 + DynLog->>DynLog: socket and bind on /tmp/.logger.. DynLog-->>Logger: Socket ready Logger->>Logger: Set isLogInited true, release gInitMutex Logger-->>App: RDK_SUCCESS @@ -234,21 +234,21 @@ sequenceDiagram #### Request Processing Call Flow -`RDK_LOG()` is an alias for `rdk_logger_msg_printf()`. On every invocation the module and format pointer are validated before calling `rdk_dbg_priv_log_msg()`. Inside `rdk_dbg_priv_log_msg()`, the Log4C category priority check acts as the fast-path filter: if the level is not enabled for the module, the function returns without any formatting or I/O. +`RDK_LOG()` is an alias for `rdk_logger_msg_printf()`. On every invocation the module and format pointer are validated before calling `rdk_dbg_priv_log()`. Inside `rdk_dbg_priv_log()`, the Log4C category priority check acts as the fast-path filter: if the level is not enabled for the module, the function returns without any formatting or I/O. ```mermaid sequenceDiagram participant Client as RDK Component Thread participant Macro as RDK_LOG macro participant MsgPrintf as rdk_logger_msg_printf - participant PrivLog as rdk_dbg_priv_log_msg + participant PrivLog as rdk_dbg_priv_log participant Log4C as Log4C Backend participant Output as Output Destination Client->>Macro: RDK_LOG(level, module, format, ...) Macro->>MsgPrintf: rdk_logger_msg_printf(level, module, format, args) MsgPrintf->>MsgPrintf: Validate module and format pointers - MsgPrintf->>PrivLog: rdk_dbg_priv_log_msg(level, module, format, args) + MsgPrintf->>PrivLog: rdk_dbg_priv_log(level, module, format, args) PrivLog->>Log4C: log4c_category_is_priority_enabled(category, priority) alt Level enabled for module Log4C-->>PrivLog: Enabled @@ -272,20 +272,20 @@ sequenceDiagram sequenceDiagram participant Admin as Operator participant Ctrl as rdklogctrl utility - participant UDP as UDP Socket (port 12035) + participant Socket as unix Socket (/tmp/.logger..) participant Listener as rdk_dyn_log_process_pending_request - participant Reconfig as rdk_dbg_priv_log_reconfig + participant Reconfig as rdk_dbg_priv_set_level participant Log4C as Log4C Category Admin->>Ctrl: rdklogctrl myapp LOG.RDK.MODULE DEBUG Ctrl->>Ctrl: Validate module name prefix and log level string - Ctrl->>UDP: sendto(127.255.255.255:12035, COMC-framed packet) + Ctrl->>Socket: sendto(/tmp/.logger.., COMC-framed packet) Note over Listener: Called from within target process event loop - Listener->>UDP: select() + recvfrom() — non-blocking - UDP-->>Listener: Binary control packet - Listener->>Listener: Verify COMC signature and sender == 127.0.0.1 + Listener->>Socket: select() + recvfrom() — non-blocking + Sicket-->>Listener: Binary control packet + Listener->>Listener: Verify COMC signature Listener->>Listener: Match __progname against app_name field - Listener->>Reconfig: rdk_dbg_priv_log_reconfig("LOG.RDK.MODULE", RDK_LOG_DEBUG) + Listener->>Reconfig: rdk_dbg_priv_set_level("LOG.RDK.MODULE", RDK_LOG_DEBUG) Reconfig->>Log4C: log4c_category_set_priority(cat, LOG4C_PRIORITY_DEBUG) Log4C-->>Reconfig: Priority updated Reconfig-->>Listener: true (success) @@ -300,12 +300,12 @@ sequenceDiagram | ------------------------- | --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | ---------------------------------------------------------------------------------- | | `Core Logging API` | Exposes the `RDK_LOG` macro, initialization functions, and log level enumeration. Entry point for all RDK components. | `include/rdk_logger.h`, `include/rdk_debug.h` | | `Initialization Manager` | Implements `rdk_logger_init()`, `rdk_logger_ext_init()`, and `rdk_logger_deinit()`. Guards one-time initialization with a mutex. Receives external data through the debug.ini file path. | `src/rdk_logger_init.c` | -| `Private Core` | Implements Log4C backend integration, all six layout formatters, three custom appender backends (`to_console`, `to_syslog`, `to_journal`) plus rolling file output via Log4C's built-in `rollingfile` appender, configuration file parsing (`rdk_logger_parse_config`), module-level log category management, and the `rdk_dbg_priv_log_msg` dispatch function. | `src/rdk_debug_priv.c`, `src/include/rdk_debug_priv.h` | -| `Debug Dispatch` | Public-facing wrappers (`rdk_logger_msg_printf`, `rdk_dbg_MsgRaw`, `rdk_logger_msg_vsprintf`) that validate parameters and forward to `rdk_dbg_priv_log_msg`. Also provides `rdk_logger_set_logLevel`, `rdk_logger_enable_logLevel`, and `rdk_logger_level_from_string`. | `src/rdk_debug.c` | -| `Dynamic Logger` | Implements the non-blocking UDP listener (port 12035) used for runtime log level control. Validates incoming `"COMC"`-signed messages and calls `rdk_dbg_priv_log_reconfig` on matched entries. | `src/rdk_dynamic_logger.c`, `src/include/rdk_dynamic_logger.h` | +| `Private Core` | Implements Log4C backend integration, all six layout formatters, three custom appender backends (`to_console`, `to_syslog`, `to_journal`) plus rolling file output via Log4C's built-in `rollingfile` appender, configuration file parsing (`rdk_logger_parse_config`), module-level log category management, and the `rdk_dbg_priv_log` dispatch function. | `src/rdk_debug_priv.c`, `src/include/rdk_debug_priv.h` | +| `Debug Dispatch` | Public-facing wrappers (`rdk_logger_msg_printf`, `rdk_dbg_MsgRaw`, `rdk_logger_msg_vsprintf`) that validate parameters and forward to `rdk_dbg_priv_log`. Also provides `rdk_logger_set_logLevel`, `rdk_logger_enable_logLevel`, and `rdk_logger_level_from_string`. | `src/rdk_debug.c` | +| `Dynamic Logger` | Implements the non-blocking socket listener used for runtime log level control. Validates incoming `"COMC"`-signed messages and calls `rdk_dbg_priv_set_level` on matched entries. | `src/rdk_dynamic_logger.c`, `src/include/rdk_dynamic_logger.h` | | `Milestone Logger` | Provides `logMilestone(msg_code)` which appends a `:` record to the milestones log file using `CLOCK_MONOTONIC_RAW`. Receives external data through the `msg_code` string argument. | `src/rdk_logger_milestone.c`, `include/rdk_logger_milestone.h` | | `Onboarding Logger` | Provides `rdk_logger_log_onboard(module, msg, ...)` for writing provisioning-phase log entries to a dedicated onboarding log file. Suppressed when `/nvram/.device_onboarded` or `/nvram/DISABLE_ONBOARD_LOGGING` exists. | `src/rdk_logger_onboard.c` | -| `Runtime Control Utility` | CLI tool (`rdklogctrl`) that constructs and sends `"COMC"`-framed UDP messages to change log levels in running processes. Also includes the milestone CLI tool (`rdklogmilestone`) and the onboarding utility (`rdk_logger_onboard_main`). | `utils/rdklogctrl.c`, `utils/rdklogmilestone.c`, `utils/rdk_logger_onboard_main.c` | +| `Runtime Control Utility` | CLI tool (`rdklogctrl`) that constructs and sends `"COMC"`-framed socket messages to change log levels in running processes. Also includes the milestone CLI tool (`rdklogmilestone`) and the onboarding utility (`rdk_logger_onboard_main`). | `utils/rdklogctrl.c`, `utils/rdklogmilestone.c`, `utils/rdk_logger_onboard_main.c` | --- @@ -322,7 +322,7 @@ RDK Logger is a foundational library where all interactions flow inward — midd | syslog daemon | System-wide log integration | `openlog()`, `syslog()`, `closelog()` — active when `HAVE_SYSLOG_H` is defined | | systemd journal | Modern Linux logging integration | `sd_journal_print()` — active when `HAVE_SYSTEMD` is defined and `libsystemd >= 209` is present | | File system | Configuration file parsing; milestone and onboarding log persistence | `fopen()`, `fgets()`, `fprintf()` on `/etc/debug.ini`, `/opt/debug.ini`, `/nvram/debug.ini`, milestone log, onboarding log | -| UDP socket (loopback) | Runtime log level control from `rdklogctrl` | `socket(AF_INET, SOCK_DGRAM)`, port 12035, `127.255.255.255` broadcast | +| unix socket (loopback) | Runtime log level control from `rdklogctrl` | `socket(AF_INET, SOCK_DGRAM)`, unicast | ### Events Published @@ -366,14 +366,14 @@ sequenceDiagram sequenceDiagram participant Operator as Operator participant Tool as rdklogctrl - participant Target as Target Process (RDK Logger UDP listener) + participant Target as Target Process (RDK Logger Socket listener) Operator->>Tool: rdklogctrl LOG.RDK. Tool->>Tool: Validate module prefix and level string - Tool->>Target: UDP packet to 127.255.255.255:12035 + Tool->>Target: Ctrl Message to unix Socket Note over Target: rdk_dyn_log_process_pending_request() polled by process Target->>Target: Verify COMC signature, sender IP, process name - Target->>Target: rdk_dbg_priv_log_reconfig(module, level) + Target->>Target: rdk_dbg_priv_set_level(module, level) Target->>Target: Log4C category priority updated immediately Target-->>Tool: (stderr confirmation in target process) ``` @@ -384,7 +384,7 @@ sequenceDiagram ### Key Implementation Logic -- **Initialization and Lifecycle Management**: `rdk_logger_init()` in `src/rdk_logger_init.c` serializes initialization using `gInitMutex` and the `isLogInited` flag to ensure idempotent behavior in multi-threaded environments. The initialization sequence calls `rdk_dbg_priv_init()` to register layout and appender types with Log4C and invoke `log4c_init()`, then calls `rdk_dbg_priv_config()` to parse the debug.ini file and set category priorities, then `rdk_dyn_log_init()` to open the UDP control socket. +- **Initialization and Lifecycle Management**: `rdk_logger_init()` in `src/rdk_logger_init.c` serializes initialization using `gInitMutex` and the `isLogInited` flag to ensure idempotent behavior in multi-threaded environments. The initialization sequence calls `rdk_dbg_priv_init()` to register layout and appender types with Log4C and invoke `log4c_init()`, then calls `rdk_dbg_priv_config()` to parse the debug.ini file and set category priorities, then `rdk_dyn_log_init()` to open the unix socket. - **Configuration Parsing**: `rdk_logger_parse_config()` in `src/rdk_debug_priv.c` reads the debug.ini file line-by-line, skipping comments and lines without `=`. For the `LOG.RDK.DEFAULT` entry it sets the root `LOG.RDK` category priority; for all other `LOG.RDK.*` entries it calls `log4c_category_get()` and `log4c_category_set_priority()`. Whitespace trimming is applied to both name and value tokens before comparison. Level strings are parsed case-insensitively by `rdk_logger_level_from_string()`. @@ -392,9 +392,9 @@ sequenceDiagram - **Extended Initialization and File Logging**: `rdk_logger_ext_init()` accepts an `rdk_logger_ext_config_t` structure specifying a module name, log level, output type (`RDKLOG_OUTPUT_CONSOLE`, `RDKLOG_OUTPUT_SYSLOG`, `RDKLOG_OUTPUT_JOURNAL`, or `RDKLOG_OUTPUT_FILE`), format type, and an optional `rdk_LogOutput_File` file policy. When `RDKLOG_OUTPUT_FILE` is selected, the `rdk_LogOutput_File` structure must be populated with `fileName` (log file prefix, max 64 chars), `fileLocation` (directory path, max 256 chars), `fileCountMax` (maximum number of rotating files), and `fileSizeMax` (maximum size per file in bytes). This path, implemented in `rdk_dbg_priv_ext_init()`, creates or retrieves a Log4C category and attaches a dedicated `rollingfile` appender with a `sizewin` rolling policy. File rolling closes the current appender before reconfiguring, preventing data loss. This mechanism is the primary means for components that require per-component log files on disk rather than shared console or system log output. -- **Runtime Log Level Control**: `rdk_dyn_log_process_pending_request()` in `src/rdk_dynamic_logger.c` uses a non-blocking `select()` call on the UDP socket to drain any pending control messages in a loop. Each message is validated for the `"COMC"` signature and loopback source address before `rdk_dyn_log_validate_component_name()` matches the target process name against `__progname`. Validated messages invoke `rdk_dbg_priv_log_reconfig()` which calls `log4c_category_set_priority()` with the new level. +- **Runtime Log Level Control**: `rdk_dyn_log_process_pending_request()` in `src/rdk_dynamic_logger.c` uses a non-blocking `select()` call on the unix socket to drain any pending control messages in a loop. Each message is validated for the `"COMC"` signature and loopback source address before `rdk_dyn_log_validate_component_name()` matches the target process name against `__progname`. Validated messages invoke `rdk_dbg_priv_set_level()` which calls `log4c_category_set_priority()` with the new level. -- **Error Handling Strategy**: If configuration file parsing fails, `rdk_logger_init()` returns `RDK_FAILURE` and writes a diagnostic message to `printf`. When `log4c_init()` encounters an error, `rdk_dbg_priv_init()` writes a diagnostic message to `stderr` and the process continues with category state unchanged. When the UDP socket cannot be bound, `rdk_dyn_log_init()` writes a diagnostic to `stderr` and the process continues with static log levels only. Onboarding log file write failures produce output on `printf` as a fallback. +- **Error Handling Strategy**: If configuration file parsing fails, `rdk_logger_init()` returns `RDK_FAILURE` and writes a diagnostic message to `printf`. When `log4c_init()` encounters an error, `rdk_dbg_priv_init()` writes a diagnostic message to `stderr` and the process continues with category state unchanged. When the unix socket cannot be bound, `rdk_dyn_log_init()` writes a diagnostic to `stderr` and the process continues with static log levels only. Onboarding log file write failures produce output on `printf` as a fallback. - **Logging & Diagnostics**: All `RDK_LOG()` calls use the `LOG.RDK.` naming convention. The root category `LOG.RDK` acts as the default parent for any module not explicitly listed in `debug.ini`. RDK Logger itself writes internal diagnostic messages to `stderr` (not through the `RDK_LOG` path) to avoid recursion during initialization or error conditions. diff --git a/docs/TROUBLESHOOTING.md b/docs/TROUBLESHOOTING.md index b5c144aa..210822a3 100644 --- a/docs/TROUBLESHOOTING.md +++ b/docs/TROUBLESHOOTING.md @@ -155,7 +155,7 @@ rdklogctrl "$(pidof -s myapp)" LOG.RDK.NETWORK DEBUG ps -ef | grep myapp # Check if process accepts socket connections -ss -xlp | grep '/tmp/.logger/' +ss -xlp | grep '/tmp/.logger_' ``` **Step 3: Test with simple module** @@ -487,10 +487,10 @@ void debug_config_loading() { #### Network Debugging for rdklogctrl ```bash # List per-process dynamic logger sockets -ss -xlpn | grep '/tmp/.logger/' +ss -xlpn | grep '/tmp/.logger_' # Verify socket ownership and permissions -ls -l /tmp/.logger +ls -l /tmp/.logger_.` ``` ### Quick Reference Checklist diff --git a/src/include/rdk_debug_priv.h b/src/include/rdk_debug_priv.h index 920db00d..f5585529 100644 --- a/src/include/rdk_debug_priv.h +++ b/src/include/rdk_debug_priv.h @@ -30,9 +30,9 @@ void rdk_dbg_priv_init(void); rdk_Error rdk_dbg_priv_config(const char *pConfigFile); void rdk_dbg_priv_deinit(void); rdk_Error rdk_dbg_priv_ext_init (const rdk_logger_ext_config_t* config); -void rdk_dbg_priv_log_msg(rdk_LogLevel level, const char *module_name, const char* format, va_list args); -bool rdk_dbg_priv_log_reconfig(const char *pModuleName, rdk_LogLevel level); -bool rdk_dbg_priv_log_get_level(const char *pModuleName, rdk_LogLevel *level); +void rdk_dbg_priv_log(rdk_LogLevel level, const char *module_name, const char* format, va_list args); +bool rdk_dbg_priv_set_level(const char *pModuleName, rdk_LogLevel level); +bool rdk_dbg_priv_get_level(const char *pModuleName, rdk_LogLevel *level); #ifdef __cplusplus } diff --git a/src/include/rdk_dynamic_logger.h b/src/include/rdk_dynamic_logger.h index 53d4b572..cefc69a1 100644 --- a/src/include/rdk_dynamic_logger.h +++ b/src/include/rdk_dynamic_logger.h @@ -23,16 +23,18 @@ #include #include -#define RDK_DYNAMIC_LOG_PACKET_MAX 128 -#define RDK_DYNAMIC_LOG_APP_NAME_MAX 120 +#define RDK_DYNAMIC_LOG_APP_NAME_MAX 64 #define RDK_DYNAMIC_LOG_COMPONENT_NAME_MAX 64 +#define RDK_DYNAMIC_SOCKET_PATH_PREFIX "/tmp/.logger" +#define RDK_DYNAMIC_LOG_SIGNATURE "COMC" +#define RDK_DYNAMIC_LOG_SIGNATURE_LEN 5 + typedef struct { - // The encoded wire packet remains capped by RDK_DYNAMIC_LOG_PACKET_MAX. - uint8_t signature[4]; + uint8_t signature[RDK_DYNAMIC_LOG_SIGNATURE_LEN]; uint8_t log_level; - char app_name[RDK_DYNAMIC_LOG_APP_NAME_MAX + 1]; - char component_name[RDK_DYNAMIC_LOG_COMPONENT_NAME_MAX + 1]; + char app_name[RDK_DYNAMIC_LOG_APP_NAME_MAX]; + char component_name[RDK_DYNAMIC_LOG_COMPONENT_NAME_MAX]; } rdk_dynamic_log_message_t; void rdk_dyn_log_init(void); diff --git a/src/rdk_debug.c b/src/rdk_debug.c index 8323e841..3e1e8734 100644 --- a/src/rdk_debug.c +++ b/src/rdk_debug.c @@ -49,7 +49,7 @@ void rdk_logger_msg_printf(rdk_LogLevel level, const char *module, const char *f if ((format) && (module)) { va_start(args, format); - rdk_dbg_priv_log_msg(level, module, format, args); + rdk_dbg_priv_log(level, module, format, args); va_end(args); } } @@ -69,7 +69,7 @@ void rdk_dbg_MsgRaw(rdk_LogLevel level, const char *module, const char *format, if ((format) && (module)) { va_start(args, format); - rdk_dbg_priv_log_msg(level, module, format, args); + rdk_dbg_priv_log(level, module, format, args); va_end(args); } } @@ -77,13 +77,13 @@ void rdk_dbg_MsgRaw(rdk_LogLevel level, const char *module, const char *format, void rdk_logger_msg_vsprintf(rdk_LogLevel level, const char *module, const char *format, va_list args) { if ((format) && (module)) - rdk_dbg_priv_log_msg(level, module, format, args); + rdk_dbg_priv_log(level, module, format, args); } void rdk_dbg_MsgRaw1(rdk_LogLevel level, const char *module, const char *format, va_list args) { if ((format) && (module)) - rdk_dbg_priv_log_msg(level, module, format, args); + rdk_dbg_priv_log(level, module, format, args); } /** @@ -97,7 +97,7 @@ void rdk_dbg_MsgRaw1(rdk_LogLevel level, const char *module, const char *format, bool rdk_logger_set_logLevel(const char *module, rdk_LogLevel logLevel) { if (module) - return rdk_dbg_priv_log_reconfig(module, logLevel); + return rdk_dbg_priv_set_level(module, logLevel); else return false; } @@ -110,7 +110,7 @@ bool rdk_logger_set_logLevel(const char *module, rdk_LogLevel logLevel) */ bool rdk_logger_get_logLevel(const char *module, rdk_LogLevel *logLevel) { - return rdk_dbg_priv_log_get_level(module, logLevel); + return rdk_dbg_priv_get_level(module, logLevel); } @@ -125,7 +125,7 @@ bool rdk_logger_enable_logLevel(const char *module, rdk_LogLevel logLevel, rdk_l { (void) enableLogLvl; if (module) - return rdk_dbg_priv_log_reconfig(module, logLevel); + return rdk_dbg_priv_set_level(module, logLevel); else return false; } diff --git a/src/rdk_debug_priv.c b/src/rdk_debug_priv.c index b422168b..b2ad7c53 100644 --- a/src/rdk_debug_priv.c +++ b/src/rdk_debug_priv.c @@ -147,6 +147,22 @@ static int rdk_logLevel_to_log4c_priority(rdk_LogLevel level) return LOG4C_PRIORITY_UNKNOWN; } +static rdk_LogLevel log4c_priority_to_rdk_logLevel (int level) +{ + switch (level) + { + case LOG4C_PRIORITY_FATAL: return RDK_LOG_FATAL; + case LOG4C_PRIORITY_ERROR: return RDK_LOG_ERROR; + case LOG4C_PRIORITY_WARN: return RDK_LOG_WARN; + case LOG4C_PRIORITY_NOTICE: return RDK_LOG_NOTICE; + case LOG4C_PRIORITY_INFO: return RDK_LOG_INFO; + case LOG4C_PRIORITY_DEBUG: return RDK_LOG_DEBUG; + case LOG4C_PRIORITY_TRACE: return RDK_LOG_TRACE; + default: + return RDK_LOG_NONE; + } +} + #if defined(HAVE_SYSTEMD) || defined(HAVE_SYSLOG_H) static int get_syslog_priority(int log4c_pr) { @@ -610,7 +626,7 @@ bool rdk_logger_is_logLevel_enabled(const char *module, rdk_LogLevel level) return isEnabled; } -void rdk_dbg_priv_log_msg(rdk_LogLevel level, const char *module_name, const char* format, va_list args) +void rdk_dbg_priv_log(rdk_LogLevel level, const char *module_name, const char* format, va_list args) { log4c_category_t* cat = NULL; int prio = 0; @@ -658,7 +674,7 @@ void rdk_dbg_priv_log_msg(rdk_LogLevel level, const char *module_name, const cha } -bool rdk_dbg_priv_log_reconfig(const char *pModuleName, rdk_LogLevel logLevel) +bool rdk_dbg_priv_set_level(const char *pModuleName, rdk_LogLevel logLevel) { bool ret = true; log4c_category_t* cat = NULL; @@ -684,10 +700,10 @@ bool rdk_dbg_priv_log_reconfig(const char *pModuleName, rdk_LogLevel logLevel) return ret; } -bool rdk_dbg_priv_log_get_level(const char *pModuleName, rdk_LogLevel *level) +bool rdk_dbg_priv_get_level(const char *pModuleName, rdk_LogLevel *level) { - log4c_category_t* cat; - int priority; + log4c_category_t* cat = NULL; + int priority = gRootPriority; if (pModuleName == NULL || pModuleName[0] == '\0' || level == NULL) return false; @@ -703,20 +719,7 @@ bool rdk_dbg_priv_log_get_level(const char *pModuleName, rdk_LogLevel *level) if (priority == LOG4C_PRIORITY_NOTSET) priority = gRootPriority; - switch (priority) { - case LOG4C_PRIORITY_FATAL: *level = RDK_LOG_FATAL; break; - case LOG4C_PRIORITY_ERROR: *level = RDK_LOG_ERROR; break; - case LOG4C_PRIORITY_WARN: *level = RDK_LOG_WARN; break; - case LOG4C_PRIORITY_NOTICE: *level = RDK_LOG_NOTICE; break; - case LOG4C_PRIORITY_INFO: *level = RDK_LOG_INFO; break; - case LOG4C_PRIORITY_DEBUG: *level = RDK_LOG_DEBUG; break; - case LOG4C_PRIORITY_TRACE: *level = RDK_LOG_TRACE; break; - case LOG4C_PRIORITY_NONE: - case LOG4C_PRIORITY_UNKNOWN: *level = RDK_LOG_NONE; break; - default: - pthread_mutex_unlock(&gLoggingMutex); - return false; - } + *level = log4c_priority_to_rdk_logLevel(priority); pthread_mutex_unlock(&gLoggingMutex); return true; diff --git a/src/rdk_dynamic_logger.c b/src/rdk_dynamic_logger.c index 129663d3..933f7dc0 100644 --- a/src/rdk_dynamic_logger.c +++ b/src/rdk_dynamic_logger.c @@ -37,43 +37,12 @@ #include "rdk_dynamic_logger.h" #include "rdk_debug_priv.h" -#define DL_SOCKET_DIR "/tmp/.logger" -#define DL_SIGNATURE "COMC" -#define DL_SIGNATURE_LEN 4 static int g_dl_socket = -1; -static char g_dl_socket_path[sizeof(((struct sockaddr_un *)0)->sun_path)]; static pid_t g_dl_socket_pid = -1; static pthread_mutex_t g_dl_request_mutex = PTHREAD_MUTEX_INITIALIZER; extern char *__progname; -static int rdk_dyn_log_make_socket_path(char *path, size_t path_size) -{ - struct stat dir_stat; - int length; - - if (__progname == NULL || __progname[0] == '\0') - return -1; - - if (mkdir(DL_SOCKET_DIR, 01777) == 0) { - /* mkdir honours the caller's umask; force the intended shared-directory mode. */ - if (chmod(DL_SOCKET_DIR, 01777) == -1) - return -1; - } else if (errno != EEXIST) { - return -1; - } - if (lstat(DL_SOCKET_DIR, &dir_stat) == -1 || !S_ISDIR(dir_stat.st_mode) || - (dir_stat.st_uid != 0 && dir_stat.st_uid != geteuid()) || - ((dir_stat.st_mode & (S_IWGRP | S_IWOTH)) && !(dir_stat.st_mode & S_ISVTX))) - return -1; - - length = snprintf(path, path_size, DL_SOCKET_DIR "/%s.%ld", __progname, (long)getpid()); - if (length < 0 || (size_t)length >= path_size || strchr(__progname, '/') != NULL) - return -1; - - return 0; -} - static char * rdk_dyn_log_logLevelToString(rdk_LogLevel log_level) { switch(log_level){ @@ -91,7 +60,7 @@ static char * rdk_dyn_log_logLevelToString(rdk_LogLevel log_level) static void rdk_dyn_log_validate_component_name(const rdk_dynamic_log_message_t *message) { - if (0 != memcmp(message->signature, DL_SIGNATURE, DL_SIGNATURE_LEN)) { + if (0 != memcmp(message->signature, RDK_DYNAMIC_LOG_SIGNATURE, RDK_DYNAMIC_LOG_SIGNATURE_LEN)) { return; } @@ -104,7 +73,7 @@ static void rdk_dyn_log_validate_component_name(const rdk_dynamic_log_message_t if((loggingLevel >= RDK_LOG_FATAL) && (loggingLevel <= RDK_LOG_NONE)) { - rdk_dbg_priv_log_reconfig(message->component_name, loggingLevel); + rdk_dbg_priv_set_level(message->component_name, loggingLevel); fprintf(stderr, "Log level change request to %s (%u) for the component %s, is success\n", rdk_dyn_log_logLevelToString(loggingLevel), loggingLevel, message->component_name); } else @@ -117,7 +86,6 @@ static void rdk_dyn_log_validate_component_name(const rdk_dynamic_log_message_t void rdk_dyn_log_process_pending_request() { - unsigned char packet[RDK_DYNAMIC_LOG_PACKET_MAX]; rdk_dynamic_log_message_t message = {0}; struct sockaddr_un sender_addr; struct timeval tv; @@ -142,6 +110,7 @@ void rdk_dyn_log_process_pending_request() pthread_mutex_unlock(&g_dl_request_mutex); return; } + while(1) { FD_ZERO(&rfds); FD_SET(g_dl_socket, &rfds); @@ -153,9 +122,7 @@ void rdk_dyn_log_process_pending_request() if(ret <= 0) break; - numbytes = recvfrom(g_dl_socket, packet, sizeof(packet), - MSG_DONTWAIT | MSG_TRUNC, - (struct sockaddr *)&sender_addr, &addr_len); + numbytes = recvfrom(g_dl_socket, &message, sizeof(message), MSG_DONTWAIT | MSG_TRUNC, (struct sockaddr *)&sender_addr, &addr_len); if (numbytes == -1) { if(errno == EAGAIN || errno == EWOULDBLOCK) break; @@ -164,100 +131,67 @@ void rdk_dyn_log_process_pending_request() return; } - if (numbytes > (int)sizeof(packet) || - numbytes < DL_SIGNATURE_LEN + 4 || - (size_t)numbytes != (size_t)packet[DL_SIGNATURE_LEN] + DL_SIGNATURE_LEN + 1 || - memcmp(packet, DL_SIGNATURE, DL_SIGNATURE_LEN) != 0) + if ((numbytes != (int)sizeof(message)) || + (memchr(message.app_name, '\0', sizeof(message.app_name)) == NULL) || + (memchr(message.component_name, '\0', sizeof(message.component_name)) == NULL)) continue; - app_len = packet[DL_SIGNATURE_LEN + 2]; - if (app_len == 0 || app_len > RDK_DYNAMIC_LOG_APP_NAME_MAX || - app_len > (size_t)numbytes - 8) - continue; - - comp_len_offset = DL_SIGNATURE_LEN + 3 + app_len; - if (comp_len_offset >= (size_t)numbytes) - continue; - comp_len = packet[comp_len_offset]; - if (comp_len == 0 || comp_len > RDK_DYNAMIC_LOG_COMPONENT_NAME_MAX || comp_len != (size_t)numbytes - comp_len_offset - 1) - continue; - - memset(&message, 0, sizeof(message)); - memcpy(message.signature, packet, DL_SIGNATURE_LEN); - message.log_level = packet[DL_SIGNATURE_LEN + 1]; - memcpy(message.app_name, packet + DL_SIGNATURE_LEN + 3, app_len); - memcpy(message.component_name, packet + comp_len_offset + 1, comp_len); - rdk_dyn_log_validate_component_name(&message); + if (0 == memcmp(message.signature, RDK_DYNAMIC_LOG_SIGNATURE, RDK_DYNAMIC_LOG_SIGNATURE_LEN)) + { + rdk_dyn_log_validate_component_name(&message); + } } pthread_mutex_unlock(&g_dl_request_mutex); } void rdk_dyn_log_init() { - struct sockaddr_un my_addr; - socklen_t addr_len; - int bind_result; + struct sockaddr_un myAddr; + socklen_t addrLen = sizeof (struct sockaddr_un); + int bind_result = -1; - pthread_mutex_lock(&g_dl_request_mutex); - if (rdk_dyn_log_make_socket_path(g_dl_socket_path, sizeof(g_dl_socket_path)) != 0) { - fprintf(stderr, "%s() invalid or unavailable socket directory/path\n", __func__); - pthread_mutex_unlock(&g_dl_request_mutex); - return; - } + memset(&myAddr, 0, sizeof(myAddr)); - /* Remove any stale entry; the sticky directory refuses to unlink entries owned by others. */ - if (unlink(g_dl_socket_path) == -1 && errno != ENOENT) { - fprintf(stderr, "%s() socket path is already in use: %s\n", __func__, strerror(errno)); - pthread_mutex_unlock(&g_dl_request_mutex); + if (__progname == NULL) return; - } - if ((g_dl_socket = socket(AF_UNIX, SOCK_DGRAM, 0)) == -1) { + pthread_mutex_lock(&g_dl_request_mutex); + + if ((g_dl_socket = socket(AF_UNIX, SOCK_DGRAM, 0)) == -1) + { fprintf(stderr, "%s() Socket creation failed. %s\n",__func__,strerror(errno)); pthread_mutex_unlock(&g_dl_request_mutex); return; } - /* Bind in a private (0700) directory so no one can queue packets before the socket is 0600. */ - char stage_dir[] = DL_SOCKET_DIR "/.stage.XXXXXX"; - char stage_path[sizeof(stage_dir) + 8]; - if (mkdtemp(stage_dir) == NULL) { - fprintf(stderr, "%s() staging directory error %s\n", __func__, strerror(errno)); + myAddr.sun_family = AF_UNIX; + + // The path is, "/tmp/.logger_." + int pathLength = 1 + snprintf(myAddr.sun_path, 0, "%s_%s.%ld", RDK_DYNAMIC_SOCKET_PATH_PREFIX, __progname, (long)getpid()); + if (pathLength > sizeof(myAddr.sun_path)) + { + fprintf (stderr, "long process name that cannot be communicated\n"); close(g_dl_socket); g_dl_socket = -1; pthread_mutex_unlock(&g_dl_request_mutex); return; } - snprintf(stage_path, sizeof(stage_path), "%s/s", stage_dir); - memset(&my_addr,0,sizeof(my_addr)); - my_addr.sun_family = AF_UNIX; - memcpy(my_addr.sun_path, stage_path, strlen(stage_path) + 1); - addr_len = (socklen_t)(offsetof(struct sockaddr_un, sun_path) + strlen(my_addr.sun_path) + 1); + snprintf(myAddr.sun_path, sizeof(myAddr.sun_path), "%s_%s.%ld", RDK_DYNAMIC_SOCKET_PATH_PREFIX, __progname, (long)getpid()); - bind_result = bind(g_dl_socket, (struct sockaddr *)&my_addr, addr_len); - if (-1 == bind_result) { + bind_result = bind(g_dl_socket, (struct sockaddr *)&myAddr, sizeof(myAddr)); + if (-1 == bind_result) + { fprintf(stderr, "%s() bind error %s\n",__func__,strerror(errno)); - rmdir(stage_dir); - close(g_dl_socket); - g_dl_socket = -1; - pthread_mutex_unlock(&g_dl_request_mutex); - return; - } - - if (chmod(stage_path, 0600) == -1 || rename(stage_path, g_dl_socket_path) == -1) { - fprintf(stderr, "%s() socket publish error %s\n",__func__,strerror(errno)); close(g_dl_socket); - unlink(stage_path); - rmdir(stage_dir); g_dl_socket = -1; pthread_mutex_unlock(&g_dl_request_mutex); return; } - rmdir(stage_dir); g_dl_socket_pid = getpid(); pthread_mutex_unlock(&g_dl_request_mutex); + return; } void rdk_dyn_log_deinit() @@ -267,10 +201,6 @@ void rdk_dyn_log_deinit() { close(g_dl_socket); g_dl_socket = -1; - /* A forked child must not remove the parent's live socket. */ - if (g_dl_socket_pid == getpid()) - unlink(g_dl_socket_path); - g_dl_socket_path[0] = '\0'; } pthread_mutex_unlock(&g_dl_request_mutex); } diff --git a/utils/rdklogctrl.c b/utils/rdklogctrl.c index d065e527..57cd0fbf 100644 --- a/utils/rdklogctrl.c +++ b/utils/rdklogctrl.c @@ -12,9 +12,6 @@ #define COMP_SIGNATURE "LOG.RDK." #define COMP_SIGNATURE_LEN 8 -#define DL_SOCKET_DIR "/tmp/.logger" -#define DL_SIGNATURE "COMC" -#define DL_SIGNATURE_LEN 4 static void usage(const char* app_name) { @@ -92,21 +89,16 @@ static int8_t validate_loglevel(const char* level) int main(int argc, char *argv[]) { - struct sockaddr_un dest_addr; + struct sockaddr_un destAddr; int sockfd, numbytes; long parsed_pid; char *pid_end; const char *pid_character; pid_t target_pid; char process_name[RDK_DYNAMIC_LOG_APP_NAME_MAX + 1]; - char socket_path[sizeof(dest_addr.sun_path)]; - int socket_path_length; - socklen_t dest_addr_length; - size_t app_len, comp_len, app_offset, component_length_offset; - size_t component_offset, packet_length; + size_t app_len, comp_len; int8_t level = -1; rdk_dynamic_log_message_t message = {0}; - unsigned char packet[RDK_DYNAMIC_LOG_PACKET_MAX] = {0}; if (argc != 4) { usage(argv[0]); @@ -127,6 +119,7 @@ int main(int argc, char *argv[]) fprintf(stderr, "Invalid process ID\n"); return -1; } + target_pid = (pid_t)parsed_pid; comp_len = strlen(argv[2]); @@ -135,6 +128,13 @@ int main(int argc, char *argv[]) return -1; } + if( (0 != strncmp(argv[2], COMP_SIGNATURE, COMP_SIGNATURE_LEN))) + { + printf("Invalid module name\n"); + usage(argv[0]); + return -1; + } + level = validate_loglevel(argv[3]); if(-1 == level) { printf("Invalid log level\n"); @@ -147,83 +147,50 @@ int main(int argc, char *argv[]) return -1; } - if(0 != strcmp("Receiver",process_name)) { - if( (0 != strncmp(argv[2],COMP_SIGNATURE,COMP_SIGNATURE_LEN))) - { - printf("Invalid module name\n"); - usage(argv[0]); - return -1; - } - } - app_len = strlen(process_name); if (app_len == 0 || app_len > RDK_DYNAMIC_LOG_APP_NAME_MAX) { fprintf(stderr, "App or module name exceeds packet field size\n"); return -1; } - app_offset = DL_SIGNATURE_LEN + 3; - if (app_offset > sizeof(packet) || app_len > sizeof(packet) - app_offset) { - fprintf(stderr, "App name exceeds packet buffer\n"); - return -1; - } - component_length_offset = app_offset + app_len; - if (component_length_offset >= sizeof(packet)) { - fprintf(stderr, "Component length offset exceeds packet buffer\n"); - return -1; - } - component_offset = component_length_offset + 1; - if (comp_len > sizeof(packet) - component_offset) { - fprintf(stderr, "Component name exceeds packet buffer\n"); - return -1; - } - packet_length = component_offset + comp_len; - socket_path_length = snprintf(socket_path, sizeof(socket_path), DL_SOCKET_DIR "/%s.%ld", - process_name, parsed_pid); - if (socket_path_length < 0 || (size_t)socket_path_length >= sizeof(socket_path)) { - fprintf(stderr, "Process socket path is too long\n"); + if ((sockfd = socket(AF_UNIX, SOCK_DGRAM, 0)) == -1) { + printf("socket: %s\n",strerror(errno)); return -1; } - if ((sockfd = socket(AF_UNIX, SOCK_DGRAM, 0)) == -1) { - printf("socket: %s\n",strerror(errno)); + memset(&destAddr, 0,sizeof(destAddr)); + destAddr.sun_family = AF_UNIX; + int pathLength = 1 + snprintf(destAddr.sun_path, 0, "%s_%s.%ld", RDK_DYNAMIC_SOCKET_PATH_PREFIX, process_name, (long)parsed_pid); + + if (pathLength > sizeof(destAddr.sun_path)) + { + printf ("long process name that cannot be communicated\n"); return -1; } - memset(&dest_addr,0,sizeof(dest_addr)); - dest_addr.sun_family = AF_UNIX; - memcpy(dest_addr.sun_path, socket_path, (size_t)socket_path_length + 1); - dest_addr_length = (socklen_t)(offsetof(struct sockaddr_un, sun_path) + - (size_t)socket_path_length + 1); + snprintf(destAddr.sun_path, sizeof(destAddr.sun_path), "%s_%s.%ld", RDK_DYNAMIC_SOCKET_PATH_PREFIX, process_name, (long)parsed_pid); - memcpy(message.signature, DL_SIGNATURE, DL_SIGNATURE_LEN); + snprintf(message.signature, RDK_DYNAMIC_LOG_SIGNATURE_LEN, "%s", RDK_DYNAMIC_LOG_SIGNATURE); message.log_level = (uint8_t)level; - memcpy(message.app_name, process_name, app_len); - memcpy(message.component_name, argv[2], comp_len); - - memcpy(packet, message.signature, DL_SIGNATURE_LEN); - packet[DL_SIGNATURE_LEN] = (uint8_t)(app_len + comp_len + 3); - packet[DL_SIGNATURE_LEN + 1] = message.log_level; - packet[DL_SIGNATURE_LEN + 2] = (uint8_t)app_len; - memcpy(packet + app_offset, message.app_name, app_len); - packet[component_length_offset] = (uint8_t)comp_len; - memcpy(packet + component_offset, message.component_name, comp_len); - - if ((numbytes=sendto(sockfd, packet, packet_length, MSG_DONTWAIT, - (struct sockaddr *)&dest_addr, dest_addr_length)) == -1) { + snprintf(message.app_name, RDK_DYNAMIC_LOG_APP_NAME_MAX, "%s", process_name); + snprintf(message.component_name, RDK_DYNAMIC_LOG_COMPONENT_NAME_MAX, "%s", argv[2]); + + if ((numbytes = sendto(sockfd, (const void*) &message, sizeof(message), MSG_DONTWAIT, (struct sockaddr *)&destAddr, sizeof(destAddr))) == -1) + { printf("sendto: %s\n",strerror(errno)); close(sockfd); return -1; } - if ((size_t)numbytes != packet_length) { + + if ((size_t)numbytes != sizeof(message)) + { fprintf(stderr, "sendto sent an incomplete dynamic log packet\n"); close(sockfd); return -1; } - printf("Sent message to update log level of %s for PID %ld (%s)\n", - argv[2], parsed_pid, process_name); + printf("Sent message to update log level of %s for PID %ld (%s)\n", argv[2], parsed_pid, process_name); close(sockfd); return 0; } From c4d78321cb3c1afa888572953b33a5bfa3369941 Mon Sep 17 00:00:00 2001 From: Deepthi Date: Thu, 22 Oct 2026 05:42:56 +0000 Subject: [PATCH 09/10] Address Copilot review comments Signed-off-by: Deepthi --- docs/README.md | 11 ++++------- unittests/rdkLoggerDynamic.cpp | 14 ++++++++++++++ 2 files changed, 18 insertions(+), 7 deletions(-) diff --git a/docs/README.md b/docs/README.md index 29b81611..59960f87 100644 --- a/docs/README.md +++ b/docs/README.md @@ -170,7 +170,7 @@ sequenceDiagram PrivCore-->>Logger: RDK_SUCCESS Logger->>DynLog: rdk_dyn_log_init() - DynLog->>DynLog: socket(AF_INET, SOCK_DGRAM) bind /tmp/.logger.. + DynLog->>DynLog: socket(AF_UNIX, SOCK_DGRAM) bind /tmp/.logger_. DynLog-->>Logger: Socket listener ready Note over Logger: isLogInited = true @@ -282,7 +282,7 @@ sequenceDiagram Ctrl->>Socket: sendto(/tmp/.logger.., COMC-framed packet) Note over Listener: Called from within target process event loop Listener->>Socket: select() + recvfrom() — non-blocking - Sicket-->>Listener: Binary control packet + Socket-->>Listener: Binary control packet Listener->>Listener: Verify COMC signature Listener->>Listener: Match __progname against app_name field Listener->>Reconfig: rdk_dbg_priv_set_level("LOG.RDK.MODULE", RDK_LOG_DEBUG) @@ -322,8 +322,7 @@ RDK Logger is a foundational library where all interactions flow inward — midd | syslog daemon | System-wide log integration | `openlog()`, `syslog()`, `closelog()` — active when `HAVE_SYSLOG_H` is defined | | systemd journal | Modern Linux logging integration | `sd_journal_print()` — active when `HAVE_SYSTEMD` is defined and `libsystemd >= 209` is present | | File system | Configuration file parsing; milestone and onboarding log persistence | `fopen()`, `fgets()`, `fprintf()` on `/etc/debug.ini`, `/opt/debug.ini`, `/nvram/debug.ini`, milestone log, onboarding log | -| unix socket (loopback) | Runtime log level control from `rdklogctrl` | `socket(AF_INET, SOCK_DGRAM)`, unicast | - +| Unix-domain datagram socket | Runtime log level control from `rdklogctrl` | `socket(AF_UNIX, SOCK_DGRAM)`, `/tmp/.logger_.` | ### Events Published RDK Logger operates as a logging service, receiving log messages and control commands from RDK components and routing output to configured destinations. The table below captures the operational signals it emits. @@ -392,9 +391,7 @@ sequenceDiagram - **Extended Initialization and File Logging**: `rdk_logger_ext_init()` accepts an `rdk_logger_ext_config_t` structure specifying a module name, log level, output type (`RDKLOG_OUTPUT_CONSOLE`, `RDKLOG_OUTPUT_SYSLOG`, `RDKLOG_OUTPUT_JOURNAL`, or `RDKLOG_OUTPUT_FILE`), format type, and an optional `rdk_LogOutput_File` file policy. When `RDKLOG_OUTPUT_FILE` is selected, the `rdk_LogOutput_File` structure must be populated with `fileName` (log file prefix, max 64 chars), `fileLocation` (directory path, max 256 chars), `fileCountMax` (maximum number of rotating files), and `fileSizeMax` (maximum size per file in bytes). This path, implemented in `rdk_dbg_priv_ext_init()`, creates or retrieves a Log4C category and attaches a dedicated `rollingfile` appender with a `sizewin` rolling policy. File rolling closes the current appender before reconfiguring, preventing data loss. This mechanism is the primary means for components that require per-component log files on disk rather than shared console or system log output. -- **Runtime Log Level Control**: `rdk_dyn_log_process_pending_request()` in `src/rdk_dynamic_logger.c` uses a non-blocking `select()` call on the unix socket to drain any pending control messages in a loop. Each message is validated for the `"COMC"` signature and loopback source address before `rdk_dyn_log_validate_component_name()` matches the target process name against `__progname`. Validated messages invoke `rdk_dbg_priv_set_level()` which calls `log4c_category_set_priority()` with the new level. - -- **Error Handling Strategy**: If configuration file parsing fails, `rdk_logger_init()` returns `RDK_FAILURE` and writes a diagnostic message to `printf`. When `log4c_init()` encounters an error, `rdk_dbg_priv_init()` writes a diagnostic message to `stderr` and the process continues with category state unchanged. When the unix socket cannot be bound, `rdk_dyn_log_init()` writes a diagnostic to `stderr` and the process continues with static log levels only. Onboarding log file write failures produce output on `printf` as a fallback. +- **Runtime Log Level Control**: `rdk_dyn_log_process_pending_request()` in `src/rdk_dynamic_logger.c` uses a non-blocking `select()` call on the Unix socket to drain pending control messages. Each message is checked for its size, terminated name fields, and `"COMC"` signature before `rdk_dyn_log_validate_component_name()` matches the target process name against `__progname` and validates the log level. Validated messages invoke `rdk_dbg_priv_set_level()` to update the category priority. Sender credentials are not checked. - **Logging & Diagnostics**: All `RDK_LOG()` calls use the `LOG.RDK.` naming convention. The root category `LOG.RDK` acts as the default parent for any module not explicitly listed in `debug.ini`. RDK Logger itself writes internal diagnostic messages to `stderr` (not through the `RDK_LOG` path) to avoid recursion during initialization or error conditions. diff --git a/unittests/rdkLoggerDynamic.cpp b/unittests/rdkLoggerDynamic.cpp index 8498b3de..95c4b639 100644 --- a/unittests/rdkLoggerDynamic.cpp +++ b/unittests/rdkLoggerDynamic.cpp @@ -361,6 +361,20 @@ static int run_and_print(const std::string& command, std::string& output) { return pclose(pipe); } +TEST(RdkDynamicLoggerTest, Critical001_AcceptsBoundaryComponentName) { + ASSERT_EQ(rdk_logger_init(GTEST_DEBUG_INI_FILE), RDK_SUCCESS); + const std::string component = "LOG.RDK." + std::string(56, 'A'); + ASSERT_EQ(component.size(), 64U); + ASSERT_TRUE(rdk_logger_set_logLevel(component.c_str(), RDK_LOG_NONE)); + std::string output; + ASSERT_EQ(run_and_print("./rdklogctrl " + std::to_string((long)getpid()) + " " + + component + " INFO", output), 0); + rdk_logger_msg_printf(RDK_LOG_ERROR, "LOG.RDK.TESTMOD", "Process dynamic log request\n"); + rdk_LogLevel level = RDK_LOG_NONE; + ASSERT_TRUE(rdk_logger_get_logLevel(component.c_str(), &level)); + EXPECT_EQ(level, RDK_LOG_INFO); + } + TEST(RdkDynamicLoggerTest, Critical001_RejectsOversizedComponentName) { // 65 characters: one more than the 64-byte component limit const std::string component = "LOG.RDK." + std::string(57, 'A'); From 494e6bd5b3ec288350ac011bd209adb028eb666a Mon Sep 17 00:00:00 2001 From: Deepthi Date: Thu, 22 Oct 2026 06:05:46 +0000 Subject: [PATCH 10/10] Restore terminator space for boundary-length names Signed-off-by: Deepthi --- src/include/rdk_dynamic_logger.h | 4 ++-- utils/rdklogctrl.c | 4 ++-- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/src/include/rdk_dynamic_logger.h b/src/include/rdk_dynamic_logger.h index cefc69a1..276a0699 100644 --- a/src/include/rdk_dynamic_logger.h +++ b/src/include/rdk_dynamic_logger.h @@ -33,8 +33,8 @@ typedef struct { uint8_t signature[RDK_DYNAMIC_LOG_SIGNATURE_LEN]; uint8_t log_level; - char app_name[RDK_DYNAMIC_LOG_APP_NAME_MAX]; - char component_name[RDK_DYNAMIC_LOG_COMPONENT_NAME_MAX]; + char app_name[RDK_DYNAMIC_LOG_APP_NAME_MAX + 1]; + char component_name[RDK_DYNAMIC_LOG_COMPONENT_NAME_MAX + 1]; } rdk_dynamic_log_message_t; void rdk_dyn_log_init(void); diff --git a/utils/rdklogctrl.c b/utils/rdklogctrl.c index 57cd0fbf..cd8e76fb 100644 --- a/utils/rdklogctrl.c +++ b/utils/rdklogctrl.c @@ -173,8 +173,8 @@ int main(int argc, char *argv[]) snprintf(message.signature, RDK_DYNAMIC_LOG_SIGNATURE_LEN, "%s", RDK_DYNAMIC_LOG_SIGNATURE); message.log_level = (uint8_t)level; - snprintf(message.app_name, RDK_DYNAMIC_LOG_APP_NAME_MAX, "%s", process_name); - snprintf(message.component_name, RDK_DYNAMIC_LOG_COMPONENT_NAME_MAX, "%s", argv[2]); + snprintf(message.app_name, sizeof(message.app_name), "%s", process_name); + snprintf(message.component_name, sizeof(message.component_name), "%s", argv[2]); if ((numbytes = sendto(sockfd, (const void*) &message, sizeof(message), MSG_DONTWAIT, (struct sockaddr *)&destAddr, sizeof(destAddr))) == -1) {