logger icon indicating copy to clipboard operation
logger copied to clipboard

formatter_glue fails when no unnamed arguments

Open r2evans opened this issue 7 months ago • 9 comments

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 avatar Nov 19 '23 00:11 r2evans

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 avatar Nov 19 '23 21:11 r2evans

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.

r2evans avatar Nov 20 '23 12:11 r2evans

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

daroczig avatar Mar 01 '24 23:03 daroczig

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

r2evans avatar Mar 02 '24 18:03 r2evans

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.

daroczig avatar Mar 05 '24 08:03 daroczig

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.)

r2evans avatar Mar 05 '24 14:03 r2evans

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).

daroczig avatar Mar 05 '24 22:03 daroczig

@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.

atalv avatar Mar 21 '24 04:03 atalv

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

daroczig avatar Mar 21 '24 10:03 daroczig