Hoernchen has uploaded this change for review. ( https://gerrit.osmocom.org/c/libosmocore/+/30633 ) Change subject: logging: add log level cache ...................................................................... logging: add log level cache This ensures multithreaded logging attempts, in particular ones that do nothing, do not hold the lock just for checking the level, which interferes with other logging attempts. Change-Id: I35f8dd9127dd6e7feae392094fd6b3ce2d32558d --- M include/osmocom/core/logging.h M src/logging.c M src/vty/logging_vty.c 3 files changed, 105 insertions(+), 1 deletion(-) git pull ssh://gerrit.osmocom.org:29418/libosmocore refs/changes/33/30633/1 diff --git a/include/osmocom/core/logging.h b/include/osmocom/core/logging.h index 5ae38c7..a74f2af 100644 --- a/include/osmocom/core/logging.h +++ b/include/osmocom/core/logging.h @@ -409,7 +409,7 @@ /* filter on the targets */ void log_set_all_filter(struct log_target *target, int); - +void log_update_cache(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/logging.c b/src/logging.c index ce42e4c..1238ef0 100644 --- a/src/logging.c +++ b/src/logging.c @@ -60,6 +60,7 @@ #include <errno.h> #include <pthread.h> + #include <osmocom/core/talloc.h> #include <osmocom/core/utils.h> #include <osmocom/core/logging.h> @@ -93,6 +94,54 @@ 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. */ +volatile uint8_t* log_level_lookup_cache; + +/* Updates cache for all targets for all categies, needs log mutex */ +static void log_cache_update_all() { + struct log_target *tgt; + uint8_t tmp_en[osmo_log_info->num_cat]; + uint8_t tmp_level[osmo_log_info->num_cat]; + memset(tmp_en, 0, osmo_log_info->num_cat); + memset(tmp_level, 100, 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] = OSMO_MIN(tmp_level[i], tgt->loglevel); + } + } + + for (int i = 0; i < osmo_log_info->num_cat; i++) { + log_level_lookup_cache[i] = tmp_en[i] ? tmp_level[i] : 99; + } +} + +/* Updates cache for this subsys, needs log mutex */ +void log_update_cache(int mapped_subsys, uint8_t enabled, uint8_t level) { + struct log_target *tgt; + struct log_category tmp = {99,0}; + + /* 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.enabled = OSMO_MAX(tmp.enabled, enabled); + tmp.loglevel = OSMO_MIN(tmp.loglevel, level); + + log_level_lookup_cache[mapped_subsys] = tmp.enabled ? tmp.loglevel : 99; +} + +static bool log_check_quick(int mapped_subsys, int level) { + 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 @@ -420,6 +469,10 @@ } } while ((category_token = strtok(NULL, ":"))); +#if !defined(EMBEDDED) + log_cache_update_all(); +#endif + free(mask); } @@ -706,6 +759,11 @@ subsys = map_subsys(subsys); +#if !defined(EMBEDDED) + if (!log_check_quick(subsys, level)) + return; +#endif + log_tgt_mutex_lock(); llist_for_each_entry(tar, &osmo_log_target_list, entry) { @@ -780,6 +838,9 @@ 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 @@ -788,6 +849,9 @@ void log_del_target(struct log_target *target) { llist_del(&target->entry); +#if (!EMBEDDED) + log_cache_update_all(); +#endif } /*! Reset (clear) the logging context */ @@ -948,6 +1012,9 @@ 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 @@ -964,6 +1031,8 @@ category = map_subsys(category); target->categories[category].enabled = !!enable; target->categories[category].loglevel = level; + + log_update_cache(category, !!enable, level); } #if (!EMBEDDED) @@ -1072,6 +1141,13 @@ /* global log level */ target->loglevel = 0; + + /* update cache */ + for (i = 0; i < osmo_log_info->num_cat; i++) { + const struct log_info_cat* c = &osmo_log_info->cat[i]; + log_update_cache(i, c->enabled, c->loglevel); + } + return target; } @@ -1449,6 +1525,16 @@ osmo_log_info->num_cat += inf->num_cat; } +#if !defined(EMBEDDED) + log_level_lookup_cache = talloc_zero_array(osmo_log_info, uint8_t, + osmo_log_info->num_cat); + if (!log_level_lookup_cache ) { + talloc_free(osmo_log_info); + log_level_lookup_cache = NULL; + return -ENOMEM; + } +#endif + cat_ptr = talloc_zero_array(osmo_log_info, struct log_info_cat, osmo_log_info->num_cat); if (!cat_ptr) { @@ -1479,6 +1565,12 @@ osmo_log_info->cat = cat_ptr; +#if !defined(EMBEDDED) + /* copy everything for level lookup cache */ + for (i = 0; i < inf->num_cat; i++) + log_level_lookup_cache[i] = cat_ptr[i].loglevel; +#endif + return 0; } @@ -1511,6 +1603,11 @@ subsys = map_subsys(subsys); +#if !defined(EMBEDDED) + if (osmo_log_tgt_mutex_on && !log_check_quick(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 59c8a9c..30cbf32 100644 --- a/src/vty/logging_vty.c +++ b/src/vty/logging_vty.c @@ -382,6 +382,10 @@ tgt->categories[category].enabled = 1; tgt->categories[category].loglevel = level; +#if !defined(EMBEDDED) + log_update_cache(category, 1, level); +#endif + RET_WITH_UNLOCK(CMD_SUCCESS); } @@ -406,6 +410,9 @@ cat->enabled = 1; cat->loglevel = level; +#if !defined(EMBEDDED) + log_update_cache(i, 1, level); +#endif } RET_WITH_UNLOCK(CMD_SUCCESS); } -- To view, visit https://gerrit.osmocom.org/c/libosmocore/+/30633 To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings Gerrit-Project: libosmocore Gerrit-Branch: master Gerrit-Change-Id: I35f8dd9127dd6e7feae392094fd6b3ce2d32558d Gerrit-Change-Number: 30633 Gerrit-PatchSet: 1 Gerrit-Owner: Hoernchen &lt;ewild(a)sysmocom.de&gt; Gerrit-MessageType: newchange