diff --git a/lib/sentry/config.ex b/lib/sentry/config.ex index 9c2d48fd..7e3385ba 100644 --- a/lib/sentry/config.ex +++ b/lib/sentry/config.ex @@ -519,7 +519,7 @@ defmodule Sentry.Config do default: [], doc: """ Configuration for the BEAM runtime metrics collector, which periodically - reports total, process, binary, ETS and atom memory usage in bytes. + reports memory usage in bytes and scheduler utilization. *Available since 14.0.0*. """, keys: [ diff --git a/lib/sentry/metrics.ex b/lib/sentry/metrics.ex index a910ef4e..a2063a08 100644 --- a/lib/sentry/metrics.ex +++ b/lib/sentry/metrics.ex @@ -37,6 +37,8 @@ defmodule Sentry.Metrics do Once enabled, a supervised collector reports these gauges every 30 seconds: + * `elixir.runtime.scheduler.utilization` — busy fraction of scheduler time, + as a ratio between `0.0` and `1.0` * `elixir.runtime.mem.total`, `elixir.runtime.mem.processes`, `elixir.runtime.mem.binary`, `elixir.runtime.mem.ets`, `elixir.runtime.mem.atom` — in bytes diff --git a/lib/sentry/metrics/runtime.ex b/lib/sentry/metrics/runtime.ex index c56a7d51..66e5861a 100644 --- a/lib/sentry/metrics/runtime.ex +++ b/lib/sentry/metrics/runtime.ex @@ -15,7 +15,7 @@ defmodule Sentry.Metrics.Runtime do # collectors behave consistently across Sentry SDKs. @min_interval 1_000 - defstruct [:interval, :attributes, :memory_available?] + defstruct [:interval, :attributes, :memory_available?, :normal_schedulers, :scheduler_sample] @spec start_link(keyword()) :: GenServer.on_start() def start_link(opts) when is_list(opts) do @@ -32,24 +32,39 @@ defmodule Sentry.Metrics.Runtime do version_attributes(Keyword.get(opts, :version_attributes, false)) ) + _ = :erlang.system_flag(:scheduler_wall_time, true) + schedule_tick(interval) + normal_schedulers = :erlang.system_info(:schedulers) + {:ok, %__MODULE__{ interval: interval, attributes: attributes, - memory_available?: memory_available?() + memory_available?: memory_available?(), + normal_schedulers: normal_schedulers, + scheduler_sample: scheduler_sample(normal_schedulers) }} end @impl true def handle_info(:tick, %__MODULE__{} = state) do - collect_and_emit(state) + state = collect_and_emit(state) schedule_tick(state.interval) {:noreply, state} end defp collect_and_emit(%__MODULE__{} = state) do + sample = scheduler_sample(state.normal_schedulers) + + gauge( + state, + "elixir.runtime.scheduler.utilization", + utilization(state.scheduler_sample, sample), + unit: "ratio" + ) + if state.memory_available? do memory = :erlang.memory() @@ -58,7 +73,32 @@ defmodule Sentry.Metrics.Runtime do end) end - :ok + %{state | scheduler_sample: sample} + end + + # `:scheduler_wall_time` also reports dirty CPU schedulers, whose ids run above the normal + # ones. They stay idle unless the application runs dirty NIFs, yet their wall time still + # advances, so counting them roughly halves the reported utilization. + defp scheduler_sample(normal_schedulers) do + case :erlang.statistics(:scheduler_wall_time) do + :undefined -> + [] + + sample -> + sample + |> Enum.filter(fn {id, _active, _total} -> id <= normal_schedulers end) + |> Enum.sort() + end + end + + defp utilization(previous, current) do + {active, total} = + Enum.zip(previous, current) + |> Enum.reduce({0, 0}, fn {{_, active0, total0}, {_, active1, total1}}, {active, total} -> + {active + (active1 - active0), total + (total1 - total0)} + end) + + if total > 0, do: active / total, else: 0.0 end # `:erlang.memory/0` raises `notsup` when an `erts_alloc` allocator was disabled at boot. diff --git a/test/sentry/metrics/runtime_test.exs b/test/sentry/metrics/runtime_test.exs index a68a270f..332ef6ed 100644 --- a/test/sentry/metrics/runtime_test.exs +++ b/test/sentry/metrics/runtime_test.exs @@ -6,7 +6,8 @@ defmodule Sentry.Metrics.RuntimeTest do alias Sentry.Metrics.Runtime - @gauge_count 5 + @gauge_count 6 + @memory_gauge_count 5 setup do Sentry.Test.setup_sentry( @@ -71,7 +72,7 @@ defmodule Sentry.Metrics.RuntimeTest do end describe "unsupported memory measurement" do - test "stays alive and reports nothing when memory cannot be measured", %{ref: ref} do + test "skips only the memory gauges when memory cannot be measured", %{ref: ref} do pid = start_collector([]) # `:erlang.memory/0` raises `notsup` on a VM booted with a disabled allocator, which @@ -81,8 +82,37 @@ defmodule Sentry.Metrics.RuntimeTest do send(pid, :tick) :sys.get_state(pid) + names = + ref + |> collect_sentry_metric_items(@gauge_count - @memory_gauge_count, timeout: 2_000) + |> Enum.flat_map(& &1["items"]) + |> Enum.map(& &1["name"]) + assert Process.alive?(pid) - refute_receive {:bypass_envelope, ^ref, _body}, 200 + refute Enum.any?(names, &String.starts_with?(&1, "elixir.runtime.mem.")) + assert "elixir.runtime.scheduler.utilization" in names + end + end + + describe "scheduler utilization" do + test "reports scheduler utilization as a ratio", %{ref: ref} do + collect_once() + + assert metric = find_metric(ref, "elixir.runtime.scheduler.utilization") + assert metric["type"] == "gauge" + assert metric["unit"] == "ratio" + assert metric["value"] >= 0.0 + assert metric["value"] <= 1.0 + end + + test "reports near-full utilization when every scheduler is busy", %{ref: ref} do + pid = start_collector([]) + + saturate_schedulers(400) + send(pid, :tick) + + assert metric = find_metric(ref, "elixir.runtime.scheduler.utilization") + assert metric["value"] > 0.8 end end @@ -214,6 +244,26 @@ defmodule Sentry.Metrics.RuntimeTest do |> Enum.flat_map(& &1["items"]) end + defp saturate_schedulers(duration_ms) do + parent = self() + + pids = + for _ <- 1..:erlang.system_info(:schedulers_online) do + spawn(fn -> + deadline = System.monotonic_time(:millisecond) + duration_ms + + spin = fn f -> + if System.monotonic_time(:millisecond) < deadline, do: f.(f), else: :ok + end + + spin.(spin) + send(parent, {:spun, self()}) + end) + end + + for pid <- pids, do: assert_receive({:spun, ^pid}, duration_ms * 10) + end + defp find_metric(ref, name) do Enum.find(snapshot(ref), &(&1["name"] == name)) end