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