log: call vsnprintf only when it is needed to emit trace
authorPatrick Delaunay <patrick.delaunay@st.com>
Fri, 27 Nov 2020 10:20:59 +0000 (11:20 +0100)
committerTom Rini <trini@konsulko.com>
Fri, 15 Jan 2021 19:36:11 +0000 (14:36 -0500)
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@chromium.org>
Signed-off-by: Patrick Delaunay <patrick.delaunay@st.com>
common/log.c

index a4ed7d7..767f0fe 100644 (file)
@@ -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;
 }