Compile time purging of logger levels

Well, calls to logger cost you some cycles.

1. Calculate the arguments (some use "#{inspect foo}" everywhere, so that has to be done, regardless if it will be logged or not.
2. We have a remote call into Logger and remote calls are more expensive than local calls.
3. In the Logging function we have at least if level <= wanted_level which need to be done

All this costs your process valuable reductions, which it can’t spend with its primary task.

Therefore unpurged but filtered logger calls are a bad thing.

But you are right. Usually I do only purge debug, and keep the rest while only actively logging :warn and :error.

This seems like a serious oversight in the VM design if it can’t handle logging without stripping calls from the bytecode first.

Sorry, but I do not understand this statement.

If it were stripping things, you weren’t able to get them back at runtime, and then we are back at compile time purging.

It can, and does so just fine. However, when doing the filtering at runtime instead of compiletime, there is some expense still spent in log message that are never shown. So if you want every last bit of performance, you can strip out the debug levels you really don’t want (e.g. debug in production builds).

If you have stripped them, and you want them back in a running system, you can always build an upgrade release and hot-load it to get your debug statements back.

Logger does do as much as it can to help even when not stripped at compile time, though. If you are not showing debug statements, then the Logger.debug macro does not evaluate the parameters (e.g. strings with interpolations) …

Are you sure about that? From the docs;

 The Logger.info/2 macro emits the provided message at the :info level. Note the arguments given to 
 info/2 will only be evaluated if a message is logged. For instance, if the Logger level is set to :warn, 
 messages are never logged and therefore the arguments given above won’t even be executed.

At least it was like I’ve described it in earlier versions. As far as I remember there has even been the advise to wrap expensive to calculate arguments into an anonymous function, to make it “lazy”. Perhaps I missed the lazy by default change?

That is still true for Logger.bare_log/3, as noted in the docs, but not the case anymore for the other macros.

Is this something that could be circumvented by implementing a Logger in Rust and calling it through Elixir if Elixirs native logging performance became inhibitive, or would the call down to native be just as expensive?

Cycles are cycles. And when you have a million connections being handled by your application, those cycles add up. I’ve seen the same thing with C/C++ code bases, including ones where methods that were slow were improved by conditionally compiling out logging output that was disabled at runtime with configuration.

The fact that you can reclaim those cycles by compiling the calls right out does not equal “calls to Logger are horribly slow”. I honestly don’t know how slow they are (I don’t have numbers on that), but you could always take Benchee and wrap it around a large number of Logger calls which do not hit the backend and find out.

As for the cost of native calls: they are quite cheap: Latency of Native Functions for Erlang and Elixir · potatosalad

I’m pretty sure that was a new feature of 1.7. if you look at the docs for 1.6 here Logger – Logger v1.6.0, you’ll find: " The Logger macros also accept messages as strings, but keep in mind that strings are always evaluated regardless of log-level. As such, it is recommended to use a function whenever the message is expensive to compute." As stated by @NobbZ