[PATCH v2 9/9] log: call vsnprintf only when it is needed to emit trace

[Patrick Delaunay]

Reduce the log overhead when the traces are filtered,
by moving the vsnprintf call from _log() to log_dispatch().

This patch avoids the printf treatment when LOG features is
activated, but trace is filtered, for example when
MAX_LOG_LEVEL=8 and LOG_DEFAULT_LEVEL=6.

Reviewed-by: Simon Glass <sjg at chromium.org>
Signed-off-by: Patrick Delaunay <patrick.delaunay at st.com>
---

(no changes since v1)

 common/log.c | 20 +++++++++++++-------
 1 file changed, 13 insertions(+), 7 deletions(-)

diff --git a/common/log.c b/common/log.c
index a4ed7d79f8..767f0febc5 100644
--- a/common/log.c
+++ b/common/log.c
@@ -198,9 +198,10 @@ static bool log_passes_filters(struct log_device *ldev, struct log_rec *rec)
  * @rec:	log record to dispatch
  * Return:	0 msg sent, 1 msg not sent while already dispatching another msg
  */
-static int log_dispatch(struct log_rec *rec)
+static int log_dispatch(struct log_rec *rec, const char *fmt, va_list args)
 {
 	struct log_device *ldev;
+	char buf[CONFIG_SYS_CBSIZE];
 
 	/*
 	 * When a log driver writes messages (e.g. via the network stack) this
@@ -214,8 +215,13 @@ static int log_dispatch(struct log_rec *rec)
 	gd->processing_msg = true;
 	list_for_each_entry(ldev, &gd->log_head, sibling_node) {
 		if ((ldev->flags & LOGDF_ENABLE) &&
-		    log_passes_filters(ldev, rec))
+		    log_passes_filters(ldev, rec)) {
+			if (!rec->msg) {
+				vsnprintf(buf, sizeof(buf), fmt, args);
+				rec->msg = buf;
+			}
 			ldev->drv->emit(ldev, rec);
+		}
 	}
 	gd->processing_msg = false;
 	return 0;
@@ -224,7 +230,6 @@ static int log_dispatch(struct log_rec *rec)
 int _log(enum log_category_t cat, enum log_level_t level, const char *file,
 	 int line, const char *func, const char *fmt, ...)
 {
-	char buf[CONFIG_SYS_CBSIZE];
 	struct log_rec rec;
 	va_list args;
 
@@ -243,12 +248,15 @@ int _log(enum log_category_t cat, enum log_level_t level, const char *file,
 	rec.file = file;
 	rec.line = line;
 	rec.func = func;
+	rec.msg = NULL;
 
 	if (!(gd->flags & GD_FLG_LOG_READY)) {
 		gd->log_drop_count++;
 
 		/* display dropped traces with console puts and DEBUG_UART */
 		if (rec.level <= CONFIG_LOG_DEFAULT_LEVEL || rec.force_debug) {
+			char buf[CONFIG_SYS_CBSIZE];
+
 			va_start(args, fmt);
 			vsnprintf(buf, sizeof(buf), fmt, args);
 			puts(buf);
@@ -258,13 +266,11 @@ int _log(enum log_category_t cat, enum log_level_t level, const char *file,
 		return -ENOSYS;
 	}
 	va_start(args, fmt);
-	vsnprintf(buf, sizeof(buf), fmt, args);
-	va_end(args);
-	rec.msg = buf;
-	if (!log_dispatch(&rec)) {
+	if (!log_dispatch(&rec, fmt, args)) {
 		gd->logc_prev = cat;
 		gd->logl_prev = level;
 	}
+	va_end(args);
 
 	return 0;
 }
-- 
2.17.1