Exceptions get logged from Firefox client, but not from cURL

[DHager]

This might be a "undefined behavior, you're using it wrong", but it's sufficiently weird that I want to check. We've been using cowboy2 for a bit and started to use bandit for some endpoints, and ran into an issue where a server-side exception sometimes does not get any error logging... depending on HTTP client.

For example, suppose I drop manual ArgumentError into my controller, and load up the page in Firefox. STDOUT shows a [debug] and an [error], which is in this context what I would expect:

10:56:26.244 application=phoenix request_id=F9WQNBLv85i-0ZwAAAFF line=248 file=lib/phoenix/logger.ex ip=127.0.0.1 [debug] Converted error ArgumentError to 500 response
10:56:26.246 request_id=F9WQNBLv85i-0ZwAAAFF line=1391 file=gen_server.erl ip=127.0.0.1 [error] GenServer #PID<0.1663.0> terminating
** (ArgumentError) Forced Example Exception
    (app 0.2.18) lib/foo/api/internal/controllers/bar_controller.ex:25: Acme.Foo.API.Internal.BarController.index/2
    (app 0.2.18) lib/foo/api/internal/controllers/bar_controller.ex:1: Acme.Foo.API.Internal.BarController.action/2
    (app 0.2.18) lib/foo/api/internal/controllers/bar_controller.ex:1: Acme.Foo.API.Internal.BarController.phoenix_controller_pipeline/2
    (phoenix 1.7.3) lib/phoenix/router.ex:430: Phoenix.Router.__call__/5
    (app 0.2.18) lib/foo/api/internal/endpoint.ex:1: Acme.Foo.API.Internal.Endpoint.plug_builder_call/2
    (app 0.2.18) lib/foo/api/internal/endpoint.ex:1: Acme.Foo.API.Internal.Endpoint.call/2
    (bandit 1.4.1) lib/bandit/pipeline.ex:150: Bandit.Pipeline.call_plug!/2
    (bandit 1.4.1) lib/bandit/pipeline.ex:36: Bandit.Pipeline.run/4
    (bandit 1.4.1) lib/bandit/http2/stream_process.ex:28: Bandit.HTTP2.StreamProcess.handle_continue/2
    (stdlib 5.2) gen_server.erl:1085: :gen_server.try_handle_continue/3
    (stdlib 5.2) gen_server.erl:995: :gen_server.loop/7
    (stdlib 5.2) proc_lib.erl:241: :proc_lib.init_p_do_apply/3
Last message: {:continue, :start_stream}
State: {%Bandit.HTTP2.Stream{connection_pid: #PID<0.1662.0>, stream_id: 15, state: :idle, recv_window_size: 65535, send_window_size: 131072, bytes_remaining: nil, transport_info: %Bandit.TransportInfo{secure?: true, sockname: {{127, 0, 0, 1}, 4004}, peername: {{127, 0, 0, 1}, 53344}, peercert: nil}, read_timeout: 15000}, {Acme.Foo.API.Internal.Endpoint, []}, %ThousandIsland.Telemetry{span_name: :connection, telemetry_span_context: #Reference<0.907864227.2392326150.249420>, start_time: -576460721075489802, start_metadata: %{remote_port: 53344, remote_address: {127, 0, 0, 1}, telemetry_span_context: #Reference<0.907864227.2392326150.249420>, parent_telemetry_span_context: #Reference<0.907864227.2392326150.249211>}}, %{http: [], websocket: [], http_1: [], http_2: []}}

However when I use "Copy as cURL" and run that (even including Firefox user-agent headers) the [debug] is still there, and the client gets the expected result, but there is no [error] anymore. This difference exists even if I strip down the curl command to the basics.

I did find this 1.4.0 changelog entry (from #286) which may be relevant:

We no longer log if processes that are linked to an HTTP/2 stream process terminate unexpectedly. This has always been unspecified behaviour so is not considered a breaking change

Questions:

• What causes this difference? Perhaps something about how the different clients negotiate HTTP/2 that affects genserver lifetimes?
• For anyone who was relying on "unspecified behavior", what route should take care of unexpected exceptions? Is the assumption that consumers must implement their own Logger.error calls inside a Phoenix ErrorView module?