Skip to content

Commit

Permalink
Move telemetry tests to use message based helper from Bandit
Browse files Browse the repository at this point in the history
  • Loading branch information
@mtrudel
mtrudel committed Jan 5, 2025
1 parent 8e66e81 commit a8ceaea
Show file tree
Hide file tree
Showing 8 changed files with 247 additions and 256 deletions.
5 changes: 3 additions & 2 deletions lib/thousand_island/listener.ex
View file
Original file line number Diff line number Diff line change
Expand Up @@ -32,14 +32,15 @@ defmodule ThousandIsland.Listener do
),
{:ok, {ip, port}} <-
server_config.transport_module.sockname(listener_socket) do
span_meta = %{
span_metadata = %{
handler: server_config.handler_module,
local_address: ip,
local_port: port,
transport_module: server_config.transport_module,
transport_options: server_config.transport_options
}

listener_span = ThousandIsland.Telemetry.start_span(:listener, %{}, span_meta)
listener_span = ThousandIsland.Telemetry.start_span(:listener, %{}, span_metadata)

{:ok,
%{listener_socket: listener_socket, local_info: {ip, port}, listener_span: listener_span}}
Expand Down
10 changes: 8 additions & 2 deletions lib/thousand_island/telemetry.ex
View file
Original file line number Diff line number Diff line change
Expand Up @@ -332,7 +332,9 @@ defmodule ThousandIsland.Telemetry do
@spec start_child_span(t(), span_name(), measurements(), metadata()) :: t()
def start_child_span(parent_span, span_name, measurements \\ %{}, metadata \\ %{}) do
metadata =
Map.put(metadata, :parent_telemetry_span_context, parent_span.telemetry_span_context)
metadata
|> Map.put(:parent_telemetry_span_context, parent_span.telemetry_span_context)
|> Map.put(:handler, parent_span.start_metadata.handler)

start_span(span_name, measurements, metadata)
end
Expand Down Expand Up @@ -361,7 +363,11 @@ defmodule ThousandIsland.Telemetry do
@spec untimed_span_event(t(), event_name() | untimed_event_name(), measurements(), metadata()) ::
:ok
def untimed_span_event(span, name, measurements \\ %{}, metadata \\ %{}) do
metadata = Map.put(metadata, :telemetry_span_context, span.telemetry_span_context)
metadata =
metadata
|> Map.put(:telemetry_span_context, span.telemetry_span_context)
|> Map.put(:handler, span.start_metadata.handler)

event([span.span_name, name], measurements, metadata)
end

Expand Down
38 changes: 0 additions & 38 deletions test/support/telemetry_collector.ex
View file

This file was deleted.

34 changes: 34 additions & 0 deletions test/support/telemetry_helpers.ex
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,34 @@
defmodule TelemetryHelpers do
@moduledoc false

@events [
[:thousand_island, :listener, :start],
[:thousand_island, :listener, :stop],
[:thousand_island, :acceptor, :start],
[:thousand_island, :acceptor, :stop],
[:thousand_island, :acceptor, :spawn_error],
[:thousand_island, :acceptor, :econnaborted],
[:thousand_island, :connection, :start],
[:thousand_island, :connection, :stop],
[:thousand_island, :connection, :ready],
[:thousand_island, :connection, :async_recv],
[:thousand_island, :connection, :recv],
[:thousand_island, :connection, :recv_error],
[:thousand_island, :connection, :send],
[:thousand_island, :connection, :send_error],
[:thousand_island, :connection, :sendfile],
[:thousand_island, :connection, :sendfile_error],
[:thousand_island, :connection, :socket_shutdown]
]

def attach_all_events(handler) do
ref = make_ref()
_ = :telemetry.attach_many(ref, @events, &__MODULE__.handle_event/4, {self(), handler})
fn -> :telemetry.detach(ref) end
end

def handle_event(event, measurements, %{handler: handler} = metadata, {pid, handler}),
do: send(pid, {:telemetry, event, measurements, metadata})

def handle_event(_event, _measurements, _metadata, {_pid, _handler}), do: :ok
end
203 changes: 97 additions & 106 deletions test/thousand_island/handler_test.exs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -647,64 +647,63 @@ defmodule ThousandIsland.HandlerTest do
end

test "it should send `start` telemetry event on startup" do
{:ok, collector_pid} =
start_supervised(
{ThousandIsland.TelemetryCollector, [[:thousand_island, :connection, :start]]}
)
TelemetryHelpers.attach_all_events(Telemetry.Closer)

{:ok, port} = start_handler(Telemetry.Closer)

{:ok, client} = :gen_tcp.connect(:localhost, port, active: false)
{:ok, {ip, port}} = :inet.sockname(client)
Process.sleep(100)

assert ThousandIsland.TelemetryCollector.get_events(collector_pid)
~> [
{[:thousand_island, :connection, :start], %{monotonic_time: integer()},
%{
parent_telemetry_span_context: reference(),
remote_address: ip,
remote_port: port,
telemetry_span_context: reference()
}}
]
assert_receive {:telemetry, [:thousand_island, :connection, :start], measurements,
metadata},
500

assert measurements ~> %{monotonic_time: integer()}

assert metadata
~> %{
handler: Telemetry.Closer,
parent_telemetry_span_context: reference(),
remote_address: ip,
remote_port: port,
telemetry_span_context: reference()
}
end

test "it should send `ready` telemetry event once socket is ready" do
{:ok, collector_pid} =
start_supervised(
{ThousandIsland.TelemetryCollector, [[:thousand_island, :connection, :ready]]}
)
TelemetryHelpers.attach_all_events(Telemetry.Closer)

{:ok, port} = start_handler(Telemetry.Closer)

{:ok, _client} = :gen_tcp.connect(:localhost, port, active: false)
Process.sleep(100)

assert ThousandIsland.TelemetryCollector.get_events(collector_pid)
~> [
{[:thousand_island, :connection, :ready], %{monotonic_time: integer()},
%{telemetry_span_context: reference()}}
]
assert_receive {:telemetry, [:thousand_island, :connection, :ready], measurements,
metadata},
500

assert measurements ~> %{monotonic_time: integer()}
assert metadata ~> %{handler: Telemetry.Closer, telemetry_span_context: reference()}
end

test "it should send `async_recv` telemetry event on async receipt of data" do
{:ok, collector_pid} =
start_supervised(
{ThousandIsland.TelemetryCollector, [[:thousand_island, :connection, :async_recv]]}
)
TelemetryHelpers.attach_all_events(Telemetry.CloseOnData)

{:ok, port} = start_handler(Telemetry.CloseOnData)

{:ok, client} = :gen_tcp.connect(:localhost, port, active: false)
:gen_tcp.send(client, "ping")
Process.sleep(100)

assert ThousandIsland.TelemetryCollector.get_events(collector_pid)
~> [
{[:thousand_island, :connection, :async_recv], %{data: "ping"},
%{telemetry_span_context: reference()}}
]
assert_receive {:telemetry, [:thousand_island, :connection, :async_recv], measurements,
metadata},
500

assert measurements ~> %{data: "ping"}

assert metadata
~> %{
handler: Telemetry.CloseOnData,
telemetry_span_context: reference()
}
end

defmodule Telemetry.HelloWorld do
Expand All @@ -718,34 +717,28 @@ defmodule ThousandIsland.HandlerTest do
end

test "it should send `stop` telemetry event on client shutdown" do
{:ok, collector_pid} =
start_supervised(
{ThousandIsland.TelemetryCollector, [[:thousand_island, :connection, :stop]]}
)
TelemetryHelpers.attach_all_events(Telemetry.HelloWorld)

{:ok, port} = start_handler(Telemetry.HelloWorld)

{:ok, client} = :gen_tcp.connect(:localhost, port, active: false)
{:ok, {ip, port}} = :inet.sockname(client)
{:ok, ~c"HELLO"} = :gen_tcp.recv(client, 5)
:gen_tcp.close(client)
Process.sleep(100)

# When the remote end closes the socket we do not get octet counts, unfortunately
assert ThousandIsland.TelemetryCollector.get_events(collector_pid)
~> [
{[:thousand_island, :connection, :stop],
%{
duration: integer(),
monotonic_time: integer()
},
%{
parent_telemetry_span_context: reference(),
remote_address: ip,
remote_port: port,
telemetry_span_context: reference()
}}
]

assert_receive {:telemetry, [:thousand_island, :connection, :stop], measurements, metadata},
500

assert measurements ~> %{monotonic_time: integer(), duration: integer()}

assert metadata
~> %{
handler: Telemetry.HelloWorld,
parent_telemetry_span_context: reference(),
remote_address: ip,
remote_port: port,
telemetry_span_context: reference()
}
end

defmodule Telemetry.Closer do
Expand All @@ -759,37 +752,36 @@ defmodule ThousandIsland.HandlerTest do
end

test "it should send `stop` telemetry event on shutdown" do
{:ok, collector_pid} =
start_supervised(
{ThousandIsland.TelemetryCollector, [[:thousand_island, :connection, :stop]]}
)
TelemetryHelpers.attach_all_events(Telemetry.Closer)

{:ok, port} = start_handler(Telemetry.Closer)

{:ok, client} = :gen_tcp.connect(:localhost, port, active: false)
{:ok, {ip, port}} = :inet.sockname(client)

:gen_tcp.connect(:localhost, port, active: false)
Process.sleep(100)

assert ThousandIsland.TelemetryCollector.get_events(collector_pid)
~> [
{[:thousand_island, :connection, :stop],
%{
duration: integer(),
monotonic_time: integer(),
recv_cnt: 0,
recv_oct: 0,
send_cnt: 1,
send_oct: 5
},
%{
parent_telemetry_span_context: reference(),
remote_address: ip,
remote_port: port,
telemetry_span_context: reference()
}}
]

assert_receive {:telemetry, [:thousand_island, :connection, :stop], measurements, metadata},
500

assert measurements
~> %{
monotonic_time: integer(),
duration: integer(),
recv_cnt: 0,
recv_oct: 0,
send_cnt: 1,
send_oct: 5
}

assert metadata
~> %{
handler: Telemetry.Closer,
parent_telemetry_span_context: reference(),
remote_address: ip,
remote_port: port,
telemetry_span_context: reference()
}
end

defmodule Telemetry.Error do
Expand All @@ -803,41 +795,40 @@ defmodule ThousandIsland.HandlerTest do

@tag capture_log: true
test "it should send `stop` telemetry event with payload on error" do
{:ok, collector_pid} =
start_supervised(
{ThousandIsland.TelemetryCollector, [[:thousand_island, :connection, :stop]]}
)
TelemetryHelpers.attach_all_events(Telemetry.Error)

{:ok, port} = start_handler(Telemetry.Error)

{:ok, client} = :gen_tcp.connect(:localhost, port, active: false)
{:ok, {ip, port}} = :inet.sockname(client)
Process.sleep(100)

assert ThousandIsland.TelemetryCollector.get_events(collector_pid)
~> [
{[:thousand_island, :connection, :stop],
%{
duration: integer(),
monotonic_time: integer(),
recv_cnt: 0,
recv_oct: 0,
send_cnt: 0,
send_oct: 0
},
%{
error: :nope,
parent_telemetry_span_context: reference(),
remote_address: ip,
remote_port: port,
telemetry_span_context: reference()
}}
]

assert_receive {:telemetry, [:thousand_island, :connection, :stop], measurements, metadata},
500

assert measurements
~> %{
monotonic_time: integer(),
duration: integer(),
recv_cnt: 0,
recv_oct: 0,
send_cnt: 0,
send_oct: 0
}

assert metadata
~> %{
handler: Telemetry.Error,
error: :nope,
parent_telemetry_span_context: reference(),
remote_address: ip,
remote_port: port,
telemetry_span_context: reference()
}
end
end

defp start_handler(handler, server_args \\ []) do
resolved_args = [port: 0, handler_module: handler] ++ server_args
resolved_args = [port: 0, handler_module: handler, num_acceptors: 1] ++ server_args
{:ok, server_pid} = start_supervised({ThousandIsland, resolved_args})
{:ok, {_ip, port}} = ThousandIsland.listener_info(server_pid)
{:ok, port}
Expand Down
Loading

0 comments on commit a8ceaea

Please sign in to comment.