This is merely a historical archive of years 2008-2021, before the migration to mailman3.
A maintained and still updated list archive can be found at https://lists.osmocom.org/hyperkitty/list/gerrit-log@lists.osmocom.org/.
laforge gerrit-no-reply at lists.osmocom.orglaforge has uploaded this change for review. ( https://gerrit.osmocom.org/c/libosmocore/+/20305 )
Change subject: logging: Avoid memcpy from stack to msgb in _file_output()
......................................................................
logging: Avoid memcpy from stack to msgb in _file_output()
For file and stderr output, the existing code always generates
the log string on a stack buffer, and then (in case of non-blocking
write via write_queue) copies it over to a msgb.
Let's optimize this by turning _file_output() into a raw_output
callback which first allocates the msgb and then format-prints
directly to that msgb instaed of stack + memcpy.
This has the disadvantage that we don't know how long the buffer
has to be in order to print the entire string to it. As a result
we always have to allocate a 4k-sized buffer (plus msgb overhead).
The write_queue length for log file output has been decreased from
1024 entries to 156 entries in order to stay within the same
memory requirements for each log target memory pool (about 648 kBytes).
Change-Id: I0d10b0199576d2e7ff6421a6dba19ae5ffafd946
---
M src/logging.c
1 file changed, 41 insertions(+), 17 deletions(-)
git pull ssh://gerrit.osmocom.org:29418/libosmocore refs/changes/05/20305/1
diff --git a/src/logging.c b/src/logging.c
index 4c0ea58..952c350 100644
--- a/src/logging.c
+++ b/src/logging.c
@@ -66,7 +66,7 @@
#define MAX_LOG_SIZE 4096
/* maximum number of log statements we queue in file/stderr target write queue */
-#define LOG_WQUEUE_LEN 1024
+#define LOG_WQUEUE_LEN 156
osmo_static_assert(_LOG_CTX_COUNT <= ARRAY_SIZE(((struct log_context*)NULL)->ctx),
enum_logging_ctx_items_fit_in_struct_log_context);
@@ -398,12 +398,23 @@
return bn + 1;
}
-static void _output(struct log_target *target, unsigned int subsys,
- unsigned int level, const char *file, int line, int cont,
- const char *format, va_list ap)
+/*! main output formatting function for log lines.
+ * \param[out] buf caller-allocated output buffer for the generated string
+ * \param[in] buf_len number of bytes availale in buf
+ * \param[in] target log target for which the string is to be formatted
+ * \param[in] subsys Log sub-system number
+ * \param[in] level Log level
+ * \param[in] file name of source code file generating the log
+ * \param[in] line line source code line number within 'file' generating the log
+ * \param[in] cont is this a continuation (true) or not (false)
+ * \param[in] format format string
+ * \param[in] ap variable argument list for format
+ * \returns number of bytes written to out */
+static int _output_buf(char *buf, int buf_len, struct log_target *target, unsigned int subsys,
+ unsigned int level, const char *file, int line, int cont,
+ const char *format, va_list ap)
{
- char buf[MAX_LOG_SIZE];
- int ret, len = 0, offset = 0, rem = sizeof(buf);
+ int ret, len = 0, offset = 0, rem = buf_len;
const char *c_subsys = NULL;
/* are we using color */
@@ -529,8 +540,20 @@
OSMO_SNPRINTF_RET(ret, rem, offset, len);
}
err:
- buf[sizeof(buf)-1] = '\0';
- target->output(target, level, buf, len);
+ buf[buf_len-1] = '\0';
+ return len;
+}
+
+/* Format the log line for given target; use a stack buffer and call target->output */
+static void _output(struct log_target *target, unsigned int subsys,
+ unsigned int level, const char *file, int line, int cont,
+ const char *format, va_list ap)
+{
+ char buf[MAX_LOG_SIZE];
+ int rc;
+
+ rc = _output_buf(buf, sizeof(buf), target, subsys, level, file, line, cont, format, ap);
+ target->output(target, level, buf, rc);
}
/* Catch internal logging category indexes as well as out-of-bounds indexes.
@@ -853,21 +876,21 @@
}
/* output via non-blocking write_queue, doing internal buffering */
-static void _file_output(struct log_target *target, unsigned int level,
- const char *log, int len)
+static void _file_raw_output(struct log_target *target, int subsys, unsigned int level, const char *file,
+ int line, int cont, const char *format, va_list ap)
{
struct msgb *msg;
OSMO_ASSERT(target->tgt_file.wqueue);
- msg = msgb_alloc_c(target->tgt_file.wqueue, len, "log_file_msg");
+ msg = msgb_alloc_c(target->tgt_file.wqueue, MAX_LOG_SIZE, "log_file_msg");
if (!msg)
return;
/* we simply enqueue the log message to a write queue here, to avoid any blocking
* writes on the output file. The write queue will tell us once the file is writable
* and call _file_wq_write_cb() */
- memcpy(msg->data, log, len);
- msgb_put(msg, len);
+ rc = _output_buf((char *)msgb_data(msg), msgb_tailroom(msg), target, subsys, level, file, line, cont, format, ap);
+ msgb_put(msg, rc);
osmo_wqueue_enqueue_quiet(target->tgt_file.wqueue, msg);
}
#endif
@@ -1009,7 +1032,7 @@
* 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)+512));
+ LOG_WQUEUE_LEN*(sizeof(struct msgb)+MAX_LOG_SIZE));
if (!wq)
return -ENOMEM;
osmo_wqueue_init(wq, LOG_WQUEUE_LEN);
@@ -1034,7 +1057,8 @@
return -EIO;
}
target->tgt_file.wqueue = wq;
- target->output = _file_output;
+ target->raw_output = _file_raw_output;
+ target->output = NULL;
/* now that everything succeeded, we can finally close the old output stream */
if (target->type == LOG_TGT_TYPE_FILE)
@@ -1063,7 +1087,7 @@
* 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)+512));
+ LOG_WQUEUE_LEN*(sizeof(struct msgb)+MAX_LOG_SIZE));
if (!wq) {
log_target_destroy(target);
return NULL;
@@ -1086,7 +1110,7 @@
}
target->tgt_file.wqueue = wq;
- target->output = _file_output;
+ target->raw_output = _file_raw_output;
target->tgt_file.fname = talloc_strdup(target, fname);
return target;
--
To view, visit https://gerrit.osmocom.org/c/libosmocore/+/20305
To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings
Gerrit-Project: libosmocore
Gerrit-Branch: master
Gerrit-Change-Id: I0d10b0199576d2e7ff6421a6dba19ae5ffafd946
Gerrit-Change-Number: 20305
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/20200927/0245c2f8/attachment.htm>