Getting this strange undecipherable error on a get request using the API passthrough

Phoenix Forum Questions / Help
1

I am getting this strange error when using a simple get request from Python client:

🐘 tbrowne@suprabonds:~/code/apitest$ mix phx.server
Compiling 2 files (.ex)
[info] Running ApitestWeb.Endpoint with cowboy 2.9.0 at 127.0.0.1:4000 (http)
[info] Access ApitestWeb.Endpoint at http://localhost:4000
[watch] build finished, watching for changes...
[info] GET /api/test
test-test-test
[debug] Processing with ApitestWeb.ApiController.test/2
  Parameters: %{}
  Pipelines: [:api]
[info] Sent 200 in 26ms
[info] Sent 200 in 26ms
[error] Ranch listener ApitestWeb.Endpoint.HTTP had connection process started with :cowboy_clear:start_link/4 at #PID<0.552.0> exit with reason: {:function_clause, [{:cowboy_http, :commands, [{:state, #PID<0.448.0>, ApitestWeb.Endpoint.HTTP, #Port<0.19>, :ranch_tcp, :undefined, %{env: %{dispatch: [{:_, [], [{:_, [], Phoenix.Endpoint.Cowboy2Handler, {ApitestWeb.Endpoint, []}}]}]}, stream_handlers: [:cowboy_telemetry_h, :cowboy_stream_h]}, "", %{}, {{127, 0, 0, 1}, 33434}, {{127, 0, 0, 1}, 4000}, :undefined, #Reference<0.939587077.3699376130.130145>, true, 2, {:ps_request_line, 0}, 65535, 1, :done, 1, [{:stream, 1, {:cowboy_telemetry_h, {:state, {:cowboy_stream_h, {:state, :undefined, ApitestWeb.Endpoint.HTTP, #PID<0.553.0>, :undefined, :undefined, :undefined, :undefined, 0, :nofin, "", 0, ...}}, #Function<0.118987493/1 in :cowboy_telemetry_h."-fun.metrics_callback/1-">, :undefined, %{body_length: 0, cert: :undefined, has_body: false, headers: %{"accept" => "*/*", "connection" => "close", "host" => "127.0.0.1:4000", "user-agent" => "curl/7.68.0"}, host: "127.0.0.1", method: "GET", path: "/api/test", peer: {{127, 0, ...}, 33434}, pid: #PID<0.552.0>, port: 4000, qs: "", ...}, "200 OK", %{"cache-control" => "max-age=0, private, must-revalidate", "content-length" => "2", "date" => "Mon, 11 Apr 2022 08:20:21 GMT", "server" => "Cowboy", "x-request-id" => "FuTJx2JFde1JhukAAAKS"}, ApitestWeb.Endpoint.HTTP, -576460727033596992, :undefined, :undefined, :undefined, -576460726896282972, -576460726896282972, %{#PID<0.553.0> => %{...}}, [], ...}}, "GET", :"HTTP/1.0", :undefined, :undefined, 0, []}], [{:child, #PID<0.553.0>, 1, 5000, :undefined}]}, 1, [{:response, "200 OK", %{"cache-control" => "max-age=0, private, must-revalidate", "content-length" => "2", "date" => "Mon, 11 Apr 2022 08:20:21 GMT", "server" => "Cowboy", "x-request-id" => "FuTJx2JFde1JhukAAAKS"}, "ok"}]], [file: '/home/tbrowne/code/apitest/deps/cowboy/src/cowboy_http.erl', line: 957]}, {:cowboy_http, :loop, 1, [file: '/home/tbrowne/code/apitest/deps/cowboy/src/cowboy_http.erl', line: 257]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 226]}]}

This is simply using `curl XXXX

Here is an image of the error:

image
image913×779 88.9 KB

Note how it’s sending out information twice ie [info] Sent 200 in 37ms appears twice.

Here is my router.ex:

defmodule ApitestWeb.Router do
  use ApitestWeb, :router

  pipeline :browser do
    plug :accepts, ["html"]
    plug :fetch_session
    plug :fetch_live_flash
    plug :put_root_layout, {ApitestWeb.LayoutView, :root}
    plug :protect_from_forgery
    plug :put_secure_browser_headers
  end

  pipeline :api do
    plug :accepts, ["json"]
  end

  scope "/", ApitestWeb do
    pipe_through :browser

    get "/", PageController, :index
  end

  scope "/api", ApitestWeb do
    pipe_through :api
    get "/test", ApiController, :test
  end

# .....continues with usual liveview etc
end

And here is the associated controller:

🐘 tbrowne@suprabonds:~/code/apitest/lib/apitest_web/controllers$ cat api_controller.ex 
defmodule ApitestWeb.ApiController do
  use ApitestWeb, :controller

  def test(conn, _params) do
    # this is where commands come in
    IO.puts("test-test-test")
    json(conn, %{data: "yabadadoo"}) 
    conn
    |> put_status(:ok)
    |> send_resp(200, "ok")
  end

end

This is brand new project that I just created using mix phx.new apitest, running on Elixir 1.14.0-dev on Erlang 24, and using Phoenix 1.6.6, and then added the above code to it.

Why is this error occurring? What is it and what am I doing wrong?

2

json/2 executes send_resp/3 under the hood (see code), so your code is attempting to send 2 responses.

Why it’s erroring out is explained in Plug.Conn.send_resp/1

Note that this function does not halt the connection, so if subsequent plugs try to send another response, it will error out. Use halt/1 after this function if you want to halt the plug pipeline.

Since json/2 is executing send_resp/3 but doesn’t implicitly halt the connect, your code is trying to send another response on a connection that’s already :sent and therefore crashes with a frankly quite cryptic error.

At least I think that’s what’s happening, but looking at the code for send_resp it should be raising an AlreadySent error? I’m not sure if my analysis of the error is correct. But in any case, try to remove the code after json(conn, %{data: "yabadadoo"}) and see what happens.

2 Likes
3

Awesome! it works perfectly! Thank you from a fellow (London based) south african.

1 Like
4

Just wanted to say this was my problem, too. Thanks so much for taking the time to post this!!

2 Likes