Change in libosmocore[master]: logging: Attempt a synchronous, non-blocking write first (file, stderr)

[laforge]

laforge has uploaded this change for review. ( https://gerrit.osmocom.org/c/libosmocore/+/20317 )


Change subject: logging: Attempt a synchronous, non-blocking write first (file, stderr)
......................................................................

logging: Attempt a synchronous, non-blocking write first (file, stderr)

In the old days, we performed synchronous, blocking writes to the log
file or stderr.  This was replaced by code that turned all log
file/stderr writes into non-blocking writes behind a write_queue.

This patch now introduces a further optimization: If we currently
don't have any log messages pending in the write queue, we are not
back-logged and assume we have a fair chance of writing the log message
right now, synchronously.  So we try that first, and only enqueue
the log message if the write fails (no bytes or insufficient number
of bytes written).

This way we should get the best of both worlds: No delay/re-ordering
(and lower select syscall load) for the "normal" case (benefits of
the old synchronous writes) while at the same time never risking to
block on log output.

Change-Id: I08469a7e4be9bc5bbd39140457bb582f4a0b1703
---
M src/logging.c
1 file changed, 30 insertions(+), 17 deletions(-)



  git pull ssh://gerrit.osmocom.org:29418/libosmocore refs/changes/17/20317/1

diff --git a/src/logging.c b/src/logging.c
index b538754..3d05bef 100644
--- a/src/logging.c
+++ b/src/logging.c
@@ -867,6 +867,24 @@
 }
 
 #if (!EMBEDDED)
+/* 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;
+}
+
+/* output via buffered, blocking stdio streams */
 static void _file_output_stream(struct log_target *target, unsigned int level,
 			 const char *log)
 {
@@ -892,6 +910,18 @@
 	 * and call _file_wq_write_cb() */
 	rc = _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) */
 	osmo_wqueue_enqueue_quiet(target->tgt_file.wqueue, msg);
 }
 #endif
@@ -963,23 +993,6 @@
 }
 
 #if (!EMBEDDED)
-/* 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;
-}
-
 /*! Create a new file-based log target using buffered, blocking stream output
  *  \param[in] fname File name of the new log file
  *  \returns Log target in case of success, NULL otherwise

-- 
To view, visit https://gerrit.osmocom.org/c/libosmocore/+/20317
To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings

Gerrit-Project: libosmocore
Gerrit-Branch: master
Gerrit-Change-Id: I08469a7e4be9bc5bbd39140457bb582f4a0b1703
Gerrit-Change-Number: 20317
Gerrit-PatchSet: 1
Gerrit-Owner: laforge <laforge at osmocom.org>
Gerrit-MessageType: newchange
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.osmocom.org/pipermail/gerrit-log/attachments/20200929/01d5963f/attachment.htm>