ErrorTracker.Integrations.Phoenix detached after GenServer timeout

[jaimeiniesta]

Hi, I found a situation where ErrorTracker detaches, after a GenServer has a timeout:

[error] Handler ErrorTracker.Integrations.Phoenix has failed and has been detached. Class=:error
Reason=%Protocol.UndefinedError{
  protocol: String.Chars,
  value: {:timeout, {GenServer, :call, [:myapp_server, :ready?, 5000]}},
  description: ""
}
Stacktrace=[
  {String.Chars, :impl_for!, 1, [file: 'lib/string/chars.ex', line: 3]},
  {String.Chars, :to_string, 1, [file: 'lib/string/chars.ex', line: 22]},
  {ErrorTracker, :normalize_exception, 2,
   [file: 'lib/error_tracker.ex', line: 222]},
  {ErrorTracker, :report, 3, [file: 'lib/error_tracker.ex', line: 118]},
  {:telemetry, :"-execute/3-fun-0-", 4,
   [
     file: '/Users/jaime/code/myapp/myapp/deps/telemetry/src/telemetry.erl',
     line: 160
   ]},
  {:lists, :foreach_1, 2, [file: 'lists.erl', line: 1442]},
  {:telemetry, :span, 3,
   [
     file: '/Users/jaime/code/myapp/myapp/deps/telemetry/src/telemetry.erl',
     line: 333
   ]},
  {Phoenix.LiveView.Channel, :render_diff, 3,
   [file: 'lib/phoenix_live_view/channel.ex', line: 958]},
  {Phoenix.LiveView.Channel, :handle_changed, 4,
   [file: 'lib/phoenix_live_view/channel.ex', line: 805]},
  {:gen_server, :try_dispatch, 4, [file: 'gen_server.erl', line: 1123]},
  {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 1200]},
  {:proc_lib, :wake_up, 3, [file: 'proc_lib.erl', line: 250]}
]

[error] GenServer #PID<0.5497.0> terminating
** (stop) exited in: GenServer.call(:myapp_server, :ready?, 5000)
    ** (EXIT) time out
    (elixir 1.14.5) lib/gen_server.ex:1038: GenServer.call/3
    (myapp 0.0.1) lib/myapp_web/live/page/components/input_component.ex:12: anonymous fn/2 in myappWeb.Live.page.Components.InputComponent.user_input/1

This is in ErrorTracker 0.3.0

[crbelaus]

Interesting!

@jaimeiniesta can you reproduce the problem? Does it happen every time?

[jaimeiniesta]

Yes, I can reproduce that. If you have a GenServer in your app, you can insert a :timer.sleep inside a handle_call function. The default timeout is 5 seconds, if you can provoke a timeout you'll get this error.

[crbelaus]

The problem is caused by Exception.normalize/3 returning the payload for non-errors. In this case we don't have an :error but an :exit tuple so it returns the whole payload, which is something like:

{:timeout, {GenServer, :call, [:myapp_server, :ready?, 5000]}}

Then we try to convert this to a string and trigger the error that you are experiencing. Working on a fix at the moment.

[crbelaus]

@jaimeiniesta the changes in PR #110 should fix this problem as we now can safely convert any payload to a string.

[jaimeiniesta]

Hey that was fast, thanks!

I've checked and the change in that PR fixes the issue.

Thanks!

[crbelaus]

Great. We will push a new release with this fix soon!