aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorHarald Welte <laforge@osmocom.org>2020-09-27 12:17:40 +0200
committerHarald Welte <laforge@osmocom.org>2020-09-29 20:22:55 +0200
commita9ee159e6e613a54764eee4e0a2963e77e72bdd7 (patch)
tree6311df2ed29cb0420411c6f625a6af4a483dc8f1
parentad541dfbdf9e7f7e194c769dcbed74200831c455 (diff)
WIP: add rate_ctr_group to log_target
This way we account for the number of dropped log messages at write_queue overflow. However, log targets have no numerical ID and hence we're not able to extract them in a reasonable manner. Change-Id: I89b696311b823267e05d6a3e85b92c1784b220ed
-rw-r--r--include/osmocom/core/logging.h4
-rw-r--r--src/logging.c40
-rw-r--r--tests/ctrl/ctrl_test.c4
3 files changed, 45 insertions, 3 deletions
diff --git a/include/osmocom/core/logging.h b/include/osmocom/core/logging.h
index 6c1199ae..42975655 100644
--- a/include/osmocom/core/logging.h
+++ b/include/osmocom/core/logging.h
@@ -10,6 +10,7 @@
#include <stdbool.h>
#include <osmocom/core/defs.h>
#include <osmocom/core/linuxlist.h>
+#include <osmocom/core/rate_ctr.h>
/*! Maximum number of logging contexts */
#define LOG_MAX_CTX 8
@@ -349,6 +350,9 @@ struct log_target {
enum log_filename_type print_filename2;
/* Where on a log line to put the source file info. */
enum log_filename_pos print_filename_pos;
+
+ /* Rate counters related to this target */
+ struct rate_ctr_group *ctrg;
};
/* use the above macros */
diff --git a/src/logging.c b/src/logging.c
index 07859828..93f7836f 100644
--- a/src/logging.c
+++ b/src/logging.c
@@ -59,6 +59,8 @@
#include <osmocom/core/timer.h>
#include <osmocom/core/select.h>
#include <osmocom/core/write_queue.h>
+#include <osmocom/core/stats.h>
+#include <osmocom/core/rate_ctr.h>
#include <osmocom/vty/logging.h> /* for LOGGING_STR. */
@@ -81,6 +83,27 @@ static struct log_context log_context;
void *tall_log_ctx = NULL;
LLIST_HEAD(osmo_log_target_list);
+enum tgt_ctr {
+ TGT_CTR_LOG_COUNT,
+ TGT_CTR_REOPEN_COUNT,
+ TGT_CTR_QUEUED_COUNT,
+ TGT_CTR_DROP_COUNT,
+};
+static const struct rate_ctr_desc log_target_ctr_description[] = {
+ { "writes", "Log write count" },
+ { "repoens", "Re-open count " },
+ { "queued", "Log writes queued due to blocked file descriptor" },
+ { "drops", "Log writes dropped due to queue overflow" },
+};
+static const struct rate_ctr_group_desc log_target_ctrg_desc = {
+ .group_name_prefix = "log:target",
+ .group_description = "Log Target Statistics",
+ .num_ctr = ARRAY_SIZE(log_target_ctr_description),
+ .ctr_desc = log_target_ctr_description,
+ .class_id = OSMO_STATS_CLASS_GLOBAL,
+};
+
+
#if (!EMBEDDED)
/*! 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
@@ -637,6 +660,8 @@ void osmo_vlogp(int subsys, int level, const char *file, int line,
if (!should_log_to_target(tar, subsys, level))
continue;
+ rate_ctr_inc(&tar->ctrg->ctr[TGT_CTR_LOG_COUNT]);
+
/* According to the manpage, vsnprintf leaves the value of ap
* in undefined state. Since _output uses vsnprintf and it may
* be called several times, we have to pass a copy of ap. */
@@ -922,10 +947,15 @@ static void _file_raw_output(struct log_target *target, int subsys, unsigned int
}
/* if we reach here, either we already had elements in the write_queue, or the synchronous write
* failed: enqueue the message to the write_queue (backlog) */
- osmo_wqueue_enqueue_quiet(target->tgt_file.wqueue, msg);
+ rate_ctr_inc(&target->ctrg->ctr[TGT_CTR_QUEUED_COUNT]);
+ rc = osmo_wqueue_enqueue_quiet(target->tgt_file.wqueue, msg);
+ if (rc < 0)
+ rate_ctr_inc(&target->ctrg->ctr[TGT_CTR_DROP_COUNT]);
}
#endif
+static int log_target_ctrg_idx = 0;
+
/*! Create a new log target skeleton
* \returns dynamically-allocated log target
* This funcition allocates a \ref log_target and initializes it
@@ -950,6 +980,12 @@ struct log_target *log_target_create(void)
talloc_free(target);
return NULL;
}
+ target->ctrg = rate_ctr_group_alloc(target, &log_target_ctrg_desc, log_target_ctrg_idx++);
+ if (!target->ctrg) {
+ talloc_free(target->categories);
+ talloc_free(target);
+ return NULL;
+ }
INIT_LLIST_HEAD(&target->entry);
@@ -1203,6 +1239,7 @@ void log_target_destroy(struct log_target *target)
}
#endif
+ rate_ctr_group_free(target->ctrg);
talloc_free(target);
}
@@ -1239,6 +1276,7 @@ int log_target_file_reopen(struct log_target *target)
return rc;
}
+ rate_ctr_inc(&target->ctrg->ctr[TGT_CTR_REOPEN_COUNT]);
return 0;
}
diff --git a/tests/ctrl/ctrl_test.c b/tests/ctrl/ctrl_test.c
index b46e9ac5..06e5d2c0 100644
--- a/tests/ctrl/ctrl_test.c
+++ b/tests/ctrl/ctrl_test.c
@@ -478,8 +478,8 @@ int main(int argc, char **argv)
test_deferred_cmd();
- /* Expecting root ctx + msgb root ctx + 5 logging elements */
- if (talloc_total_blocks(ctx) != 7) {
+ /* Expecting root ctx + msgb root ctx + 6 logging elements */
+ if (talloc_total_blocks(ctx) != 8) {
talloc_report_full(ctx, stdout);
OSMO_ASSERT(false);
}