[PATCH 3/3] 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.

Signed-off-by: Patrick Delaunay <patrick.delau...@st.com>

# Conflicts:
#       common/log.c
---

 common/log.c | 22 ++++++++++++++--------
 1 file changed, 14 insertions(+), 8 deletions(-)

diff --git a/common/log.c b/common/log.c
index aa5505943f..e5681ab323 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,13 +248,16 @@ 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++;
 
-               /* manage droppped trace at default level with debug uart */
+               /* manage droppped traces at default level with debug uart */
                if (IS_ENABLED(CONFIG_DEBUG_UART) &&
                    (rec.level <= CONFIG_LOG_DEFAULT_LEVEL || rec.force_debug)) 
{
+                       char buf[CONFIG_SYS_CBSIZE];
+
                        va_start(args, fmt);
                        vsnprintf(buf, sizeof(buf), fmt, args);
                        printascii(buf);
@@ -259,13 +267,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