* `phosphor-logging` APIs (RFC) @ 2021-07-27 20:24 Patrick Williams 2021-07-28 5:52 ` Andrew Jeffery 0 siblings, 1 reply; 7+ messages in thread From: Patrick Williams @ 2021-07-27 20:24 UTC (permalink / raw) To: OpenBMC List [-- Attachment #1: Type: text/plain, Size: 1242 bytes --] Greetings, There have been discussions before on this mailing list about the APIs present in phosphor-logging and some of the shortcomings they have. I've implemented a new API, inside phosphor-logging, that I think resolves the issues discussed here and in some offline forums. If you have an interest in the logging APIs, I would appreciate any feedback you may have. If there are additional issues with the APIs that I might have missed, please feel free to let me know and I'll see what can be done about resolving them. lg2: introduce motivation and API https://gerrit.openbmc-project.xyz/c/openbmc/phosphor-logging/+/45310 lg2: initial implementation of C++20 structured logging https://gerrit.openbmc-project.xyz/c/openbmc/phosphor-logging/+/45311 The main highlights of what I attempted to fix are: - Verbose and clumsy API for previous `logging::log`. - Poor compile-time identification of certain (common) issues. - Source location data is invalid (issue openbmc/openbmc#2207). - Useful data is missing from `journalctl` resulting in people working around it by generating strings with `fmt` et.al. - No logging present when running on a TTY. -- Patrick Williams [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: `phosphor-logging` APIs (RFC) 2021-07-27 20:24 `phosphor-logging` APIs (RFC) Patrick Williams @ 2021-07-28 5:52 ` Andrew Jeffery 2021-07-28 6:25 ` Patrick Williams 0 siblings, 1 reply; 7+ messages in thread From: Andrew Jeffery @ 2021-07-28 5:52 UTC (permalink / raw) To: Patrick Williams, OpenBMC List On Wed, 28 Jul 2021, at 05:54, Patrick Williams wrote: > Greetings, > > There have been discussions before on this mailing list about the APIs present > in phosphor-logging and some of the shortcomings they have. I've implemented a > new API, inside phosphor-logging, that I think resolves the issues discussed > here and in some offline forums. > > If you have an interest in the logging APIs, I would appreciate any feedback you > may have. If there are additional issues with the APIs that I might have > missed, please feel free to let me know and I'll see what can be done about > resolving them. > > lg2: introduce motivation and API > https://gerrit.openbmc-project.xyz/c/openbmc/phosphor-logging/+/45310 > lg2: initial implementation of C++20 structured logging > https://gerrit.openbmc-project.xyz/c/openbmc/phosphor-logging/+/45311 > > The main highlights of what I attempted to fix are: > - Verbose and clumsy API for previous `logging::log`. > - Poor compile-time identification of certain (common) issues. > - Source location data is invalid (issue openbmc/openbmc#2207). I think you wanted openbmc/openbmc#2297 there, but yes! > - Useful data is missing from `journalctl` resulting in people working > around it by generating strings with `fmt` et.al. Sounds promising! Reading the proposal it seems like you're appending certain bits of structured data to the message. I think it would be nice if the data could be interpolated into arbitrary positions and not just appended (note, I'm not asking for interpolation of arbitrary variables here unlike what can be achieved with raw use of fmt, only those captured via the structured logging). > - No logging present when running on a TTY. Great, this has caused quite a bit of confusion in the past. Andrew ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: `phosphor-logging` APIs (RFC) 2021-07-28 5:52 ` Andrew Jeffery @ 2021-07-28 6:25 ` Patrick Williams 2021-07-28 23:34 ` Andrew Jeffery 0 siblings, 1 reply; 7+ messages in thread From: Patrick Williams @ 2021-07-28 6:25 UTC (permalink / raw) To: Andrew Jeffery; +Cc: OpenBMC List [-- Attachment #1: Type: text/plain, Size: 1041 bytes --] On Wed, Jul 28, 2021 at 03:22:43PM +0930, Andrew Jeffery wrote: > On Wed, 28 Jul 2021, at 05:54, Patrick Williams wrote: > - Source location data is invalid (issue openbmc/openbmc#2207). > > I think you wanted openbmc/openbmc#2297 there, but yes! Indeed, that's the issue I meant to refer to. Seems I mentioned it correctly in the commit. > > - Useful data is missing from `journalctl` resulting in people working > > around it by generating strings with `fmt` et.al. > > Sounds promising! Reading the proposal it seems like you're appending > certain bits of structured data to the message. I think it would be > nice if the data could be interpolated into arbitrary positions and not > just appended (note, I'm not asking for interpolation of arbitrary > variables here unlike what can be achieved with raw use of fmt, only > those captured via the structured logging). Can you give me a concrete example of what you mean by this? I'm not understanding. > Andrew -- Patrick Williams [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: `phosphor-logging` APIs (RFC) 2021-07-28 6:25 ` Patrick Williams @ 2021-07-28 23:34 ` Andrew Jeffery 2021-07-29 2:53 ` Patrick Williams 0 siblings, 1 reply; 7+ messages in thread From: Andrew Jeffery @ 2021-07-28 23:34 UTC (permalink / raw) To: Patrick Williams; +Cc: OpenBMC List On Wed, 28 Jul 2021, at 15:55, Patrick Williams wrote: > On Wed, Jul 28, 2021 at 03:22:43PM +0930, Andrew Jeffery wrote: > > On Wed, 28 Jul 2021, at 05:54, Patrick Williams wrote: > > > > - Useful data is missing from `journalctl` resulting in people working > > > around it by generating strings with `fmt` et.al. > > > > Sounds promising! Reading the proposal it seems like you're appending > > certain bits of structured data to the message. I think it would be > > nice if the data could be interpolated into arbitrary positions and not > > just appended (note, I'm not asking for interpolation of arbitrary > > variables here unlike what can be achieved with raw use of fmt, only > > those captured via the structured logging). > > Can you give me a concrete example of what you mean by this? I'm not > understanding. I've left a comment on the patch: https://gerrit.openbmc-project.xyz/c/openbmc/phosphor-logging/+/45310/1/docs/structured-logging.md#60 But duplicating that here, how I'd like to use the API and what I'd like to see in the resulting journal message is: ``` value = "xyz.openbmc_project.EntityManager"; lg2::error("Error talking to {ENTITY} error code is {ERRNO}", "ENTITY", value, "ERRNO", 2); ``` The lg2 implementation renders the values into the format string and forwards the result as MESSAGE to the journal, along with the structured values (ENTITY and ERRNO in the example). ``` $ journalctl -b ... Nov 25 13:13:09 bmc fansensor[3006]: Error talking to xyz.openbmc_project.EntityManager error code is 2 ... ``` Better yet would be if we could just forward the format string and journalctl renders this at invocation time, but we'd need to work with upstream on that. Andrew ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: `phosphor-logging` APIs (RFC) 2021-07-28 23:34 ` Andrew Jeffery @ 2021-07-29 2:53 ` Patrick Williams 2021-08-03 0:27 ` Patrick Williams 0 siblings, 1 reply; 7+ messages in thread From: Patrick Williams @ 2021-07-29 2:53 UTC (permalink / raw) To: Andrew Jeffery; +Cc: OpenBMC List [-- Attachment #1: Type: text/plain, Size: 3141 bytes --] On Thu, Jul 29, 2021 at 09:04:14AM +0930, Andrew Jeffery wrote: > I've left a comment on the patch: > > https://gerrit.openbmc-project.xyz/c/openbmc/phosphor-logging/+/45310/1/docs/structured-logging.md#60 > > But duplicating that here, how I'd like to use the API and what I'd > like to see in the resulting journal message is: > > ``` > value = "xyz.openbmc_project.EntityManager"; > lg2::error("Error talking to {ENTITY} error code is {ERRNO}", "ENTITY", value, "ERRNO", 2); > ``` Thanks for the description. What you've proposed is at least able to be compiled and wouldn't increase the call-site code footprint at all. It would have more work in the [common] code that translates from the lg2 API format to systemd, but it isn't outrageous and is fairly straight-forward to implement at this point. So far there are 3 approaches on the table: ``` a. Yours. error("Hit {ERROR} during {STAGE}.", "ERROR", "bad foobar", "STAGE", "baz-grae", "EXTRA", 123); -> MESSAGE="Hit bad foobar during baz-grae." ERROR="bad foobar" STAGE="baz-grae" EXTRA=123 b. opt-in processing error("Hit error during processing.", "ERROR", primary, "bad foobar", "STAGE", primary, "baz-grae", "EXTRA", 123); -> MESSAGE="Hit error during processing. ERROR=bad foobar STAGE=baz-grae" ERROR="bad foobar" STAGE="baz-grae" EXTRA=123 c. opt-out processing error("Hit error during processing.", "ERROR", "bad foobar", "STAGE", "baz-grae", "EXTRA", quiet, 123); -> MESSAGE="Hit error during processing. ERROR=bad foobar STAGE=baz-grae" ERROR="bad foobar" STAGE="baz-grae" EXTRA=123 ``` Based on my experience trying to apply lg2 to a reasonable sample[1], (b) seems rather verbose. We're going to end up with most developers just adding a `primary` on each data entry anyhow, so it is kind of pointless. Both (a) and (c) are relatively succinct. (a) has the advantage of being slightly more human-friendly, but at a disadvantage of worse performance and redundant tag identification (which cannot be checked at compile time either). (c) is faster, has no redundancy, and is consistently structured, but is slightly less human readable. My question would be is if (a) is really that much better from a human perspective to warrant the extra processing and redundancy (and thus potential programming errors introduced by tag mismatches)? To me, (c) provides all the same information with only minimal readability impact and certainly better performing. > Better yet would be if we could just forward the format string and > journalctl renders this at invocation time, but we'd need to work with > upstream on that. I kind of doubt they'd be interesting in absorbing this kind of string formatting into the library, but maybe I'm wrong. 1. https://gerrit.openbmc-project.xyz/c/openbmc/phosphor-virtual-sensor/+/45353/1/virtualSensor.cpp -- Patrick Williams [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: `phosphor-logging` APIs (RFC) 2021-07-29 2:53 ` Patrick Williams @ 2021-08-03 0:27 ` Patrick Williams 2021-08-03 4:07 ` Andrew Jeffery 0 siblings, 1 reply; 7+ messages in thread From: Patrick Williams @ 2021-08-03 0:27 UTC (permalink / raw) To: Andrew Jeffery; +Cc: OpenBMC List [-- Attachment #1: Type: text/plain, Size: 467 bytes --] On Wed, Jul 28, 2021 at 09:53:07PM -0500, Patrick Williams wrote: > > error("Hit {ERROR} during {STAGE}.", "ERROR", "bad foobar", "STAGE", > "baz-grae", "EXTRA", 123); > I have implemented this formatting handling, since more people seemed to want it, and also added compile-time confirmation that the keys match systemd-journald requirements. Patch sequence is all updated to resolve any outstanding review comments. -- Patrick Williams [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: `phosphor-logging` APIs (RFC) 2021-08-03 0:27 ` Patrick Williams @ 2021-08-03 4:07 ` Andrew Jeffery 0 siblings, 0 replies; 7+ messages in thread From: Andrew Jeffery @ 2021-08-03 4:07 UTC (permalink / raw) To: Patrick Williams; +Cc: OpenBMC List On Tue, 3 Aug 2021, at 09:57, Patrick Williams wrote: > On Wed, Jul 28, 2021 at 09:53:07PM -0500, Patrick Williams wrote: > > > > error("Hit {ERROR} during {STAGE}.", "ERROR", "bad foobar", "STAGE", > > "baz-grae", "EXTRA", 123); > > > > I have implemented this formatting handling, since more people seemed to want > it, and also added compile-time confirmation that the keys match > systemd-journald requirements. Patch sequence is all updated to resolve any > outstanding review comments. > Thanks! The updated documentation gets a +1 from me. Andrew ^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2021-08-03 4:08 UTC | newest] Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2021-07-27 20:24 `phosphor-logging` APIs (RFC) Patrick Williams 2021-07-28 5:52 ` Andrew Jeffery 2021-07-28 6:25 ` Patrick Williams 2021-07-28 23:34 ` Andrew Jeffery 2021-07-29 2:53 ` Patrick Williams 2021-08-03 0:27 ` Patrick Williams 2021-08-03 4:07 ` Andrew Jeffery
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.