Re: OpenBMC Logging and Error Handling Dos and Don'ts

[Patrick Williams <patrick@stwcx.xyz>]

[-- Attachment #1: Type: text/plain, Size: 2627 bytes --]

On Mon, Jun 01, 2020 at 11:07:46PM -0700, William Kennington wrote:
> If you use the fmt library it would only require one extra temporary string
> to be constructed and it works trivially with something like phosphor
> logging.
> 
> log<level::INFO>(fmt::format("My error: {}", filename));
> 
> It also has the advantage of understanding basic c++ types like
> std::strings and std::string_views.
> 
> On Mon, Jun 1, 2020 at 8:33 PM 郁雷 <yulei.sh@bytedance.com> wrote:
> 
> > I have a bit concern about this. The existing phosphor-logging API
> > does not support this well.
> > Specifically, it does not support the "printf" way to generate a
> > string with the variables to log.
> > So previously we typically put the variables in entries.
> > I do agree that logging the variables in the MESSAGE field is much better.
> > But to encourage such logging, the logging API should be enhanced to
> > support the "printf" way.
> > E.g.
> >     log<level::INFO>("Something is wrong: %s:%d", xx, xxx);
> > is much better than:
> >     std::string to_log = xxx; // generate the message manually
> >     log<level::INFO>(to_log);
> >
> > Otherwise, it's really not convenient to write such logging code.
> >

Separate from this proposal from Brad, I'd like to work on a
next-generation of phosphor-logging.  When we originally implemented
phosphor-logging we were all pretty new to C++14.  I think there can be
some great improvement in the syntax of phosphor-logging now that we
have C++17 (and more experience).

The biggest change I'd like to do is in the way the structured entries
are defined, but I think we can improve the verbosity of syntax in
making a log in general.

Some example syntax:

// Current syntax (and I'm being especially verbose on the namespaces).
phosphor::logging::log<phosphor::logging::level::ERR>("Some message",
    phosphor::logging::entry("EXAMPLE=%s"), example_str);

// Potential syntax
lg::error("Some message", "EXAMPLE"_s, example_str);

In a code-review I was on, we had some discussions about how difficult
it is to create data that isn't in the "-o verbose" and I think William
and Lei are both referring to that as well.  I am concerned that a
generic format leads us more to unstructured logging, which personally I
don't like.  My suggestion is that we have some easy syntax to indicate
"also put this structured data into the raw message" so that my example
above the message becomes "Some message. EXAMPLE='the string'".

I'd be interested to hear what "next generation logging" others have in
mind.

-- 
Patrick Williams

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]