Skip to content

Commit

Permalink
Merge pull request #106 from scoutapp/more-queue-time
Browse files Browse the repository at this point in the history
queue time in Nginx format
  • Loading branch information
mitchellhenke authored Oct 29, 2019
2 parents 878a64b + b34fda9 commit 2a14044
Show file tree
Hide file tree
Showing 2 changed files with 41 additions and 1 deletion.
10 changes: 9 additions & 1 deletion lib/scout_apm/plugs/controller_timer.ex
Original file line number Diff line number Diff line change
Expand Up @@ -102,12 +102,20 @@ defmodule ScoutApm.Plugs.ControllerTimer do
end)

with true <- is_binary(queue_start_ms),
{queue_start_ms_unix, ""} <- Integer.parse(queue_start_ms) do
{queue_start_ms_unix, ""} <- parse_request_start_time(queue_start_ms) do
(unix_now - queue_start_ms_unix)
|> abs()
|> System.convert_time_unit(:millisecond, :nanosecond)
else
_ -> nil
end
end

defp parse_request_start_time("t=" <> queue_start_ms) do
Integer.parse(queue_start_ms)
end

defp parse_request_start_time(queue_start_ms) do
Integer.parse(queue_start_ms)
end
end
32 changes: 32 additions & 0 deletions test/scout_apm/plugs/controller_timer_test.exs
Original file line number Diff line number Diff line change
Expand Up @@ -84,6 +84,38 @@ defmodule ScoutApm.Plugs.ControllerTimerTest do
|> DateTime.to_unix(:millisecond)
|> Kernel.-(10)

conn(:get, "/x-forwarded-for")
|> Plug.Conn.put_req_header("x-request-start", "t=#{queue_start}")
|> ScoutApm.TestPlugApp.call([])

[%{BatchCommand: %{commands: commands}}] = ScoutApm.TestCollector.messages()

%{
TagRequest: %{
value: queue_time
}
} =
Enum.find(commands, fn command ->
map = Map.get(command, :TagRequest)

map && Map.get(map, :tag) == "scout.queue_time_ns" &&
is_integer(Map.get(map, :value))
end)

# queue_time should be about 10 million nanoseconds
# (between 10ms and 100ms)
assert is_integer(queue_time)
assert queue_time >= 10_000_000
assert queue_time < 100_000_000
end

test "adds queue time context from headers in nginx format" do
# Set queue time to ~10 milliseconds before request returns
queue_start =
DateTime.utc_now()
|> DateTime.to_unix(:millisecond)
|> Kernel.-(10)

conn(:get, "/x-forwarded-for")
|> Plug.Conn.put_req_header("x-queue-start", "#{queue_start}")
|> ScoutApm.TestPlugApp.call([])
Expand Down

0 comments on commit 2a14044

Please sign in to comment.