API heartbeat take around 100ms to reply

I created an API to check if my server is alive, after checking the log I saw my reply take >= 100s from the server but on my computer, it takes about 8ms… Can someone tell me why?

Log

14:06:29.154 request_id=XXX [info] GET /api/heartbeat
14:06:29.154 request_id=XXX [info] Sent 200 in 306s
14:06:34.155 request_id=XXX [info] GET /api/heartbeat
14:06:34.155 request_id=XXX [info] Sent 200 in 86s
14:06:39.153 request_id=XXX [info] GET /api/heartbeat
14:06:39.153 request_id=XXX [info] Sent 200 in 112s

API

def api_heartbeat(conn, _params) do
    send_resp(conn, :ok, "")
end

Route

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

scope "/api", PhoenixTWeb do
    pipe_through :api

    get "/heartbeat", PageController, :api_heartbeat
end

mix.exs

defmodule PhoenixT.MixProject do
  use Mix.Project

  def project do
    [
      app: :phoenix_t,
      version: "1.1.0",
      elixir: "1.8.2",
      elixirc_paths: elixirc_paths(Mix.env()),
      compilers: [:phoenix, :gettext] ++ Mix.compilers(),
      start_permanent: Mix.env() == :prod,
      deps: deps(),
      test_coverage: [tool: ExCoveralls],
      preferred_cli_env: [coveralls: :test, "coveralls.detail": :test, "coveralls.post": :test, "coveralls.html": :test]
    ]
  end

  # Configuration for the OTP application.
  #
  # Type `mix help compile.app` for more information.
  def application do
    [
      mod: {PhoenixT.Application, []},
      extra_applications: [:logger, :runtime_tools, :peerage]
    ]
  end

  # Specifies which paths to compile per environment.
  defp elixirc_paths(:test), do: ["lib", "test/support"]
  defp elixirc_paths(_), do: ["lib"]

  # Specifies your project dependencies.
  #
  # Type `mix help deps` for examples and options.
  defp deps do
    [
      {:phoenix, "~> 1.4.6"},
      {:phoenix_pubsub, "~> 1.1"},
      {:phoenix_html, "~> 2.11"},
      {:phoenix_live_reload, "~> 1.2", only: :dev},
      {:gettext, "~> 0.11"},
      {:jason, "~> 1.0"},
      {:plug_cowboy, "~> 2.0"},
      {:excoveralls, "~> 0.10", only: :test},
      {:distillery, "~> 2.0", override: true},
      {:peerage, "~> 1.0"},
    ]
  end
end

conf.exs

use Mix.Config

# Configures the endpoint
config :phoenix_t, PhoenixTWeb.Endpoint,
  url: [host: "localhost"],
  secret_key_base: "secret_key_base",
  render_errors: [view: PhoenixTWeb.ErrorView, accepts: ~w(html json)],
  pubsub: [name: PhoenixT.PubSub, adapter: Phoenix.PubSub.PG2]

# Configures Elixir's Logger
config :logger, :console,
  format: "$time $metadata[$level] $message\n",
  metadata: [:request_id]

# Use Jason for JSON parsing in Phoenix
config :phoenix, :json_library, Jason

# Import environment specific config. This must remain at the bottom
# of this file so it overrides the configuration defined above.
import_config "#{Mix.env()}.exs"

prod.exs

config :phoenix_t, PhoenixTWeb.Endpoint,
  http: [:inet6, port: "${PORT}"],
  url: [host: "${HOST}", port: "${PORT}"], # This is critical for ensuring web-sockets properly authorize.
  cache_static_manifest: "priv/static/cache_manifest.json",
  server: true,
  secret_key_base: "secret_key_base",
  root: ".",
  # TODO - Need to remove the ligne below
  check_origin: false,
  version: Application.spec(:phoenix_t, :vsn)

# Do not print debug messages in production
config :logger, level: :info

This looks like a terminal output problem, mine displays as Sent 200 in 92µs. Your terminal is probably having trouble displaying the µ

2 Likes

good point, what about the big gap from 86µs - 300µs ?

Mix lazy loads code. The first request always takes longer since it needs to get the code loaded. After that your 86microseconds and 112 microseconds are all pretty close. Keep in mind we’re talking about a difference of 20 millionths of a second.

5 Likes