Connection to broker is down but Tortoise is not reconnecting

[froy001]

I am using Vernemq as my broker. Every now and again the connection with the broker is lost for various reasons non of which are the client or broker being offline.(I am not sure why this happens). All I know is that restarting the application that uses Tortoise reconnects. Which means that reconnection is not happening automatically.

It is not cleat from the documentation whether one should try to restart the connection upon receiving a :down in connection/3 callback or how to do that should that happen.

As I am an elixir newbie could you point me in the right direction as to how to try to reconnect manually? Or what to log so you can figure out why Tortoise is not reconnecting automatically.

[brianmay]

My experience has always been that Tortoise will handle the re-connection automatically.

What version of tortoise are you using? Make sure you are using at least the latest release.

[froy001]

I have added the logs from connction and terminate functions. As you can see, at some point terminate with status :down. And not connection attempts are made. Any ideas as to why?

I  08:24:26.188 [debug] mqtt broker state in terminate:  => data: #{:function_clause, [{Tortoise.Connection.Controller, :handle_info, [{{Tortoise, "mqtt_manager:l42j6:dev"}, #Reference<0.2704242570.975699969.104541>, :ok}, %Tortoise.Connection.Controller{awaiting: %{}, client_id: "mqtt_manager:l42j6:prod", handler: %Tortoise.Handler{initial_args: [], module: Mqtt.Listener, state: []}, ping: {[], []}, status: :down}], [file: 'lib/tortoise/connection/controller.ex', line: 185]}, {:gen_server, :try_dispatch, 4, [file: 'gen_server.erl', line: 637]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 711]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}
 
  undefined
I  08:24:24.481 [debug] mqtt broker state in terminate:  => data: #{:function_clause, [{Tortoise.Connection.Controller, :handle_info, [{{Tortoise, "mqtt_manager:l42j6:dev"}, #Reference<0.2704242570.975699969.104357>, :ok}, %Tortoise.Connection.Controller{awaiting: %{}, client_id: "mqtt_manager:l42j6:prod", handler: %Tortoise.Handler{initial_args: [], module: Mqtt.Listener, state: []}, ping: {[], []}, status: :down}], [file: 'lib/tortoise/connection/controller.ex', line: 185]}, {:gen_server, :try_dispatch, 4, [file: 'gen_server.erl', line: 637]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 711]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}
 
  undefined
I  08:24:21.875 [debug] mqtt broker state in terminate:  => data: #{:function_clause, [{Tortoise.Connection.Controller, :handle_info, [{{Tortoise, "mqtt_manager:l42j6:dev"}, #Reference<0.2704242570.975699970.61467>, :ok}, %Tortoise.Connection.Controller{awaiting: %{}, client_id: "mqtt_manager:l42j6:prod", handler: %Tortoise.Handler{initial_args: [], module: Mqtt.Listener, state: []}, ping: {[], []}, status: :down}], [file: 'lib/tortoise/connection/controller.ex', line: 185]}, {:gen_server, :try_dispatch, 4, [file: 'gen_server.erl', line: 637]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 711]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}
 
  undefined
I  08:24:20.680 [debug] mqtt broker state in terminate:  => data: #{:function_clause, [{Tortoise.Connection.Controller, :handle_info, [{{Tortoise, "mqtt_manager:l42j6:dev"}, #Reference<0.2704242570.975699969.104163>, :ok}, %Tortoise.Connection.Controller{awaiting: %{}, client_id: "mqtt_manager:l42j6:prod", handler: %Tortoise.Handler{initial_args: [], module: Mqtt.Listener, state: []}, ping: {[], []}, status: :down}], [file: 'lib/tortoise/connection/controller.ex', line: 185]}, {:gen_server, :try_dispatch, 4, [file: 'gen_server.erl', line: 637]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 711]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}
 
  undefined
I  08:24:18.671 [debug] mqtt broker state in terminate:  => data: #{:function_clause, [{Tortoise.Connection.Controller, :handle_info, [{{Tortoise, "mqtt_manager:l42j6:dev"}, #Reference<0.2704242570.975699969.104062>, :ok}, %Tortoise.Connection.Controller{awaiting: %{}, client_id: "mqtt_manager:l42j6:prod", handler: %Tortoise.Handler{initial_args: [], module: Mqtt.Listener, state: []}, ping: {[], []}, status: :down}], [file: 'lib/tortoise/connection/controller.ex', line: 185]}, {:gen_server, :try_dispatch, 4, [file: 'gen_server.erl', line: 637]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 711]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}
 
  undefined
I  08:24:15.989 [debug] mqtt broker state in terminate:  => data: #{:function_clause, [{Tortoise.Connection.Controller, :handle_info, [{{Tortoise, "mqtt_manager:l42j6:dev"}, #Reference<0.2704242570.975699970.60636>, :ok}, %Tortoise.Connection.Controller{awaiting: %{}, client_id: "mqtt_manager:l42j6:prod", handler: %Tortoise.Handler{initial_args: [], module: Mqtt.Listener, state: []}, ping: {[], []}, status: :down}], [file: 'lib/tortoise/connection/controller.ex', line: 185]}, {:gen_server, :try_dispatch, 4, [file: 'gen_server.erl', line: 637]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 711]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}
 
  undefined
I  08:23:50.984 [debug] mqtt broker state in terminate:  => data: #{:function_clause, [{Tortoise.Connection.Controller, :handle_info, [{{Tortoise, "mqtt_manager:l42j6:dev"}, #Reference<0.2704242570.975699970.60391>, :ok}, %Tortoise.Connection.Controller{awaiting: %{}, client_id: "mqtt_manager:l42j6:prod", handler: %Tortoise.Handler{initial_args: [], module: Mqtt.Listener, state: []}, ping: {[], []}, status: :down}], [file: 'lib/tortoise/connection/controller.ex', line: 185]}, {:gen_server, :try_dispatch, 4, [file: 'gen_server.erl', line: 637]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 711]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}
 
  undefined
I  08:22:50.593 [debug] mqtt broker state in terminate:  => data: #{:function_clause, [{Tortoise.Connection.Controller, :handle_info, [{{Tortoise, "mqtt_manager:l42j6:dev"}, #Reference<0.2704242570.975699969.103446>, :ok}, %Tortoise.Connection.Controller{awaiting: %{}, client_id: "mqtt_manager:l42j6:prod", handler: %Tortoise.Handler{initial_args: [], module: Mqtt.Listener, state: []}, ping: {[], []}, status: :down}], [file: 'lib/tortoise/connection/controller.ex', line: 185]}, {:gen_server, :try_dispatch, 4, [file: 'gen_server.erl', line: 637]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 711]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}
 
  undefined
I  08:21:50.197 [debug] mqtt broker state in terminate:  => data: #{:function_clause, [{Tortoise.Connection.Controller, :handle_info, [{{Tortoise, "mqtt_manager:l42j6:dev"}, #Reference<0.2704242570.975699969.103311>, :ok}, %Tortoise.Connection.Controller{awaiting: %{}, client_id: "mqtt_manager:l42j6:prod", handler: %Tortoise.Handler{initial_args: [], module: Mqtt.Listener, state: []}, ping: {[], []}, status: :down}], [file: 'lib/tortoise/connection/controller.ex', line: 185]}, {:gen_server, :try_dispatch, 4, [file: 'gen_server.erl', line: 637]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 711]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}
 
  undefined
I  08:20:49.977 [debug] mqtt broker state in terminate:  => data: #{:function_clause, [{Tortoise.Connection.Controller, :handle_info, [{{Tortoise, "mqtt_manager:l42j6:dev"}, #Reference<0.2704242570.975699970.60041>, :ok}, %Tortoise.Connection.Controller{awaiting: %{}, client_id: "mqtt_manager:l42j6:prod", handler: %Tortoise.Handler{initial_args: [], module: Mqtt.Listener, state: []}, ping: {[], []}, status: :down}], [file: 'lib/tortoise/connection/controller.ex', line: 185]}, {:gen_server, :try_dispatch, 4, [file: 'gen_server.erl', line: 637]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 711]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}
 
I  08:19:50.213 [debug] mqtt broker state in terminate:  => data: #{:function_clause, [{Tortoise.Connection.Controller, :handle_info, [{{Tortoise, "mqtt_manager:l42j6:dev"}, #Reference<0.2704242570.975699970.59852>, :ok}, %Tortoise.Connection.Controller{awaiting: %{}, client_id: "mqtt_manager:l42j6:prod", handler: %Tortoise.Handler{initial_args: [], module: Mqtt.Listener, state: []}, ping: {[], []}, status: :up}], [file: 'lib/tortoise/connection/controller.ex', line: 185]}, {:gen_server, :try_dispatch, 4, [file: 'gen_server.erl', line: 637]}, {:gen_server, :handle_msg, 6, [file: 'gen_server.erl', line: 711]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}
 
  undefined
I  08:02:00.555 [debug] mqtt broker state:  => data: #:up
 
  undefined
I  08:02:00.463 [debug] mqtt broker state:  => data: #:up
 
  undefined

[brianmay]

My understanding is that the terminate() function should only every be called if the process is about to die, e.g it has crashed due to raised exception. Shouldn't happen for connection drops. See my bug report for details https://github.com/gausby/tortoise/issues/97. As for why this might be happening I have no idea.

[tanweerdev]

@brianmay tortoise version : 0.9.4

[tanweerdev]

and here is how we are connecting to brokers

defmodule MqttManager.Application do
  use Application

  def start(_type, _args) do
    import Supervisor.Spec, warn: false

    children = [
      {Tortoise.Supervisor,
      [
        name: MyApp.Connection.Supervisor,
        strategy: :one_for_one
      ]}
    ]

    {:ok, pid} =
      Supervisor.start_link(children, strategy: :one_for_one, name: MqttManager.Supervisor)

    connect_to_brokers()

    {:ok, pid}
  end

  def connect_to_brokers() do
    port = Application.get_env(:mqtt_manager, VERNMQ)[:port]
    app_env = Application.get_env(:mqtt_manager, VERNMQ)[:app_env]
    subscriptions = Application.get_env(:mqtt_manager, VERNMQ)[:subscriptions]

    subscriptions_dev =
      Application.get_env(:mqtt_manager, VERNMQ)[:subscriptions_dev]

    subscriptions_stg =
      Application.get_env(:mqtt_manager, VERNMQ)[:subscriptions_stg]

    client_id_prod = MqttManager.MqttEnv.client_id("prod")
    handler_prod = {Mqtt.Listener, []}
    password_prod = Application.get_env(:mqtt_manager, VERNMQ)[:mqtt_host_pwd_prod]
    host_prod = Application.get_env(:mqtt_manager, VERNMQ)[:mqtt_host_prod]

    if app_env != "prod" do
      handler = {Mqtt.Listener, []}
      client_id = MqttManager.MqttEnv.client_id(app_env)
      password = Application.get_env(:mqtt_manager, VERNMQ)[:mqtt_broker_pwd]
      host = Application.get_env(:mqtt_manager, VERNMQ)[:host]
      _connect_to_broker(host, client_id, handler, port, password, subscriptions)
    end

    case app_env do
      "prod" ->
        _connect_to_broker(
          host_prod,
          client_id_prod,
          handler_prod,
          port,
          password_prod,
          subscriptions
        )

      env when env in ["stage", "dev", "stg"] ->
        subscriptions_env = if env == "dev", do: subscriptions_dev, else: subscriptions_stg

        _connect_to_broker(
          host_prod,
          client_id_prod,
          handler_prod,
          port,
          password_prod,
          subscriptions_env
        )

      _ ->
        nil
    end
  end

  defp _connect_to_broker(host, client, handler, port, pwd, subscriptions) do
    Utils.BasicLogger.log_action_success(
      client,
      "client #{client} handler #{inspect(handler)} connect"
    )

    Tortoise.Supervisor.start_child(
      MyApp.Connection.Supervisor,
      client_id: client,
      handler: handler,
      user_name: "mqtt_manager",
      password: pwd,
      server: {Tortoise.Transport.Tcp, host: host, port: port},
      subscriptions: subscriptions
    )
  end
end

[gausby]

Hi. I am in the middle of moving to another country; so sorry for the lack of involvement from my side. I hope I will get back to tortoise development soon.

[gausby]

Tortoise should be busy trying to reestablish the connection when you receive the ":down" message; you shouldn't need to tell it to reconnect yourself.

My tired eyes cannot spot anything obviously wrong in the connection setup; how about your callback implementation; do you receive something unexpected that is not caught by a pattern match ?