From 43018ec1610a17db699451b403898a8fe33ec9e6 Mon Sep 17 00:00:00 2001 From: Hoernchen Date: Thu, 11 Jan 2024 16:51:46 +0000 Subject: [PATCH] Revert "Revert "logging: add log level cache"" This reverts commit 7f1fb3ea817578f3f2f63e8065aa50f8355caa3b - slightly amended with the new log_cache_enalbe() function. The cache is hence disabled by default, and applications can enable it, if they wish to benefit from it. Reason for the original revert was: some fallout expected due to log manipulation in test code Change-Id: I539872fc9e3c50b407e6bc388f1e091fa2c826c3 --- include/osmocom/core/logging.h | 3 +- src/core/libosmocore.map | 2 + src/core/logging.c | 135 +++++++++++++++++++++++++++++++++ src/vty/logging_vty.c | 7 ++ 4 files changed, 146 insertions(+), 1 deletion(-) diff --git a/include/osmocom/core/logging.h b/include/osmocom/core/logging.h index e8433a14c..82e686f2a 100644 --- a/include/osmocom/core/logging.h +++ b/include/osmocom/core/logging.h @@ -409,7 +409,8 @@ int log_set_context(uint8_t ctx, void *value); /* filter on the targets */ void log_set_all_filter(struct log_target *target, int); - +int log_cache_enable(void); +void log_cache_update(int mapped_subsys, uint8_t enabled, uint8_t level); void log_set_use_color(struct log_target *target, int); void log_set_print_extended_timestamp(struct log_target *target, int); void log_set_print_timestamp(struct log_target *target, int); diff --git a/src/core/libosmocore.map b/src/core/libosmocore.map index 072efee37..fb294ba6b 100644 --- a/src/core/libosmocore.map +++ b/src/core/libosmocore.map @@ -58,6 +58,8 @@ gsmtap_type_names; log_add_target; log_category_name; log_check_level; +log_cache_enable; +log_cache_update; log_del_target; log_enable_multithread; log_fini; diff --git a/src/core/logging.c b/src/core/logging.c index 6941f9bf7..e17212419 100644 --- a/src/core/logging.c +++ b/src/core/logging.c @@ -93,6 +93,80 @@ LLIST_HEAD(osmo_log_target_list); static __thread long int logging_tid; #if (!EMBEDDED) +/*! One global copy that contains the union of log levels for all targets +* for all categories, used for quick lock free checks of log targets. */ +static volatile uint8_t *log_level_lookup_cache; + +/*! Updates cache for all targets for all categies, caller must hold osmo_log_tgt_mutex. */ +static void log_cache_update_all(void) +{ + struct log_target *tgt; + uint8_t tmp_en[osmo_log_info->num_cat]; + uint8_t tmp_level[osmo_log_info->num_cat]; + + if (!log_level_lookup_cache) + return; + + memset(tmp_en, 0, osmo_log_info->num_cat); + memset(tmp_level, UINT8_MAX, osmo_log_info->num_cat); + + /* values can also decrease.. */ + llist_for_each_entry(tgt, &osmo_log_target_list, entry) { + for (int i = 0; i < osmo_log_info->num_cat; i++) { + struct log_category *cat = &tgt->categories[i]; + tmp_en[i] = OSMO_MAX(tmp_en[i], cat->enabled); + tmp_level[i] = OSMO_MIN(tmp_level[i], cat->loglevel); + tmp_level[i] = tgt->loglevel ? OSMO_MIN(tmp_level[i], tgt->loglevel) : tmp_level[i]; + } + } + + for (int i = 0; i < osmo_log_info->num_cat; i++) + log_level_lookup_cache[i] = tmp_en[i] ? tmp_level[i] : UINT8_MAX; +} + +/*! Updates single cache entry, caller must hold osmo_log_tgt_mutex. + * + * \param[in] mapped_subsys plain category index (after mapping) + * \param[in] enabled log category enabled? + * \param[in] level log level + */ +void log_cache_update(int mapped_subsys, uint8_t enabled, uint8_t level) +{ + struct log_target *tgt; + struct log_category tmp = { UINT8_MAX, 0 }; + + if (!log_level_lookup_cache) + return; + + /* values can also decrease.. */ + llist_for_each_entry(tgt, &osmo_log_target_list, entry) { + struct log_category *cat = &tgt->categories[mapped_subsys]; + tmp.enabled = OSMO_MAX(tmp.enabled, cat->enabled); + tmp.loglevel = OSMO_MIN(tmp.loglevel, cat->loglevel); + tmp.loglevel = tgt->loglevel ? OSMO_MIN(tmp.loglevel, tgt->loglevel) : tmp.loglevel; + } + tmp.enabled = OSMO_MAX(tmp.enabled, enabled); + tmp.loglevel = OSMO_MIN(tmp.loglevel, level); + + log_level_lookup_cache[mapped_subsys] = tmp.enabled ? tmp.loglevel : UINT8_MAX; +} + +/*! Queries log level cache. + * + * \param[in] mapped_subsys plain category index (after mapping) + * \param[in] level log level + * \returns true if logging should happen for at least one log target +*/ +static bool log_cache_check(int mapped_subsys, int level) +{ + if (!log_level_lookup_cache) { + /* log-cache is not enabled, so we simply behave like we did before the cache */ + return true; + } + + return (level < log_level_lookup_cache[mapped_subsys]) ? false : true; +} + /*! This mutex must be held while using osmo_log_target_list or any of its log_targets in a multithread program. Prevents race conditions between threads like producing unordered timestamps or VTY deleting a target while another @@ -426,6 +500,10 @@ void log_parse_category_mask(struct log_target* target, const char *_mask) } } while ((category_token = strtok(NULL, ":"))); +#if !defined(EMBEDDED) + log_cache_update_all(); +#endif + free(mask); } @@ -680,6 +758,11 @@ void osmo_vlogp(int subsys, int level, const char *file, int line, subsys = map_subsys(subsys); +#if !defined(EMBEDDED) + if (!log_cache_check(subsys, level)) + return; +#endif + log_tgt_mutex_lock(); llist_for_each_entry(tar, &osmo_log_target_list, entry) { @@ -754,6 +837,9 @@ void logp_stub(const char *file, int line, int cont, const char *format, ...) void log_add_target(struct log_target *target) { llist_add_tail(&target->entry, &osmo_log_target_list); +#if (!EMBEDDED) + log_cache_update_all(); +#endif } /*! Unregister a log target from the logging core @@ -762,6 +848,9 @@ void log_add_target(struct log_target *target) void log_del_target(struct log_target *target) { llist_del(&target->entry); +#if (!EMBEDDED) + log_cache_update_all(); +#endif } /*! Reset (clear) the logging context */ @@ -922,6 +1011,9 @@ void log_set_print_level(struct log_target *target, int print_level) void log_set_log_level(struct log_target *target, int log_level) { target->loglevel = log_level; +#if !defined(EMBEDDED) + log_cache_update_all(); +#endif } /*! Set a category filter on a given log target @@ -938,6 +1030,10 @@ void log_set_category_filter(struct log_target *target, int category, category = map_subsys(category); target->categories[category].enabled = !!enable; target->categories[category].loglevel = level; + +#if !defined(EMBEDDED) + log_cache_update(category, !!enable, level); +#endif } #if (!EMBEDDED) @@ -1046,6 +1142,15 @@ struct log_target *log_target_create(void) /* global log level */ target->loglevel = 0; + +#if !defined(EMBEDDED) + /* update cache */ + for (i = 0; i < osmo_log_info->num_cat; i++) { + const struct log_info_cat *c = &osmo_log_info->cat[i]; + log_cache_update(i, c->enabled, c->loglevel); + } +#endif + return target; } @@ -1393,6 +1498,31 @@ int log_targets_reopen(void) return rc; } +/*! Enable the log level lookup cache to bypass string formatting and other code for log statements which are + * not actually enabled/needed by any existing log target. + * \retruns 0 in case of success, negative -errno in case of error. */ +int log_cache_enable(void) +{ +#if !defined(EMBEDDED) + if (log_level_lookup_cache) + return -EEXIST; + + log_level_lookup_cache = talloc_zero_array(osmo_log_info, uint8_t, osmo_log_info->num_cat); + if (!log_level_lookup_cache) + return -ENOMEM; + + /* copy everything for level lookup cache */ + log_tgt_mutex_lock(); + log_cache_update_all(); + log_tgt_mutex_unlock(); + + return 0; +#else + return -ENOTSUP; +#endif +} + + /*! Initialize the Osmocom logging core * \param[in] inf Information regarding logging categories, could be NULL * \param[in] ctx talloc context for logging allocations @@ -1486,6 +1616,11 @@ int log_check_level(int subsys, unsigned int level) subsys = map_subsys(subsys); +#if !defined(EMBEDDED) + if (!log_cache_check(subsys, level)) + return 0; +#endif + /* TODO: The following could/should be cached (update on config) */ log_tgt_mutex_lock(); diff --git a/src/vty/logging_vty.c b/src/vty/logging_vty.c index 2a074222d..678ae6864 100644 --- a/src/vty/logging_vty.c +++ b/src/vty/logging_vty.c @@ -382,6 +382,10 @@ DEFUN(logging_level, tgt->categories[category].enabled = 1; tgt->categories[category].loglevel = level; +#if !defined(EMBEDDED) + log_cache_update(category, 1, level); +#endif + RET_WITH_UNLOCK(CMD_SUCCESS); } @@ -406,6 +410,9 @@ DEFUN(logging_level_set_all, logging_level_set_all_cmd, cat->enabled = 1; cat->loglevel = level; +#if !defined(EMBEDDED) + log_cache_update(i, 1, level); +#endif } RET_WITH_UNLOCK(CMD_SUCCESS); }