Live Reload initial WS connection always fails after compile

[oskarkook]

Reproducible with the following steps:

• Create new project with default configuration: mix phx.new phoenix_test
• Run server with mix phx.server
• Make a change to PageController file, no live reload should be triggered
• When you manually refresh page, a compile will be triggered and initial Live Reload connection to websockets will fail:

  Compiling 2 files (.ex)
  [error] #PID<0.771.0> running PhoenixTestWeb.Endpoint (connection #PID<0.770.0>, stream id 1) terminated
  Server: localhost:4000 (http)
  Request: GET /phoenix/live_reload/socket/websocket?vsn=2.0.0
  ** (exit) an exception was raised:
  ** (UndefinedFunctionError) function PhoenixTestWeb.Endpoint.__handler__/2 is undefined (module PhoenixTestWeb.Endpoint is not available)
      (phoenix_test) PhoenixTestWeb.Endpoint.__handler__(%Plug.Conn{adapter: {Plug.Cowboy.Conn, :...}, assigns: %{}, before_send: [], body_params: %Plug.Conn.Unfetched{aspect: :body_params}, cookies: %Plug.Conn.Unfetched{aspect: :cookies}, halted: false, host: "localhost", method: "GET", owner: #PID<0.771.0>, params: %Plug.Conn.Unfetched{aspect: :params}, path_info: ["phoenix", "live_reload", "socket", "websocket"], path_params: %{}, port: 4000, private: %{}, query_params: %Plug.Conn.Unfetched{aspect: :query_params}, query_string: "vsn=2.0.0", remote_ip: {127, 0, 0, 1}, req_cookies: %Plug.Conn.Unfetched{aspect: :cookies}, req_headers: [{"accept", "*/*"}, {"accept-encoding", "gzip, deflate"}, {"accept-language", "en-US,en;q=0.5"}, {"cache-control", "no-cache"}, {"connection", "keep-alive, Upgrade"}, {"cookie", "_constructor_key=SFMyNTY.g3QAAAADbQAAAAtfY3NyZl90b2tlbm0AAAAYSFJrZUpqNGtoWUhqcGhtejRRSmxmcWkybQAAAAZsb2NhbGVtAAAABWV0X0VFbQAAAAd1c2VyX2lkbQAAAAEx.PmfgcXUbunsM0lzoDZWvPgG1jE6M4h-nOljf7afTUUk; locale=et_EE; _demo_key=SFMyNTY.g3QAAAABbQAAAAtfY3NyZl90b2tlbm0AAAAYVklvaHAydlc4cm5DbDh0YnZqbU5qRWl4.ku1noT-GCAR1rHe-ty_51ApsqrQ500gLEP7JnKdMHKE"}, {"host", "localhost:4000"}, {"origin", "http://localhost:4000"}, {"pragma", "no-cache"}, {"sec-websocket-extensions", "permessage-deflate"}, {"sec-websocket-key", "7ZGb2eUpSoM03ZP4+r8dJA=="}, {"sec-websocket-version", "13"}, {"upgrade", "websocket"}, {"user-agent", "Mozilla/5.0 (X11; Fedora; Linux x86_64; rv:68.0) Gecko/20100101 Firefox/68.0"}], request_path: "/phoenix/live_reload/socket/websocket", resp_body: nil, resp_cookies: %{}, resp_headers: [{"cache-control", "max-age=0, private, must-revalidate"}], scheme: :http, script_name: [], secret_key_base: nil, state: :unset, status: nil}, [])
      (phoenix) lib/phoenix/endpoint/cowboy2_handler.ex:17: Phoenix.Endpoint.Cowboy2Handler.init/2
      (cowboy) /home/oskar/Development/phoenix_test/deps/cowboy/src/cowboy_handler.erl:41: :cowboy_handler.execute/2
      (cowboy) /home/oskar/Development/phoenix_test/deps/cowboy/src/cowboy_stream_h.erl:296: :cowboy_stream_h.execute/3
      (cowboy) /home/oskar/Development/phoenix_test/deps/cowboy/src/cowboy_stream_h.erl:274: :cowboy_stream_h.request_process/3
      (stdlib) proc_lib.erl:249: :proc_lib.init_p_do_apply/3
  [info] GET /
  [debug] Processing with PhoenixTestWeb.PageController.index/2
  Parameters: %{}
  Pipelines: [:browser]
  [info] Sent 200 in 263µs

WS connection will be established after first failure, so Live Reload still works, but these exceptions make it really annoying to parse the log.

There's some discussion on the problem here..

[josevalim]

I cannot reproduce it but it does seem to be a race condition. What is your phoenix_live_reload version? Are you on latest? For posterity, here are my dependencies:

$ mix deps
* ranch (Hex package) (rebar3)
  locked at 1.7.1 (ranch) 6b1fab51
  the dependency build is outdated, please run "mix deps.compile"
* telemetry 0.4.0 (Hex package) (rebar3)
  locked at 0.4.0 (telemetry) 8339bee3
  ok
* jason 1.0.0 (Hex package) (mix)
  locked at 1.0.0 (jason) 0f7cfa9b
  ok
* phoenix_pubsub (https://github.com/phoenixframework/phoenix_pubsub.git) (mix)
  locked at 1bc0b25
  the dependency build is outdated, please run "mix deps.compile"
* cowlib (Hex package) (rebar3)
  locked at 2.7.3 (cowlib) a7ffcd09
  the dependency build is outdated, please run "mix deps.compile"
* cowboy (Hex package) (rebar3)
  locked at 2.6.3 (cowboy) 99aa50e9
  the dependency build is outdated, please run "mix deps.compile"
* mime 1.3.1 (Hex package) (mix)
  locked at 1.3.1 (mime) 30ce04ab
  ok
* plug_crypto 1.0.0 (Hex package) (mix)
  locked at 1.0.0 (plug_crypto) 18e49317
  ok
* plug (Hex package) (mix)
  locked at 1.8.2 (plug) 0bcce1da
  the dependency build is outdated, please run "mix deps.compile"
* plug_cowboy (Hex package) (mix)
  locked at 2.1.0 (plug_cowboy) b7576815
  the dependency build is outdated, please run "mix deps.compile"
* phoenix_html (Hex package) (mix)
  locked at 2.13.0 (phoenix_html) 3bad10de
  the dependency build is outdated, please run "mix deps.compile"

[oskarkook]

mix deps result here: https://gist.github.com/oskarkook/b70ac5fbb995e2fb353f7934a5ae67de

Although now I feel like the issue is not LiveReload specific. The same error can be encountered with other Phoenix channels (e.g. LiveView). The issue is actually especially annoying with LiveView as you can end up with a blank page altogether (as opposed to just erroring out once with LiveReload).

[josevalim]

Thanks. Can you please report it on Phoenix instead and copy me? I have a suggestion to fix it. :)