Ref-strings in logging messages (was: Performance issue with CPython 3.10 + Cython)

[Barry Scott]

> On 8 Oct 2022, at 11:50, Weatherby,Gerard <gweatherby at uchc.edu> wrote:
> 
> Logging does support passing a callable, if indirectly. It only calls __str__ on the object passed if debugging is enabled.
>  
> class Defer:
> 
>     def __init__(self,fn):
>         self.fn = fn
> 
>     def __str__(self):
>         return self.fn()
> 
> def some_expensive_function():
>     return "hello"
> 
> logging.basicConfig()
> logging.debug(Defer(some_expensive_function))

Oh what a clever hack. Took a few minutes of code reading to see why this works.
You are exploiting the str(msg) that is in class LogRecords getMessage().

```
    def getMessage(self):
        """
        Return the message for this LogRecord.

        Return the message for this LogRecord after merging any user-supplied
        arguments with the message.
        """
        msg = str(self.msg)
        if self.args:
            msg = msg % self.args
        return msg
```

Barry


>  
>  
> From: Python-list <python-list-bounces+gweatherby=uchc.edu at python.org <mailto:python-list-bounces+gweatherby=uchc.edu at python.org>> on behalf of Barry <barry at barrys-emacs.org <mailto:barry at barrys-emacs.org>>
> Date: Friday, October 7, 2022 at 1:30 PM
> To: MRAB <python at mrabarnett.plus.com <mailto:python at mrabarnett.plus.com>>
> Cc: python-list at python.org <mailto:python-list at python.org> <python-list at python.org <mailto:python-list at python.org>>
> Subject: Re: Ref-strings in logging messages (was: Performance issue with CPython 3.10 + Cython)
> 
> *** Attention: This is an external email. Use caution responding, opening attachments or clicking on links. ***
> 
> > On 7 Oct 2022, at 18:16, MRAB <python at mrabarnett.plus.com> wrote:
> >
> > On 2022-10-07 16:45, Skip Montanaro wrote:
> >>> On Fri, Oct 7, 2022 at 9:42 AM Andreas Ames <andreas.0815.qwertz at gmail.com>
> >>> wrote:
> >>> 1. The culprit was me. As lazy as I am, I have used f-strings all over the
> >>> place in calls to `logging.logger.debug()` and friends, evaluating all
> >>> arguments regardless of whether the logger was enabled or not.
> >>>
> >> I thought there was some discussion about whether and how to efficiently
> >> admit f-strings to the logging package. I'm guessing that's not gone
> >> anywhere (yet).
> > Letting you pass in a callable to call might help because that you could use lambda.
> 
> Yep, that’s the obvious way to avoid expensive log data generation.
> Would need logging module to support that use case.
> 
> Barry
> 
> > --
> > https://urldefense.com/v3/__https://mail.python.org/mailman/listinfo/python-list__;!!Cn_UX_p3!mrESxAj9YCHsdtNAfkNiY-Zf6U3WTIqaNrgBmbw1ELlQy51ilob43dD0ONsqvg4a94MEdOdwomgyqfyABbvRnA$ <https://urldefense.com/v3/__https:/mail.python.org/mailman/listinfo/python-list__;!!Cn_UX_p3!mrESxAj9YCHsdtNAfkNiY-Zf6U3WTIqaNrgBmbw1ELlQy51ilob43dD0ONsqvg4a94MEdOdwomgyqfyABbvRnA$>
> >
> 
> --
> https://urldefense.com/v3/__https://mail.python.org/mailman/listinfo/python-list__;!!Cn_UX_p3!mrESxAj9YCHsdtNAfkNiY-Zf6U3WTIqaNrgBmbw1ELlQy51ilob43dD0ONsqvg4a94MEdOdwomgyqfyABbvRnA$ <https://urldefense.com/v3/__https:/mail.python.org/mailman/listinfo/python-list__;!!Cn_UX_p3!mrESxAj9YCHsdtNAfkNiY-Zf6U3WTIqaNrgBmbw1ELlQy51ilob43dD0ONsqvg4a94MEdOdwomgyqfyABbvRnA$>