Re: Logging Library-GSOC

[Priyesh kumar]

Hi armin,

> This would print wrong-ish timestamps that couldn't really be used for profiling (I mean, it could; you just have to know which timestamp belongs to which message).  I would suggest to 

> rather store a flag after reading `\n` and attach the timestamp to the following message.

I am also following this approach for printing timestamp and FT_COMPONENT.

Actually dlg uses a flag `dlg_features` in which different features like  `dlg_output_timestamp`(for timestamps) and `dlg_output_tags`(for FT_COMPONENTS) are summed up using binary OR operator.

For the first log message, these flags are kept ON so that timestamp and FT_COMPONENT values are printed, and for the next coming log messages the following logic is used:

If the current log message contains a `\n` in it then the flags will be toggled ON for the next coming log message assuming that it is end of a log message, 

and if the current log message doesn't contain `\n` then these flags are toggled OFF for the next coming log message assuming that it is in continuation of current log message.

> Also, I would believe that `fmt[strlen(fmt) - 1] == '\n'` is rather fast, esp. given that this is followed by an IO operation.  To be tested though :)

OK

> Writing this lead me to look for multi-linebreak traces (e.g. src/pcf/pfcread.c:504) -- should that have one timestamp for the entire statement or one timestamp per line?

With the above logic for these types of logs, there will be one timestamp per line...

Thanks,

Priyesh

On Sun, Jul 12, 2020 at 2:02 PM <armin@hasitzka.com> wrote:

> Since debugging isn't time critical it might be necessary to add an additional
> step that scans tracing messages for newline characters, then massaging the
> output by inserting the time stamp.  In other words, all occurrences of
>
>   `\n`
>
> should be replaced with
>
>   `\n[time stamp] `
>
> or something similar.

This would print wrong-ish timestamps that couldn't really be used for profiling (I mean, it could; you just have to know which timestamp belongs to which message).  I would suggest to rather store a flag after reading `\n` and attach the timestamp to the following message.  Also, I would believe that `fmt[strlen(fmt) - 1] == '\n'` is rather fast, esp. given that this is followed by an IO operation.  To be tested though :)

Writing this lead me to look for multi-linebreak traces (e.g. src/pcf/pfcread.c:504) -- should that have one timestamp for the entire statement or one timestamp per line?

Armin