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.

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

Jump to bottom

Send total time metrics #98

Merged
merged 1 commit into from Feb 11, 2019
Merged

Send total time metrics #98

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
36 changes: 34 additions & 2 deletions lib/new_relic/harvest/collector/metric_data.ex
View file
Open in desktop
Expand Up @@ -5,7 +5,7 @@ defmodule NewRelic.Harvest.Collector.MetricData do

alias NewRelic.Metric

def transform({:transaction, name}, duration_s: duration_s),
def transform({:transaction, name}, duration_s: duration_s, total_time_s: total_time_s),
do: [
%Metric{
name: :HttpDispatcher,
Expand All @@ -30,10 +30,26 @@ defmodule NewRelic.Harvest.Collector.MetricData do
total_exclusive_time: duration_s,
min_call_time: duration_s,
max_call_time: duration_s
},
%Metric{
name: :WebTransactionTotalTime,
call_count: 1,
total_call_time: total_time_s,
total_exclusive_time: total_time_s,
min_call_time: total_time_s,
max_call_time: total_time_s
},
%Metric{
name: join(["WebTransactionTotalTime", name]),
call_count: 1,
total_call_time: total_time_s,
total_exclusive_time: total_time_s,
min_call_time: total_time_s,
max_call_time: total_time_s
}
]

def transform({:other_transaction, name}, duration_s: duration_s),
def transform({:other_transaction, name}, duration_s: duration_s, total_time_s: total_time_s),
do: [
%Metric{
name: :"OtherTransaction/all",
Expand All @@ -50,6 +66,22 @@ defmodule NewRelic.Harvest.Collector.MetricData do
total_exclusive_time: duration_s,
min_call_time: duration_s,
max_call_time: duration_s
},
%Metric{
name: :OtherTransactionTotalTime,
call_count: 1,
total_call_time: total_time_s,
total_exclusive_time: total_time_s,
min_call_time: total_time_s,
max_call_time: total_time_s
},
%Metric{
name: join(["OtherTransactionTotalTime", name]),
call_count: 1,
total_call_time: total_time_s,
total_exclusive_time: total_time_s,
min_call_time: total_time_s,
max_call_time: total_time_s
}
]

Expand Down
58 changes: 36 additions & 22 deletions lib/new_relic/transaction/complete.ex
View file
Open in desktop
Expand Up @@ -7,7 +7,11 @@ defmodule NewRelic.Transaction.Complete do
alias NewRelic.Transaction

def run(tx_attrs, pid) do
{tx_segments, tx_attrs, tx_error, span_events, apdex} = gather_transaction_info(tx_attrs, pid)
{tx_segments, tx_attrs, tx_error, span_events, apdex} =
tx_attrs
|> transform_name_attrs
|> transform_time_attrs
|> extract_transaction_info(pid)

report_transaction_event(tx_attrs)
report_transaction_trace(tx_attrs, tx_segments)
Expand All @@ -19,13 +23,6 @@ defmodule NewRelic.Transaction.Complete do
report_span_events(span_events)
end

defp gather_transaction_info(tx_attrs, pid) do
tx_attrs
|> transform_name_attrs
|> transform_time_attrs
|> extract_transaction_info(pid)
end

defp transform_name_attrs(%{custom_name: name} = tx), do: Map.put(tx, :name, name)
defp transform_name_attrs(%{framework_name: name} = tx), do: Map.put(tx, :name, name)
defp transform_name_attrs(%{plug_name: name} = tx), do: Map.put(tx, :name, name)
Expand Down Expand Up @@ -57,13 +54,6 @@ defmodule NewRelic.Transaction.Complete do
{process_exits, tx_attrs} = Map.pop(tx_attrs, :trace_process_exits, [])
{tx_error, tx_attrs} = Map.pop(tx_attrs, :transaction_error, nil)

apdex = calculate_apdex(tx_attrs, tx_error)

tx_attrs =
tx_attrs
|> Map.merge(NewRelic.Config.automatic_attributes())
|> Map.put(:"nr.apdexPerfZone", Util.Apdex.label(apdex))

function_segments =
function_segments
|> Enum.map(&transform_time_attrs/1)
Expand All @@ -73,7 +63,7 @@ defmodule NewRelic.Transaction.Complete do
|> Enum.group_by(& &1.pid)
|> Enum.into(%{}, &generate_process_segment_tree(&1))

top_segment =
root_process_segment =
tx_attrs
|> Map.take([:name, :pid, :start_time, :end_time])
|> List.wrap()
Expand All @@ -83,22 +73,38 @@ defmodule NewRelic.Transaction.Complete do
|> List.first()
|> Map.put(:id, pid)

top_segment =
process_segments =
process_spawns
|> collect_process_segments(process_names, process_exits)
|> Enum.map(&transform_trace_time_attrs(&1, tx_attrs.start_time))
|> Enum.map(&transform_trace_name_attrs/1)
|> Enum.map(&struct(Transaction.Trace.Segment, &1))
|> Enum.sort_by(& &1.relative_start_time)

segment_tree =
process_segments
|> Enum.map(&Map.put(&1, :children, function_segments[&1.pid] || []))
|> generate_process_tree(root: top_segment)
|> generate_process_tree(root: root_process_segment)

top_children = List.wrap(function_segments[inspect(pid)])
top_segment = Map.update!(top_segment, :children, &(&1 ++ top_children))
segment_tree = Map.update!(segment_tree, :children, &(&1 ++ top_children))

span_events = extract_span_events(tx_attrs, pid, process_spawns, process_names, process_exits)

{[top_segment], tx_attrs, tx_error, span_events, apdex}
apdex = calculate_apdex(tx_attrs, tx_error)

total_time =
process_segments
|> Enum.map(&(&1.relative_end_time - &1.relative_start_time))
|> Enum.sum()

tx_attrs =
tx_attrs
|> Map.merge(NewRelic.Config.automatic_attributes())
|> Map.put(:"nr.apdexPerfZone", Util.Apdex.label(apdex))
|> Map.put(:total_time_s, tx_attrs.duration_s + total_time / 1000)

{[segment_tree], tx_attrs, tx_error, span_events, apdex}
end

defp extract_span_events(tx_attrs, pid, spawns, names, exits) do
Expand Down Expand Up @@ -278,6 +284,7 @@ defmodule NewRelic.Transaction.Complete do
Collector.TransactionEvent.Harvester.report_event(%Transaction.Event{
timestamp: tx_attrs.start_time,
duration: tx_attrs.duration_s,
total_time: tx_attrs.total_time_s,
name: Util.metric_join(["WebTransaction", tx_attrs.name]),
user_attributes:
Map.merge(tx_attrs, %{
Expand All @@ -290,6 +297,7 @@ defmodule NewRelic.Transaction.Complete do
Collector.TransactionEvent.Harvester.report_event(%Transaction.Event{
timestamp: tx_attrs.start_time,
duration: tx_attrs.duration_s,
total_time: tx_attrs.total_time_s,
name: Util.metric_join(["OtherTransaction", tx_attrs.name]),
user_attributes: tx_attrs
})
Expand Down Expand Up @@ -464,11 +472,17 @@ defmodule NewRelic.Transaction.Complete do
end

def report_transaction_metric(%{other_transaction_name: _} = tx) do
NewRelic.report_metric({:other_transaction, tx.name}, duration_s: tx.duration_s)
NewRelic.report_metric({:other_transaction, tx.name},
duration_s: tx.duration_s,
total_time_s: tx.total_time_s
)
end

def report_transaction_metric(tx) do
NewRelic.report_metric({:transaction, tx.name}, duration_s: tx.duration_s)
NewRelic.report_metric({:transaction, tx.name},
duration_s: tx.duration_s,
total_time_s: tx.total_time_s
)
end

def report_apdex_metric(:ignore), do: :ignore
Expand Down
2 changes: 2 additions & 0 deletions lib/new_relic/transaction/event.ex
View file
Open in desktop
Expand Up @@ -5,6 +5,7 @@ defmodule NewRelic.Transaction.Event do
timestamp: nil,
name: nil,
duration: nil,
total_time: nil,
user_attributes: %{}

@moduledoc false
Expand All @@ -17,6 +18,7 @@ defmodule NewRelic.Transaction.Event do
[
%{
webDuration: transaction.web_duration,
totalTime: transaction.total_time,
databaseDuration: transaction.database_duration,
timestamp: transaction.timestamp,
name: transaction.name,
Expand Down
21 changes: 21 additions & 0 deletions test/transaction_test.exs
View file
Open in desktop
Expand Up @@ -97,6 +97,13 @@ defmodule TransactionTest do
NewRelic.ignore_transaction()
send_resp(conn, 200, "ignored")
end

get "/total_time" do
t1 = Task.async(fn -> ExternalService.query(200) end)
ExternalService.query(200)
Task.await(t1)
send_resp(conn, 200, "ok")
end
end

test "Basic transaction" do
Expand Down Expand Up @@ -257,4 +264,18 @@ defmodule TransactionTest do

assert events == []
end

test "Calculate total time" do
TestHelper.restart_harvest_cycle(Collector.TransactionEvent.HarvestCycle)

TestHelper.request(TestPlugApp, conn(:get, "/total_time"))

[[_, event]] = TestHelper.gather_harvest(Collector.TransactionEvent.Harvester)

assert event[:duration_s] >= 0.2
assert event[:duration_s] < 0.3

assert event[:total_time_s] > 0.3
assert event[:total_time_s] < 0.5
end
end