diff mbox series

[1/2] log: allow for message continuation

Message ID 20200917121902.57403-2-xypron.glpk@gmx.de
State Changes Requested
Delegated to: Simon Glass
Headers show
Series log: allow for message continuation | expand

Commit Message

Heinrich Schuchardt Sept. 17, 2020, 12:19 p.m. UTC
Some drivers use macro pr_cont() for continuing a message sent via printk.
Hence if we want to convert printk messaging to using the logging system,
we must support continuation of log messages too.

As pr_cont() does not provide a message level we need a means of
remembering the last log level.

With the patch a pseudo log level LOGL_CONT as well as a pseudo log
category LOGC_CONT are introduced. Using these results in the application
of the same log level and category as in the previous log message.

Signed-off-by: Heinrich Schuchardt <xypron.glpk@gmx.de>
---
 common/log.c            | 23 ++++++++++++++++++-----
 doc/develop/logging.rst |  6 ++++++
 include/log.h           |  2 ++
 3 files changed, 26 insertions(+), 5 deletions(-)

--
2.28.0

Comments

Simon Glass Sept. 22, 2020, 6:48 p.m. UTC | #1
Hi Heinrich,

On Thu, 17 Sep 2020 at 06:19, Heinrich Schuchardt <xypron.glpk@gmx.de> wrote:
>
> Some drivers use macro pr_cont() for continuing a message sent via printk.
> Hence if we want to convert printk messaging to using the logging system,
> we must support continuation of log messages too.
>
> As pr_cont() does not provide a message level we need a means of
> remembering the last log level.
>
> With the patch a pseudo log level LOGL_CONT as well as a pseudo log
> category LOGC_CONT are introduced. Using these results in the application
> of the same log level and category as in the previous log message.
>
> Signed-off-by: Heinrich Schuchardt <xypron.glpk@gmx.de>
> ---
>  common/log.c            | 23 ++++++++++++++++++-----
>  doc/develop/logging.rst |  6 ++++++
>  include/log.h           |  2 ++
>  3 files changed, 26 insertions(+), 5 deletions(-)
>
> diff --git a/common/log.c b/common/log.c
> index 9a5f100da3..bafc09f263 100644
> --- a/common/log.c
> +++ b/common/log.c
> @@ -183,10 +183,12 @@ static bool log_passes_filters(struct log_device *ldev, struct log_rec *rec)
>   * log_dispatch() - Send a log record to all log devices for processing
>   *
>   * The log record is sent to each log device in turn, skipping those which have
> - * filters which block the record
> + * filters which block the record.
>   *
> - * @rec: Log record to dispatch
> - * @return 0 (meaning success)
> + * All log messages created while processing log record @rec are ignored.
> + *
> + * @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)
>  {
> @@ -199,7 +201,7 @@ static int log_dispatch(struct log_rec *rec)
>          * as this might result in infinite recursion.
>          */
>         if (processing_msg)
> -               return 0;
> +               return 1;
>
>         /* Emit message */
>         processing_msg = 1;
> @@ -214,10 +216,18 @@ 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, ...)
>  {
> +       static enum log_category_t logc_prev = LOGC_NONE;
> +       static enum log_level_t logl_prev = LOGL_INFO;

I don't think we can use static variables in logging. Perhaps we can
use gobal_data?


>         char buf[CONFIG_SYS_CBSIZE];
>         struct log_rec rec;
>         va_list args;
>
> +       /* Check for message continuation */
> +       if (cat == LOGC_CONT)

Regards,
Simon
Heinrich Schuchardt Sept. 22, 2020, 7:10 p.m. UTC | #2
On 9/22/20 8:48 PM, Simon Glass wrote:
> Hi Heinrich,
>
> On Thu, 17 Sep 2020 at 06:19, Heinrich Schuchardt <xypron.glpk@gmx.de> wrote:
>>
>> Some drivers use macro pr_cont() for continuing a message sent via printk.
>> Hence if we want to convert printk messaging to using the logging system,
>> we must support continuation of log messages too.
>>
>> As pr_cont() does not provide a message level we need a means of
>> remembering the last log level.
>>
>> With the patch a pseudo log level LOGL_CONT as well as a pseudo log
>> category LOGC_CONT are introduced. Using these results in the application
>> of the same log level and category as in the previous log message.
>>
>> Signed-off-by: Heinrich Schuchardt <xypron.glpk@gmx.de>
>> ---
>>  common/log.c            | 23 ++++++++++++++++++-----
>>  doc/develop/logging.rst |  6 ++++++
>>  include/log.h           |  2 ++
>>  3 files changed, 26 insertions(+), 5 deletions(-)
>>
>> diff --git a/common/log.c b/common/log.c
>> index 9a5f100da3..bafc09f263 100644
>> --- a/common/log.c
>> +++ b/common/log.c
>> @@ -183,10 +183,12 @@ static bool log_passes_filters(struct log_device *ldev, struct log_rec *rec)
>>   * log_dispatch() - Send a log record to all log devices for processing
>>   *
>>   * The log record is sent to each log device in turn, skipping those which have
>> - * filters which block the record
>> + * filters which block the record.
>>   *
>> - * @rec: Log record to dispatch
>> - * @return 0 (meaning success)
>> + * All log messages created while processing log record @rec are ignored.
>> + *
>> + * @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)
>>  {
>> @@ -199,7 +201,7 @@ static int log_dispatch(struct log_rec *rec)
>>          * as this might result in infinite recursion.
>>          */
>>         if (processing_msg)
>> -               return 0;
>> +               return 1;
>>
>>         /* Emit message */
>>         processing_msg = 1;
>> @@ -214,10 +216,18 @@ 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, ...)
>>  {
>> +       static enum log_category_t logc_prev = LOGC_NONE;
>> +       static enum log_level_t logl_prev = LOGL_INFO;
>
> I don't think we can use static variables in logging. Perhaps we can
> use gobal_data?

Are you worried about relocation?

The initialization of the global data fields should be done in
log_init() before gd->flags |= GD_FLG_LOG_READY; I assume.

Is the rest ok for you?

Best regards

Heinrich

>
>
>>         char buf[CONFIG_SYS_CBSIZE];
>>         struct log_rec rec;
>>         va_list args;
>>
>> +       /* Check for message continuation */
>> +       if (cat == LOGC_CONT)
>
> Regards,
> Simon
>
Simon Glass Sept. 22, 2020, 10:03 p.m. UTC | #3
Hi Heinrich,

On Tue, 22 Sep 2020 at 13:10, Heinrich Schuchardt <xypron.glpk@gmx.de> wrote:
>
> On 9/22/20 8:48 PM, Simon Glass wrote:
> > Hi Heinrich,
> >
> > On Thu, 17 Sep 2020 at 06:19, Heinrich Schuchardt <xypron.glpk@gmx.de> wrote:
> >>
> >> Some drivers use macro pr_cont() for continuing a message sent via printk.
> >> Hence if we want to convert printk messaging to using the logging system,
> >> we must support continuation of log messages too.
> >>
> >> As pr_cont() does not provide a message level we need a means of
> >> remembering the last log level.
> >>
> >> With the patch a pseudo log level LOGL_CONT as well as a pseudo log
> >> category LOGC_CONT are introduced. Using these results in the application
> >> of the same log level and category as in the previous log message.
> >>
> >> Signed-off-by: Heinrich Schuchardt <xypron.glpk@gmx.de>
> >> ---
> >>  common/log.c            | 23 ++++++++++++++++++-----
> >>  doc/develop/logging.rst |  6 ++++++
> >>  include/log.h           |  2 ++
> >>  3 files changed, 26 insertions(+), 5 deletions(-)
> >>
> >> diff --git a/common/log.c b/common/log.c
> >> index 9a5f100da3..bafc09f263 100644
> >> --- a/common/log.c
> >> +++ b/common/log.c
> >> @@ -183,10 +183,12 @@ static bool log_passes_filters(struct log_device *ldev, struct log_rec *rec)
> >>   * log_dispatch() - Send a log record to all log devices for processing
> >>   *
> >>   * The log record is sent to each log device in turn, skipping those which have
> >> - * filters which block the record
> >> + * filters which block the record.
> >>   *
> >> - * @rec: Log record to dispatch
> >> - * @return 0 (meaning success)
> >> + * All log messages created while processing log record @rec are ignored.
> >> + *
> >> + * @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)
> >>  {
> >> @@ -199,7 +201,7 @@ static int log_dispatch(struct log_rec *rec)
> >>          * as this might result in infinite recursion.
> >>          */
> >>         if (processing_msg)
> >> -               return 0;
> >> +               return 1;
> >>
> >>         /* Emit message */
> >>         processing_msg = 1;
> >> @@ -214,10 +216,18 @@ 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, ...)
> >>  {
> >> +       static enum log_category_t logc_prev = LOGC_NONE;
> >> +       static enum log_level_t logl_prev = LOGL_INFO;
> >
> > I don't think we can use static variables in logging. Perhaps we can
> > use gobal_data?
>
> Are you worried about relocation?

Yes, and SPL.

>
> The initialization of the global data fields should be done in
> log_init() before gd->flags |= GD_FLG_LOG_READY; I assume.

Yes.

>
> Is the rest ok for you?

Yes. If you are adding new things to global_data you could convert
default_log_level to a char to avoid using more space.


>
> Best regards
>
> Heinrich
>
> >
> >
> >>         char buf[CONFIG_SYS_CBSIZE];
> >>         struct log_rec rec;
> >>         va_list args;
> >>
> >> +       /* Check for message continuation */
> >> +       if (cat == LOGC_CONT)
> >
> > Regards,
> > Simon
> >
>
Simon Glass Oct. 5, 2020, 1:41 a.m. UTC | #4
Hi Heinrich,

On Tue, 22 Sep 2020 at 16:03, Simon Glass <sjg@chromium.org> wrote:
>
> Hi Heinrich,
>
> On Tue, 22 Sep 2020 at 13:10, Heinrich Schuchardt <xypron.glpk@gmx.de> wrote:
> >
> > On 9/22/20 8:48 PM, Simon Glass wrote:
> > > Hi Heinrich,
> > >
> > > On Thu, 17 Sep 2020 at 06:19, Heinrich Schuchardt <xypron.glpk@gmx.de> wrote:
> > >>
> > >> Some drivers use macro pr_cont() for continuing a message sent via printk.
> > >> Hence if we want to convert printk messaging to using the logging system,
> > >> we must support continuation of log messages too.
> > >>
> > >> As pr_cont() does not provide a message level we need a means of
> > >> remembering the last log level.
> > >>
> > >> With the patch a pseudo log level LOGL_CONT as well as a pseudo log
> > >> category LOGC_CONT are introduced. Using these results in the application
> > >> of the same log level and category as in the previous log message.
> > >>
> > >> Signed-off-by: Heinrich Schuchardt <xypron.glpk@gmx.de>
> > >> ---
> > >>  common/log.c            | 23 ++++++++++++++++++-----
> > >>  doc/develop/logging.rst |  6 ++++++
> > >>  include/log.h           |  2 ++
> > >>  3 files changed, 26 insertions(+), 5 deletions(-)
> > >>
> > >> diff --git a/common/log.c b/common/log.c
> > >> index 9a5f100da3..bafc09f263 100644
> > >> --- a/common/log.c
> > >> +++ b/common/log.c
> > >> @@ -183,10 +183,12 @@ static bool log_passes_filters(struct log_device *ldev, struct log_rec *rec)
> > >>   * log_dispatch() - Send a log record to all log devices for processing
> > >>   *
> > >>   * The log record is sent to each log device in turn, skipping those which have
> > >> - * filters which block the record
> > >> + * filters which block the record.
> > >>   *
> > >> - * @rec: Log record to dispatch
> > >> - * @return 0 (meaning success)
> > >> + * All log messages created while processing log record @rec are ignored.
> > >> + *
> > >> + * @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)
> > >>  {
> > >> @@ -199,7 +201,7 @@ static int log_dispatch(struct log_rec *rec)
> > >>          * as this might result in infinite recursion.
> > >>          */
> > >>         if (processing_msg)
> > >> -               return 0;
> > >> +               return 1;
> > >>
> > >>         /* Emit message */
> > >>         processing_msg = 1;
> > >> @@ -214,10 +216,18 @@ 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, ...)
> > >>  {
> > >> +       static enum log_category_t logc_prev = LOGC_NONE;
> > >> +       static enum log_level_t logl_prev = LOGL_INFO;
> > >
> > > I don't think we can use static variables in logging. Perhaps we can
> > > use gobal_data?
> >
> > Are you worried about relocation?
>
> Yes, and SPL.
>
> >
> > The initialization of the global data fields should be done in
> > log_init() before gd->flags |= GD_FLG_LOG_READY; I assume.
>
> Yes.
>
> >
> > Is the rest ok for you?
>
> Yes. If you are adding new things to global_data you could convert
> default_log_level to a char to avoid using more space.
>

Also I notice that the processing_msg variable in log.c crashes
logging in SPL/TPL. Can you please move this to global_data too?

Regards,
Simon
diff mbox series

Patch

diff --git a/common/log.c b/common/log.c
index 9a5f100da3..bafc09f263 100644
--- a/common/log.c
+++ b/common/log.c
@@ -183,10 +183,12 @@  static bool log_passes_filters(struct log_device *ldev, struct log_rec *rec)
  * log_dispatch() - Send a log record to all log devices for processing
  *
  * The log record is sent to each log device in turn, skipping those which have
- * filters which block the record
+ * filters which block the record.
  *
- * @rec: Log record to dispatch
- * @return 0 (meaning success)
+ * All log messages created while processing log record @rec are ignored.
+ *
+ * @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)
 {
@@ -199,7 +201,7 @@  static int log_dispatch(struct log_rec *rec)
 	 * as this might result in infinite recursion.
 	 */
 	if (processing_msg)
-		return 0;
+		return 1;

 	/* Emit message */
 	processing_msg = 1;
@@ -214,10 +216,18 @@  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, ...)
 {
+	static enum log_category_t logc_prev = LOGC_NONE;
+	static enum log_level_t logl_prev = LOGL_INFO;
 	char buf[CONFIG_SYS_CBSIZE];
 	struct log_rec rec;
 	va_list args;

+	/* Check for message continuation */
+	if (cat == LOGC_CONT)
+		cat = logc_prev;
+	if (level == LOGL_CONT)
+		level = logl_prev;
+
 	rec.cat = cat;
 	rec.level = level;
 	rec.file = file;
@@ -232,7 +242,10 @@  int _log(enum log_category_t cat, enum log_level_t level, const char *file,
 			gd->log_drop_count++;
 		return -ENOSYS;
 	}
-	log_dispatch(&rec);
+	if (!log_dispatch(&rec)) {
+		logc_prev = cat;
+		logl_prev = level;
+	}

 	return 0;
 }
diff --git a/doc/develop/logging.rst b/doc/develop/logging.rst
index 7ce8482ab6..c36f6bbbe4 100644
--- a/doc/develop/logging.rst
+++ b/doc/develop/logging.rst
@@ -38,6 +38,9 @@  There are a number logging levels available, in increasing order of verbosity:
 * LOGL_DEBUG_CONTENT - Debug message showing full message content
 * LOGL_DEBUG_IO - Debug message showing hardware I/O access

+To continue a log message in a separate call of function log() use
+
+* LOGL_CONT - Use same log level as in previous call

 Logging category
 ----------------
@@ -56,6 +59,9 @@  The following main categories are defined:
 * LOGC_DT - Related to device tree control
 * LOGC_EFI - Related to EFI implementation

+To continue a log message in a separate call of function log() use
+
+* LOGC_CONT - Use same category as in previous call

 Enabling logging
 ----------------
diff --git a/include/log.h b/include/log.h
index 2859ce1f2e..567cd32d34 100644
--- a/include/log.h
+++ b/include/log.h
@@ -35,6 +35,7 @@  enum log_level_t {

 	LOGL_FIRST = LOGL_EMERG,
 	LOGL_MAX = LOGL_DEBUG_IO,
+	LOGL_CONT = -1,		/* Use same log level as in previous call */
 };

 /**
@@ -60,6 +61,7 @@  enum log_category_t {

 	LOGC_COUNT,	/* Number of log categories */
 	LOGC_END,	/* Sentinel value for a list of log categories */
+	LOGC_CONT = -1,	/* Use same category as in previous call */
 };

 /* Helper to cast a uclass ID to a log category */