Logger.debug "my_fun/1: input: #{inspect input}"
Logger.debug fn ->
"my_fun/1: input: #{inspect input}"
end
message = "my_fun/1: input: #{inspect input}"Logger.debug message
--
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 elixir-lang-core+unsubscribe@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/elixir-lang-core/64a8c3d6-7ee3-4578-9d17-98979db5cf65%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
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
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.
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.
On Fri, Jan 13, 2017 at 7:41 PM, Jake Mitchell <jacob.d....@gmail.com> 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"). 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 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 elixir-lang-co...@googlegroups.com.
Sorry but I fail to see how the compile time level purging being per project or per module would make a difference. While we surely can provide such feature, the lazy approach would have the exact same trade-offs?