Skip to content

feat: add metrics for auth_query and SecretChecker erpc calls #969

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
mentels wants to merge 7 commits into
base: main
Choose a base branch
from
Draft

feat: add metrics for auth_query and SecretChecker erpc calls #969

Show file tree
Hide file tree
Changes from 6 commits
Commits
Show all changes
7 commits
Select commit Hold shift + click to select a range
c6457a9
feat: add metrics for auth_query and SecretChecker erpc calls
mentels May 6, 2026
fa67901
chore: refactor and add missing tests
mentels May 7, 2026
0b68ea8
chore: make the test faster: from ~4s down to ~10ms
mentels May 7, 2026
f76e9dc
fixup! chore: make the test faster: from ~4s down to ~10ms
mentels May 7, 2026
8818e8f
fixup! fixup! chore: make the test faster: from ~4s down to ~10ms
mentels May 7, 2026
ea0dcec
fixup! fixup! fixup! chore: make the test faster: from ~4s down to ~10ms
mentels May 7, 2026
ecbf21b
WIP: add connection_listener
mentels May 19, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
53 changes: 38 additions & 15 deletions lib/supavisor/auth_query.ex
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ defmodule Supavisor.AuthQuery do

alias Supavisor.Errors.AuthQueryError
alias Supavisor.Helpers
alias Supavisor.Monitoring.Telem
alias Supavisor.Secrets.{ManagerSecrets, SASLSecrets}
alias Supavisor.Tenants.Tenant

Expand All @@ -17,20 +18,23 @@ defmodule Supavisor.AuthQuery do
def start_link(%Tenant{} = tenant, %ManagerSecrets{} = manager) do
ssl_opts = build_ssl_options(tenant)
ip_version = Helpers.ip_version(tenant.ip_version, tenant.db_host)
start = System.monotonic_time()

case Postgrex.start_link(
hostname: tenant.db_host,
port: tenant.db_port,
database: tenant.db_database,
password: manager.db_password,
username: manager.db_user,
parameters: [application_name: "Supavisor (auth_query)"],
ssl: tenant.upstream_ssl,
socket_options: [ip_version],
queue_target: 1_000,
queue_interval: 5_000,
ssl_opts: ssl_opts
) do
[
hostname: tenant.db_host,
port: tenant.db_port,
database: tenant.db_database,
password: manager.db_password,
username: manager.db_user,
parameters: [application_name: "Supavisor (auth_query)"],
ssl: tenant.upstream_ssl,
socket_options: [ip_version],
queue_target: 1_000,
queue_interval: 5_000,
ssl_opts: ssl_opts
]
|> Postgrex.start_link()

@v0idpwn v0idpwn May 7, 2026 •
edited
Loading

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Connection in postgrex is async unless we pass the sync flag, this function returns a pid even without the connection being complete, so the measurement won't get slow connections

|> case do
{:ok, pid} ->
{:ok, pid}

Expand All @@ -40,6 +44,7 @@ defmodule Supavisor.AuthQuery do
{:error, reason} ->
{:error, %AuthQueryError{reason: :connection_failed, details: inspect(reason)}}
end
|> tap(&telemetry_connection_stop(start, &1))
end

@doc """
Expand Down Expand Up @@ -96,11 +101,19 @@ defmodule Supavisor.AuthQuery do
"""
@spec fetch_user_secret(pid(), String.t() | nil, String.t()) ::
{:ok, SASLSecrets.t()} | {:error, AuthQueryError.t()}
def fetch_user_secret(_conn, nil, _user) do
def fetch_user_secret(conn, auth_query, user) do
start = System.monotonic_time()

conn
|> do_fetch_user_secret(auth_query, user)
|> tap(&telemetry_query_stop(start, &1))
end

defp do_fetch_user_secret(_conn, nil, _user) do
{:error, %AuthQueryError{reason: :no_auth_query}}
end

def fetch_user_secret(conn, auth_query, user) when is_binary(auth_query) do
defp do_fetch_user_secret(conn, auth_query, user) when is_binary(auth_query) do
Postgrex.query!(conn, auth_query, [user])
catch
_error, reason ->
Expand Down Expand Up @@ -167,4 +180,14 @@ defmodule Supavisor.AuthQuery do
defp build_ssl_options(_tenant) do
[verify: :verify_none]
end

defp telemetry_connection_stop(start, result),
do:
Telem.auth_query_connection_stop(System.monotonic_time() - start, telemetry_status(result))

defp telemetry_query_stop(start, result),
do: Telem.auth_query_query_stop(System.monotonic_time() - start, telemetry_status(result))

defp telemetry_status({:ok, _}), do: :ok
defp telemetry_status(_), do: :error
end
45 changes: 45 additions & 0 deletions lib/supavisor/monitoring/telem.ex
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ defmodule Supavisor.Monitoring.Telem do
require Supavisor

@disabled Application.compile_env(:supavisor, :metrics_disabled, false)
@slow_auth_query_ms 1_000

@mentels mentels May 7, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not sure if this is the right number, we can see what the times are in the first cluster we deploy to.


if @disabled do
defp telemetry_execute(_name, _measurements, _meta), do: :ok
Expand Down Expand Up @@ -117,6 +118,50 @@ defmodule Supavisor.Monitoring.Telem do
)
end

@spec auth_query_connection_stop(integer(), :ok | :error) :: :ok
def auth_query_connection_stop(duration, status) do
telemetry_execute(
[:supavisor, :auth_query, :connection, :stop],
%{duration: duration},
%{status: status}
)
end

@spec auth_query_query_stop(integer(), :ok | :error) :: :ok
def auth_query_query_stop(duration, status) do
duration_ms = System.convert_time_unit(duration, :native, :millisecond)

if duration_ms > @slow_auth_query_ms do
Logger.warning("auth_query took over #{@slow_auth_query_ms}ms (#{duration_ms}ms)")
end
Comment on lines +134 to +136

@v0idpwn v0idpwn May 7, 2026

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Really like this!


telemetry_execute(
[:supavisor, :auth_query, :query, :stop],
%{duration: duration},
%{status: status}
)
end

@spec secret_checker_get_secrets_stop(integer(), :ok | :error, :local | :remote) :: :ok
def secret_checker_get_secrets_stop(duration, status, locality)
when locality in [:local, :remote] do
telemetry_execute(
[:supavisor, :secret_checker, :get_secrets, :stop, locality],
%{duration: duration},
%{status: status}
)
end

@spec secret_checker_update_credentials_stop(integer(), :ok | :error, :local | :remote) :: :ok
def secret_checker_update_credentials_stop(duration, status, locality)
when locality in [:local, :remote] do
telemetry_execute(
[:supavisor, :secret_checker, :update_credentials, :stop, locality],
%{duration: duration},
%{status: status}
)
end

@spec id_to_tags(Supavisor.id()) :: map()
defp id_to_tags(
Supavisor.id(
Expand Down
65 changes: 64 additions & 1 deletion lib/supavisor/monitoring/tenant.ex
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,8 @@ defmodule Supavisor.PromEx.Plugins.Tenant do
[
system_metrics(),
client_metrics(),
db_metrics()
db_metrics(),
client_auth_metrics()
]
end

Expand Down Expand Up @@ -191,6 +192,68 @@ defmodule Supavisor.PromEx.Plugins.Tenant do
)
end

defp client_auth_metrics do

@mentels mentels May 7, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

technically, these are not per-tenant metrics but thought it's not worth creating a new module just for them

Event.build(
:supavisor_client_auth_event_metrics,
[
distribution(
[:supavisor, :auth_query, :connection, :duration],
event_name: [:supavisor, :auth_query, :connection, :stop],
measurement: :duration,
description: "Duration of auth_query Postgrex connection setup.",
tags: [:status],
unit: {:native, :millisecond},
reporter_options: [peep_bucket_calculator: Buckets]
),
distribution(
[:supavisor, :auth_query, :query, :duration],
event_name: [:supavisor, :auth_query, :query, :stop],
measurement: :duration,
description: "Duration of auth_query execution including Postgrex queue wait.",
tags: [:status],
unit: {:native, :millisecond},
reporter_options: [peep_bucket_calculator: Buckets]
),
distribution(
[:supavisor, :secret_checker, :get_secrets, :duration, :local],
event_name: [:supavisor, :secret_checker, :get_secrets, :stop, :local],
measurement: :duration,
description: "Duration of get_secrets erpc call (same-node).",
tags: [:status],
unit: {:native, :millisecond},
reporter_options: [peep_bucket_calculator: Buckets]
),
distribution(
[:supavisor, :secret_checker, :get_secrets, :duration, :remote],
event_name: [:supavisor, :secret_checker, :get_secrets, :stop, :remote],
measurement: :duration,
description: "Duration of get_secrets erpc call (cross-node).",
tags: [:status],
unit: {:native, :millisecond},
reporter_options: [peep_bucket_calculator: Buckets]
),
distribution(
[:supavisor, :secret_checker, :update_credentials, :duration, :local],
event_name: [:supavisor, :secret_checker, :update_credentials, :stop, :local],
measurement: :duration,
description: "Duration of update_credentials erpc call (same-node).",
tags: [:status],
unit: {:native, :millisecond},
reporter_options: [peep_bucket_calculator: Buckets]
),
distribution(
[:supavisor, :secret_checker, :update_credentials, :duration, :remote],
event_name: [:supavisor, :secret_checker, :update_credentials, :stop, :remote],
measurement: :duration,
description: "Duration of update_credentials erpc call (cross-node).",
tags: [:status],
unit: {:native, :millisecond},
reporter_options: [peep_bucket_calculator: Buckets]
)
]
)
end

defp db_metrics do
Event.build(
:supavisor_tenant_db_event_metrics,
Expand Down
30 changes: 29 additions & 1 deletion lib/supavisor/secret_checker.ex
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@ defmodule Supavisor.SecretChecker do
alias Supavisor.ClientAuthentication
alias Supavisor.ClientAuthentication.ValidationSecrets
alias Supavisor.Errors.AuthQueryError
alias Supavisor.Monitoring.Telem

@interval :timer.seconds(15)

Expand Down Expand Up @@ -40,7 +41,10 @@ defmodule Supavisor.SecretChecker do
{:error, %AuthQueryError{reason: :timeout}}

:exit, reason ->
Logger.error("SecretChecker: get_secrets call exited: #{inspect(reason)}")
Logger.error("SecretChecker: get_secrets call exited: #{inspect(reason)}",
project: Supavisor.id(id, :tenant)
)
Comment on lines +44 to +46

@mentels mentels May 7, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we were missing the project md if that was an RPC call


{:error, :not_started}
end
end
Expand Down Expand Up @@ -161,9 +165,12 @@ defmodule Supavisor.SecretChecker do
defp jitter, do: :rand.uniform(div(@interval, 10))

defp erpc_call_node(id, mod, fun, args) do
start = System.monotonic_time()

case Supavisor.get_global_sup(id) do
nil ->
{:error, :not_started}
|> tap(&telemetry_stop(fun, start, &1, :local))
Comment on lines 172 to +173

@v0idpwn v0idpwn May 7, 2026 •
edited
Loading

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think not_started as in "pool not up" should not be tagged as error in telemetry but as something else... Maybe should review the return values of the function too and do telemetry via reason, e.g.: not_started, exited, timeout, ...?


pid ->
try do
Expand All @@ -173,6 +180,27 @@ defmodule Supavisor.SecretChecker do
Logger.error("SecretChecker: erpc call exited: #{inspect(reason)}")
{:error, :not_started}
end
|> tap(&telemetry_stop(fun, start, &1, (node(pid) == node() && :local) || :remote))
end
end

defp telemetry_stop(:do_get_secrets, start, result, locality) do
Telem.secret_checker_get_secrets_stop(
System.monotonic_time() - start,
telemetry_status(result),
locality
)
end

defp telemetry_stop(:do_update_credentials, start, result, locality) do
Telem.secret_checker_update_credentials_stop(
System.monotonic_time() - start,
telemetry_status(result),
locality
)
end

defp telemetry_status({:error, _}), do: :error
defp telemetry_status({:ok, _}), do: :ok
defp telemetry_status(:ok), do: :ok
end
Loading
Loading