On Friday, January 13, 2017 at 10:54:18 AM UTC-8, José Valim wrote:
>
> The problem with auto-thunking is that it changes the semantic of the code
> and it is not enough when the bulk of the expensive work is done outside of
> the Logger call. For example this would be enough for auto-thunking to not
> work:
>
> message = "my_fun/1: input: #{inspect input}"
> Logger.debug message
>
>
I concede the proposal doesn't solve every possible suboptimal call.
However, it trades the cost of evaluating thunks for protection from the
risk that a dependency, direct or indirect, has or eventually introduces a
subset of the possible suboptimal logging calls. I'm ambivalent about
:lazy's default value, but I think the option to enable it is valuable for
anyone willing to make this trade-off.
>
> We already have a similar behaviour to auto-thunking, which is the compile
> time purging. If you are sure you are not going to run :debug in
> production, you can erase all Logger calls and their arguments from ever
> being evaluated. Your option gives the ability to still revert to :debug
> but that feels like a small change to make the new option worth it.
>
Unless there are built-in mechanisms to control logging levels per package
or module (maybe there are?), respectfully I still think :lazy is worth
having. As I understand it :compile_time_purge_level's scope includes a
project and all its dependencies. There's no way to have *X* level log
purging only for the code in a project and *Y* level purging for the code
in the project's dependencies without custom support for that from each
dependency, is there?
If we have that feature I would agree :lazy isn't compelling. However, if
Elixir doesn't and won't likely have such a feature, I'd very much like to
have :lazy. I can open a new proposal if you like the idea of finer logging
control and Elixir doesn't already have it.
>
> If we really want to change how people use Logger, we should probably
> start by rewriting the documentation to use the function format and explain
> the non-function format in a later section.
>
Yes, I agree. I'm happy to contribute after the fate of this proposal is
decided.
Would it also be worth emitting warnings for suboptimal calls detected at
compile-time?
>
>
>
>
> *José Valim*
> www.plataformatec.com.br
> Skype: jv.ptec
> Founder and Director of R&D
>
> On Fri, Jan 13, 2017 at 7:41 PM, Jake Mitchell <[email protected]
> <javascript:>> wrote:
>
>> Purpose
>>
>> Optimize slow logging calls, especially in dependencies that might
>> violate logging best practices.
>>
>> Current best practice
>>
>> When a Logger.debug call, for instance, is passed an input that's
>> expensive to compute the best practice is to wrap it in a thunk (zero
>> argument function). That way, if the application's current log level is
>> higher than :debug the computation can be skipped. This approach works
>> regardless of whether the logger call was purged at compile-time using
>> :compile_time_purge_level.
>>
>> Example
>>
>> The following may be slow due to inspect.
>>
>> Logger.debug "my_fun/1: input: #{inspect input}"
>>
>> An optimized version:
>>
>> Logger.debug fn ->
>> "my_fun/1: input: #{inspect input}"
>> end
>>
>>
>> Proposal
>>
>> Add a new Logger application configuration setting, say :lazy, which
>> makes all the Logger macros wrap their chardata_or_fun input in a thunk.
>> We could use an is_function guard to avoid wrapping inputs that are
>> already thunks, but it's not strictly necessary; nested thunks already
>> repeatedly evaluate until they reach a non-thunk.
>>
>> To maintain current behavior this new parameter would be disabled by
>> default. However, it's worth considering whether the potential cost of
>> hidden, suboptimal logging calls are greater than the cost of calling one
>> thunk per logging call. Before I learned the best practice the problem
>> apparent in my own package which calls Logger.debug thousands of times in
>> an expensive recursive function (see "Logging: a silent performance
>> killer"
>> <https://elixirforum.com/t/logging-a-silent-performance-killer/3258>).
>> It's conceivable that many packages aren't following the best practice, and
>> that the performance degradation is more often death by a thousand cuts
>> than a centralized and noticeable issue like mine was.
>>
>> If, for whatever reason, this proposal isn't accepted another avenue for
>> improvement is detecting suboptimal Logger calls through static analysis.
>> This could mean having elixirc emit warnings or adding checks to a 3rd
>> party linter. I already opened a proposal
>> <https://github.com/rrrene/credo/issues/299>with Credo.
>>
>> --
>> You received this message because you are subscribed to the Google Groups
>> "elixir-lang-core" group.
>> To unsubscribe from this group and stop receiving emails from it, send an
>> email to [email protected] <javascript:>.
>> To view this discussion on the web visit
>> https://groups.google.com/d/msgid/elixir-lang-core/64a8c3d6-7ee3-4578-9d17-98979db5cf65%40googlegroups.com
>>
>> <https://groups.google.com/d/msgid/elixir-lang-core/64a8c3d6-7ee3-4578-9d17-98979db5cf65%40googlegroups.com?utm_medium=email&utm_source=footer>
>> .
>> For more options, visit https://groups.google.com/d/optout.
>>
>
>
--
You received this message because you are subscribed to the Google Groups
"elixir-lang-core" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
To view this discussion on the web visit
https://groups.google.com/d/msgid/elixir-lang-core/86f17410-f520-4233-a57a-ac15cbda9891%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
