feat: add check to warn about ignored Logger metadata

[milmazz]

All the metadata added via Logger macros such as Logger.error/2 is optional and it may not always be available. This credo check warns about those scenarios if you do something like:

{Credo.Check.Warning.IgnoredLoggerMetadata, [allowed_metadata: "config/prod.exs" |> Config.Reader.read!() |> get_in([:logger, :console, :metadata])]},

From the docs

For example, you might wish to include a custom :error_code metadata in your logs:

Logger.error("We have a problem", [error_code: :pc_load_letter])

In your app's logger configuration, you would need to include the :error_code key and you would need to include $metadata as part of your log format template:

config :logger, :console,
 format: "[$level] $message $metadata\n",
 metadata: [:error_code, :file]

Your logs might then receive lines like this:

[error] We have a problem error_code=pc_load_letter file=lib/app.ex

NOTE: A lot of this check implementation was borrowed from: Credo.Check.Warning.LazyLogging

EDIT: Just noticed this repo for proposals. I didn't know about it, so, please let me know how I should proceed from here.

[rrrene]

Hi, first: Thx for putting this together. But unfortunately I am really unsure about this.

It took me 15 minutes (well rested, on a sunday, already had my coffee) to even grasp what this does - and I am still not sure if I got it right.

So we have a check called IgnoredLoggerMetadata which helps "avoid ignoring Logger metadata in your logger config".

Then this check has two params

• ignore to ignore certain function calls, but why would we "ignore" debug by default? (also super unsure what "ignored" means in a check that already contains "Ignored" in the name??)
• allowed_metadata described as "Do not raise an issue for these metadata keys"

So is this check for "forbidding" certain metadata except the "allowed" ones? As I said, still not sure.

From your check's description I would have thought this is about not forgetting to include metadata in the config, which is used in the actual code, because otherwise it does not appear in the log.

But if that is the case, why does this need the confusing allowed_metadata param. Wouldn't we simply check all :logger configurations, regardless of env? (I am unsure because there is this super-confusing example in this PR of explicitly reading the :prod config file to use with the check - or was this done this way because we have difficulty determining the config in a static way?)

Finally, I usually get what a check does when I look at the tests. But the tests in this PR are just autogenerating multiple generic cases while also always using the same check parameters for both happy and bad paths and supposed corner cases.

Maybe this has something to do with english not being my first language and I apologize if this is the reason I am coming off as ignorant or dump. Help me out here, please!

[milmazz]

Hi, first: Thx for putting this together.

@rrrene Thanks to you for this project. It's beneficial for the Elixir community.

But unfortunately I am really unsure about this.

No worries. We're using a similar approach internally. I just wanted to contribute back to the community. So, hopefully, I can make the case on why I find this is a helpful check.

So we have a check called IgnoredLoggerMetadata which helps "avoid ignoring Logger metadata in your logger config".

Assume the following function

 # lib/my_app.ex
defmodule MyApp do
  require Logger
  def hello do
    Logger.info("hello", account_id: 1)
  end
end

With the following configuration:

 # config/config.exs
import Config

config :logger, :console,
 format: "[$level] $message $metadata\n",
 metadata: []

If you compile and run that function, you get this:

$ mix run -e "MyApp.hello"
[info] hello

So, to see the metadata key in the log you need to update the config to be something like:

config :logger, :console,
 format: "[$level] $message $metadata\n",
 metadata: [:account_id]

That way, you get:

$ mix run -e "MyApp.hello"
[info] hello account_id=1

Which is the expected behavior.

So, this check warns when a logger metadata key will be discarded or ignored at the end based on your current configuration, or that's the idea. Why is this important? While tracking some logs in a Logging as a Service platform for a legacy application, you might want to filter the results by the metadata or attributes. If you're not familiar with the codebase, you kind of trust that Logger.info("hello", account_id: 1) is publishing that metadata, but then, you waste time trying to filter the data when the attribute is not available in the first place because the logger config doesn't include that metadata key.

Then this check has two params

• ignore to ignore certain function calls, but why would we "ignore" debug by default? (also super unsure what "ignored" means in a check that already contains "Ignored" in the name??)
• allowed_metadata described as "Do not raise an issue for these metadata keys"

I'm open to suggestions about naming conventions here. But, the reasoning was:

• ignore - this is present on the LazyLogging implementation. And I keep it that way because I thought it could be useful for folks to let them decide if they want to ignore calls like Logger.debug("message", key: :value) or others. I'm ok with removing this option or leaving the default as []
• allowed_metadata, again, I don't know if it's the best name here, but the point of this option is to list the metadata keys that you have in your production environment. We should not offer a default because you don't know where the developer is putting their config. This value might be valid sometimes "config/prod.exs" |> Config.Reader.read!() |> get_in([:logger, :console, :metadata]), but not all the time.

From your check's description I would have thought this is about not forgetting to include metadata in the config, which is used in the actual code, because otherwise it does not appear in the log.

Exactly, that's the goal.

But if that is the case, why does this need the confusing allowed_metadata param. Wouldn't we simply check all :logger configurations, regardless of env? (I am unsure because there is this super-confusing example in this PR of explicitly reading the :prod config file to use with the check - or was this done this way because we have difficulty determining the config in a static way?)

Oh, I see that reading the prod config caused some confusion here. Again, I'm open to suggestions. If the allowed_metadata is causing some confusion here, we can use the :logger config via :logger |> Application.get_env(:console) |> Keyword.get(:metadata) as you suggested, but that's assuming that the :logger config it's the same between environments, which seems a good trade-off here.

HTH

[rrrene]

Ah, this makes more sense now.

Maybe we could brainstorm some alternatives for the check's name? As I said, not a native speaker, but I feel like the metadata is less "ignored" and more "ineffective" or "void". Maybe UnrecognizedLoggerMetadata?

I think we should ditch the :ignore parameter as I feel it does not make sense to allow for unrecognized metadata to be used in any Logger function. WDYT?

I like the change to :metadata_keys! But I think we can not initialize this inside Credo with

metadata_keys: :logger |> Application.get_env(:console, []) |> Keyword.get(:metadata, [])

as this will read the config during compile time, not when Credo is run (?)

[milmazz]

Maybe we could brainstorm some alternatives for the check's name?

Sure, we can continue talking about names.

As I said, not a native speaker,

Don't worry. We're on the same boat here.

but I feel like the metadata is less "ignored" and more "ineffective" or "void". Maybe UnrecognizedLoggerMetadata?

I don't think we should be talking about UnrecognizedLoggerMetadata in this case; is it not that, nor UnavailableLoggerMetadata. Instead, I think we could rename the module to be something like MissedMetadataKeyInLoggerConfig, which seems to follow a "credo convention"

$ ls -R lib/credo/check | grep _in_
space_in_parentheses
space_in_parentheses.ex
lib/credo/check/consistency/space_in_parentheses:
parentheses_in_condition.ex
match_in_condition.ex
negated_conditions_in_unless.ex
application_config_in_module_attribute.ex

And I think that's a good name because this custom check traverses the code and only warns when it finds a logger metadata key that is missing in the _logger configuration, which translates to missed metadata key in logger configuration to me.

I think we should ditch the :ignore parameter

Yes, I'm totally ok with that, I will remove that option in the following commit.

[milmazz]

I like the change to :metadata_keys! But I think we can not initialize this inside Credo with

metadata_keys: :logger |> Application.get_env(:console, []) |> Keyword.get(:metadata, [])

as this will read the config during compile time, not when Credo is run (?)

TBH, I think this library should avoid reading the global logger configuration at all. That's why at the beginning, the allowed_metadata (later renamed to metadata_keys) option was empty. Instead, I think the value should always be provided or injected by the developers.

And yes, you're right, the way it is right now is reading the logger config at compile time, not at runtime time, I can change that if you feel strongly in favor of reading the global configuration from this library.

[milmazz]

@rrrene Included some changes. Please let me know what do you think.

[rrrene]

This is part of Credo v1.7.0-rc.1 :+1: