[L] Change in libosmocore[master]: Implement log file target using osmo_io

23 Jan 2026

pespin has uploaded this change for review. ( https://gerrit.osmocom.org/c/libosmocore/+/41925?usp=email )
Change subject: Implement log file target using osmo_io
......................................................................
Implement log file target using osmo_io
TODO: re-add talloc_pool.
Related: OS#6918
Change-Id: Ieb6420246454ef59442b1fd7b1d14e2c00fa69a5
---
M include/osmocom/core/logging_internal.h
M src/core/logging_file.c
M src/vty/logging_vty.c
M tests/logging/logging_test.c
M tests/logging/logging_test.err
5 files changed, 112 insertions(+), 145 deletions(-)
git pull ssh://gerrit.osmocom.org:29418/libosmocore refs/changes/25/41925/1

diff --git a/include/osmocom/core/logging_internal.h b/include/osmocom/core/logging_internal.h
index cadd4df..187a7df 100644
--- a/include/osmocom/core/logging_internal.h
+++ b/include/osmocom/core/logging_internal.h
@@ -9,6 +9,7 @@
 #include <osmocom/core/utils.h>
 #include <osmocom/core/linuxlist.h>
 #include <osmocom/core/logging.h>
+#include <osmocom/core/osmo_io.h>
/* maximum length of the log string of a single log event (typically  line) */
 #define MAX_LOG_SIZE	4096
@@ -52,8 +53,8 @@
    		/* direct, blocking output via stdio */
    		FILE *out;
    		const char *fname;
-			/* indirect output via write_queue and osmo_select_main() */
-			struct osmo_wqueue *wqueue;
+			/* indirect output via iofd and osmo_select_main() */
+			struct osmo_io_fd *iofd;
    	} tgt_file;
struct {
diff --git a/src/core/logging_file.c b/src/core/logging_file.c
index 1a5bdb2..d859dab 100644
--- a/src/core/logging_file.c
+++ b/src/core/logging_file.c
@@ -37,44 +37,52 @@
 #include <osmocom/core/talloc.h>
 #include <osmocom/core/utils.h>
 #include <osmocom/core/select.h>
-#include <osmocom/core/write_queue.h>
+#include <osmocom/core/osmo_io.h>
 #include <osmocom/core/logging_internal.h>
/* maximum number of log statements we queue in file/stderr target write queue */
 #define LOG_WQUEUE_LEN	156
-
 /*! close and re-open a log file (for log file rotation)
  *  \param[in] target log target to re-open
  *  \returns 0 in case of success; negative otherwise */
 int log_target_file_reopen(struct log_target *target)
 {
-	struct osmo_wqueue *wq;
    int rc;
-	OSMO_ASSERT(target->type == LOG_TGT_TYPE_FILE || target->type == LOG_TGT_TYPE_STDERR);
-	OSMO_ASSERT(target->tgt_file.out || target->tgt_file.wqueue);
+	OSMO_ASSERT(target->type == LOG_TGT_TYPE_FILE ||
+		    target->type == LOG_TGT_TYPE_STDERR);
+	OSMO_ASSERT(target->tgt_file.out || target->tgt_file.iofd);
-	if (target->tgt_file.out) {
-		fclose(target->tgt_file.out);
-		target->tgt_file.out = fopen(target->tgt_file.fname, "a");
-		if (!target->tgt_file.out)
-			return -errno;
-	} else {
-		wq = target->tgt_file.wqueue;
-		if (wq->bfd.fd >= 0) {
-			osmo_fd_unregister(&wq->bfd);
-			close(wq->bfd.fd);
-			wq->bfd.fd = -1;
+	if (target->type == LOG_TGT_TYPE_STDERR)
+		return -ENOTSUP;
+
+	switch (target->type) {
+	case LOG_TGT_TYPE_STDERR:
+		return -ENOTSUP;
+	case LOG_TGT_TYPE_FILE:
+		if (target->tgt_file.out) { /* stream mode */
+			fclose(target->tgt_file.out);
+			target->tgt_file.out = fopen(target->tgt_file.fname, "a");
+			if (!target->tgt_file.out)
+				return -errno;
+			return 0;
    	}
+		osmo_iofd_close(target->tgt_file.iofd);
    	rc = open(target->tgt_file.fname, O_WRONLY|O_APPEND|O_CREAT|O_NONBLOCK, 0660);
    	if (rc < 0)
    		return -errno;
-		wq->bfd.fd = rc;
-		rc = osmo_fd_register(&wq->bfd);
-		if (rc < 0)
-			return rc;
+
+		rc = osmo_iofd_register(target->tgt_file.iofd, rc);
+		if (rc < 0) {
+			osmo_iofd_free(target->tgt_file.iofd);
+			target->tgt_file.iofd = NULL;
+			return -EIO;
+		}
+		break;
+	default:
+		OSMO_ASSERT(0);
    }
return 0;
@@ -87,7 +95,6 @@
  * object. */
 void log_target_file_destroy(struct log_target *target)
 {
-	struct osmo_wqueue *wq;
OSMO_ASSERT(target->type == LOG_TGT_TYPE_FILE ||
    	    target->type == LOG_TGT_TYPE_STDERR);
@@ -97,38 +104,20 @@
    		fclose(target->tgt_file.out);
    	target->tgt_file.out = NULL;
    }
-	wq = target->tgt_file.wqueue;
-	if (wq) {
-		if (wq->bfd.fd >= 0) {
-			osmo_fd_unregister(&wq->bfd);
-			if (target->type == LOG_TGT_TYPE_FILE)
-				close(wq->bfd.fd);
-			wq->bfd.fd = -1;
-		}
-		osmo_wqueue_clear(wq);
-		talloc_free(wq);
-		target->tgt_file.wqueue = NULL;
+
+	if (target->tgt_file.iofd) {
+		osmo_iofd_free(target->tgt_file.iofd);
+		target->tgt_file.iofd = NULL;
    }
+
    talloc_free((void *)target->tgt_file.fname);
    target->tgt_file.fname = NULL;
 }
-/* write-queue tells us we should write another msgb (log line) to the output fd */
-static int _file_wq_write_cb(struct osmo_fd *ofd, struct msgb *msg)
-{
-	int rc;
-
-	rc = write(ofd->fd, msgb_data(msg), msgb_length(msg));
-	if (rc < 0)
-		return rc;
-	if (rc != msgb_length(msg)) {
-		/* pull the number of bytes we have already written */
-		msgb_pull(msg, rc);
-		/* ask write_queue to re-insert the msgb at the head of the queue */
-		return -EAGAIN;
-	}
-	return 0;
-}
+static struct osmo_io_ops log_target_file_io_ops = {
+	.read_cb = NULL,
+	.write_cb = NULL,
+};
/* output via buffered, blocking stdio streams */
 static void _file_output_stream(struct log_target *target, unsigned int level,
@@ -146,8 +135,8 @@
    struct msgb *msg;
    int rc;
-	OSMO_ASSERT(target->tgt_file.wqueue);
-	msg = msgb_alloc_c(target->tgt_file.wqueue, MAX_LOG_SIZE, "log_file_msg");
+	OSMO_ASSERT(target->tgt_file.iofd);
+	msg = msgb_alloc_c(target->tgt_file.iofd, MAX_LOG_SIZE, "log_file_msg");
    if (!msg)
    	return;
@@ -157,18 +146,8 @@
    rc = log_output_buf((char *)msgb_data(msg), msgb_tailroom(msg), target, subsys, level, file, line, cont, format, ap);
    msgb_put(msg, rc);
-	/* attempt a synchronous, non-blocking write, if the write queue is empty */
-	if (target->tgt_file.wqueue->current_length == 0) {
-		rc = _file_wq_write_cb(&target->tgt_file.wqueue->bfd, msg);
-		if (rc == 0) {
-			/* the write was complete, we can exit early */
-			msgb_free(msg);
-			return;
-		}
-	}
-	/* 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) */
-	if (osmo_wqueue_enqueue_quiet(target->tgt_file.wqueue, msg) < 0) {
+	rc = osmo_iofd_write_msgb(target->tgt_file.iofd, msg);
+	if (rc < 0) {
    	msgb_free(msg);
    	/* TODO: increment some counter so we can see that messages were dropped */
    }
@@ -181,7 +160,7 @@
  */
 int log_target_file_switch_to_stream(struct log_target *target)
 {
-	struct osmo_wqueue *wq;
+	unsigned int prev_queue_len;
if (!target)
    	return -ENODEV;
@@ -191,37 +170,28 @@
    	return 1;
    }
-	wq = target->tgt_file.wqueue;
-	OSMO_ASSERT(wq);
-
    /* re-open output as stream */
    if (target->type == LOG_TGT_TYPE_STDERR)
    	target->tgt_file.out = stderr;
    else
    	target->tgt_file.out = fopen(target->tgt_file.fname, "a");
+
    if (!target->tgt_file.out)
    	return -EIO;
-	/* synchronously write anything left in the queue */
-	while (!llist_empty(&wq->msg_queue)) {
-		struct msgb *msg = msgb_dequeue(&wq->msg_queue);
-		fwrite(msgb_data(msg), msgb_length(msg), 1, target->tgt_file.out);
-		msgb_free(msg);
-	}
+	prev_queue_len = osmo_iofd_txqueue_len(target->tgt_file.iofd);
-	/* now that everything succeeded, we can finally close the old output fd */
-	if (target->type == LOG_TGT_TYPE_FILE) {
-		osmo_fd_unregister(&wq->bfd);
-		close(wq->bfd.fd);
-		wq->bfd.fd = -1;
-	}
-
-	/* release the queue itself */
-	talloc_free(wq);
-	target->tgt_file.wqueue = NULL;
+	/* now that everything succeeded, we can finally close the old iofd */
+	osmo_iofd_free(target->tgt_file.iofd);
+	target->tgt_file.iofd = NULL;
    target->output = _file_output_stream;
    target->raw_output = NULL;
+
+	if (prev_queue_len > 0)
+		LOGP(DLGLOBAL, LOGL_NOTICE,
+		     "Dropped %u messages switching log target file to stream\n", prev_queue_len);
+
    return 0;
 }
@@ -232,8 +202,7 @@
  */
 int log_target_file_switch_to_wqueue(struct log_target *target)
 {
-	struct osmo_wqueue *wq;
-	int rc;
+	int rc, fd;
if (!target)
    	return -ENODEV;
@@ -243,35 +212,33 @@
    	return 1;
    }
-	/* we create a ~640kB sized talloc pool within the write-queue to ensure individual
-	 * log lines (stored as msgbs) will not put result in malloc() calls, and also to
-	 * reduce the OOM probability within logging, as the pool is already allocated */
-	wq = talloc_pooled_object(target, struct osmo_wqueue, LOG_WQUEUE_LEN,
-				  LOG_WQUEUE_LEN*(sizeof(struct msgb)+MAX_LOG_SIZE));
-	if (!wq)
-		return -ENOMEM;
-	osmo_wqueue_init(wq, LOG_WQUEUE_LEN);
-
    fflush(target->tgt_file.out);
-	if (target->type == LOG_TGT_TYPE_FILE) {
-		rc = open(target->tgt_file.fname, O_WRONLY|O_APPEND|O_CREAT|O_NONBLOCK, 0660);
-		if (rc < 0) {
-			talloc_free(wq);
-			return -errno;
-		}
-	} else {
-		rc = STDERR_FILENO;
-	}
-	wq->bfd.fd = rc;
-	wq->bfd.when = OSMO_FD_WRITE;
-	wq->write_cb = _file_wq_write_cb;
+	if (target->type == LOG_TGT_TYPE_FILE)
+		fd = open(target->tgt_file.fname, O_WRONLY|O_APPEND|O_CREAT|O_NONBLOCK, 0660);
+	else /* LOG_TGT_TYPE_STDERR: dup file so we can close it later with osmo_iofd_free() */
+		fd = dup(STDERR_FILENO);
-	rc = osmo_fd_register(&wq->bfd);
-	if (rc < 0) {
-		talloc_free(wq);
+	if (fd < 0)
+		return -errno;
+
+	target->tgt_file.iofd = osmo_iofd_setup(target, fd, target->tgt_file.fname,
+						OSMO_IO_FD_MODE_READ_WRITE,
+						&log_target_file_io_ops, target);
+	if (!target->tgt_file.iofd) {
+		if (target->type == LOG_TGT_TYPE_FILE)
+			close(fd);
    	return -EIO;
    }
-	target->tgt_file.wqueue = wq;
+
+	osmo_iofd_set_txqueue_max_length(target->tgt_file.iofd, LOG_WQUEUE_LEN);
+
+	rc = osmo_iofd_register(target->tgt_file.iofd, -1);
+	if (rc < 0) {
+		osmo_iofd_free(target->tgt_file.iofd);
+		target->tgt_file.iofd = NULL;
+		return -EIO;
+	}
+
    target->raw_output = _file_raw_output;
    target->output = NULL;
@@ -290,45 +257,40 @@
 struct log_target *log_target_create_file(const char *fname)
 {
    struct log_target *target;
-	struct osmo_wqueue *wq;
-	int rc;
+	int rc, fd;
target = log_target_create();
    if (!target)
    	return NULL;
target->type = LOG_TGT_TYPE_FILE;
-	/* we create a ~640kB sized talloc pool within the write-queue to ensure individual
-	 * log lines (stored as msgbs) will not put result in malloc() calls, and also to
-	 * reduce the OOM probability within logging, as the pool is already allocated */
-	wq = talloc_pooled_object(target, struct osmo_wqueue, LOG_WQUEUE_LEN,
-				  LOG_WQUEUE_LEN*(sizeof(struct msgb)+MAX_LOG_SIZE));
-	if (!wq) {
-		log_target_destroy(target);
-		return NULL;
-	}
-	osmo_wqueue_init(wq, LOG_WQUEUE_LEN);
-	wq->bfd.fd = open(fname, O_WRONLY|O_APPEND|O_CREAT|O_NONBLOCK, 0660);
-	if (wq->bfd.fd < 0) {
-		talloc_free(wq);
-		log_target_destroy(target);
-		return NULL;
-	}
-	wq->bfd.when = OSMO_FD_WRITE;
-	wq->write_cb = _file_wq_write_cb;
-
-	rc = osmo_fd_register(&wq->bfd);
-	if (rc < 0) {
-		talloc_free(wq);
-		log_target_destroy(target);
-		return NULL;
-	}
-
-	target->tgt_file.wqueue = wq;
-	target->raw_output = _file_raw_output;
    target->tgt_file.fname = talloc_strdup(target, fname);
+	OSMO_ASSERT(target->tgt_file.fname);
+	target->raw_output = _file_raw_output;
+
+	fd = open(fname, O_WRONLY|O_APPEND|O_CREAT|O_NONBLOCK, 0660);
+	if (fd < 0)
+		goto free_ret;
+
+	target->tgt_file.iofd = osmo_iofd_setup(target, fd, target->tgt_file.fname,
+						OSMO_IO_FD_MODE_READ_WRITE,
+						&log_target_file_io_ops, target);
+	if (!target->tgt_file.iofd) {
+		close(fd);
+		goto free_ret;
+	}
+
+	osmo_iofd_set_txqueue_max_length(target->tgt_file.iofd, LOG_WQUEUE_LEN);
+
+	rc = osmo_iofd_register(target->tgt_file.iofd, -1);
+	if (rc < 0)
+		goto free_ret;
return target;
+
+free_ret:
+	log_target_destroy(target);
+	return NULL;
 }
 #endif
diff --git a/src/vty/logging_vty.c b/src/vty/logging_vty.c
index 6fd7abc..8e10582 100644
--- a/src/vty/logging_vty.c
+++ b/src/vty/logging_vty.c
@@ -1043,7 +1043,7 @@
    	return 1;
    	break;
    case LOG_TGT_TYPE_STDERR:
-		if (tgt->tgt_file.wqueue)
+		if (tgt->tgt_file.iofd)
    		vty_out(vty, "log stderr%s", VTY_NEWLINE);
    	else
    		vty_out(vty, "log stderr blocking-io%s", VTY_NEWLINE);
@@ -1057,7 +1057,7 @@
 #endif
    	break;
    case LOG_TGT_TYPE_FILE:
-		if (tgt->tgt_file.wqueue)
+		if (tgt->tgt_file.iofd)
    		vty_out(vty, "log file %s%s", tgt->tgt_file.fname, VTY_NEWLINE);
    	else
    		vty_out(vty, "log file %s blocking-io%s", tgt->tgt_file.fname, VTY_NEWLINE);
diff --git a/tests/logging/logging_test.c b/tests/logging/logging_test.c
index 3548b1d..27ad550 100644
--- a/tests/logging/logging_test.c
+++ b/tests/logging/logging_test.c
@@ -16,6 +16,7 @@
  */
#include <osmocom/core/logging.h>
+#include <osmocom/core/select.h>
 #include <osmocom/core/utils.h>
#include <stdlib.h>
@@ -138,5 +139,8 @@
    log_set_print_filename_pos(stderr_target, LOG_FILENAME_POS_LINE_END);
    DEBUGP(DLGLOBAL, "A message with source info printed last\n");
+	for (int i = 0; i < 20; i++)
+		osmo_select_main(1);
+
    return 0;
 }
diff --git a/tests/logging/logging_test.err b/tests/logging/logging_test.err
index 01ab878..fb5181c 100644
--- a/tests/logging/logging_test.err
+++ b/tests/logging/logging_test.err
@@ -7,5 +7,5 @@
 DLGLOBAL You should see this on DLGLOBAL (d)
 DLGLOBAL You should see this on DLGLOBAL (e)
 DLGLOBAL You should see this (DLGLOBAL on DEBUG)
-DLGLOBAL logging_test.c:137 A message with source info printed first
-DLGLOBAL A message with source info printed last (logging_test.c:139)
+DLGLOBAL logging_test.c:138 A message with source info printed first
+DLGLOBAL A message with source info printed last (logging_test.c:140)
-- 
To view, visit https://gerrit.osmocom.org/c/libosmocore/+/41925?usp=email
To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings?usp=email

Gerrit-MessageType: newchange
Gerrit-Project: libosmocore
Gerrit-Branch: master
Gerrit-Change-Id: Ieb6420246454ef59442b1fd7b1d14e2c00fa69a5
Gerrit-Change-Number: 41925
Gerrit-PatchSet: 1
Gerrit-Owner: pespin pespin@sysmocom.de



    

2026

2025

2024

2023

2022

[L] Change in libosmocore[master]: Implement log file target using osmo_io