[v2,2/9] log: don't build the trace buffer when log is not ready

Update _log function to drop any traces when log is yet initialized:
vsnprintf is no more executed in this case.

This patch allows to reduce the cost for the dropped early debug trace.

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

(no changes since v1)

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

On 11/27/20 5:20 AM, Patrick Delaunay wrote:
> Update _log function to drop any traces when log is yet initialized:
> vsnprintf is no more executed in this case.
> 
> This patch allows to reduce the cost for the dropped early debug trace.
> 
> Reviewed-by: Simon Glass <sjg@chromium.org>
> Signed-off-by: Patrick Delaunay <patrick.delaunay@st.com>
> ---
> 
> (no changes since v1)
> 
>   common/log.c | 13 ++++++++-----
>   1 file changed, 8 insertions(+), 5 deletions(-)
> 
> diff --git a/common/log.c b/common/log.c
> index ce39918e04..212789d6b3 100644
> --- a/common/log.c
> +++ b/common/log.c
> @@ -228,6 +228,9 @@ int _log(enum log_category_t cat, enum log_level_t level, const char *file,
>   	struct log_rec rec;
>   	va_list args;
>   
> +	if (!gd)
> +		return -ENOSYS;

How early are you expecting this function to get called? AFAIK this will
only return true before board_init_f_init_reserve. Shouldn't functions
that early just not call log in the first place?

--Sean

> +
>   	/* Check for message continuation */
>   	if (cat == LOGC_CONT)
>   		cat = gd->logc_prev;
> @@ -240,15 +243,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;
> +
> +	if (!(gd->flags & GD_FLG_LOG_READY)) {
> +		gd->log_drop_count++;
> +		return -ENOSYS;
> +	}
>   	va_start(args, fmt);
>   	vsnprintf(buf, sizeof(buf), fmt, args);
>   	va_end(args);
>   	rec.msg = buf;
> -	if (!gd || !(gd->flags & GD_FLG_LOG_READY)) {
> -		if (gd)
> -			gd->log_drop_count++;
> -		return -ENOSYS;
> -	}
>   	if (!log_dispatch(&rec)) {
>   		gd->logc_prev = cat;
>   		gd->logl_prev = level;
>

Hi Sean,

On Fri, 27 Nov 2020 at 07:50, Sean Anderson <seanga2@gmail.com> wrote:
>
> On 11/27/20 5:20 AM, Patrick Delaunay wrote:
> > Update _log function to drop any traces when log is yet initialized:
> > vsnprintf is no more executed in this case.
> >
> > This patch allows to reduce the cost for the dropped early debug trace.
> >
> > Reviewed-by: Simon Glass <sjg@chromium.org>
> > Signed-off-by: Patrick Delaunay <patrick.delaunay@st.com>
> > ---
> >
> > (no changes since v1)
> >
> >   common/log.c | 13 ++++++++-----
> >   1 file changed, 8 insertions(+), 5 deletions(-)
> >
> > diff --git a/common/log.c b/common/log.c
> > index ce39918e04..212789d6b3 100644
> > --- a/common/log.c
> > +++ b/common/log.c
> > @@ -228,6 +228,9 @@ int _log(enum log_category_t cat, enum log_level_t level, const char *file,
> >       struct log_rec rec;
> >       va_list args;
> >
> > +     if (!gd)
> > +             return -ENOSYS;
>
> How early are you expecting this function to get called? AFAIK this will
> only return true before board_init_f_init_reserve. Shouldn't functions
> that early just not call log in the first place?

Heinrich may have some thoughts here.

I think we will end up using log very early, since it is sort-of the
replacement for printf() and debug().

Regards,
Simon

Hi Sean,

> From: Sean Anderson <seanga2@gmail.com>
> Sent: vendredi 27 novembre 2020 15:51
> 
> On 11/27/20 5:20 AM, Patrick Delaunay wrote:
> > Update _log function to drop any traces when log is yet initialized:
> > vsnprintf is no more executed in this case.
> >
> > This patch allows to reduce the cost for the dropped early debug trace.
> >
> > Reviewed-by: Simon Glass <sjg@chromium.org>
> > Signed-off-by: Patrick Delaunay <patrick.delaunay@st.com>
> > ---
> >
> > (no changes since v1)
> >
> >   common/log.c | 13 ++++++++-----
> >   1 file changed, 8 insertions(+), 5 deletions(-)
> >
> > diff --git a/common/log.c b/common/log.c index ce39918e04..212789d6b3
> > 100644
> > --- a/common/log.c
> > +++ b/common/log.c
> > @@ -228,6 +228,9 @@ int _log(enum log_category_t cat, enum log_level_t
> level, const char *file,
> >   	struct log_rec rec;
> >   	va_list args;
> >
> > +	if (!gd)
> > +		return -ENOSYS;
> 
> How early are you expecting this function to get called? AFAIK this will only return
> true before board_init_f_init_reserve. Shouldn't functions that early just not call log
> in the first place?

I don't change the existing behavior, this test exists since the first commit on log.c, done
by Simon.

Patch 8/15 of
http://patchwork.ozlabs.org/project/uboot/list/?series=16677&state=*

I check, this line exist since the first version of this serie....

But I think you are right, log/debug fucntions should not called before C runtime is ready
(including gd configuration in board_init_f_alloc_reserve), it seens as over-protection.

> --Sean
> 
> > +
> >   	/* Check for message continuation */
> >   	if (cat == LOGC_CONT)
> >   		cat = gd->logc_prev;
> > @@ -240,15 +243,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;
> > +
> > +	if (!(gd->flags & GD_FLG_LOG_READY)) {
> > +		gd->log_drop_count++;
> > +		return -ENOSYS;
> > +	}
> >   	va_start(args, fmt);
> >   	vsnprintf(buf, sizeof(buf), fmt, args);
> >   	va_end(args);
> >   	rec.msg = buf;
> > -	if (!gd || !(gd->flags & GD_FLG_LOG_READY)) {
> > -		if (gd)
> > -			gd->log_drop_count++;
> > -		return -ENOSYS;
> > -	}
> >   	if (!log_dispatch(&rec)) {
> >   		gd->logc_prev = cat;
> >   		gd->logl_prev = level;
> >

Patrick

On Fri, Nov 27, 2020 at 11:20:52AM +0100, Patrick Delaunay wrote:

> Update _log function to drop any traces when log is yet initialized:
> vsnprintf is no more executed in this case.
> 
> This patch allows to reduce the cost for the dropped early debug trace.
> 
> Reviewed-by: Simon Glass <sjg@chromium.org>
> Signed-off-by: Patrick Delaunay <patrick.delaunay@st.com>

Applied to u-boot/master, thanks!