Handler has failed and has been detached

[wkirschbaum]

Describe the bug

I get the following errors when booting up a phoenix 1.18.0-rc-4, liveview 1.1.0-rc.3 application:

[error] Handler {Appsignal.Phoenix.LiveView, [:phoenix, :live_view, :handle_event, :start]} has failed and has been detached. Class=:error
Reason=:badarg
Stacktrace=[
  {:binary, :match,
   [
     "_target",
     {:compiled, {:ac, #Reference<0.1504776825.681181185.176524>},
      {:ac, #Reference<0.1504776825.681181185.176525>}}
   ], [error_info: %{module: :erl_stdlib_errors}]},
  {String, :contains?, 2, [file: ~c"lib/string.ex", line: 2836]},
  {Appsignal.Utils.MapFilter, :"-discard_values/2-fun-0-", 2,
   [file: ~c"lib/appsignal/utils/map_filter.ex", line: 19]},
  {Enum, :"-map/2-fun-0-", 3, [file: ~c"lib/enum.ex", line: 1722]},
  {:maps, :fold_1, 4, [file: ~c"maps.erl", line: 894]},
  {Enum, :map, 2, [file: ~c"lib/enum.ex", line: 2558]},
  {Enum, :into, 3, [file: ~c"lib/enum.ex", line: 1608]},
  {Appsignal.Span, :do_set_sample_data, 5,
   [file: ~c"lib/appsignal/span.ex", line: 255]},
  {Appsignal.Phoenix.LiveView, :handle_event_start, 4,
   [file: ~c"lib/appsignal_phoenix/live_view.ex", line: 100]},
  {:telemetry, :"-execute/3-fun-0-", 4,
   [
     file: ~c"/home/whk/src/flt/moneyclub/deps/telemetry/src/telemetry.erl",
     line: 167
   ]},
  {:lists, :foreach_1, 2, [file: ~c"lists.erl", line: 2641]},
  {:telemetry, :span, 3,
   [
     file: ~c"/home/whk/src/flt/moneyclub/deps/telemetry/src/telemetry.erl",
     line: 318
   ]},
  {Phoenix.LiveView.Channel, :handle_info, 2,
   [file: ~c"lib/phoenix_live_view/channel.ex", line: 260]},
  {:gen_server, :try_handle_info, 3, [file: ~c"gen_server.erl", line: 2434]},
  {:gen_server, :handle_msg, 3, [file: ~c"gen_server.erl", line: 2420]},
  {:proc_lib, :init_p_do_apply, 3, [file: ~c"proc_lib.erl", line: 333]}
]

[error] Handler {Appsignal.Oban, [:oban, :job, :start]} has failed and has been detached. Class=:error
Reason=:badarg
Stacktrace=[
  {:binary, :match,
   [
     "scheduled",
     {:compiled, {:ac, #Reference<0.175430199.3900833793.93548>},
      {:ac, #Reference<0.175430199.3900833793.93549>}}
   ], [error_info: %{module: :erl_stdlib_errors}]},
  {String, :contains?, 2, [file: ~c"lib/string.ex", line: 2836]},
  {Appsignal.Utils.MapFilter, :"-discard_values/2-fun-0-", 2,
   [file: ~c"lib/appsignal/utils/map_filter.ex", line: 19]},
  {Enum, :"-map/2-fun-0-", 3, [file: ~c"lib/enum.ex", line: 1722]},
  {:maps, :fold_1, 4, [file: ~c"maps.erl", line: 894]},
  {Enum, :map, 2, [file: ~c"lib/enum.ex", line: 2558]},
  {Enum, :into, 3, [file: ~c"lib/enum.ex", line: 1608]},
  {Appsignal.Span, :do_set_sample_data, 5,
   [file: ~c"lib/appsignal/span.ex", line: 255]},
  {Appsignal.Oban, :oban_job_start, 4,
   [file: ~c"lib/appsignal/oban.ex", line: 66]},
  {:telemetry, :"-execute/3-fun-0-", 4,
   [
     file: ~c"/[my app]/deps/telemetry/src/telemetry.erl",
     line: 167
   ]},
  {:lists, :foreach_1, 2, [file: ~c"lists.erl", line: 2641]},
  {Oban.Queue.Executor, :record_started, 1,
   [file: ~c"lib/oban/queue/executor.ex", line: 97]},
  {Oban.Queue.Executor, :call, 1,
   [file: ~c"lib/oban/queue/executor.ex", line: 73]},
  {Task.Supervised, :invoke_mfa, 2,
   [file: ~c"lib/task/supervised.ex", line: 101]},
  {Task.Supervised, :reply, 4, [file: ~c"lib/task/supervised.ex", line: 36]}
]

To Reproduce

Steps to reproduce the behavior:

• Using AppSignal for Elixir package version 1.18.0-rc.4 and live_view 1.1.0-rc.3
• Add standard configuration

[wkirschbaum]

This might be the culprit:

Application.get_env(:phoenix, :filter_parameters, []) #=> {:compiled, {:ac, #Reference<0.3078477181.148766722.55229>},
 {:ac, #Reference<0.3078477181.148766722.55230>}}

As read in Appsignal.Utils.MapFilter.fiter/1

[wkirschbaum]

After updating the Appsignal code with the latest phoenix code it is working again, so certainly a bug in Appsignal, as it relied on internals.

I can submit my code as a PR to fix this, but might not be that useful as it won't be backwards compatible I believe.

[tombruijn]

Hi @wkirschbaum, thanks for the report!
I can reproduce, although with a slightly different error, on a new Phoenix 1.18.0 rc4 app.
Looks like we need to update our map filter the work with the new compiled format of the filter_parameters config.
I think we can detect if it's in the new format and send it filter it similar to how Phoenix does it, so it should be backwards compatible.

[wkirschbaum]

@tombruijn thanks. We have a forked version in production working well, but our version is not backwards compatible.

[navinpeiris]

In case it's useful, I get this on 1.8.0-rc.4 on [:router_dispatch] as well:

[11:01:03.237] [error] Handler {Appsignal.Phoenix.EventHandler, [:phoenix, :router_dispatch, :stop]} has failed and has been detached. Class=:error
Reason=:badarg
Stacktrace=[
  {:binary, :match,
   [
     "path",
     {:compiled, {:bm, #Reference<0.3407103571.3447062537.71389>},
      {:bm, #Reference<0.3407103571.3447062537.71390>}}
   ], [error_info: %{module: :erl_stdlib_errors}]},
  {String, :contains?, 2, [file: ~c"lib/string.ex", line: 2836]},
  {Appsignal.Utils.MapFilter, :"-discard_values/2-fun-0-", 2,
   [file: ~c"lib/appsignal/utils/map_filter.ex", line: 19]},
  {Enum, :"-map/2-fun-0-", 3, [file: ~c"lib/enum.ex", line: 1722]},
  {:maps, :fold_1, 4, [file: ~c"maps.erl", line: 860]},
  {Enum, :map, 2, [file: ~c"lib/enum.ex", line: 2558]},
  {Enum, :into, 3, [file: ~c"lib/enum.ex", line: 1608]},
  {Appsignal.Span, :do_set_sample_data, 5,
   [file: ~c"lib/appsignal/span.ex", line: 255]},
  {Appsignal.Phoenix.EventHandler, :set_span_data, 2,
   [file: ~c"lib/appsignal_phoenix/event_handler.ex", line: 133]},
  {Appsignal.Phoenix.EventHandler, :phoenix_router_dispatch_stop, 4,
   [file: ~c"lib/appsignal_phoenix/event_handler.ex", line: 61]},
  {:telemetry, :"-execute/3-fun-0-", 4,
   [
     file: ~c"/[my_app]/deps/telemetry/src/telemetry.erl",
     line: 167
   ]},
  {:lists, :foreach_1, 2, [file: ~c"lists.erl", line: 2310]},
  {Phoenix.Router, :__call__, 5, [file: ~c"lib/phoenix/router.ex", line: 421]},
  {MyAppWeb.Endpoint, :plug_builder_call, 2,
   [file: ~c"lib/my_app_web/endpoint.ex", line: 1]},
  {MyAppWeb.Endpoint, :"call (overridable 3)", 2,
   [file: ~c"deps/plug/lib/plug/debugger.ex", line: 155]},
  {MyAppWeb.Endpoint, :call, 2, [file: ~c"lib/my_app_web/endpoint.ex", line: 1]},
  {Phoenix.Endpoint.SyncCodeReloadPlug, :do_call, 4,
   [file: ~c"lib/phoenix/endpoint/sync_code_reload_plug.ex", line: 22]},
  {Bandit.Pipeline, :call_plug!, 2,
   [file: ~c"lib/bandit/pipeline.ex", line: 131]},
  {Bandit.Pipeline, :run, 5, [file: ~c"lib/bandit/pipeline.ex", line: 42]},
  {Bandit.HTTP1.Handler, :handle_data, 3,
   [file: ~c"lib/bandit/http1/handler.ex", line: 13]}
]

[tombruijn]

@navinpeiris that's the error I get locally as well, and it's no longer happening with the change sin PR #1009.

[tombruijn]

I released a fix in version v2.15.10 of the appsignal package. Please update and let me know if it works!

[wkirschbaum]

@tombruijn thanks for the quick fix of this. It seems to work on my side and the code also makes sense to me.

[navinpeiris]

Thanks @tombruijn, can confirm it works for me too! 🥳