engine: expose internal logging call counts as internal metrics #10326

alecholmes · 2025-05-13T00:04:37Z

This PR adds a new v2 runtime metric that exposes the number of logger calls by message type. A fluent-bit process consistently logging errors can be indicative of significant configuration or infrastructure problems. A common pattern for observing failures across many instances of software is to expose failures as metric counters that can then be observed and alerted on.

The implementation piggybacks on the src/flb_log.c logging library already extracting a worker context from the current thread.

Here is the example output of curling a fluent-bit with a service http_server enabled:

> curl localhost:5432/api/v2/metrics/prometheus 2>&1 | grep logger

fluentbit_logger_logs_total{severity="error"} 2
fluentbit_logger_logs_total{severity="warn"} 0
fluentbit_logger_logs_total{severity="info"} 10
fluentbit_logger_logs_total{severity="debug"} 0
fluentbit_logger_logs_total{severity="trace"} 0
fluentbit_logger_logs_total{severity="help"} 0

Enter [N/A] in the box, if an item is not applicable to your change.

Testing
Before we can approve your change; please submit the following in a comment:

[N/A] Example configuration file for the change
Debug log output from testing the change (see example from curling above)
Attached Valgrind output that shows no leaks or memory corruption was found

> valgrind -s bin/flb-rt-core_internal_logger

SUCCESS: All unit tests have passed.
==118424==
==118424== HEAP SUMMARY:
==118424==     in use at exit: 0 bytes in 0 blocks
==118424==   total heap usage: 2,098 allocs, 2,098 frees, 720,751 bytes allocated
==118424==
==118424== All heap blocks were freed -- no leaks are possible
==118424==
==118424== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)

If this is a change to packaging of containers or native binaries then please confirm it works for all targets.

[N/A] Run local packaging test showing all targets (including any new ones) build.
[N/A] Set ok-package-test label to test for all targets (requires maintainer to do).

Documentation

Documentation required for this feature (I will create a docs PR to update the metric name table once this PR is approved)

Backporting

[N/A] Backport to latest stable release.

Fluent Bit is licensed under Apache 2.0, by submitting this pull request I understand that this code will be released under the terms of that license.

src/flb_sds.c

alecholmes · 2025-05-13T00:06:24Z

tests/runtime/core_internal_logger.c

+        return NULL;
+    }
+
+    ret_ctx->u = flb_upstream_create(ret_ctx->config, "127.0.0.1", 2020, 0, NULL);


Is there any pattern or prior art for picking random free ports in tests?

There's not but we can talk about it if you're interested in making that improvement, I'd appreciate it.

alecholmes · 2025-05-14T03:37:20Z

I'm not convinced this PR introduced the fuzzer failures since I'm able to repro them on master.

The signv4_fuzzer failure, for example, seems to have been introduced at some point between 352bb31 and 6899dc1 -- it's hard to bisect because the commits in the middle of that range do not compile.

leonardo-albertovich · 2025-05-14T08:18:15Z

include/fluent-bit/flb_config.h

@@ -164,6 +164,7 @@ struct flb_config {
    /* Logging */
    char *log_file;
    struct flb_log *log;
+    struct flb_log_metrics *log_metrics_ctx; /* Global metrics for logging calls */


Isn't this metrics context supposed to be limited to the logger instance? If that's the case then it should be declared inside if flb_log instead of flb_config?

I've moved the metrics to flb_log and the lifecycle of them is now managed by flb_log_create and flb_log_destroy.

leonardo-albertovich · 2025-05-14T08:19:37Z

include/fluent-bit/flb_log.h

@@ -232,6 +242,8 @@ static inline int flb_log_suppress_check(int log_suppress_interval, const char *
 int flb_log_worker_init(struct flb_worker *worker);
 int flb_log_worker_destroy(struct flb_worker *worker);
 int flb_errno_print(int errnum, const char *file, int line);
+struct flb_log_metrics *flb_log_metrics_create();


These two shouldn't be public as they should be only invoked by flb_log_create and flb_log_destroy.

Removed from the header file.

leonardo-albertovich · 2025-05-14T08:19:55Z

src/flb_config.c

@@ -391,6 +391,14 @@ struct flb_config *flb_config_init()
    flb_regex_init();
 #endif

+    /* Create internal logger metrics */


This should be moved to flb_log_create

leonardo-albertovich · 2025-05-14T08:20:51Z

src/flb_log.c

@@ -573,39 +597,32 @@ int flb_log_construct(struct log_message *msg, int *ret_len,
    int total;
    time_t now;
    const char *header_color = NULL;
-    const char *header_title = NULL;
+    const char *header_title = flb_log_message_type_str(type);


Please don't make function calls in the middle of the declarations, initialize it to NULL and move the function call to line 606.

leonardo-albertovich · 2025-05-14T08:21:16Z

src/flb_log.c

@@ -564,6 +566,28 @@ struct flb_log *flb_log_create(struct flb_config *config, int type,
    return log;
 }

+static inline char *flb_log_message_type_str(int type)


Please change the return type to const char * to match the current usage.

leonardo-albertovich · 2025-05-14T08:27:49Z

src/flb_log.c

+    return lm;
+
+error:
+    if (lm && lm->logs_total_counter) {


If this code was to stay this would be a much cleaner structure which I'd ask you to follow:

if (lm != NULL) { if (lm->logs_total_counter != NULL) { cmt_counter_destroy(lm->logs_total_counter); } if (lm->cmt != NULL) { cmt_destroy(lm->cmt); } flb_free(lm); }

I reverted to not using goto. The pattern of using goto to jump to a cleanup section that effectively unwinds the allocations was something Phil and I had talked a bit about ahead of the PR, but I can bring that up as a discussion separately.

leonardo-albertovich · 2025-05-14T08:29:57Z

src/flb_log.c

+            break;
+        }
+
+        if (cmt_counter_set(lm->logs_total_counter, ts, 0, 1, (char *[]) {message_type_str}) == -1) {


Please don't put function calls inside of the conditions, it's ok to use simpler functions such as strlen sometimes there but this is not the case, declare a variable, store the result value there and then compare it.

The compiler will optimize it anyway and the result code will remain in a register in 99% of the cases, especially in the modern fastcall-ish conventions (amd64 & arm).

leonardo-albertovich · 2025-05-14T08:30:54Z

src/flb_log.c

+     * Initialize counters for all log message types to 0.
+     * This assumes types are contiguous starting at 1 (FLB_LOG_ERROR).
+     */
+    i = 1;


i is already initialized by the for, remove this.

src/flb_sds.c

leonardo-albertovich · 2025-05-14T08:39:53Z

tests/runtime/core_internal_logger.c

+        return NULL;
+    }
+
+    ret_ctx->u = flb_upstream_create(ret_ctx->config, "127.0.0.1", 2020, 0, NULL);


There's not but we can talk about it if you're interested in making that improvement, I'd appreciate it.

leonardo-albertovich · 2025-05-19T22:31:43Z

src/flb_config.c

@@ -345,6 +345,11 @@ struct flb_config *flb_config_init()
    mk_list_init(&config->cmetrics);
    mk_list_init(&config->cf_parsers_list);

+    /* Initialize multiline-parser list. We need this here, because from now


Let's isolate this in another PR, I've already approved yours as it was and don't want to mix things up so please revert this change and open a new one with the appropriate context so your reasoning is easy to follow and validate.

niedbalski

Looks generally ok -- I have some nitpicks.

src/flb_log.c

niedbalski · 2025-05-20T08:47:01Z

tests/runtime/core_internal_logger.c

+
+    /* If the assertion fails, retry in a sleep loop since the fluent-bit's HTTP server
+     * may not be ready yet */
+    for (i = 1; i <= attempt_count; i++) {


for (i = 0; i < attempt_count; i++) { if (assert_internal_log_metrics(http_ctx, i == attempt_count - 1)) { break; } flb_time_msleep(100); }

niedbalski · 2025-05-20T08:49:04Z

src/flb_log.c

+        if (config != NULL && config->log != NULL) {
+            msg_type_str = flb_log_message_type_str(type);
+            ts = cfl_time_now();
+            cmt_counter_inc(config->log->metrics->logs_total_counter, ts, 1, (char *[]) {msg_type_str}); // Ignoring inc error


I don't think we should silently ignore this error. At least we should put a debug statement to track in case we are chasing a bug.

int ret; ret = cmt_counter_inc(config->log->metrics->logs_total_counter, ts, 1, (char *[]) {msg_type_str}); if (ret != 0) { flb_debug("[log] failed to increment log total counter for message type '%s' (error=%d)", msg_type_str ? msg_type_str : "unknown", ret); }```

I updated to log the failure, though I didn't call flb_debug since that recurses in this same function and would likely hit the same log increment error again. Instead, opted to log the increment error using fprintf(stderr, ...).

Please don't use inline conditionals.

niedbalski · 2025-05-20T08:52:13Z

tests/runtime/core_internal_logger.c

+    /* The process startup should have logged at least 1 info log */
+    regex = flb_regex_create(
+        "fluentbit_logger_logs_total\\{message_type=\"info\"\\} [1-9]+[0-9]*");
+    TEST_CHECK(regex != NULL);


You can early return here.

if (!TEST_CHECK(regex != NULL)) { TEST_MSG("Failed to create regex for info log count check"); flb_http_client_destroy(http_client); return -1; }

src/flb_log.c

alecholmes · 2025-05-20T17:31:59Z

@niedbalski thanks for taking a look. Pushed a temporary commit addressing your feedback.

Internal logger calls increment a new v2 metric exposed by the HTTP server Prometheus scrape endpoint. There is one time series per log message type. Signed-off-by: Alec Holmes <[email protected]>

Signed-off-by: Alec Holmes <[email protected]>

leonardo-albertovich · 2025-05-23T09:07:11Z

src/flb_metrics_exporter.c

+    if (ctx->log != NULL) {
+        ret = cmt_cat(cmt, ctx->log->metrics->cmt);
+        if (ret == -1) {
+            flb_error("[metrics exporter] could not append global log_metrics_ctx");


Please change this so the message reflect what it is rather than the context name.

leonardo-albertovich · 2025-05-23T09:12:17Z

src/flb_log.c

+    }
+
+    metrics->cmt = cmt_create();
+    if (!metrics->cmt) {


Please compare explicitly against NULL here and in any other places where it's not done in that way.

leonardo-albertovich · 2025-05-23T09:17:10Z

src/flb_log.c

+     * This assumes types are contiguous starting at 1 (FLB_LOG_ERROR).
+     */
+    ts = cfl_time_now();
+    for (i = 1; ; i++) {


Please change this loop so it explicitly iterates from FLB_LOG_ERROR up to FLB_LOG_TRACE.

Your mechanism is smart but not obvious at first glance and in order to minimize the chance of someone misunderstanding the code and making a mistake we need to make things painfully obvious when possible.

Also, rename i to a proper name, we don't use single letter variables because it's a slippery slope that can lead to sub par and hard to follow code which can (and has) cause(d) issues.

leonardo-albertovich · 2025-05-23T09:19:45Z

src/flb_log.c

+                              0,
+                              1, (char *[]) {message_type_str});
+        if (ret == -1) {
+            cmt_counter_destroy(metrics->logs_total_counter);


Please replace this cleanup block (and the one before) with a call to flb_log_metrics_destroy

leonardo-albertovich · 2025-05-23T09:21:34Z

src/flb_log.c

+/* Frees the metrics instance and its associated resources. */
+void flb_log_metrics_destroy(struct flb_log_metrics *metrics)
+{
+    cmt_counter_destroy(metrics->logs_total_counter);


Please remove this, cmt_destroy iterates the metrics in the context and destroys them so you don't need to. Also, if this function is called by flb_log_metrics_create when cmt_counter_create fails we'd need to add a conditional to avoid calling cmt_counter_destry which makes no sense since it's automatic.

leonardo-albertovich · 2025-05-23T09:28:16Z

src/flb_log.c

+        fprintf(stderr, "[log] could not create log metrics\n");
+        mk_event_loop_destroy(log->evl);
+        flb_free(log);
+        config->log = NULL;


While looking at this I noticed that config->log is set immediately after allocating it.

I've checked the client code and verified that there are no threading issues, however, I wanted to use this as an example of bad logic for the new contributors.

The problem is that the uninitialized log context is set to config which means it could be prematurely accessed by other threads. The right thing would be to only set config->log at the end of this function when we know for sure that the context is fully initialized and usable.

You don't need to change anything here, just look at it and if you have any questions ask them.

leonardo-albertovich · 2025-05-23T09:29:54Z

src/flb_log.c

+                                  ts,
+                                  1, (char *[]) {msg_type_str});
+            if (ret == -1) {
+                // Not using flb_log_debug to avoid recursing into this same function.


Please replace this with a C style comment /**/

leonardo-albertovich · 2025-05-23T09:33:33Z

src/flb_metrics_exporter.c

@@ -299,6 +299,15 @@ struct cmt *flb_me_get_cmetrics(struct flb_config *ctx)
        }
    }

+    if (ctx->log != NULL) {
+        ret = cmt_cat(cmt, ctx->log->metrics->cmt);
+        if (ret == -1) {


Invert this conditional son instead of matching -1 it matches anything different than 0.

The idea is that while at the moment this function returns -1 in every error return branch this is not great if we care about diagnosing issues and we'd like to leave the door open to improve it in the future.

alecholmes requested review from edsiper, leonardo-albertovich, fujimotos and koleini as code owners May 13, 2025 00:04

github-actions bot added the docs-required label May 13, 2025

alecholmes commented May 13, 2025

View reviewed changes

src/flb_sds.c Show resolved Hide resolved

alecholmes commented May 13, 2025

View reviewed changes

alecholmes temporarily deployed to pr May 13, 2025 04:00 — with GitHub Actions Inactive

alecholmes temporarily deployed to pr May 13, 2025 04:28 — with GitHub Actions Inactive

alecholmes force-pushed the alec/2025-05-08-expose-log-counts branch from d83dbeb to 68ede1c Compare May 13, 2025 15:52

alecholmes requested a review from niedbalski as a code owner May 13, 2025 15:52

alecholmes temporarily deployed to pr May 13, 2025 16:21 — with GitHub Actions Inactive

alecholmes temporarily deployed to pr May 13, 2025 16:45 — with GitHub Actions Inactive

alecholmes force-pushed the alec/2025-05-08-expose-log-counts branch from 68ede1c to e61c2c0 Compare May 13, 2025 17:11

alecholmes temporarily deployed to pr May 13, 2025 19:21 — with GitHub Actions Inactive

alecholmes temporarily deployed to pr May 13, 2025 19:45 — with GitHub Actions Inactive

alecholmes had a problem deploying to pr May 13, 2025 19:46 — with GitHub Actions Failure

alecholmes temporarily deployed to pr May 13, 2025 19:46 — with GitHub Actions Inactive

leonardo-albertovich requested changes May 14, 2025

View reviewed changes

alecholmes force-pushed the alec/2025-05-08-expose-log-counts branch from 8023366 to 98b4e24 Compare May 19, 2025 22:29

leonardo-albertovich requested changes May 19, 2025

View reviewed changes

alecholmes force-pushed the alec/2025-05-08-expose-log-counts branch from 98b4e24 to 48b63d6 Compare May 19, 2025 22:42

alecholmes temporarily deployed to pr May 20, 2025 08:26 — with GitHub Actions Inactive

alecholmes temporarily deployed to pr May 20, 2025 08:49 — with GitHub Actions Inactive

alecholmes temporarily deployed to pr May 20, 2025 08:50 — with GitHub Actions Inactive

niedbalski requested changes May 20, 2025

View reviewed changes

alecholmes force-pushed the alec/2025-05-08-expose-log-counts branch from 48b63d6 to 0e0e134 Compare May 20, 2025 17:29

alecholmes temporarily deployed to pr May 20, 2025 17:29 — with GitHub Actions Inactive

alecholmes temporarily deployed to pr May 20, 2025 17:53 — with GitHub Actions Inactive

alecholmes added 4 commits May 21, 2025 08:31

engine: expose internal logging call counts as internal metrics

b89fdac

Internal logger calls increment a new v2 metric exposed by the HTTP server Prometheus scrape endpoint. There is one time series per log message type. Signed-off-by: Alec Holmes <[email protected]>

Feedback (temporary -- will squash into above)

e8d522f

Signed-off-by: Alec Holmes <[email protected]>

Feedback (temporary -- will squash into above)

8ff4ffb

Signed-off-by: Alec Holmes <[email protected]>

Feedback (temporary -- will squash into above)

a48e7ab

Signed-off-by: Alec Holmes <[email protected]>

alecholmes force-pushed the alec/2025-05-08-expose-log-counts branch from 0e0e134 to a48e7ab Compare May 21, 2025 15:34

alecholmes temporarily deployed to pr May 21, 2025 15:35 — with GitHub Actions Inactive

alecholmes temporarily deployed to pr May 21, 2025 15:58 — with GitHub Actions Inactive

alecholmes temporarily deployed to pr May 21, 2025 15:59 — with GitHub Actions Inactive

leonardo-albertovich requested changes May 23, 2025

View reviewed changes

engine: expose internal logging call counts as internal metrics #10326

Are you sure you want to change the base?

engine: expose internal logging call counts as internal metrics #10326

Uh oh!

Conversation

alecholmes commented May 13, 2025

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

alecholmes commented May 14, 2025

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

niedbalski left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

alecholmes commented May 20, 2025

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!