defmodule MicrowavepropWeb.MetricsLogSuppressionTest do @moduledoc """ Regression test for the `/metrics` log-suppression bug. `Plug.forward/4` rewrites `conn.path_info` to the remainder after the matched prefix before dispatching to the forwarded plug. For the `forward "/metrics", MetricsPlug` route this means `path_info` is `[]` (and `script_name` is `["metrics"]`) by the time the response is being sent. Since `send_resp/2` runs inside the forwarded plug, the `register_before_send` callback installed by `Plug.Telemetry` sees the rewritten conn and the endpoint's `log_level/1` pattern on `path_info: ["metrics" | _]` never matches — so a `Sent 200 in Xms` line is logged on every Prometheus scrape. """ use MicrowavepropWeb.ConnCase, async: false import ExUnit.CaptureLog setup do # The project config sets :logger level to :warning in test, which # would drop the :info-level "Sent 200" line before capture_log ever # saw it. Bump to :info for this test so the suppression behaviour # is actually observable, then restore afterwards. prev_level = Logger.level() Logger.configure(level: :info) on_exit(fn -> Logger.configure(level: prev_level) end) :ok end test "GET /metrics does not emit a Phoenix endpoint Sent log line", %{conn: conn} do log = capture_log([level: :info], fn -> conn = get(conn, "/metrics") assert conn.status == 200 end) refute log =~ "Sent 200" end test "GET /live does not emit a Phoenix endpoint Sent log line", %{conn: conn} do log = capture_log([level: :info], fn -> conn = get(conn, "/live") assert conn.status == 200 end) refute log =~ "Sent 200" refute log =~ "GET /live" end test "log_level/1 returns false for /live", %{conn: _conn} do assert MicrowavepropWeb.Endpoint.log_level(%{ request_path: "/live", method: "GET" }) == false end test "log_level/1 returns false for the rewritten conn shape produced by forward", %{ conn: _conn } do # When Plug.forward dispatches to the MetricsPlug, the conn it passes # has path_info stripped (empty) and script_name holding the prefix. # Plug.Telemetry's before_send sees this exact shape. rewritten = %{ path_info: [], script_name: ["metrics"], request_path: "/metrics", method: "GET" } assert MicrowavepropWeb.Endpoint.log_level(rewritten) == false end test "log_level/1 returns false when the original method stashed before Plug.Head was HEAD" do # Plug.Head runs BEFORE Plug.Telemetry's register_before_send fires # and rewrites HEAD→GET, so matching `method: \"HEAD\"` at log time # never hits. Endpoint now stashes the original method in private # before Plug.Head runs; assert the filter keys off it. conn = %{ request_path: "/some/page", method: "GET", private: %{original_method: "HEAD"} } assert MicrowavepropWeb.Endpoint.log_level(conn) == false end test "HEAD request to a real route does not emit a Phoenix endpoint Sent log line", %{ conn: conn } do log = capture_log([level: :info], fn -> conn = dispatch(conn, MicrowavepropWeb.Endpoint, "HEAD", "/") assert conn.status in [200, 302] end) refute log =~ "Sent 200" refute log =~ "Sent 302" refute log =~ "HEAD /" end end