Trying to learn the concept of supervision without using OTP. The server doesn't restart throwing an error

I’m following a video tutorial. The moment where the author exits the process by Process.exit(pid, :because) it works out. But I’m running into a bit of a snag. I tried to retype everything twice, then I tried to run the author’s code on my machine. The author mix’s file had version of elixir 1.9 and mine was 1.8.1, so I thought it might be it. After updating and running the author’s code I had the same exception.

defmodule HttpServer do
  require Logger # because Logger built in part with macros
  @port 8000
  @http_options [active: false, packet: :http_bin, reuseaddr: true]

  def start_link() do
    spawn_link(HttpServer, :init, [])
  end

  def init() do
    Process.flag(:trap_exit, true)

    start_listener()
    |> supervise()
  end

  def supervise(socket) do
    receive do
      {:EXIT, pid, reason} ->
        Logger.error("Listener process (#{inspect(pid)}) Crashed. #{reason}")
        :gen_tcp.close(socket)

        start_listener()
        |> supervise()
    end
  end

  def start_listener() do
    {:ok, socket} = :gen_tcp.listen(@port, @http_options)
    IO.inspect socket, label: "START_LISTENER SOCKET :: :"
    pid = spawn_link(HttpServer, :accept, [socket])
    Logger.info("Listener started #{inspect(pid)}")
    socket
  end

  def accept(socket) do
    IO.inspect socket, label: "ACCEPT SOCKET :: :"
    {:ok, client} = :gen_tcp.accept(socket)
    IO.inspect client, label: "CLIENT :: :: :"
    pid = spawn(HttpServer, :handle, [client])
    :ok = :gen_tcp.controlling_process(client, pid)
    accept(socket)
  end

  def handle(client) do
    Logger.info("Servicing a new request on pid #{inspect(self())}")
    body = "Hello from Elixir #{inspect(self())}"
    :gen_tcp.send(client, view(body))
    :gen_tcp.close(client)
  end

  def view(body) do
    [
      "HTTP/1.1 200\n",
      "Content-Type: text/html\n",
      "Content-Length: ",
      "#{byte_size(body)}",
      "\n\n",
      body
    ]
  end
end
  1. I start the server
  2. Then I make a few requests with curl. The server works fine and handle the requests in the way it is supposed to.
  3. Then I run Process.exit(pid, :because)
  4. The server logs the message as it should
    19:41:45.997 [error] Listener process (#PID<0.144.0>) Crashed. because
  5. But then it’s supposed to restart and it doesn’t.

I understand that I can handle the error by pattern matching in the start_listener() function, but I did exactly as the author of the video and for him everything works out fine.

iex(1)> HttpServer.start_link
#PID<0.146.0>
iex(2)> 
19:41:11.828 [info]  Listener started #PID<0.147.0>
 
19:41:27.829 [info]  Servicing new request on pid #PID<0.149.0>
 
nil
iex(3)> Process.exit(pid(0,146,0), :because)
true
iex(4)> 
19:41:45.997 [error] Listener process (#PID<0.144.0>) Crashed. because
 
19:41:45.997 [info]  Listener started #PID<0.152.0>
 
19:41:45.997 [error] Process #PID<0.147.0> raised an exception
** (MatchError) no match of right hand side value: {:error, :closed}
    (http_server 0.1.0) lib/http_server.ex:36: HttpServer.accept/1
** (EXIT from #PID<0.144.0>) shell process exited with reason: an exception was raised:
    ** (Protocol.UndefinedError) protocol String.Chars not implemented for {{:badmatch, {:error, :closed}}, [{HttpServer, :accept, 1, [file: 'lib/http_server.ex', line: 36]}]} of type Tuple. This protocol is implemented for the following type(s): Date, Integer, List, Atom, BitString, NaiveDateTime, DateTime, URI, Version, Version.Requirement, Time, Float
        (elixir 1.12.3) lib/string/chars.ex:3: String.Chars.impl_for!/1
        (elixir 1.12.3) lib/string/chars.ex:22: String.Chars.to_string/1
        (http_server 0.1.0) lib/http_server.ex:27: HttpServer.supervise/1
        
iex(4)> 
19:41:46.003 [error] Process #PID<0.146.0> raised an exception
** (Protocol.UndefinedError) protocol String.Chars not implemented for {{:badmatch, {:error, :closed}}, [{HttpServer, :accept, 1, [file: 'lib/http_server.ex', line: 36]}]} of type Tuple. This protocol is implemented for the following type(s): Date, Integer, List, Atom, BitString, NaiveDateTime, DateTime, URI, Version, Version.Requirement, Time, Float
    (elixir 1.12.3) lib/string/chars.ex:3: String.Chars.impl_for!/1
    (elixir 1.12.3) lib/string/chars.ex:22: String.Chars.to_string/1
    (http_server 0.1.0) lib/http_server.ex:27: HttpServer.supervise/1
Interactive Elixir (1.12.3) - press Ctrl+C to exit (type h() ENTER for help)

P.S. I first put the code on gist.github, but then thought it might be okay to post the full code here.

You are crashing in:

 Logger.error("Listener process (#{inspect(pid)}) Crashed. #{reason}")

Because reason is not a string, its a tuple. You’ll get to the next bug if you change this to:

 Logger.error("Listener process (#{inspect(pid)}) Crashed. #{inspect(reason)}")

:slight_smile:

3 Likes

I did as you said and indeed I got my next bug. Which turned out not to be a bug on the part of the code. IT WAS ME who was the bug :innocent:

HttpServer.start_link
#PID<0.143.0>
LISTENER SOCKET :: :: #Port<0.7>
ACCEPT SOCKET :: :: #Port<0.7>
iex(2)> 
13:19:39.723 [info]  Listener started #PID<0.145.0>
ACCEPT SOCKET :: :: #Port<0.7>
iex(2)> 
13:19:43.353 [info]  Servicing a new request on pid #PID<0.146.0>
 
nil
iex(3)> Process.exit pid(0,143,0), :because

13:19:58.276 [error] Listener process (#PID<0.141.0>) Crashed. :because
LISTENER SOCKET :: :: #Port<0.9>
true
ACCEPT SOCKET :: :: #Port<0.9>

13:19:58.277 [info]  Listener started #PID<0.148.0>
iex(4)> 
13:19:58.290 [error] Listener process (#PID<0.145.0>) Crashed. {{:badmatch, {:error, :closed}}, [{HttpServer, :accept, 1, [file: 'lib/http_server.ex', line: 38]}]}
LISTENER SOCKET :: :: #Port<0.10>
LISTENER SOCKET :: :: #Port<0.11>
ACCEPT SOCKET :: :: #Port<0.10>
ACCEPT SOCKET :: :: #Port<0.11>
LISTENER SOCKET :: :: #Port<0.12>
iex(4)> 
13:19:58.291 [info]  Listener started #PID<0.150.0>
ACCEPT SOCKET :: :: #Port<0.12>
iex(4)> 
13:19:58.291 [error] Listener process (#PID<0.148.0>) Crashed. {{:badmatch, {:error, :closed}}, [{HttpServer, :accept, 1, [file: 'lib/http_server.ex', line: 38]}]}

I looked at pids more closely and thought why it says {:error, :closed}. Then it dawned on me. I was killing the main supervisor and not the listener process!

P.S. @kip by the way, thank you.

4 Likes

Its great exploring the concepts that underpin OTP. It helps us appreciate that we can lean on more then 20 years of smart people getting both the conceptual model and the implementation so right.

4 Likes