aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorHarald Welte <laforge@osmocom.org>2020-09-29 11:32:35 +0200
committerHarald Welte <laforge@osmocom.org>2020-09-29 20:06:57 +0200
commitad541dfbdf9e7f7e194c769dcbed74200831c455 (patch)
tree8b8be5bcab90a36e39a9935d942b83487217f80e
parent11a6bf90b8ec4d04ac85b0246912f53c3a4c8af1 (diff)
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
-rw-r--r--src/logging.c47
1 files changed, 30 insertions, 17 deletions
diff --git a/src/logging.c b/src/logging.c
index 952869c3..07859828 100644
--- a/src/logging.c
+++ b/src/logging.c
@@ -867,6 +867,24 @@ void log_set_category_filter(struct log_target *target, int category,
}
#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 @@ static void _file_raw_output(struct log_target *target, int subsys, unsigned int
* 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 @@ struct log_target *log_target_create_stderr(void)
}
#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