Hoernchen has submitted this change. ( https://gerrit.osmocom.org/c/libosmocore/+/30633?usp=email ) 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. Closes: OS#5818 Change-Id: I35f8dd9127dd6e7feae392094fd6b3ce2d32558d --- M include/osmocom/core/logging.h M src/core/libosmocore.map M src/core/logging.c M src/vty/logging_vty.c M tests/ctrl/ctrl_test.c 5 files changed, 138 insertions(+), 2 deletions(-) Approvals: fixeria: Looks good to me, but someone else must approve Jenkins Builder: Verified laforge: Looks good to me, but someone else must approve Hoernchen: Looks good to me, approved diff --git a/include/osmocom/core/logging.h b/include/osmocom/core/logging.h index e8433a1..e4859cd 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_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 b66e37d..06a3864 100644 --- a/src/core/libosmocore.map +++ b/src/core/libosmocore.map @@ -58,6 +58,7 @@ log_add_target; log_category_name; log_check_level; +log_cache_update; log_del_target; log_enable_multithread; log_fini; diff --git a/src/core/logging.c b/src/core/logging.c index 6941f9b..906d664 100644 --- a/src/core/logging.c +++ b/src/core/logging.c @@ -93,6 +93,68 @@ 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]; + 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 }; + + /* 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) +{ + 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 +488,10 @@ } } while ((category_token = strtok(NULL, ":"))); +#if !defined(EMBEDDED) + log_cache_update_all(); +#endif + free(mask); } @@ -680,6 +746,11 @@ 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 +825,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 @@ -762,6 +836,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 */ @@ -922,6 +999,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 @@ -938,6 +1018,10 @@ 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 +1130,15 @@ /* 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; } @@ -1424,6 +1517,15 @@ 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); + osmo_log_info = NULL; + return -ENOMEM; + } +#endif + cat_ptr = talloc_zero_array(osmo_log_info, struct log_info_cat, osmo_log_info->num_cat); if (!cat_ptr) { @@ -1454,6 +1556,12 @@ osmo_log_info->cat = cat_ptr; +#if !defined(EMBEDDED) + /* copy everything for level lookup cache */ + for (i = 0; i < osmo_log_info->num_cat; i++) + log_level_lookup_cache[i] = cat_ptr[i].loglevel; +#endif + return 0; } @@ -1486,6 +1594,11 @@ 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 2a07422..678ae68 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_cache_update(category, 1, level); +#endif + RET_WITH_UNLOCK(CMD_SUCCESS); } @@ -406,6 +410,9 @@ cat->enabled = 1; cat->loglevel = level; +#if !defined(EMBEDDED) + log_cache_update(i, 1, level); +#endif } RET_WITH_UNLOCK(CMD_SUCCESS); } diff --git a/tests/ctrl/ctrl_test.c b/tests/ctrl/ctrl_test.c index 1d4d4d7..7b7e6ce 100644 --- a/tests/ctrl/ctrl_test.c +++ b/tests/ctrl/ctrl_test.c @@ -482,7 +482,7 @@ test_deferred_cmd(); /* Expecting root ctx + msgb root ctx + 5 logging elements */ - if (talloc_total_blocks(ctx) != 7) { + if (talloc_total_blocks(ctx) != 8) { talloc_report_full(ctx, stdout); OSMO_ASSERT(false); } -- To view, visit https://gerrit.osmocom.org/c/libosmocore/+/30633?usp=email 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: 15 Gerrit-Owner: Hoernchen &lt;ewild(a)sysmocom.de&gt; Gerrit-Reviewer: Hoernchen &lt;ewild(a)sysmocom.de&gt; Gerrit-Reviewer: Jenkins Builder Gerrit-Reviewer: fixeria &lt;vyanitskiy(a)sysmocom.de&gt; Gerrit-Reviewer: laforge &lt;laforge(a)osmocom.org&gt; Gerrit-CC: arehbein &lt;arehbein(a)sysmocom.de&gt; Gerrit-CC: pespin &lt;pespin(a)sysmocom.de&gt; Gerrit-MessageType: merged