tompave

tompave

Logger: when to use an anonymous function

I am looking for some extra info and examples on when to use the Logger with functions instead of binaries. I’ve read that the function version is lazily evaluated and useful when the log statement could be ignored.

For example, Dave Thomas writes in Programming Elixir 1.2 (chapter 13):

The basic logging functions are Logger.debug, .info, .warn, and .error. Each function takes either a string or a zero-arity function:

Logger.debug "Order total #{total(order)}"
Logger.debug fn -> "Order total #{total(order)}" end

Why have the function version? Perhaps the calculation of the order total is expensive. In the first version, we’ll always call it to interpolate the value into our string, even if the runtime log level is set to ignore debug-level messages. In the function variant, though, the total function will be invoked only if the log message is needed.

This seems to contradict other things I’ve learned as I’m getting more familiar with the language.
For example I’m aware that Logger.info/2 and friends are implemented as macros and the fact that, even though originally it was to get the caller metadata, this allows to remove logging calls that would not be used with the current log level (depending on the value compile_time_purge_level).

Now, since the interface is already made of macros, the binary messages should be lazily evaluated. That is, if Logger.info/2 was a function, the arguments would be evaluated first. Since it’s a macro that returns a quoted expression, the argument will be evaluated later. More precisely, when we hand it over to the Logger.bare_log/3 function.

What’s the purpose of using a function, then? Is it to keep the evaluation lazy even when we change the log level at runtime? How often does that happen though? I’d expect that the expensive log calls will have been already purged through compile_time_purge_level.

Most Liked

a_lixer

a_lixer

This is an old thread, but I think I can close the loop by mentioning that Elixir 1.7 removed the need to use anonymous functions with Logger.

See Logger compile-time purging in Elixir 1.7 release notes.

Also, there is a credo check specifically for this, which is disabled for Elixir 1.7+.

benwilson512

benwilson512

Author of Craft GraphQL APIs in Elixir with Absinthe

Since it’s a macro that returns a quoted expression, the argument will be evaluated later.

This is not correct. The only thing that being a macro does is give Logger the opportunity to purge at compile time. If you do not do that then it leaves the AST largely alone, and then at runtime it’s evaluated just as you would expect.

Logger COULD always wrap the argument in an anonymous function so that it was always lazy, but this could produce quite a bit of unexpected behaviour for people, so it is not what is done

Plenty of people forego compile_time_purge_level because they want to be able to alter the log level dynamically. If the debug values are compile time purged then even if you change the log level while it’s running the debug calls won’t happen. If you wrap expensive debug calls in an anonymous function, then you can switch to debug logging and get the values dynamically

benwilson512

benwilson512

Author of Craft GraphQL APIs in Elixir with Absinthe

What you have is exactly what happens with compile time purge on, but is not what happens when compile time purge is off. Your check of the log level happens at compile time which makes it impossible to change dynamically at runtime.

tompave

tompave

Hi @benwilson512, thank you for the answer.

Logger COULD always wrap the argument in an anonymous function so that it was always lazy, but this could produce quite a bit of unexpected behaviour for people, so it is not what is done

Plenty of people forego compile_time_purge_level because they want to be able to alter the log level dynamically. If the debug values are compile time purged then even if you change the log level while it’s running the debug calls won’t happen. If you wrap expensive debug calls in an anonymous function, then you can switch to debug logging and get the values dynamically

I see, this makes sense.

Since it’s a macro that returns a quoted expression, the argument will be evaluated later.

This is not correct. The only thing that being a macro does is give Logger the opportunity to purge at compile time. If you do not do that then it leaves the AST largely alone, and then at runtime it’s evaluated just as you would expect.

I guess this is the bit I’m still not sure about.
For example, with this simple test I can see that the evaluation is deferred and only executed when necessary:

defmodule NaiveLogger do
  def do_log(level, message) do
    IO.puts "log[#{level}] : #{message}"
  end

  defmacro log(level, message) do
    if level > 2 do
      quote do
        NaiveLogger.do_log(unquote(level), unquote(message))
      end
    else
      :ok
    end
  end
end

give_me_the_message = fn() ->
  IO.puts "I'm being executed!"
  "something is happening"
end


require NaiveLogger

NaiveLogger.log(3, "message: #{give_me_the_message.()}")
# I'm being executed!
# log[3] : message: something is happening
# :ok

NaiveLogger.log(1, "message: #{give_me_the_message.()}")
# :ok

Were you referring to something different, or have I missed a step?

Where Next?

Popular in Questions Top

gshaw
What is the idiomatic way of matching for not nil in Elixir? E.g., First way: defp halt_if_not_signed_in(conn, signed_in_account) when...
New
LegitStack
I’m hoping you guys can give me some general advice and perhaps code examples if you’re feeling up to it. I’m very interested in Elixir,...
New
lastday4you
I wanted to check elixir version in phoenix because i found that my elixir is 1.5 but when i use Enum.chunk_by it said the function is un...
New
mgjohns61585
Could someone help me? I'm making my first elixir program, number guessing game. I can't figure out how to convert the user's guess from ...
New
shahryarjb
Hello, I have map which I want to convert it to string like this: the map: %{last_name: "tavakkoli", name: "shahryar"} the string I ne...
New
LegitStack
I’m trying to make a websocket server in Phoenix or raw Elixir. I heard about gun, I think I could use cowboy, but since I’m not that sma...
New
chrisalley
ExUnit now has describe blocks which is a welcome addition coming from RSpec. In the docs, it states that nested hierarchies of describe ...
New
belgoros
I’m not a pro in using Regex and can’t figure out why the following behaviour happens, especially if we take into account the difference ...
New
skosch
To my knowledge, put_in, Map.update etc. all have the one limitation of not automatically creating intermediate keys when needed (for exa...
New
idi527
I’ve been re-reading swift book again and noticed that multiline strings there don’t have a trailing line break, unlike in elixir iex(2)...
New

Other popular topics Top

JDanielMartinez
Hi! May someone helps me, please! I have two apps into an umbrella project: the first one is Database, which manages queries, and the se...
New
srinivasu
How to handle excepions in elixir? Suppose i have A, B, C ,D, E modules. and each module has get() function. A.get() method will call th...
New
pmjoe
I have a relationship of love and hate with Elixir. Lots of things are just absolutely right, but there are some things that are kind of ...
New
openscript
Hello! Sorry for this astonishing simple question, but I’m really stuck. I try to set up the intellij-elixir plugin, but I don’t know ho...
New
aalberti333
As the title describes, I’m trying to run Enum.map() over a list of key/value pairs, where the value is a map. My data looks like this: ...
New
lk-geimfari
What is most correct way to open, read and parse JSON file with poison? For example if we have example.json file in root of some projec...
New
chrismccord
As promised, the first release candidate of Phoenix 1.3.0 is out! This release focuses on code generators with improved project structure...
New
fireproofsocks
Forgive me if this is obvious, but how does one delete a database record WITHOUT selecting it first? https://hexdocs.pm/ecto/Ecto.Repo.h...
New
Patoshizzle
After calling mix ecto.create I get this error: 17:00:32.162 [error] GenServer #PID<0.412.0> terminating ** (Postgrex.Error) FATAL...
New
aesmail
Hello guys, I have finally made it. I created an admin interface for a framework. It’s been on my todo list for years and with the curre...
New

We're in Beta

About us Mission Statement