Why is Logger's default level :debug?

[asweet-confluent]

I recently noticed that Elixir’s Logger defaults its primary log level to :debug when no :logger, :level application configuration is present.

In Logger.App, the default ultimately comes from this line:

Application.get_env(:logger, :level, :debug)

Would something like :info or even :warning be a more reasonable default?

I bring this up because I ran into an issue where someone changed our log level from :info to :warn and it resulted in log spam. While Logger is pretty good about changing :warn into :warning under the hood, we have some code that goes through :logger.set_handler_config, which doesn’t have that check and just returns an error. If you don’t catch that, you’re left on :debug.

I’m thinking about how to prevent this situation in the future, and while I can add error handling around every call into :logger, I don’t see a good way to structurally prevent this sort of thing from happening again - it seems like it just comes down to “remember to do it right”, which makes me think this is a footgun in Logger rather than something I should be solving.

[hauleth]

Yes, it would be more reasonable default to use :info by default, but because of backward compatibility it needs to be :debug.

[jhogberg]

@asweet-confluent

I don’t see a good way to structurally prevent this sort of thing from happening again - it seems like it just comes down to “remember to do it right”, which makes me think this is a footgun in Logger rather than something I should be solving.

The way to structurally prevent this from happening is having :debug as a default: you noticed it, didn’t you?

[NobbZ]

I hate logging systems that hide messages by default from me.

When initially developing I want to see all the messages without having to mind about configuration.

[mat-hek]

In Membrane, we have a debug_verbose: boolean flag set via config, defaulting to false, and a corresponding debug_verbose macro. It’s intended for logs that are only useful for debugging the library itself, so we decided to hide them from the user by default.

For the regular debugs, I’d prefer if they were also disabled by default, as they’re intended for, well, debugging

[asweet-confluent]

What’s the bar for breaking compatibility? There’s some precedent for doing so when it prevents confusion:

feat(logger): return primary level as is, without conversion
This is breaking change, but inevitable to not confuse users.

Changing the default log level to something safer for production doesn’t seem like a huge stretch by comparison.

It would be nice to have a deprecation path. Can Logger reliably distinguish between an explicitly configured log level and falling back to its implicit :debug default? If so, it seems like reliance on the implicit default could first be deprecated, giving users who actually want :debug a chance to configure it explicitly.

Another interesting data point: Phoenix’s default production configuration sets the level to :info. If Phoenix is as widely used as I think it is, I suspect this masks the problem since most people never have to deal with the consequences of Logger’s defaults.

[hauleth]

@asweet-confluent

What’s the bar for breaking compatibility? There’s some precedent for doing so when it prevents confusion:

Yeah, I know, that is my work.

I 100% agree with you that default of :debug is wrong and should be changed, ideally to match Erlang’s :notice, as it would make a lot of stuff much easier.

@asweet-confluent

Can Logger reliably distinguish between an explicitly configured log level and falling back to its implicit :debug default?

Unfortunately - no. If that would be possible then I would propose that in the first place, but there is no way to detect that.

@NobbZ

I hate logging systems that hide messages by default from me.

When initially developing I want to see all the messages without having to mind about configuration.

I believe that the default configuration of logger should match the production environment, not dev. Dev environment is form of special environment, and accidental leakage of private data (which may be logged in debug logs) is bigger issue IMHO.

[mudasobwa]

@asweet-confluent

What’s the bar for breaking compatibility?

For me and my libraries the bar is never. Breaking backward compatibility is a clear sign of code authors don’t give a dime about their users.

[asweet-confluent]

@hauleth

Unfortunately - no. If that would be possible then I would propose that in the first place, but there is no way to detect that.

Couldn’t Logger.App.start/2 detect this by checking both Application.fetch_env(:logger, :level) and the preexisting :logger primary level?

If no Elixir level is configured and OTP is still at its default :notice, then Logger is about to introduce the implicit :debug. What case would make that detection incorrect?

[hauleth]

@asweet-confluent

Couldn’t Logger.App.start/2 detect this by checking both Application.fetch_env(:logger, :level) and the preexisting :logger primary level?

If no Elixir level is configured and OTP is still at its default :notice, then Logger is about to introduce the implicit :debug. What case would make that detection incorrect?

It will not work when someone sets logger level using kernel application option. That option is not easily useable in development, but in production deployments it is more common.

[asweet-confluent]

Does that configuration matter here though? Logger.start wipes it out unconditionally.

elixir --erl "-kernel logger_level warning" -e '
IO.inspect(Application.get_env(:kernel, :logger_level), label: "kernel.logger_level")
IO.inspect(Application.get_env(:logger, :level), label: "Elixir Logger level")
IO.inspect(:logger.get_primary_config()[:level], label: "actual primary level")
'
kernel.logger_level: :warning
Elixir Logger level: nil
actual primary level: :debug