* OpenBMC Logging and Error Handling Dos and Don'ts @ 2020-06-01 20:35 Brad Bishop 2020-06-02 3:32 ` 郁雷 0 siblings, 1 reply; 10+ messages in thread From: Brad Bishop @ 2020-06-01 20:35 UTC (permalink / raw) To: openbmc I would like to start a document centered on logging best practices in OpenBMC. To get started I used a simple Do/Don't format and picked an easy topic that I've repeatedly gotten feedback on. Please let me know if you like the format or have any feedback. Also please feel free to reply with suggestions for additional Do/Don't items...I may write them up if time allows. thanks! -brad ---------- # OpenBMC Logging and Error Handling Dos and Don'ts **Audience:** OpenBMC application developers **Prerequisites:** None --- ## Don't require `-o verbose` for systemd journal MESSAGE field context The MESSAGE field of a systemd journal entry should be self describing and not rely on additional structured log data. For example when the MESSAGE field references a filesystem path, the path should appear in the MESSAGE field. When the MESSAGE field references a failed system call, the system call and the return value should appear in the MESSAGE field. This keeps the journal informative and useful for casual journal users. Note that it is perfectly acceptible to add (duplicate) structured log entry values for the data that appears in MESSAGE. This guideline only prescribes that the data _not_ be omitted from the MESSAGE field value. ## Don't #2 TBD ## Do #1 TBD ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: OpenBMC Logging and Error Handling Dos and Don'ts 2020-06-01 20:35 OpenBMC Logging and Error Handling Dos and Don'ts Brad Bishop @ 2020-06-02 3:32 ` 郁雷 2020-06-02 6:07 ` William Kennington 0 siblings, 1 reply; 10+ messages in thread From: 郁雷 @ 2020-06-02 3:32 UTC (permalink / raw) To: Brad Bishop; +Cc: openbmc > --- > ## Don't require `-o verbose` for systemd journal MESSAGE field context > The MESSAGE field of a systemd journal entry should be self describing and not > rely on additional structured log data. For example when the MESSAGE field > references a filesystem path, the path should appear in the MESSAGE field. > When the MESSAGE field references a failed system call, the system call and the > return value should appear in the MESSAGE field. This keeps the journal > informative and useful for casual journal users. Note that it is perfectly > acceptible to add (duplicate) structured log entry values for the data that > appears in MESSAGE. This guideline only prescribes that the data _not_ be > omitted from the MESSAGE field value. > 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. ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: OpenBMC Logging and Error Handling Dos and Don'ts 2020-06-02 3:32 ` 郁雷 @ 2020-06-02 6:07 ` William Kennington 2020-06-02 23:06 ` Patrick Williams 0 siblings, 1 reply; 10+ messages in thread From: William Kennington @ 2020-06-02 6:07 UTC (permalink / raw) To: 郁雷; +Cc: Brad Bishop, openbmc [-- Attachment #1: Type: text/plain, Size: 1919 bytes --] 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: > > --- > > ## Don't require `-o verbose` for systemd journal MESSAGE field context > > The MESSAGE field of a systemd journal entry should be self describing > and not > > rely on additional structured log data. For example when the MESSAGE > field > > references a filesystem path, the path should appear in the MESSAGE > field. > > When the MESSAGE field references a failed system call, the system call > and the > > return value should appear in the MESSAGE field. This keeps the journal > > informative and useful for casual journal users. Note that it is > perfectly > > acceptible to add (duplicate) structured log entry values for the data > that > > appears in MESSAGE. This guideline only prescribes that the data _not_ > be > > omitted from the MESSAGE field value. > > > > 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. > [-- Attachment #2: Type: text/html, Size: 2385 bytes --] ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: OpenBMC Logging and Error Handling Dos and Don'ts 2020-06-02 6:07 ` William Kennington @ 2020-06-02 23:06 ` Patrick Williams 2020-06-02 23:09 ` William Kennington 2020-06-03 0:07 ` Vernon Mauery 0 siblings, 2 replies; 10+ messages in thread From: Patrick Williams @ 2020-06-02 23:06 UTC (permalink / raw) To: William Kennington; +Cc: 郁雷, openbmc, Brad Bishop [-- 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 --] ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: OpenBMC Logging and Error Handling Dos and Don'ts 2020-06-02 23:06 ` Patrick Williams @ 2020-06-02 23:09 ` William Kennington 2020-06-03 0:07 ` Vernon Mauery 1 sibling, 0 replies; 10+ messages in thread From: William Kennington @ 2020-06-02 23:09 UTC (permalink / raw) To: Patrick Williams; +Cc: 郁雷, openbmc, Brad Bishop [-- Attachment #1: Type: text/plain, Size: 3159 bytes --] The structured messaging is good to keep, but we should put more useful information into the message. The message doesn't need to have structure. Having duplicate information should be okay and desirable to make messages nicely human parseable. Not sure I like just appending in the key/values passed as systemd message entries. On Tue, Jun 2, 2020 at 4:06 PM Patrick Williams <patrick@stwcx.xyz> wrote: > 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: Type: text/html, Size: 3949 bytes --] ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: OpenBMC Logging and Error Handling Dos and Don'ts 2020-06-02 23:06 ` Patrick Williams 2020-06-02 23:09 ` William Kennington @ 2020-06-03 0:07 ` Vernon Mauery 2020-06-03 2:51 ` 郁雷 2020-06-03 19:02 ` Vijay Khemka 1 sibling, 2 replies; 10+ messages in thread From: Vernon Mauery @ 2020-06-03 0:07 UTC (permalink / raw) To: Patrick Williams Cc: William Kennington, Brad Bishop, openbmc, 郁雷 On 02-Jun-2020 06:06 PM, Patrick Williams wrote: >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. One more change I would like to see is a way to actually have the real filename and line number show up in the systemd log. Right now the filename and line number are always the logger code: CODE_LINE=76 CODE_FUNC=helper_log CODE_FILE=.../usr/include/phosphor-logging/log.hpp It looks like C++20 has a shiny new helper for this: source_location https://en.cppreference.com/w/cpp/experimental/source_location --Vernon >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 ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: OpenBMC Logging and Error Handling Dos and Don'ts 2020-06-03 0:07 ` Vernon Mauery @ 2020-06-03 2:51 ` 郁雷 2020-06-03 19:02 ` Vijay Khemka 1 sibling, 0 replies; 10+ messages in thread From: 郁雷 @ 2020-06-03 2:51 UTC (permalink / raw) To: Vernon Mauery; +Cc: Patrick Williams, William Kennington, Brad Bishop, openbmc > > One more change I would like to see is a way to actually have the real > filename and line number show up in the systemd log. Right now the > filename and line number are always the logger code: > CODE_LINE=76 > CODE_FUNC=helper_log > CODE_FILE=.../usr/include/phosphor-logging/log.hpp > > It looks like C++20 has a shiny new helper for this: source_location > https://en.cppreference.com/w/cpp/experimental/source_location Yup, this is what the logging needs to improve as well. The new logging API is better to resolve the issue: https://github.com/openbmc/openbmc/issues/2297 ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: OpenBMC Logging and Error Handling Dos and Don'ts 2020-06-03 0:07 ` Vernon Mauery 2020-06-03 2:51 ` 郁雷 @ 2020-06-03 19:02 ` Vijay Khemka 2020-06-03 19:17 ` Johnathan Mantey 1 sibling, 1 reply; 10+ messages in thread From: Vijay Khemka @ 2020-06-03 19:02 UTC (permalink / raw) To: Vernon Mauery, Patrick Williams Cc: openbmc, Brad Bishop, 郁雷, William Kennington On 6/2/20, 5:08 PM, "openbmc on behalf of Vernon Mauery" <openbmc-bounces+vijaykhemka=fb.com@lists.ozlabs.org on behalf of vernon.mauery@linux.intel.com> wrote: On 02-Jun-2020 06:06 PM, Patrick Williams wrote: >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. One more change I would like to see is a way to actually have the real filename and line number show up in the systemd log. Right now the filename and line number are always the logger code: CODE_LINE=76 CODE_FUNC=helper_log CODE_FILE=.../usr/include/phosphor-logging/log.hpp It will be good if we can have debug as a level and somehow we can see messages from debug by enabling or disabling. It looks like C++20 has a shiny new helper for this: source_location https://urldefense.proofpoint.com/v2/url?u=https-3A__en.cppreference.com_w_cpp_experimental_source-5Flocation&d=DwIFaQ&c=5VD0RTtNlTh3ycd41b3MUw&r=v9MU0Ki9pWnTXCWwjHPVgpnCR80vXkkcrIaqU7USl5g&m=qFbu7FdFQSHVMy4ZvMtHDH5RzYQnqMUQ_T0h4qL0Xd0&s=QRsbQvb4LKAEoa8AITFyPFhcoCSVHtFLMOU66UodPnM&e= --Vernon >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 ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: OpenBMC Logging and Error Handling Dos and Don'ts 2020-06-03 19:02 ` Vijay Khemka @ 2020-06-03 19:17 ` Johnathan Mantey 2020-06-03 19:25 ` William Kennington 0 siblings, 1 reply; 10+ messages in thread From: Johnathan Mantey @ 2020-06-03 19:17 UTC (permalink / raw) To: Vijay Khemka, Vernon Mauery, Patrick Williams Cc: openbmc, Brad Bishop, 郁雷, William Kennington [-- Attachment #1.1.1: Type: text/plain, Size: 4567 bytes --] I would like it to be easier to determine how to change the error message level. I don't bother with the log code because I don't know where it's controlled. On 6/3/20 12:02 PM, Vijay Khemka wrote: > > On 6/2/20, 5:08 PM, "openbmc on behalf of Vernon Mauery" <openbmc-bounces+vijaykhemka=fb.com@lists.ozlabs.org on behalf of vernon.mauery@linux.intel.com> wrote: > > On 02-Jun-2020 06:06 PM, Patrick Williams wrote: > >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. > > One more change I would like to see is a way to actually have the real > filename and line number show up in the systemd log. Right now the > filename and line number are always the logger code: > CODE_LINE=76 > CODE_FUNC=helper_log > CODE_FILE=.../usr/include/phosphor-logging/log.hpp > > It will be good if we can have debug as a level and somehow we can see > messages from debug by enabling or disabling. > > It looks like C++20 has a shiny new helper for this: source_location > https://urldefense.proofpoint.com/v2/url?u=https-3A__en.cppreference.com_w_cpp_experimental_source-5Flocation&d=DwIFaQ&c=5VD0RTtNlTh3ycd41b3MUw&r=v9MU0Ki9pWnTXCWwjHPVgpnCR80vXkkcrIaqU7USl5g&m=qFbu7FdFQSHVMy4ZvMtHDH5RzYQnqMUQ_T0h4qL0Xd0&s=QRsbQvb4LKAEoa8AITFyPFhcoCSVHtFLMOU66UodPnM&e= > > --Vernon > > >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 > > > -- Johnathan Mantey Senior Software Engineer *azad te**chnology partners* Contributing to Technology Innovation since 1992 Phone: (503) 712-6764 Email: johnathanx.mantey@intel.com <mailto:johnathanx.mantey@intel.com> [-- Attachment #1.1.2: Type: text/html, Size: 6310 bytes --] [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 488 bytes --] ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: OpenBMC Logging and Error Handling Dos and Don'ts 2020-06-03 19:17 ` Johnathan Mantey @ 2020-06-03 19:25 ` William Kennington 0 siblings, 0 replies; 10+ messages in thread From: William Kennington @ 2020-06-03 19:25 UTC (permalink / raw) To: Johnathan Mantey Cc: Vijay Khemka, Vernon Mauery, Patrick Williams, openbmc, Brad Bishop, 郁雷 [-- Attachment #1: Type: text/plain, Size: 5156 bytes --] The local process always emits all logs generated by phosphor-logging, it is up to the journald configuration what levels are used for different things. https://www.freedesktop.org/software/systemd/man/journald.conf.html You can change the priority level output by journalctl on the command line too, to filter out lower priority messages. `journal -p err` or some other level On Wed, Jun 3, 2020 at 12:18 PM Johnathan Mantey < johnathanx.mantey@intel.com> wrote: > I would like it to be easier to determine how to change the error message > level. > I don't bother with the log code because I don't know where it's > controlled. > > On 6/3/20 12:02 PM, Vijay Khemka wrote: > > On 6/2/20, 5:08 PM, "openbmc on behalf of Vernon Mauery" <openbmc-bounces+vijaykhemka=fb.com@lists.ozlabs.org on behalf of vernon.mauery@linux.intel.com> <openbmc-bounces+vijaykhemka=fb.com@lists.ozlabs.orgonbehalfofvernon.mauery@linux.intel.com> wrote: > > On 02-Jun-2020 06:06 PM, Patrick Williams wrote: > >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> <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. > > One more change I would like to see is a way to actually have the real > filename and line number show up in the systemd log. Right now the > filename and line number are always the logger code: > CODE_LINE=76 > CODE_FUNC=helper_log > CODE_FILE=.../usr/include/phosphor-logging/log.hpp > > It will be good if we can have debug as a level and somehow we can see > messages from debug by enabling or disabling. > > It looks like C++20 has a shiny new helper for this: source_location > https://urldefense.proofpoint.com/v2/url?u=https-3A__en.cppreference.com_w_cpp_experimental_source-5Flocation&d=DwIFaQ&c=5VD0RTtNlTh3ycd41b3MUw&r=v9MU0Ki9pWnTXCWwjHPVgpnCR80vXkkcrIaqU7USl5g&m=qFbu7FdFQSHVMy4ZvMtHDH5RzYQnqMUQ_T0h4qL0Xd0&s=QRsbQvb4LKAEoa8AITFyPFhcoCSVHtFLMOU66UodPnM&e= > > --Vernon > > >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 > > > > > > -- > Johnathan Mantey > Senior Software Engineer > *azad te**chnology partners* > Contributing to Technology Innovation since 1992 > Phone: (503) 712-6764 > Email: johnathanx.mantey@intel.com > > [-- Attachment #2: Type: text/html, Size: 7098 bytes --] ^ permalink raw reply [flat|nested] 10+ messages in thread
end of thread, other threads:[~2020-06-03 19:25 UTC | newest] Thread overview: 10+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2020-06-01 20:35 OpenBMC Logging and Error Handling Dos and Don'ts Brad Bishop 2020-06-02 3:32 ` 郁雷 2020-06-02 6:07 ` William Kennington 2020-06-02 23:06 ` Patrick Williams 2020-06-02 23:09 ` William Kennington 2020-06-03 0:07 ` Vernon Mauery 2020-06-03 2:51 ` 郁雷 2020-06-03 19:02 ` Vijay Khemka 2020-06-03 19:17 ` Johnathan Mantey 2020-06-03 19:25 ` William Kennington
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.