diff --git a/config/config.exs b/config/config.exs index 4fa96764..cf2597b6 100644 --- a/config/config.exs +++ b/config/config.exs @@ -49,7 +49,9 @@ config :logger, :default_handler, filters: [ # Suppress HTTP/0.9 and other invalid protocol errors from Bandit # These are typically from port scanners and automated bots - bandit_invalid_http: {&Towerops.LogFilter.filter_bandit_errors/2, []} + bandit_invalid_http: {&Towerops.LogFilter.filter_bandit_errors/2, []}, + # Suppress benign port_died and write_failed errors during K8s pod shutdown + shutdown_errors: {&Towerops.LoggerFilters.drop_shutdown_errors/2, []} ] # Register protobuf MIME type for agent API diff --git a/config/runtime.exs b/config/runtime.exs index 0ce71bc4..6a4e129e 100644 --- a/config/runtime.exs +++ b/config/runtime.exs @@ -151,6 +151,7 @@ if config_env() == :prod do config :towerops, Oban, engine: Oban.Pro.Engines.Smart, repo: Towerops.Repo, + shutdown_grace_period: to_timeout(second: 40), queues: [ default: 10, discovery: 10, diff --git a/lib/towerops/application.ex b/lib/towerops/application.ex index 4fb22fb2..2e4ad537 100644 --- a/lib/towerops/application.ex +++ b/lib/towerops/application.ex @@ -83,6 +83,9 @@ defmodule Towerops.Application do topologies = Application.get_env(:libcluster, :topologies, []) + # Supervision tree order matters for shutdown: children shut down in reverse start order. + # Oban is placed AFTER its dependencies (SnmpKit, TaskSupervisor) so it shuts down + # BEFORE them, allowing in-flight jobs to complete cleanly during the grace period. children = [ {Cluster.Supervisor, [topologies, [name: Towerops.ClusterSupervisor]]}, @@ -94,7 +97,6 @@ defmodule Towerops.Application do redis_spec(), # Rate limiting backend (ETS-based, per-node) {Towerops.RateLimit, [clean_period: to_timeout(minute: 1)]}, - {Oban, Application.fetch_env!(:towerops, Oban)}, {DNSCluster, query: Application.get_env(:towerops, :dns_cluster_query) || :ignore}, pubsub_spec(), # MIB name cache for fast profile matching (starts asynchronous pre-resolution) @@ -105,7 +107,9 @@ defmodule Towerops.Application do SnmpKit.SnmpMgr.Config, SnmpKit.SnmpMgr.MIB, # Task supervisor for fire-and-forget background tasks (e.g. polling data processing) - {Task.Supervisor, name: Towerops.TaskSupervisor} + {Task.Supervisor, name: Towerops.TaskSupervisor}, + # Oban after its dependencies so it drains jobs before they shut down + {Oban, Application.fetch_env!(:towerops, Oban)} ] ++ dev_only_workers() ++ background_workers() ++ diff --git a/lib/towerops/honeybadger_filter.ex b/lib/towerops/honeybadger_filter.ex index a5a7e9c6..63a2e312 100644 --- a/lib/towerops/honeybadger_filter.ex +++ b/lib/towerops/honeybadger_filter.ex @@ -136,6 +136,8 @@ defmodule Towerops.HoneybadgerFilter do :normal -> true :shutdown -> true {:shutdown, _} -> true + {:port_died, :normal} -> true + {:port_died, :shutdown} -> true _ -> false end end diff --git a/lib/towerops/honeybadger_notice_filter.ex b/lib/towerops/honeybadger_notice_filter.ex index 80f1bafb..b28f7ffa 100644 --- a/lib/towerops/honeybadger_notice_filter.ex +++ b/lib/towerops/honeybadger_notice_filter.ex @@ -20,8 +20,19 @@ defmodule Towerops.HoneybadgerNoticeFilter do @impl Honeybadger.NoticeFilter def filter(%Honeybadger.Notice{} = notice) do - send_error_email(notice) - notice + if shutdown_error?(notice) do + nil + else + send_error_email(notice) + notice + end + end + + defp shutdown_error?(%Honeybadger.Notice{error: error}) do + msg = error.message || "" + + String.contains?(msg, "port_died") or + (String.contains?(msg, "write_failed") and String.contains?(msg, "epipe")) end defp send_error_email(%Honeybadger.Notice{error: error, server: server}) do diff --git a/lib/towerops/logger_filters.ex b/lib/towerops/logger_filters.ex index b7e1732f..a29b9cb7 100644 --- a/lib/towerops/logger_filters.ex +++ b/lib/towerops/logger_filters.ex @@ -63,4 +63,22 @@ defmodule Towerops.LoggerFilters do end defp snmp_mib_error?(_), do: false + + @doc """ + Drops benign shutdown errors that occur during Kubernetes pod termination. + + These errors are expected when the BEAM shuts down inside a container: + - `{:port_died, :normal}` - SNMP polling jobs hold UDP sockets that become invalid + - `{:write_failed, ...} {:device, :epipe}` - Logger writes to stdout after container runtime closes the pipe + """ + def drop_shutdown_errors(log_event, _opts) do + if shutdown_log_message?(log_event), do: :stop, else: :ignore + end + + defp shutdown_log_message?(%{msg: {:string, msg}}) when is_binary(msg) do + String.contains?(msg, "port_died") or + (String.contains?(msg, "write_failed") and String.contains?(msg, "epipe")) + end + + defp shutdown_log_message?(_), do: false end diff --git a/test/towerops/honeybadger_filter_test.exs b/test/towerops/honeybadger_filter_test.exs index ac617dbe..5233af05 100644 --- a/test/towerops/honeybadger_filter_test.exs +++ b/test/towerops/honeybadger_filter_test.exs @@ -219,5 +219,21 @@ defmodule Towerops.HoneybadgerFilterTest do assert filtered == nil end + + test "filters port_died with :normal reason" do + context = %{reason: {:port_died, :normal}} + + filtered = HoneybadgerFilter.filter_context(context) + + assert filtered == nil + end + + test "filters port_died with :shutdown reason" do + context = %{reason: {:port_died, :shutdown}} + + filtered = HoneybadgerFilter.filter_context(context) + + assert filtered == nil + end end end diff --git a/test/towerops/honeybadger_notice_filter_test.exs b/test/towerops/honeybadger_notice_filter_test.exs index fb90bb3f..af2b3bb8 100644 --- a/test/towerops/honeybadger_notice_filter_test.exs +++ b/test/towerops/honeybadger_notice_filter_test.exs @@ -99,5 +99,59 @@ defmodule Towerops.HoneybadgerNoticeFilterTest do assert email.from == {"Towerops", "hi@towerops.net"} end) end + + test "drops notice with port_died error message (no email, no report)" do + notice = + build_notice(%{ + error: %{ + class: "ErlangError", + message: "Erlang error: {:port_died, :normal}" + } + }) + + assert HoneybadgerNoticeFilter.filter(notice) == nil + assert_no_email_sent() + end + + test "drops notice with write_failed and epipe error message" do + notice = + build_notice(%{ + error: %{ + class: "ErlangError", + message: "{:write_failed, :standard_io, :enoent, {:no_translation, :unicode, :latin1}} {:device, :epipe}" + } + }) + + assert HoneybadgerNoticeFilter.filter(notice) == nil + assert_no_email_sent() + end + + test "does not drop write_failed without epipe" do + notice = + build_notice(%{ + error: %{ + class: "ErlangError", + message: "{:write_failed, :standard_io, :enoent}" + } + }) + + result = HoneybadgerNoticeFilter.filter(notice) + + assert result == notice + end + + test "does not drop unrelated errors" do + notice = + build_notice(%{ + error: %{ + class: "RuntimeError", + message: "something totally unrelated" + } + }) + + result = HoneybadgerNoticeFilter.filter(notice) + + assert result == notice + end end end diff --git a/test/towerops/logger_filters_test.exs b/test/towerops/logger_filters_test.exs index 77e67f7c..5ae417ff 100644 --- a/test/towerops/logger_filters_test.exs +++ b/test/towerops/logger_filters_test.exs @@ -143,4 +143,52 @@ defmodule Towerops.LoggerFiltersTest do assert LoggerFilters.drop_oban_shutdown(log_event, %{key: "value"}) == :ignore end end + + describe "drop_shutdown_errors/2" do + test "stops port_died log messages" do + log_event = %{ + msg: {:string, "Erlang error: {:port_died, :normal}"} + } + + assert LoggerFilters.drop_shutdown_errors(log_event, []) == :stop + end + + test "stops write_failed with epipe log messages" do + log_event = %{ + msg: {:string, "{:write_failed, :standard_io, :enoent, {:no_translation, :unicode, :latin1}} {:device, :epipe}"} + } + + assert LoggerFilters.drop_shutdown_errors(log_event, []) == :stop + end + + test "ignores write_failed without epipe" do + log_event = %{ + msg: {:string, "{:write_failed, :standard_io, :enoent}"} + } + + assert LoggerFilters.drop_shutdown_errors(log_event, []) == :ignore + end + + test "ignores normal log messages" do + log_event = %{ + msg: {:string, "Some regular log message"} + } + + assert LoggerFilters.drop_shutdown_errors(log_event, []) == :ignore + end + + test "ignores non-string log messages" do + log_event = %{ + msg: {:report, %{some: :data}} + } + + assert LoggerFilters.drop_shutdown_errors(log_event, []) == :ignore + end + + test "ignores log events with nil message" do + log_event = %{msg: nil} + + assert LoggerFilters.drop_shutdown_errors(log_event, []) == :ignore + end + end end