time_log

defmodule TimeLog.TimePlug do
  import Plug.Conn
  require Logger
  alias TimeLog.PreLogPlug
  @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.
  """

  @doc false
  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
  @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.
  """
  @doc false
  def init(_opts) do
    {}
  end

  def call(conn, _opts) do
    log_request conn
  end

  @doc ~S"""
  Logs the request including the IP address
  """
  @spec log_request(Plug.Conn)::Plug.Conn
  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

  @doc ~S"""
  Returns the IP address in a Format fit for logging.
  If set in config the IP addresses retourned are anonymized by replacing the last digits with 'XXX'.
  Requests that use internal (e.g. company) Ip addresses can be filtered if set in config(`config :time_log, internal_ips: ["127.0.0.1"]`).
  """
  @spec get_ip(Plug.Conn)::String
  def get_ip(conn) do
    header_map = conn.req_headers |> Enum.into(%{})
    ip = if is_nil(header_map["x-forwarded-for"]), do: conn.remote_ip |> Tuple.to_list |> Enum.join(".") , 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