Current section

Files

Jump to
electric lib electric telemetry system_monitor.ex
Raw

lib/electric/telemetry/system_monitor.ex

defmodule Electric.Telemetry.SystemMonitor do
@moduledoc """
Application-wide process that initializes Erlang's system monitor and consumes monitoring events.
Currently the follow events are tracked:
- long_gc
- long_schedule
- long_message_queue
"""
use GenServer
import Electric.Telemetry.Processes, only: [proc_type: 1]
require Logger
@vm_monitor_long_gc [:vm, :monitor, :long_gc]
@vm_monitor_long_schedule [:vm, :monitor, :long_schedule]
@vm_monitor_long_message_queue [:vm, :monitor, :long_message_queue]
def start_link(opts) do
GenServer.start_link(__MODULE__, opts, name: __MODULE__)
end
def init(opts) do
:erlang.system_monitor(self(),
long_gc: opts.long_gc_threshold,
long_schedule: opts.long_schedule_threshold,
long_message_queue:
{opts.long_message_queue_disable_threshold, opts.long_message_queue_enable_threshold}
)
{:ok, %{long_message_queue_pids: %{}, long_message_queue_timer: nil}}
end
def handle_info({:monitor, gc_pid, :long_gc, info}, state) do
type = proc_type(gc_pid)
Logger.debug(
"Long GC detected for pid #{inspect(gc_pid)} (#{inspect(type)}): took #{Keyword.fetch!(info, :timeout)}ms. #{inspect(info, limit: :infinity)}"
)
:telemetry.execute(@vm_monitor_long_gc, Map.new(info), %{process_type: type})
{:noreply, state}
end
def handle_info({:monitor, port, :long_schedule, info}, state) when is_port(port) do
Logger.debug(
"Long schedule detected for port #{inspect(port)}, took #{Keyword.fetch!(info, :timeout)}ms"
)
:telemetry.execute(@vm_monitor_long_schedule, Map.new(info), %{process_type: :port})
{:noreply, state}
end
def handle_info({:monitor, pid, :long_schedule, info}, state) when is_pid(pid) do
type = proc_type(pid)
Logger.debug(fn ->
locations =
info
|> Keyword.delete(:timeout)
|> Map.new(fn {loc, {m, f, a}} when loc in [:in, :out] ->
{loc, Exception.format_mfa(m, f, a)}
end)
locs_str =
if map_size(locations) > 0 do
"; " <>
(locations |> Enum.map(fn {key, val} -> "#{key}: #{val}" end) |> Enum.join(", "))
else
""
end
"Long schedule detected for pid #{inspect(pid)} (#{inspect(type)}), took #{Keyword.fetch!(info, :timeout)}ms" <>
locs_str
end)
:telemetry.execute(@vm_monitor_long_schedule, %{timeout: Keyword.fetch!(info, :timeout)}, %{
process_type: type
})
{:noreply, state}
end
def handle_info({:monitor, pid, :long_message_queue, true}, state) do
type = proc_type(pid)
Logger.debug("Long message queue detected for pid #{inspect(pid)} (#{inspect(type)})")
log_long_message_queue_event(pid, type)
state =
%{state | long_message_queue_pids: Map.put(state.long_message_queue_pids, pid, type)}
|> maybe_start_long_message_queue_timer()
{:noreply, state}
end
def handle_info({:monitor, pid, :long_message_queue, false}, state) do
Logger.debug("Long message queue no longer detected for pid #{inspect(pid)}")
{:noreply, %{state | long_message_queue_pids: Map.delete(state.long_message_queue_pids, pid)}}
end
def handle_info(:recheck_message_queues, state)
when map_size(state.long_message_queue_pids) == 0 do
:timer.cancel(state.long_message_queue_timer)
{:noreply, %{state | long_message_queue_timer: nil}}
end
def handle_info(:recheck_message_queues, state) do
Enum.each(state.long_message_queue_pids, fn {pid, type} ->
log_long_message_queue_event(pid, type)
end)
{:noreply, state}
end
defp log_long_message_queue_event(pid, type) do
with {:message_queue_len, queue_len} <- Process.info(pid, :message_queue_len) do
:telemetry.execute(@vm_monitor_long_message_queue, %{length: queue_len}, %{
process_type: type
})
end
end
defp maybe_start_long_message_queue_timer(%{long_message_queue_timer: nil} = state) do
# A process whose message queue length exceeds the threshold is likely to be spiraling out of
# control. Therefore we need recheck it quite often to capture the dynamics.
#
# Though there's still no guarantee that the VM will not run out of memory before it
# reaches the next metric export tick.
{:ok, timer} = :timer.send_interval(200, :recheck_message_queues)
%{state | long_message_queue_timer: timer}
end
defp maybe_start_long_message_queue_timer(state), do: state
end