time_log

defmodule TimeLog.TimePlug do
  import Plug.Conn
  require Logger
  alias TimeLog.PreLogPlug
  @bahaviour Plug
  @moduledoc ~S"""
  This plug stops the time a request takes.
  The plug needs to be called as early in the `endpoint.ex` as possible, ideally right after the socked received a request.
  Additionally the get_duration function can be called from everywhere in order to know how long the request took so far.
  """

  def init(_opts) do
    {}
  end

  def call(conn, _opts) do
    start_time = Time.utc_now
    conn
    |> put_private(:time_plug_start_time, start_time)
    |> Plug.Conn.register_before_send(&log_response(&1, start_time))

  end

  def log_response(conn, start_time) do
    [c_id] = get_resp_header(conn, "correlation_id")
    if :controller_body in Map.keys(conn.private) do
      http_struct = %{method: conn.method, url: conn.request_path, query: conn.query_string, header: inspect(conn.resp_headers),
                      ip_address: PreLogPlug.get_ip(conn), body: Poison.encode!(conn.private[:controller_body]),
                      status_code: conn.status, duration_ms: get_duration(start_time)}
      Logger.info(Poison.encode!(%{correlation_id: c_id, type: "Response", http: http_struct}), application_log: 1)
    else
        http_struct = %{method: conn.method, url: conn.request_path, query: conn.query_string, header: inspect(conn.resp_headers),
                        ip_address: PreLogPlug.get_ip(conn), body: "There was no body for this request",
                        status_code: conn.status, duration_ms: get_duration(start_time)}
      Logger.info(Poison.encode!(%{correlation_id: c_id, type: "Response", http: http_struct}), application_log: 1)
    end
    conn
  end

  @doc ~S"""
  Returns the time in ms the request took so far.
  May be called with either a Time struct https://hexdocs.pm/elixir/Time.html or with the current conn https://hexdocs/pm/plug/Plug.Conn.html.

  ## Examples

  iex> TimeLog.TimePlug.get_duration(conn)
  ~T[09:24:20.296862]

  iex> start_time = Time.utc_now
  ...
  ...
  iex> TimeLog.TimePlug.get_duration(start_time)
  65
  """
  @spec get_duration(Time)::Time
  def get_duration(start_time = %Time{}) do
    Time.utc_now
    |> Time.diff(start_time, :milliseconds)
    |> round
  end
  @spec get_duration(Plug.Conn)::Time
  def get_duration(conn = %Plug.Conn{}) do
    Time.utc_now
    |> Time.diff(conn.private[:time_plug_start_time], :milliseconds)
    |> round
  end
end

# -----------------------------------------------------------------------

defmodule TimeLog.PreLogPlug do
  import Plug.Conn
  require Logger
  @bahaviour Plug
  @moduledoc ~S"""
  This plug logs the incoming requests.
  It logs the IP address and has the ability to anonymize the IP address if set in config.
  Allows calls to get_ip from other apps too.
  """

  def init(_opts) do
    {}
  end

  def call(conn, _opts) do
    log_request conn
  end

  def log_request(conn) do
    unless conn.request_path in Application.get_env(:time_log, :ignore_urls) do
      [c_id] = if is_nil(get_resp_header(conn, "correlation_id")), do: get_resp_header(conn, "x-request-id"), else: get_resp_header(conn, "correlation_id")
      http_struct = %{method: conn.method, url: conn.request_path, query: conn.query_string, ip_address: get_ip(conn), header: inspect(conn.req_headers), params: Poison.encode!(conn.params)}
      Logger.info Poison.encode!(%{correlation_id: c_id, type: "Request", http: http_struct}), application_log: 1
    end
    conn
  end

  def get_ip(conn) do
    header_map = conn.req_headers |> Enum.into(%{})
    ip = if is_nil(header_map["x-forwarded-for"]), do: "Not forwarded", else: header_map["x-forwarded-for"]
    |> String.split(",")
    |> List.first
    Logger.debug "IP: #{ip}"
    cond do
      ip in Application.get_env(:time_log, :internal_ips) -> Application.get_env(:time_log, :internal_name)
      Application.get_env(:time_log, :anonymize_ips?) -> String.replace(ip, "\.\d{1,3}$", "\.XXX")
      true -> ip
    end
  end
end