pespin has submitted this change. (
https://gerrit.osmocom.org/c/libosmocore/+/42088?usp=email )
Change subject: logging: Support nonblocking-io for log target stderr & file,
make it default
......................................................................
logging: Support nonblocking-io for log target stderr & file, make it default
The nonblocking-io used to be the mode used until recently, where wq
only was used if the write buffer was full.
This is more performant that always waiting for poll() to write, plus
the fact that we write to system synchronously, hence seeing output
immediatelly or not losing it if program crashes.
Furthermore, It turns out using wq in multithreaded programs may cause
problems, so better switch back to using nonblocking-io by default.
Related: OS#6947
Change-Id: I46420f4b174d3a9ed01e993e2e89aea3b46c0dd7
---
M include/osmocom/core/logging.h
M src/core/libosmocore.map
M src/core/logging_file.c
M src/vty/logging_vty.c
M tests/logging/logging_vty_test.vty
5 files changed, 96 insertions(+), 24 deletions(-)
Approvals:
laforge: Looks good to me, but someone else must approve
Jenkins Builder: Verified
daniel: Looks good to me, approved
diff --git a/include/osmocom/core/logging.h b/include/osmocom/core/logging.h
index ac6e553..1a5cb7c 100644
--- a/include/osmocom/core/logging.h
+++ b/include/osmocom/core/logging.h
@@ -457,6 +457,8 @@
int log_target_file_reopen(struct log_target *tgt);
int log_target_file_switch_to_stream(struct log_target *tgt);
int log_target_file_switch_to_wqueue(struct log_target *tgt);
+int log_target_file_get_nonblock(const struct log_target *target);
+int log_target_file_set_nonblock(struct log_target *target, int on);
int log_targets_reopen(void);
void log_add_target(struct log_target *target);
diff --git a/src/core/libosmocore.map b/src/core/libosmocore.map
index 5a3c3e8..06a9009 100644
--- a/src/core/libosmocore.map
+++ b/src/core/libosmocore.map
@@ -103,7 +103,9 @@
log_target_create_systemd;
log_target_create_emscripten;
log_target_destroy;
+log_target_file_get_nonblock;
log_target_file_reopen;
+log_target_file_set_nonblock;
log_target_file_switch_to_stream;
log_target_file_switch_to_wqueue;
log_target_find;
diff --git a/src/core/logging_file.c b/src/core/logging_file.c
index 067f993..0e99ca2 100644
--- a/src/core/logging_file.c
+++ b/src/core/logging_file.c
@@ -29,6 +29,7 @@
#include <errno.h>
#include <fcntl.h>
#include <stdarg.h>
+#include <stdbool.h>
#include <stdlib.h>
#include <stdio.h>
#include <string.h>
@@ -60,10 +61,12 @@
return -ENOTSUP;
if (target->tgt_file.out) { /* stream mode */
+ int nonblock_flag = log_target_file_get_nonblock(target) != 0 ?
1 : 0;
fclose(target->tgt_file.out);
target->tgt_file.out = fopen(target->tgt_file.fname, "a");
if (!target->tgt_file.out)
return -errno;
+ log_target_file_set_nonblock(target, nonblock_flag);
return 0;
}
@@ -89,6 +92,62 @@
#if (!EMBEDDED)
+/*! Set the log target fd as non-blocking (see sockopt O_NONBLOCK).
+ * \param[in] target log target which we should switch
+ * \param[in] on set to 1 to set as non-blocking, 0 to set as blocking.
+ * \returns 0 on success; negative on error
+ *
+ * This setting is ignored when \ref target is in wqueue mode.
+ */
+int log_target_file_set_nonblock(struct log_target *target, int on)
+{
+ int flags;
+ int fd;
+
+ if (!target->tgt_file.out)
+ return 0;
+
+ fd = fileno(target->tgt_file.out);
+ if (fd < 0)
+ return fd;
+
+ flags = fcntl(fd, F_GETFL);
+ if (flags < 0)
+ return flags;
+
+ if (on)
+ flags |= O_NONBLOCK;
+ else
+ flags &= ~O_NONBLOCK;
+
+ flags = fcntl(fd, F_SETFL, flags);
+ if (flags < 0)
+ return flags;
+ return 0;
+}
+
+/*! Find whether the log target fd is configured as non-blocking (see sockopt
O_NONBLOCK).
+ * \param[in] target log target which we should switch
+ * \returns 1 if set as non-block; 0 otherwise; negative on error
+ */
+int log_target_file_get_nonblock(const struct log_target *target)
+{
+ int flags;
+ int fd;
+
+ if (!target->tgt_file.out)
+ return -1;
+
+ fd = fileno(target->tgt_file.out);
+ if (fd < 0)
+ return fd;
+
+ flags = fcntl(fd, F_GETFL);
+ if (flags < 0)
+ return flags;
+ return (flags & O_NONBLOCK) ? 1 : 0;
+}
+
/* This is the file-specific subclass destructor logic, called from
* log_target_destroy(). User should call log_target_destroy() to destroy this
* object. */
@@ -309,14 +368,13 @@
return 0;
}
-/*! Create a new file-based log target using non-blocking write_queue
+/*! Create a new file-based log target using a stream
* \param[in] fname File name of the new log file
* \returns Log target in case of success, NULL otherwise
*/
struct log_target *log_target_create_file(const char *fname)
{
struct log_target *target;
- int rc, fd;
target = log_target_create();
if (!target)
@@ -325,14 +383,10 @@
target->type = LOG_TGT_TYPE_FILE;
target->tgt_file.fname = talloc_strdup(target, fname);
OSMO_ASSERT(target->tgt_file.fname);
- target->raw_output = _file_raw_output;
+ target->output = _file_output_stream;
- fd = open(fname, O_WRONLY|O_APPEND|O_CREAT|O_NONBLOCK, 0660);
- if (fd < 0)
- goto free_ret;
-
- rc = _log_target_file_setup_iofd(target, fd);
- if (rc < 0)
+ target->tgt_file.out = fopen(target->tgt_file.fname, "a");
+ if (!target->tgt_file.out)
goto free_ret;
return target;
diff --git a/src/vty/logging_vty.c b/src/vty/logging_vty.c
index 3fa62a1..a7a9efa 100644
--- a/src/vty/logging_vty.c
+++ b/src/vty/logging_vty.c
@@ -886,11 +886,15 @@
}
DEFUN(cfg_log_stderr, cfg_log_stderr_cmd,
- "log stderr [blocking-io]",
+ "log stderr [(nonblocking-io|blocking-io|wq)]",
LOG_STR "Logging via STDERR of the process\n"
- "Use blocking, synchronous I/O\n")
+ "Use non-blocking, synchronous I/O (may lose msgs if file write buffer
becomes full) (default)\n"
+ "Use blocking, synchronous I/O (only for debug purposes or when
blocking is acceptable)\n"
+ "Use Tx workqueue, asynchronous I/O (may lose msgs if queue becomes
full)\n")
{
struct log_target *tgt;
+ bool wq_mode = argc > 0 && (strcmp(argv[0], "wq") == 0);
+ bool blocking_io = argc > 0 && (strcmp(argv[0], "blocking-io") == 0);
log_tgt_mutex_lock();
tgt = log_target_find(LOG_TGT_TYPE_STDERR, NULL);
@@ -904,10 +908,12 @@
log_add_target(tgt);
}
- if (argc > 0 && !strcmp(argv[0], "blocking-io"))
- log_target_file_switch_to_stream(tgt);
- else
+ if (wq_mode) {
log_target_file_switch_to_wqueue(tgt);
+ } else {
+ log_target_file_switch_to_stream(tgt);
+ log_target_file_set_nonblock(tgt, blocking_io ? 0 : 1);
+ }
vty->index = tgt;
vty->node = CFG_LOG_NODE;
@@ -935,11 +941,15 @@
}
DEFUN(cfg_log_file, cfg_log_file_cmd,
- "log file FILENAME [blocking-io]",
+ "log file FILENAME [(nonblocking-io|blocking-io|wq)]",
LOG_STR "Logging to text file\n" "Filename\n"
- "Use blocking, synchronous I/O\n")
+ "Use non-blocking, synchronous I/O (may lose msgs if file write buffer
becomes full) (default)\n"
+ "Use blocking, synchronous I/O (only for debug purposes or when
blocking is acceptable)\n"
+ "Use Tx workqueue, asynchronous I/O (may lose msgs if queue becomes
full)\n")
{
const char *fname = argv[0];
+ bool wq_mode = argc > 1 && (strcmp(argv[1], "wq") == 0);
+ bool blocking_io = argc > 1 && (strcmp(argv[1], "blocking-io") == 0);
struct log_target *tgt;
log_tgt_mutex_lock();
@@ -954,10 +964,12 @@
log_add_target(tgt);
}
- if (argc > 1 && !strcmp(argv[1], "blocking-io"))
- log_target_file_switch_to_stream(tgt);
- else
+ if (wq_mode) {
log_target_file_switch_to_wqueue(tgt);
+ } else {
+ log_target_file_switch_to_stream(tgt);
+ log_target_file_set_nonblock(tgt, blocking_io ? 0 : 1);
+ }
vty->index = tgt;
vty->node = CFG_LOG_NODE;
@@ -1084,9 +1096,10 @@
break;
case LOG_TGT_TYPE_STDERR:
if (tgt->tgt_file.wqueue)
- vty_out(vty, "log stderr%s", VTY_NEWLINE);
+ vty_out(vty, "log stderr wq%s", VTY_NEWLINE);
else
- vty_out(vty, "log stderr blocking-io%s", VTY_NEWLINE);
+ vty_out(vty, "log stderr%s%s",
+ log_target_file_get_nonblock(tgt) == 0 ? "
blocking-io" : "", VTY_NEWLINE);
break;
case LOG_TGT_TYPE_SYSLOG:
#ifdef ENABLE_SYSLOG_LOGGING
@@ -1098,9 +1111,10 @@
break;
case LOG_TGT_TYPE_FILE:
if (tgt->tgt_file.wqueue)
- vty_out(vty, "log file %s%s", tgt->tgt_file.fname,
VTY_NEWLINE);
+ vty_out(vty, "log file %s wq%s", tgt->tgt_file.fname,
VTY_NEWLINE);
else
- vty_out(vty, "log file %s blocking-io%s",
tgt->tgt_file.fname, VTY_NEWLINE);
+ vty_out(vty, "log file %s%s%s", tgt->tgt_file.fname,
+ log_target_file_get_nonblock(tgt) == 0 ? "
blocking-io" : "", VTY_NEWLINE);
break;
case LOG_TGT_TYPE_STRRB:
vty_out(vty, "log alarms %zu%s",
diff --git a/tests/logging/logging_vty_test.vty
b/tests/logging/logging_vty_test.vty
index edf0512..b78678b 100644
--- a/tests/logging/logging_vty_test.vty
+++ b/tests/logging/logging_vty_test.vty
@@ -2,7 +2,7 @@
logging_vty_test# show running-config
...
-log stderr
+log stderr wq
... !logging level all
logging level aa debug
logging level bb info
--
To view, visit https://gerrit.osmocom.org/c/libosmocore/+/42088?usp=email
To unsubscribe, or for help writing mail filters, visit
https://gerrit.osmocom.org/settings?usp=email
Gerrit-MessageType: merged
Gerrit-Project: libosmocore
Gerrit-Branch: master
Gerrit-Change-Id: I46420f4b174d3a9ed01e993e2e89aea3b46c0dd7
Gerrit-Change-Number: 42088
Gerrit-PatchSet: 3
Gerrit-Owner: pespin <[email protected]>
Gerrit-Reviewer: Jenkins Builder
Gerrit-Reviewer: daniel <[email protected]>
Gerrit-Reviewer: fixeria <[email protected]>
Gerrit-Reviewer: laforge <[email protected]>
Gerrit-Reviewer: osmith <[email protected]>
Gerrit-Reviewer: pespin <[email protected]>
