From 8dc713ce3f3bf2c84b69a04c308250635aedbf10 Mon Sep 17 00:00:00 2001
From: Graham McIntire <graham@mcintire.me>
Date: Sat, 25 Oct 2025 17:04:59 -0500
Subject: [PATCH] Add info logging for mobile websocket events and filter
 healthcheck logs

- Add info-level logging to all mobile websocket handle_in callbacks to track
  incoming messages (subscribe_bounds, update_bounds, search_callsign, etc.)
- Create LogFilter plug to exclude K8s healthcheck requests from Phoenix logs
- Filter logs for /health, /ready, and / endpoints to reduce noise from
  continuous healthcheck probes
- Configure Plug.Telemetry to use custom log level function

This eliminates noisy healthcheck logs while providing better visibility
into mobile websocket API usage.
---
 lib/aprsme_web/channels/mobile_channel.ex | 26 +++++++++++++++++------
 lib/aprsme_web/endpoint.ex                |  2 +-
 lib/aprsme_web/plugs/log_filter.ex        | 26 +++++++++++++++++++++++
 3 files changed, 46 insertions(+), 8 deletions(-)
 create mode 100644 lib/aprsme_web/plugs/log_filter.ex

diff --git a/lib/aprsme_web/channels/mobile_channel.ex b/lib/aprsme_web/channels/mobile_channel.ex
index 8ef6272..d25897b 100644
--- a/lib/aprsme_web/channels/mobile_channel.ex
+++ b/lib/aprsme_web/channels/mobile_channel.ex
@@ -66,6 +66,8 @@ defmodule AprsmeWeb.MobileChannel do
         %{"north" => north, "south" => south, "east" => east, "west" => west} = payload,
         socket
       ) do
+    Logger.info("Mobile websocket received subscribe_bounds: #{inspect(payload)}")
+
     bounds = %{
       north: ensure_float(north),
       south: ensure_float(south),
@@ -102,7 +104,13 @@ defmodule AprsmeWeb.MobileChannel do
   end
 
   @impl true
-  def handle_in("update_bounds", %{"north" => north, "south" => south, "east" => east, "west" => west}, socket) do
+  def handle_in(
+        "update_bounds",
+        %{"north" => north, "south" => south, "east" => east, "west" => west} = payload,
+        socket
+      ) do
+    Logger.info("Mobile websocket received update_bounds: #{inspect(payload)}")
+
     bounds = %{
       north: ensure_float(north),
       south: ensure_float(south),
@@ -138,7 +146,9 @@ defmodule AprsmeWeb.MobileChannel do
   end
 
   @impl true
-  def handle_in("unsubscribe", _payload, socket) do
+  def handle_in("unsubscribe", payload, socket) do
+    Logger.info("Mobile websocket received unsubscribe: #{inspect(payload)}")
+
     if socket.assigns[:subscribed] && socket.assigns[:bounds] do
       Aprsme.StreamingPacketsPubSub.unsubscribe(self())
 
@@ -157,11 +167,11 @@ defmodule AprsmeWeb.MobileChannel do
 
   @impl true
   def handle_in("search_callsign", %{"query" => query} = payload, socket) do
+    Logger.info("Mobile websocket received search_callsign: #{inspect(payload)}")
+
     limit = Map.get(payload, "limit", 50)
     limit = min(limit, 500)
 
-    Logger.debug("Mobile client searching for callsign: #{query}")
-
     results = search_callsign(query, limit)
 
     {:reply, {:ok, %{results: results, count: length(results)}}, socket}
@@ -169,6 +179,8 @@ defmodule AprsmeWeb.MobileChannel do
 
   @impl true
   def handle_in("subscribe_callsign", %{"callsign" => callsign} = payload, socket) do
+    Logger.info("Mobile websocket received subscribe_callsign: #{inspect(payload)}")
+
     hours_back = Map.get(payload, "hours_back", 24)
     # Max 1 week
     hours_back = min(hours_back, 168)
@@ -176,8 +188,6 @@ defmodule AprsmeWeb.MobileChannel do
     # Normalize callsign to uppercase
     callsign = String.upcase(callsign)
 
-    Logger.info("Mobile client #{socket.assigns[:client_id]} subscribing to callsign: #{callsign}")
-
     # Load historical packets for this callsign
     socket = load_callsign_history(socket, callsign, hours_back)
 
@@ -188,7 +198,9 @@ defmodule AprsmeWeb.MobileChannel do
   end
 
   @impl true
-  def handle_in("unsubscribe_callsign", _payload, socket) do
+  def handle_in("unsubscribe_callsign", payload, socket) do
+    Logger.info("Mobile websocket received unsubscribe_callsign: #{inspect(payload)}")
+
     if socket.assigns[:tracked_callsign] do
       callsign = socket.assigns.tracked_callsign
       socket = assign(socket, :tracked_callsign, nil)
diff --git a/lib/aprsme_web/endpoint.ex b/lib/aprsme_web/endpoint.ex
index 726a88d..23ec002 100644
--- a/lib/aprsme_web/endpoint.ex
+++ b/lib/aprsme_web/endpoint.ex
@@ -45,7 +45,7 @@ defmodule AprsmeWeb.Endpoint do
     cookie_key: "request_logger"
 
   plug Plug.RequestId
-  plug Plug.Telemetry, event_prefix: [:phoenix, :endpoint]
+  plug Plug.Telemetry, event_prefix: [:phoenix, :endpoint], log: {AprsmeWeb.Plugs.LogFilter, :log_level, []}
 
   plug Plug.Parsers,
     parsers: [:urlencoded, :multipart, :json],
diff --git a/lib/aprsme_web/plugs/log_filter.ex b/lib/aprsme_web/plugs/log_filter.ex
new file mode 100644
index 0000000..74833cd
--- /dev/null
+++ b/lib/aprsme_web/plugs/log_filter.ex
@@ -0,0 +1,26 @@
+defmodule AprsmeWeb.Plugs.LogFilter do
+  @moduledoc """
+  Log filter that excludes healthcheck and other noisy requests from Phoenix logs.
+
+  Used by Plug.Telemetry to determine the log level for requests.
+  Returns `false` for requests that shouldn't be logged (like K8s healthchecks),
+  or `:info` for normal requests.
+  """
+
+  @doc """
+  Determines the log level for a given request.
+
+  Returns `false` to skip logging, or `:info` to log at info level.
+  """
+  def log_level(conn) do
+    if should_skip_logging?(conn) do
+      false
+    else
+      :info
+    end
+  end
+
+  defp should_skip_logging?(conn) do
+    conn.request_path in ["/health", "/ready", "/"]
+  end
+end