Cowboy/Ranch Exits with vague error message. Why?

Phoenix Forum Questions / Help
1

Hi! After upgrading to Phoenix 1.7 (and cowboy 2.9 to 2.10), we’re seeing a bunch of odd errors from Cowboy. We haven’t noticed any user facing errors, so I’m quite confused.

The stated error is:

Ranch listener AppWeb.Endpoint.HTTP had connection process started with
:cowboy_clear:start_link/4 at #PID<0.8556.164> exit with reason:
{:function_clause, [{:cowboy_http, :commands, ....

But that doesn’t appear very helpful. Any ideas what’s going on? Has anyone else seen this?

Here's the full error: 
Ranch listener AppWeb.Endpoint.HTTP had connection process started with
:cowboy_clear:start_link/4 at #PID<0.8556.164> exit with reason:
{:function_clause, [{:cowboy_http, :commands, [{:state, #PID<0.5243.0>,
AppWeb.Endpoint.HTTP, #Port<0.552217>, :ranch_tcp, :undefined, %{compress:
true, env: %{dispatch: [{:_, [], [{:_, [], Plug.Cowboy.Handler,
{AppWeb.Endpoint, []}}]}]}, idle_timeout: 70000, max_header_value_length:
50000, max_keepalive: 5000000, stream_handlers: [:cowboy_compress_h,
:cowboy_telemetry_h, :cowboy_stream_h]}, "", %{}, {{10, 0, 1, 207}, 10480},
{{<snip>, 17, 0, 3}, 4000}, :undefined,
#Reference<0.1990757299.4122214401.120008>, true, 13, {:ps_request_line, 0},
65535, 12, :done, 5000000, [{:stream, 12, {:cowboy_compress_h, {:state,
{:cowboy_telemetry_h, {:state, {:cowboy_stream_h, {:state, :undefined,
AppWeb.Endpoint.HTTP, #PID<0.3209.164>, :undefined, :undefined, :undefined,
:undefined, ...}}, #Function<0.39451584/1 in
:cowboy_telemetry_h.metrics_callback>, :undefined, %{body_length: 0, cert:
:undefined, has_body: false, headers: %{"accept" => "*/*", "accept-encoding"
=> "gzip, deflate, br, zstd", "accept-language" => "en-US,en;q=0.9", ...},
host: "www.commoncurriculum.com", method: "GET", path:
"<snip>",
...}, "200 OK", %{"Connection" => "keep-alive",
"access-control-allow-credentials" => "true", "access-control-allow-origin" =>
"*", "access-control-expose-headers" => "", "cache-control" => "max-age=0,
private, must-revalidate", ...}, AppWeb.Endpoint.HTTP, -576097733072733623,
:undefined, :undefined, :undefined, ...}}, 300, :gzip, :undefined, :sync}},
"GET", :"HTTP/1.1", :undefined, :undefined, 0, []}], [{:child,
#PID<0.3209.164>, 12, 5000, :undefined}]}, 12, [{:response, "200 OK",
%{"Connection" => "keep-alive", "access-control-allow-credentials" => "true",
"access-control-allow-origin" => "*", "access-control-expose-headers" => "",
"cache-control" => "max-age=0, private, must-revalidate", "content-encoding"
=> "gzip", "content-length" => "1379", "content-type" => "application/json;
charset=utf-8", "date" => "Tue, 27 Feb 2024 06:21:44 GMT", "server" =>
"Cowboy", "vary" => "accept-encoding", "x-request-id" =>
"<snip>"}, [[<<31, 139, 8, 0, 0, 0, 0, 0, 0, 3>>], <<237, 152,
109, 111, 163, 70, 16, 199, 191, 74, 197, 219, 218, 167, 93, 88, 48, 248, 93,
122, 74, 37, 75, 105, 175, 106, 210, 158, 170, 83, 84, 237, 195, 16,
...>>]}]], [file: ~c"/app/deps/cowboy/src/cowboy_http.erl", line: 957]},
{:cowboy_http, :loop, 1, [file: ~c"/app/deps/cowboy/src/cowboy_http.erl",
line: 257]}, {:proc_lib, :init_p_do_apply, 3, [file: ~c"proc_lib.erl", line:
240]}]}
2

The error is complaining that no head of :cowboy_http.commands matches the input:

  • a state record with out_state set to :done
  • a stream ID of 12
  • a list of commands:
    [
  {:response, "200 OK", %{"Connection" => "keep-alive", ...}, <<...>>}
]

This appears to be caused by a late response from the handler - the head that handles response commands matches on out_state being :wait, so it doesn’t match:

3

Thank you @al2o3cr ! That’s very insightful. Any idea what could be causing this? Is it related t Phoenix or something we might be doing in our app?

4

Just wanted to followup and say my problem is I was calling render two times in the controller (result of a bad merge):

2 Likes