From babfa5cebe72b2802b5c1ec5b2df05bbe2613001 Mon Sep 17 00:00:00 2001 From: Alexander Mohr Date: Tue, 22 Oct 2024 12:02:56 +0200 Subject: [PATCH] trace-load: improve lookup speeds and reduce cpu load caused Signed-off-by: Alexander Mohr --- include/dlt/dlt_user.h.in | 3 ++ src/daemon/dlt-daemon.c | 67 ++++++++++++++++------- src/daemon/dlt_daemon_common.c | 26 ++++++--- src/daemon/dlt_daemon_common.h | 5 +- src/lib/dlt_user.c | 97 +++++++++++++++++++++------------- src/shared/dlt_common.c | 10 +++- 6 files changed, 143 insertions(+), 65 deletions(-) diff --git a/include/dlt/dlt_user.h.in b/include/dlt/dlt_user.h.in index 42254acec..5a0ec1e26 100644 --- a/include/dlt/dlt_user.h.in +++ b/include/dlt/dlt_user.h.in @@ -180,6 +180,9 @@ typedef struct /* Log Level changed callback */ void (*log_level_changed_callback)(char context_id[DLT_ID_SIZE], uint8_t log_level, uint8_t trace_status); +#ifdef DLT_TRACE_LOAD_CTRL_ENABLE + DltTraceLoadSettings *trace_load_settings; /**< trace load setting for the context */ +#endif } dlt_ll_ts_type; /** diff --git a/src/daemon/dlt-daemon.c b/src/daemon/dlt-daemon.c index 884338b52..703afe1a3 100644 --- a/src/daemon/dlt-daemon.c +++ b/src/daemon/dlt-daemon.c @@ -112,6 +112,7 @@ struct DltTraceLoadLogParams { }; static DltReturnValue dlt_daemon_output_internal_msg(DltLogLevelType loglevel, const char *text, void *params); +static void dlt_trace_load_free(DltDaemon* daemon); pthread_rwlock_t trace_load_rw_lock; #endif @@ -1636,6 +1637,9 @@ int main(int argc, char *argv[]) dlt_gateway_deinit(&daemon_local.pGateway, daemon_local.flags.vflag); dlt_daemon_free(&daemon, daemon_local.flags.vflag); +#ifdef DLT_TRACE_LOAD_CTRL_ENABLE + dlt_trace_load_free(&daemon); +#endif dlt_log(LOG_NOTICE, "Leaving DLT daemon\n"); @@ -1646,6 +1650,18 @@ int main(int argc, char *argv[]) } /* main() */ #endif +#ifdef DLT_TRACE_LOAD_CTRL_ENABLE +void dlt_trace_load_free(DltDaemon* daemon) +{ + if (daemon->preconfigured_trace_load_settings != NULL) { + free(daemon->preconfigured_trace_load_settings); + daemon->preconfigured_trace_load_settings = NULL; + } + pthread_rwlock_destroy(&trace_load_rw_lock); +} +#endif + + int dlt_daemon_local_init_p1(DltDaemon *daemon, DltDaemonLocal *daemon_local, int verbose) { PRINT_FUNCTION_VERBOSE(verbose); @@ -3976,27 +3992,40 @@ bool trace_load_keep_message(DltDaemonApplication *app, app->apid, }; - DltTraceLoadSettings *trace_load_settings = - dlt_find_runtime_trace_load_settings( - app->trace_load_settings, app->trace_load_settings_count, - app->apid, msg->extendedheader->ctid); - - if (trace_load_settings != NULL) { - pthread_rwlock_wrlock(&trace_load_rw_lock); - keep_message = dlt_check_trace_load( - trace_load_settings, mtin, msg->headerextra.tmsp, size, - dlt_daemon_output_internal_msg, (void *)(¶ms)); - pthread_rwlock_unlock(&trace_load_rw_lock); - } - else { - dlt_vlog( - LOG_ERR, - "Failed to lookup trace load limits for %s, " - "dropping message, likely app was not registered properly\n", - app->apid); - keep_message = false; + DltDaemonContext *context = dlt_daemon_context_find( + daemon, + app->apid, + msg->extendedheader->ctid, + daemon->ecuid, + verbose); + + + if (context == NULL) { + context = dlt_daemon_context_add( + daemon, + app->apid, + msg->extendedheader->ctid, + daemon->default_log_level, + daemon->default_trace_status, + 0, + app->user_handle, + "", + daemon->ecuid, + verbose); + if (context == NULL) { + dlt_vlog(LOG_WARNING, + "Can't add ContextID '%.4s' for ApID '%.4s' in %s\n", + msg->extendedheader->ctid, app->apid, __func__); + return false; + } } + pthread_rwlock_wrlock(&trace_load_rw_lock); + keep_message = dlt_check_trace_load( + context->trace_load_settings, mtin, msg->headerextra.tmsp, size, + dlt_daemon_output_internal_msg, (void *)(¶ms)); + pthread_rwlock_unlock(&trace_load_rw_lock); + return keep_message; } #endif diff --git a/src/daemon/dlt_daemon_common.c b/src/daemon/dlt_daemon_common.c index f3aa277b9..9104295d4 100644 --- a/src/daemon/dlt_daemon_common.c +++ b/src/daemon/dlt_daemon_common.c @@ -442,13 +442,6 @@ int dlt_daemon_free(DltDaemon *daemon, int verbose) free(daemon->app_id_log_level_settings); } #endif -#ifdef DLT_TRACE_LOAD_CTRL_ENABLE - if (daemon->preconfigured_trace_load_settings != NULL) { - free(daemon->preconfigured_trace_load_settings); - daemon->preconfigured_trace_load_settings = NULL; - } - pthread_rwlock_destroy(&trace_load_rw_lock); -#endif if (app_recv_buffer) free(app_recv_buffer); @@ -1134,6 +1127,10 @@ DltDaemonContext *dlt_daemon_context_add(DltDaemon *daemon, dlt_set_id(context->apid, apid); dlt_set_id(context->ctid, ctid); +#ifdef DLT_TRACE_LOAD_CTRL_ENABLE + context->trace_load_settings = NULL; +#endif + application->num_contexts++; new_context = 1; } @@ -1213,6 +1210,21 @@ DltDaemonContext *dlt_daemon_context_add(DltDaemon *daemon, context->log_level_pos = log_level_pos; context->user_handle = user_handle; +#ifdef DLT_TRACE_LOAD_CTRL_ENABLE + DltTraceLoadSettings* tl_settings = dlt_find_runtime_trace_load_settings( + application->trace_load_settings, + application->trace_load_settings_count, + application->apid, + context->ctid); + if (tl_settings == NULL) { + dlt_vlog(LOG_WARNING, "failed to find trace load settings for application %s context %s\n", + application->apid, context->ctid); + } else { + context->trace_load_settings = tl_settings; + } +#endif + + /* In case a context is loaded from runtime config file, * the user_handle is 0 and we mark that context as predefined. */ diff --git a/src/daemon/dlt_daemon_common.h b/src/daemon/dlt_daemon_common.h index fc91ee934..02470322f 100644 --- a/src/daemon/dlt_daemon_common.h +++ b/src/daemon/dlt_daemon_common.h @@ -162,7 +162,10 @@ typedef struct int user_handle; /**< connection handle for connection to user application */ char *context_description; /**< context description */ int8_t storage_log_level; /**< log level set for offline logstorage */ - bool predefined; /**< set to true if this context is predefined by runtime configuration file */ + bool predefined; +#ifdef DLT_TRACE_LOAD_CTRL_ENABLE + DltTraceLoadSettings* trace_load_settings; /**< trace load setting for the context */ +#endif } DltDaemonContext; /* diff --git a/src/lib/dlt_user.c b/src/lib/dlt_user.c index a20cd7814..0ed53d24f 100644 --- a/src/lib/dlt_user.c +++ b/src/lib/dlt_user.c @@ -227,6 +227,7 @@ static DltReturnValue dlt_unregister_app_util(bool force_sending_messages); #ifdef DLT_TRACE_LOAD_CTRL_ENABLE /* For trace load control feature */ static DltReturnValue dlt_user_output_internal_msg(DltLogLevelType loglevel, const char *text, void* params); +DltContext trace_load_context = {0}; DltTraceLoadSettings* trace_load_settings = NULL; uint32_t trace_load_settings_count = 0; pthread_rwlock_t trace_load_rw_lock = PTHREAD_RWLOCK_INITIALIZER; @@ -514,7 +515,6 @@ DltReturnValue dlt_init(void) #endif #ifdef DLT_TRACE_LOAD_CTRL_ENABLE pthread_rwlock_wrlock(&trace_load_rw_lock); - trace_load_settings = malloc(sizeof(DltTraceLoadSettings)); if (trace_load_settings == NULL) { dlt_vlog(LOG_ERR, "Failed to allocate memory for trace load settings\n"); @@ -526,9 +526,7 @@ DltReturnValue dlt_init(void) trace_load_settings[0].hard_limit = DLT_TRACE_LOAD_CLIENT_HARD_LIMIT_DEFAULT; strncpy(trace_load_settings[0].apid, dlt_user.appID, DLT_ID_SIZE); trace_load_settings_count = 1; - pthread_rwlock_unlock(&trace_load_rw_lock); - #endif #ifdef DLT_LIB_USE_UNIX_SOCKET_IPC @@ -1307,7 +1305,18 @@ DltReturnValue dlt_register_app(const char *apid, const char *description) DLT_SEM_FREE(); #ifdef DLT_TRACE_LOAD_CTRL_ENABLE + pthread_rwlock_wrlock(&trace_load_rw_lock); strncpy(trace_load_settings[0].apid, dlt_user.appID, DLT_ID_SIZE); + pthread_rwlock_unlock(&trace_load_rw_lock); + if (!trace_load_context.contextID[0]) + { + // Register Special Context ID for output DLT library internal message + ret = dlt_register_context(&trace_load_context, DLT_TRACE_LOAD_CONTEXT_ID, "DLT user library internal context"); + if (ret < DLT_RETURN_OK) + { + return ret; + } + } #endif ret = dlt_user_log_send_register_application(); @@ -1542,9 +1551,17 @@ DltReturnValue dlt_register_context_ll_ts_llccb(DltContext *handle, log.trace_status = tracestatus; dlt_user.dlt_ll_ts_num_entries++; - DLT_SEM_FREE(); +#ifdef DLT_TRACE_LOAD_CTRL_ENABLE + pthread_rwlock_rdlock(&trace_load_rw_lock); + DltTraceLoadSettings *settings = dlt_find_runtime_trace_load_settings( + trace_load_settings, trace_load_settings_count, dlt_user.appID, + ctx_entry->contextID); + ctx_entry->trace_load_settings = settings; + pthread_rwlock_unlock(&trace_load_rw_lock); +#endif + return dlt_user_log_send_register_context(&log); } @@ -1676,6 +1693,10 @@ DltReturnValue dlt_unregister_context(DltContext *handle) return DLT_RETURN_ERROR; } +#ifdef DLT_TRACE_LOAD_CTRL_ENABLE + pthread_rwlock_wrlock(&trace_load_rw_lock); +#endif + DLT_SEM_LOCK(); handle->log_level_ptr = NULL; @@ -1712,7 +1733,9 @@ DltReturnValue dlt_unregister_context(DltContext *handle) dlt_user.dlt_ll_ts[handle->log_level_pos].nrcallbacks = 0; dlt_user.dlt_ll_ts[handle->log_level_pos].log_level_changed_callback = 0; } - +#ifdef DLT_TRACE_LOAD_CTRL_ENABLE + pthread_rwlock_unlock(&trace_load_rw_lock); +#endif DLT_SEM_FREE(); /* Inform daemon to unregister context */ @@ -4169,13 +4192,25 @@ DltReturnValue dlt_user_log_send_log(DltContextData *log, const int mtype, int * /* check trace load before output */ if (!sent_size) { + if ((uint32_t)log->handle->log_level_pos > dlt_user.dlt_ll_ts_num_entries) { + char msg[255]; + sprintf(msg, "log handle has invalid log level pos %d, current entries: %u, dropping message\n", + log->handle->log_level_pos, dlt_user.dlt_ll_ts_num_entries); + dlt_user_output_internal_msg(LOG_ERR, msg, NULL); + return DLT_RETURN_ERROR; + } + pthread_rwlock_wrlock(&trace_load_rw_lock); - DltTraceLoadSettings* settings = - dlt_find_runtime_trace_load_settings( + dlt_ll_ts_type* ll_ts = &dlt_user.dlt_ll_ts[log->handle->log_level_pos]; + if (ll_ts->trace_load_settings == NULL) { + ll_ts->trace_load_settings = dlt_find_runtime_trace_load_settings( trace_load_settings, trace_load_settings_count, dlt_user.appID, log->handle->contextID); + } + const bool trace_load_in_limits = dlt_check_trace_load( - settings, - log->log_level, time_stamp, + ll_ts->trace_load_settings, + log->log_level, + time_stamp, sizeof(DltUserHeader) + msg.headersize - sizeof(DltStorageHeader) + log->size, @@ -4403,7 +4438,6 @@ DltReturnValue dlt_user_log_send_register_context(DltContextData *log) usercontext.description_length); return DLT_RETURN_OK; - } DltReturnValue dlt_user_log_send_unregister_context(DltContextData *log) @@ -4887,16 +4921,11 @@ DltReturnValue dlt_user_log_check_user_message(void) // Remove the default created at startup if (trace_load_settings != NULL) { free(trace_load_settings); + trace_load_settings = NULL; } - char msg[255]; trace_load_settings_alloc_size = sizeof(DltTraceLoadSettings) * trace_load_settings_user_messages_count; trace_load_settings = malloc(trace_load_settings_alloc_size); - if (trace_load_settings == NULL) { - pthread_rwlock_unlock(&trace_load_rw_lock); - dlt_log(LOG_ERR, "Failed to allocate memory for trace load settings\n"); - return DLT_RETURN_ERROR; - } memset(trace_load_settings, 0, trace_load_settings_alloc_size); for (i = 0; i < trace_load_settings_user_messages_count; i++) { strncpy(trace_load_settings[i].apid, dlt_user.appID, DLT_ID_SIZE); @@ -4904,18 +4933,24 @@ DltReturnValue dlt_user_log_check_user_message(void) trace_load_settings[i].soft_limit = trace_load_settings_user_messages[i].soft_limit; trace_load_settings[i].hard_limit = trace_load_settings_user_messages[i].hard_limit; } + trace_load_settings_count = trace_load_settings_user_messages_count; + for (i = 0; i < dlt_user.dlt_ll_ts_num_entries; ++i) { + dlt_ll_ts_type* ctx_entry = &dlt_user.dlt_ll_ts[i]; + ctx_entry->trace_load_settings = dlt_find_runtime_trace_load_settings( + trace_load_settings, trace_load_settings_count, dlt_user.appID, ctx_entry->contextID); + } pthread_rwlock_unlock(&trace_load_rw_lock); - - // must be sent with unlocked trace_load_rw_lock + pthread_rwlock_rdlock(&trace_load_rw_lock); + // The log messages only can be produced safely when + // the trace load settings are set up fully. + char msg[255]; for (i = 0; i < trace_load_settings_user_messages_count; i++) { if (trace_load_settings[i].ctid[0] == '\0') { - snprintf( - msg, sizeof(msg), - "Received trace load settings: apid=%.4s, soft_limit=%u, hard_limit=%u\n", - trace_load_settings[i].apid, - trace_load_settings[i].soft_limit, - trace_load_settings[i].hard_limit); + snprintf(msg, sizeof(msg), "Received trace load settings: apid=%.4s, soft_limit=%u, hard_limit=%u\n", + trace_load_settings[i].apid, + trace_load_settings[i].soft_limit, + trace_load_settings[i].hard_limit); } else { snprintf( msg, sizeof(msg), @@ -4927,6 +4962,7 @@ DltReturnValue dlt_user_log_check_user_message(void) } dlt_user_output_internal_msg(DLT_LOG_INFO, msg, NULL); } + pthread_rwlock_unlock(&trace_load_rw_lock); /* keep not read data in buffer */ if (dlt_receiver_remove(receiver, trace_load_settings_user_message_bytes_required) @@ -5360,21 +5396,10 @@ static DltReturnValue dlt_user_output_internal_msg( const DltLogLevelType loglevel, const char *const text, void* const params) { (void)params; // parameter is not needed - static DltContext handle; DltContextData log; int ret; int sent_size = 0; - if (!handle.contextID[0]) - { - // Register Special Context ID for output DLT library internal message - ret = dlt_register_context(&handle, DLT_TRACE_LOAD_CONTEXT_ID, "DLT user library internal context"); - if (ret < DLT_RETURN_OK) - { - return ret; - } - } - if (dlt_user.verbose_mode == 0) { return DLT_RETURN_ERROR; @@ -5391,7 +5416,7 @@ static DltReturnValue dlt_user_output_internal_msg( return DLT_RETURN_WRONG_PARAMETER; } - ret = dlt_user_log_write_start(&handle, &log, loglevel); + ret = dlt_user_log_write_start(&trace_load_context, &log, loglevel); // Ok means below threshold // see src/dlt-qnx-system/dlt-qnx-slogger2-adapter.cpp::sloggerinfo_callback for reference diff --git a/src/shared/dlt_common.c b/src/shared/dlt_common.c index 23a3def10..794f1d2c8 100644 --- a/src/shared/dlt_common.c +++ b/src/shared/dlt_common.c @@ -4453,6 +4453,12 @@ bool dlt_check_trace_load( return true; } + if (tl_settings == NULL) + { + internal_dlt_log(DLT_LOG_ERROR, "tl_settings is NULL", internal_dlt_log_params); + return false; + } + if (size < 0) { dlt_vlog(LOG_ERR, "Invalid size: %d", size); @@ -4485,11 +4491,11 @@ bool dlt_check_trace_load( DltTraceLoadSettings* dlt_find_runtime_trace_load_settings(DltTraceLoadSettings *settings, uint32_t settings_count, const char* apid, const char* ctid) { - if ((apid == NULL) || (strlen(apid) == 0)) + if ((apid == NULL) || (strnlen(apid, DLT_ID_SIZE) == 0)) return NULL; DltTraceLoadSettings* app_level = NULL; - size_t ctid_len = (ctid != NULL) ? strlen(ctid) : 0; + size_t ctid_len = (ctid != NULL) ? strnlen(ctid, DLT_ID_SIZE) : 0; for (uint32_t i = 0; i < settings_count; ++i) { if (strncmp(apid, settings->apid, DLT_ID_SIZE) != 0) {