Skip to content
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.

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

Telemetry instrumentation #27

Closed
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
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
31 changes: 27 additions & 4 deletions lib/plug/cowboy/handler.ex
Original file line number Diff line number Diff line change
Expand Up @@ -6,16 +6,39 @@ defmodule Plug.Cowboy.Handler do
def init(req, {plug, opts}) do
conn = @connection.conn(req)

system_time = System.system_time()
start_time_mono = System.monotonic_time()

:telemetry.execute(
[:plug_cowboy, :handler, :start],
%{system_time: system_time},
%{conn: conn}
)

try do
%{adapter: {@connection, req}} =
conn
|> plug.call(opts)
conn =
%{adapter: {@connection, req}} =
plug.call(conn, opts)
|> maybe_send(plug)

:telemetry.execute(
[:plug_cowboy, :handler, :stop],
%{duration: System.monotonic_time() - start_time_mono},
%{conn: conn}
)

{:ok, req, {plug, opts}}
catch
kind, reason ->
exit_on_error(kind, reason, System.stacktrace(), {plug, :call, [conn, opts]})
stack = System.stacktrace()

:telemetry.execute(
[:plug_cowboy, :handler, :exception],
%{duration: System.monotonic_time() - start_time_mono},
%{conn: conn, kind: kind, reason: reason, stack: stack}
)

exit_on_error(kind, reason, stack, {plug, :call, [conn, opts]})
after
receive do
@already_sent -> :ok
Expand Down
1 change: 1 addition & 0 deletions mix.exs
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@ defmodule Plug.Cowboy.MixProject do
[
{:plug, "~> 1.7"},
{:cowboy, "~> 2.5"},
{:telemetry, "~> 0.4"},
{:ex_doc, "~> 0.20", only: :docs},
{:hackney, "~> 1.2.0", only: :test},
{:kadabra, "0.3.4", only: :test},
Expand Down
35 changes: 18 additions & 17 deletions mix.lock
Original file line number Diff line number Diff line change
@@ -1,19 +1,20 @@
%{
"cowboy": {:hex, :cowboy, "2.5.0", "4ef3ae066ee10fe01ea3272edc8f024347a0d3eb95f6fbb9aed556dacbfc1337", [:rebar3], [{:cowlib, "~> 2.6.0", [hex: :cowlib, repo: "hexpm", optional: false]}, {:ranch, "~> 1.6.2", [hex: :ranch, repo: "hexpm", optional: false]}], "hexpm"},
"cowlib": {:hex, :cowlib, "2.6.0", "8aa629f81a0fc189f261dc98a42243fa842625feea3c7ec56c48f4ccdb55490f", [:rebar3], [], "hexpm"},
"earmark": {:hex, :earmark, "1.4.3", "364ca2e9710f6bff494117dbbd53880d84bebb692dafc3a78eb50aa3183f2bfd", [:mix], [], "hexpm"},
"ex_doc": {:hex, :ex_doc, "0.21.2", "caca5bc28ed7b3bdc0b662f8afe2bee1eedb5c3cf7b322feeeb7c6ebbde089d6", [:mix], [{:earmark, "~> 1.3.3 or ~> 1.4", [hex: :earmark, repo: "hexpm", optional: false]}, {:makeup_elixir, "~> 0.14", [hex: :makeup_elixir, repo: "hexpm", optional: false]}], "hexpm"},
"hackney": {:hex, :hackney, "1.2.0", "41d352d5c272a150127517ab29e00cf5521a04af925f260667bf55161fbee68f", [:rebar], [{:idna, "~> 1.0.2", [hex: :idna, repo: "hexpm", optional: false]}, {:ssl_verify_hostname, "~> 1.0.5", [hex: :ssl_verify_hostname, repo: "hexpm", optional: false]}], "hexpm"},
"hpack": {:hex, :hpack_erl, "0.2.3", "17670f83ff984ae6cd74b1c456edde906d27ff013740ee4d9efaa4f1bf999633", [:rebar3], [], "hexpm"},
"idna": {:hex, :idna, "1.0.3", "d456a8761cad91c97e9788c27002eb3b773adaf5c893275fc35ba4e3434bbd9b", [:rebar3], [], "hexpm"},
"kadabra": {:hex, :kadabra, "0.3.4", "677d0c5d28a016c7dec167b3f969fe72b4bf18e9568a399cc262efa1ef124925", [:mix], [{:hpack, "~> 0.2.3", [hex: :hpack_erl, repo: "hexpm", optional: false]}, {:scribe, "~> 0.4", [hex: :scribe, repo: "hexpm", optional: true]}], "hexpm"},
"makeup": {:hex, :makeup, "1.0.0", "671df94cf5a594b739ce03b0d0316aa64312cee2574b6a44becb83cd90fb05dc", [:mix], [{:nimble_parsec, "~> 0.5.0", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm"},
"makeup_elixir": {:hex, :makeup_elixir, "0.14.0", "cf8b7c66ad1cff4c14679698d532f0b5d45a3968ffbcbfd590339cb57742f1ae", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}], "hexpm"},
"mime": {:hex, :mime, "1.3.0", "5e8d45a39e95c650900d03f897fbf99ae04f60ab1daa4a34c7a20a5151b7a5fe", [:mix], [], "hexpm"},
"nimble_parsec": {:hex, :nimble_parsec, "0.5.3", "def21c10a9ed70ce22754fdeea0810dafd53c2db3219a0cd54cf5526377af1c6", [:mix], [], "hexpm"},
"plug": {:hex, :plug, "1.7.0", "cd8c8de89bd9de55eba1c918bf0e7f319737e109b6014875104af025a623e16e", [:mix], [{:mime, "~> 1.0", [hex: :mime, repo: "hexpm", optional: false]}, {:plug_crypto, "~> 1.0", [hex: :plug_crypto, repo: "hexpm", optional: false]}], "hexpm"},
"plug_crypto": {:hex, :plug_crypto, "1.0.0", "18e49317d3fa343f24620ed22795ec29d4a5e602d52d1513ccea0b07d8ea7d4d", [:mix], [], "hexpm"},
"ranch": {:hex, :ranch, "1.6.2", "6db93c78f411ee033dbb18ba8234c5574883acb9a75af0fb90a9b82ea46afa00", [:rebar3], [], "hexpm"},
"ssl_verify_hostname": {:hex, :ssl_verify_hostname, "1.0.6", "45866d958d9ae51cfe8fef0050ab8054d25cba23ace43b88046092aa2c714645", [:make], [], "hexpm"},
"x509": {:hex, :x509, "0.6.0", "51a274a8368cf6fe771c1920ce5b075d28a076745987666593adb818aadf1bf7", [:mix], [], "hexpm"},
"cowboy": {:hex, :cowboy, "2.5.0", "4ef3ae066ee10fe01ea3272edc8f024347a0d3eb95f6fbb9aed556dacbfc1337", [:rebar3], [{:cowlib, "~> 2.6.0", [hex: :cowlib, repo: "hexpm", optional: false]}, {:ranch, "~> 1.6.2", [hex: :ranch, repo: "hexpm", optional: false]}], "hexpm", "07763d253314bd76017157e3a33e2cd32c1500e0ecf7ceb4e80aa09d2939aa30"},
"cowlib": {:hex, :cowlib, "2.6.0", "8aa629f81a0fc189f261dc98a42243fa842625feea3c7ec56c48f4ccdb55490f", [:rebar3], [], "hexpm", "45a1a08e05e4c66f2af665295955e337d52c2d33b1f1cf24d353cadeddf34992"},
"earmark": {:hex, :earmark, "1.4.3", "364ca2e9710f6bff494117dbbd53880d84bebb692dafc3a78eb50aa3183f2bfd", [:mix], [], "hexpm", "8cf8a291ebf1c7b9539e3cddb19e9cef066c2441b1640f13c34c1d3cfc825fec"},
"ex_doc": {:hex, :ex_doc, "0.21.2", "caca5bc28ed7b3bdc0b662f8afe2bee1eedb5c3cf7b322feeeb7c6ebbde089d6", [:mix], [{:earmark, "~> 1.3.3 or ~> 1.4", [hex: :earmark, repo: "hexpm", optional: false]}, {:makeup_elixir, "~> 0.14", [hex: :makeup_elixir, repo: "hexpm", optional: false]}], "hexpm", "f1155337ae17ff7a1255217b4c1ceefcd1860b7ceb1a1874031e7a861b052e39"},
"hackney": {:hex, :hackney, "1.2.0", "41d352d5c272a150127517ab29e00cf5521a04af925f260667bf55161fbee68f", [:rebar], [{:idna, "~> 1.0.2", [hex: :idna, repo: "hexpm", optional: false]}, {:ssl_verify_hostname, "~> 1.0.5", [hex: :ssl_verify_hostname, repo: "hexpm", optional: false]}], "hexpm", "c7851a8a2e07ad18f9d92f8bce93ea96af0617fb873961bbd3993073bf27da4b"},
"hpack": {:hex, :hpack_erl, "0.2.3", "17670f83ff984ae6cd74b1c456edde906d27ff013740ee4d9efaa4f1bf999633", [:rebar3], [], "hexpm", "06f580167c4b8b8a6429040df36cc93bba6d571faeaec1b28816523379cbb23a"},
"idna": {:hex, :idna, "1.0.3", "d456a8761cad91c97e9788c27002eb3b773adaf5c893275fc35ba4e3434bbd9b", [:rebar3], [], "hexpm", "357d489a51112db4f216034406834f9172b3c0ff5a12f83fb28b25ca271541d1"},
"kadabra": {:hex, :kadabra, "0.3.4", "677d0c5d28a016c7dec167b3f969fe72b4bf18e9568a399cc262efa1ef124925", [:mix], [{:hpack, "~> 0.2.3", [hex: :hpack_erl, repo: "hexpm", optional: false]}, {:scribe, "~> 0.4", [hex: :scribe, repo: "hexpm", optional: true]}], "hexpm", "b6ba901a42095e2f99f54a5114c48920999439f43c6cc77d6f9029f7e9a0d222"},
"makeup": {:hex, :makeup, "1.0.0", "671df94cf5a594b739ce03b0d0316aa64312cee2574b6a44becb83cd90fb05dc", [:mix], [{:nimble_parsec, "~> 0.5.0", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "a10c6eb62cca416019663129699769f0c2ccf39428b3bb3c0cb38c718a0c186d"},
"makeup_elixir": {:hex, :makeup_elixir, "0.14.0", "cf8b7c66ad1cff4c14679698d532f0b5d45a3968ffbcbfd590339cb57742f1ae", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}], "hexpm", "d4b316c7222a85bbaa2fd7c6e90e37e953257ad196dc229505137c5e505e9eff"},
"mime": {:hex, :mime, "1.3.0", "5e8d45a39e95c650900d03f897fbf99ae04f60ab1daa4a34c7a20a5151b7a5fe", [:mix], [], "hexpm", "5e839994289d60326aa86020c4fbd9c6938af188ecddab2579f07b66cd665328"},
"nimble_parsec": {:hex, :nimble_parsec, "0.5.3", "def21c10a9ed70ce22754fdeea0810dafd53c2db3219a0cd54cf5526377af1c6", [:mix], [], "hexpm", "589b5af56f4afca65217a1f3eb3fee7e79b09c40c742fddc1c312b3ac0b3399f"},
"plug": {:hex, :plug, "1.7.0", "cd8c8de89bd9de55eba1c918bf0e7f319737e109b6014875104af025a623e16e", [:mix], [{:mime, "~> 1.0", [hex: :mime, repo: "hexpm", optional: false]}, {:plug_crypto, "~> 1.0", [hex: :plug_crypto, repo: "hexpm", optional: false]}], "hexpm", "e21e0ea7cbf87ecbc6ab6a9418db78fa1285dc12c8e0586f44dd6dfa842a190b"},
"plug_crypto": {:hex, :plug_crypto, "1.0.0", "18e49317d3fa343f24620ed22795ec29d4a5e602d52d1513ccea0b07d8ea7d4d", [:mix], [], "hexpm", "73c1682f0e414cfb5d9b95c8e8cd6ffcfdae699e3b05e1db744e58b7be857759"},
"ranch": {:hex, :ranch, "1.6.2", "6db93c78f411ee033dbb18ba8234c5574883acb9a75af0fb90a9b82ea46afa00", [:rebar3], [], "hexpm", "0b65d1de7f1ebe96feb57803c8d698f7776b663ba10b6dcff34527e4a4f8ff43"},
"ssl_verify_hostname": {:hex, :ssl_verify_hostname, "1.0.6", "45866d958d9ae51cfe8fef0050ab8054d25cba23ace43b88046092aa2c714645", [:make], [], "hexpm", "72b2fc8a8e23d77eed4441137fefa491bbf4a6dc52e9c0045f3f8e92e66243b5"},
"telemetry": {:hex, :telemetry, "0.4.1", "ae2718484892448a24470e6aa341bc847c3277bfb8d4e9289f7474d752c09c7f", [:rebar3], [], "hexpm", "4738382e36a0a9a2b6e25d67c960e40e1a2c95560b9f936d8e29de8cd858480f"},
"x509": {:hex, :x509, "0.6.0", "51a274a8368cf6fe771c1920ce5b075d28a076745987666593adb818aadf1bf7", [:mix], [], "hexpm", "111d29a5388e059413aa4553b64f041452fe49777be310622cd71e451d29630d"},
}
58 changes: 58 additions & 0 deletions test/plug/cowboy/telemetry_test.exs
Original file line number Diff line number Diff line change
@@ -0,0 +1,58 @@
defmodule Plug.Cowboy.TelemetryTest do
use ExUnit.Case

@start [:plug_cowboy, :handler, :start]
@stop [:plug_cowboy, :handler, :stop]
@exception [:plug_cowboy, :handler, :exception]

defmodule TestPlugApp do
use Plug.Router

plug(:match)
plug(:dispatch)

get "/raise" do
raise "BadNews"
end

match _ do
send_resp(conn, 200, "Hey!")
end
end

defmodule TestHandler do
def handle_event(event, measurements, metadata, %{pid: pid}) do
send(pid, {event, measurements, metadata})
end
end

setup context do
:telemetry.attach_many(
context.test,
[@start, @stop, @exception],
&TestHandler.handle_event/4,
%{pid: self()}
)

on_exit(fn -> :telemetry.detach(context.test) end)

:ok
end

test "telemetry events" do
start_supervised!({Plug.Cowboy, scheme: :http, plug: TestPlugApp, options: [port: 8006]})

{:ok, 200, _, _} = :hackney.request(:get, "localhost:8006/path", [], "", [])

assert_receive {@start, _meas, %{conn: %{request_path: "/path", state: :unset}}}
assert_receive {@stop, _meas, %{conn: %{request_path: "/path", status: 200}}}

{:ok, 500, _, _} = :hackney.request(:get, "localhost:8006/raise", [], "", [])

assert_receive {@start, _meas, %{conn: %{request_path: "/raise", state: :unset}}}
assert_receive {@exception, _meas, %{conn: %{request_path: "/raise", state: :unset}}}

# Not possible yet:
# assert_receive {@exception, _meas, %{conn: %{request_path: "/raise", status: 500}}}
end
end