newrelic / elixir_agent

New Relic's Open Source Elixir Agent
https://hex.pm/packages/new_relic_agent
Apache License 2.0
254 stars 97 forks source link

Error parsing error info in logger translator #430

Open tpitale opened 8 months ago

tpitale commented 8 months ago

Describe the bug

Seem to be having an error on startup in our service where parse_error_info(nil) is being called. If we trace this up the stack we get to some newly changed code around error reporting in the logger translator.

15:52:33.199 [info] Failure while translating Erlang's logger event
** (FunctionClauseError) no function clause matching in NewRelic.Error.Reporter.parse_error_info/1
    (new_relic_agent 1.29.0) lib/new_relic/error/reporter.ex:91: NewRelic.Error.Reporter.parse_error_info(nil)
    (new_relic_agent 1.29.0) lib/new_relic/error/reporter.ex:44: NewRelic.Error.Reporter.report_error/2
    (new_relic_agent 1.29.0) lib/new_relic/error/logger_handler.ex:16: NewRelic.Error.LoggerHandler.translator/4
    (logger 1.15.7) lib/logger/utils.ex:47: Logger.Utils.translate/5
    (logger 1.15.7) lib/logger/utils.ex:28: Logger.Utils.translator/2
    (kernel 9.2.2) logger_backend.erl:101: :logger_backend.do_apply_filters/4
    (kernel 9.2.2) logger_backend.erl:86: :logger_backend.apply_filters/4
    (kernel 9.2.2) logger_backend.erl:32: :logger_backend.log_allowed/3

Environment

This line seems different than the docs suggest: https://github.com/newrelic/elixir_agent/pull/421/files#diff-810b4a095e0cf9779a97430561fa26fb924a45377bb2f61394bc4849a14f45a7R22

Docs: https://hexdocs.pm/logger/1.15.7/Logger.Translator.html#c:translate/4

tpitale commented 8 months ago

This causes our translator to be removed and we miss errors.

@tmaszk Do you happen to have any ideas why the report would be nil from the translator function call?

tpitale commented 8 months ago

This code looks like it takes min_level, level, :format | :report, and the report itself, which is either a map or a keyword list.

https://github.com/elixir-lang/elixir/blob/v1.15.7/lib/logger/lib/logger/translator.ex#L35

tpitale commented 7 months ago

I've tried to trigger the translator using Logger.error() and raise. I'm guessing the apparatus is more complicated to get in there. If anyone knows how, let me know and I'll write some tests.

tpitale commented 7 months ago

Okay, in essence, we are getting a message through that does not include :error_info in the kw list. Not sure if best to guard against that case, or continue to dig to try to find out what is being sent to us.

tpitale commented 7 months ago

Going to fork it and update our app to add more logging on this. See what we get on startup.

tpitale commented 7 months ago

Looks like a bunch of kafka messages from erlkaf (an erlang lib). Going to check if it is a :format or :report.

tpitale commented 7 months ago

Okay, so these are only of kind = :format. I think I'm going to PR filtering down to just :report.