fix: suppress benign shutdown errors during K8s pod rollouts

Filter port_died and write_failed/epipe errors from Honeybadger reports,
email notifications, and logs. Reorder supervision tree so Oban drains
before its dependencies shut down, and add 40s shutdown grace period.
This commit is contained in:
Graham McIntire 2026-02-12 12:16:40 -06:00
parent bafa7fd8c7
commit c6a4e88a4a
No known key found for this signature in database
9 changed files with 161 additions and 5 deletions

View file

@ -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

View file

@ -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,

View file

@ -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() ++

View file

@ -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

View file

@ -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

View file

@ -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

View file

@ -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

View file

@ -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

View file

@ -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