daroczig / logger

A lightweight, modern and flexible, log4j and futile.logger inspired logging utility for R
https://daroczig.github.io/logger
285 stars 42 forks source link

formatter_glue fails when no unnamed arguments #130

Open r2evans opened 10 months ago

r2evans commented 10 months ago

Occasionally I forget (i.e., when interactive) to set log_formatter(formatter_json). When this happens, any log messages that use named arguments will be blank. For instance,

log_info(quux="foo", a=pi)
# INFO [2023-11-18 19:50:26] 

where the initial intent was to have this:

log_formatter(formatter_json)
log_info(quux="foo", a=pi)
# INFO [2023-11-18 19:50:54] {"quux":"foo","a":3.1416}

I'm fine with the fact that part of the reason is that I forgot the formatter, but it would be nice if formatter_glue did not drop named arguments. I suggest the names can be dropped, and pasted together (with a space). Something like:

log_formatter(formatter_glue)
log_info(quux="foo", a=pi)
# INFO [2023-11-18 19:52:12] foo 3.14159265358979

Edit ... as I'm thinking about this, the purpose and layout of glue is rather simple, where unnamed objects are strings to format, and named objects are variables to use for substitution ... so I think the paste-ing above should only be done when none of ... are unnamed ... or perhaps just assume the first or first character or similar.

Bottom line, having it completely drop the message is perhaps not good. Thoughts?

r2evans commented 10 months ago

Revision: it's extra, yes, but perhaps we create a format string from the names/values of the arguments.

For instance, one of:

log_formatter(formatter_glue)
log_info(quux="a", b=pi)
# INFO [2023-11-19 16:16:23] a 3.14159265358979
##### or
log_info(quux="a", b=pi)
# INFO [2023-11-19 16:16:41] quux=a b=3.14159265358979

While one could play with this type of mechanism for hours, I suggest going anywhere beyond this is too much: the only reason to do any of this is to prevent an empty log entry; if the user wants more control (semi-delimited, quoted strings, whatever) then they should format it the right way the first time.

r2evans commented 10 months ago

More so ... if one does go this one step of auto-adding a simple format string for glue, perhaps there should be a once-per-day warning or message: once to get the point across but not necessarily every single log message.

daroczig commented 7 months ago

Thanks a ton for this report, and I agree that it can be frustrating when this happens :disappointed:

But I'm hesitant to make such overrides in how glue works in its formatted :zipper_mouth_face: And I'd rather keep it a very thin layer on glue, so if it returns nothing for the inputs, we will log nothing:

> str(glue::glue("foo", NULL, quux="a", b=pi))
 'glue' chr(0) 

My suggestion is to check what glue returns, and throw an R warning if the log message was empty. That warnings is printed in the console, so that the user can investigate, and it has it's debouncer (will not show all, but the user can look at the last with warnings()), and logger supports logging warnings as well :)

Please see an example implementation at #147

r2evans commented 7 months ago

I don't see quite how adding a warning is much better than adding a safeguard, but it's your call. Thanks!

daroczig commented 7 months ago

Needed to drop this PR as per above: azlogr expects no error/warning/message in such case. Opened a ticket to discuss how to proceed.

r2evans commented 7 months ago

If azlogr doesn't reply quickly, are you amenable to and would it be simpler to switch back to the safeguard instead of a warning?

Perhaps it would be useful to know the use-case that azlogr is considering when it triggers the new warning? Either they're using it incorrectly, or their using it in a way that you (we) had not considered.

In the end, though, I believe that my recommended change is "safe": for those already using logger, if they are using it and have no instances of "no unnamed args", then the behavior of logger will not change for them. (Adding a warning should also change nothing, true, but perhaps azlogr is trying something we had not considered.)

daroczig commented 7 months ago

These are very good points, @r2evans, thanks!

I've opened a ticket (see above) and looking forward to hearing from the azlogr folks, then we can decide how to proceed. For now, I went ahead and pushed a CRAN update without either the warning or the safeguard.

Now that it's done, we can update the dev version again at any time, run the reverse dependency checks again, and warn users about the change in formatter_glue .. and hopefully submit a new CRAN version relatively soon (although will have to wait for the downstream maintainers to release a new version of their packages on CRAN first).

atalv commented 6 months ago

@daroczig made appropriate changes on azlogr and submitted to CRAN. Your future release should not be an issue from azlogr perspective for this change you are about to make.

daroczig commented 6 months ago

Awesome, thank you so much, @atalv :raised_hands: :bow: