Elixir, Phoenix and Ecto : When database is down, requests to serve cached data become really slow (from 100ms to 3 seconds)

Question

I created a phoenix project with --no-html and --database mysql

The version we're using at work is :

Erlang/OTP 21 [erts-10.2] [source] [64-bit] [smp:12:12] [ds:12:12:10] [async-threads:1] [hipe]

Elixir 1.8.0 (compiled with Erlang/OTP 20)

I'm doing a project that serves as a proxy between a status page tool (hund.io) and our own APIs and reporting tools, so I needed a database to store services names + url to requests, and, as I need a bit to dissociate with the database Cachex (https://github.com/whitfin/cachex) to put my data in cache

When data is cached, using postman to request my wrapper's api it takes ~100ms to get a response and phoenix's logs say things like [info] Sent 200 in 1ms But, I ever shut the database down, it goes up to 3 whole seconds for postman to get a response, phoenix logs still say that kind of things [info] Sent 200 in 1ms

I know for sure that the wrapper uses cached data in both cases :

My code :

def show(conn, %{"service_name" => service_name}) do
    Logger.debug("Top of show func")

    case Cachex.get(:proxies, service_name) do
      {:ok, nil} ->
        Logger.debug("Service #{service_name} not found in cache")
        proxy = Health.get_proxy_by_name!(service_name)
        Logger.debug("Service #{service_name} found in db")
        Cachex.put(:proxies, service_name, proxy)
        proxy_with_health = Checker.call_api(proxy)

        render(conn, "show.json", proxy_health: proxy_with_health)

      {:ok, proxy} ->
        Logger.debug("Found service #{service_name} in cache")
        proxy_with_health = Checker.call_api(proxy)
        render(conn, "show.json", proxy_health: proxy_with_health)
    end
  end

The log :

[info] GET /api/proxies_health/docto
[debug] Processing with StatusWeb.ProxyHealthController.show/2
  Parameters: %{"service_name" => "docto"}
  Pipelines: [:api]
[debug] Top of show func
[debug] Found service docto in cache

For the router part :

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

  scope "/api", StatusWeb do
    pipe_through :api

    resources "/proxies", ProxyController, except: [:new, :edit]
    get "/proxies_health", ProxyHealthController, :index
    get "/proxies_health/:service_name", ProxyHealthController, :show
  end

I also get two errors in the logs :

[error] MyXQL.Connection (#PID<0.373.0>) failed to connect: ** (DBConnection.ConnectionError) connection refused

Which seems "normal", continuously as the application wants to reconnect to the database and this one, right before a request is processed (at least according to the logs)

[error] Could not create schema migrations table. This error usually happens due to the following:

  * The database does not exist
  * The "schema_migrations" table, which Ecto uses for managing
    migrations, was defined by another library
  * There is a deadlock while migrating (such as using concurrent
    indexes with a migration_lock)

To fix the first issue, run "mix ecto.create".

To address the second, you can run "mix ecto.drop" followed by
"mix ecto.create". Alternatively you may configure Ecto to use
another table and/or repository for managing migrations:

    config :status, Status.Repo,
      migration_source: "some_other_table_for_schema_migrations",
      migration_repo: AnotherRepoForSchemaMigrations

The full error report is shown below.

[error] GenServer #PID<0.620.0> terminating
** (DBConnection.ConnectionError) connection refused
    (db_connection) lib/db_connection/connection.ex:100: DBConnection.Connection.connect/2
    (connection) lib/connection.ex:622: Connection.enter_connect/5
    (stdlib) proc_lib.erl:249: :proc_lib.init_p_do_apply/3
Last message: nil
State: MyXQL.Connection

I tried to put in my Status.Repo file (repo.ex) while looking at How do I detect database connection issues from Elixir Ecto?

backoff_type: :stop

but it changed nothing to my issue

Answer 1

As my code, in the path were an object is found in the cache doesn't (at all) involve the database, we finally found on discord that the problem comes from a plug in the endpoint which should be present only in dev environment (MyAppWeb/endpoint.ex)

   if code_reloading? do
      plug Phoenix.CodeReloader
      plug Phoenix.Ecto.CheckRepoStatus, otp_app: :status
  end

It's a plug which will check, at each request, if the database is up, if the migrations were run etc Waiting for an answer from Ecto, with a timeout in the genserver realizing the call resulted in the delay experienced !

The fix is to simply comment the line

          plug Phoenix.Ecto.CheckRepoStatus, otp_app: :status