Skip to content

Commit

Permalink
Send number of allocations in span as metric
Browse files Browse the repository at this point in the history
I recently noticed that while we usually collect the number of memory
allocations on a given span, we send it as an "allocations" field to
the agent and this data never seems to make it to the backend.

Instead, this refactor reports it as a span metric, which makes
it available to customers.
  • Loading branch information
ivoanjo committed Dec 8, 2021
1 parent 422584e commit 59e8449
Show file tree
Hide file tree
Showing 5 changed files with 21 additions and 18 deletions.
6 changes: 0 additions & 6 deletions lib/ddtrace/span.rb
Original file line number Diff line number Diff line change
Expand Up @@ -28,7 +28,6 @@ class Span
EXTERNAL_MAX_ID = 1 << 64

attr_accessor \
:allocations,
:end_time,
:id,
:meta,
Expand Down Expand Up @@ -62,7 +61,6 @@ class Span
# TODO: Remove span_type
def initialize(
name,
allocations: 0,
duration: nil,
end_time: nil,
id: nil,
Expand Down Expand Up @@ -90,8 +88,6 @@ def initialize(
@metrics = metrics || {}
@status = status || 0

@allocations = allocations || 0

# start_time and end_time track wall clock. In Ruby, wall clock
# has less accuracy than monotonic clock, so if possible we look to only use wall clock
# to measure duration when a time is supplied by the user, or if monotonic clock
Expand Down Expand Up @@ -141,7 +137,6 @@ def to_s
# isn't handled by this method.
def to_hash
h = {
allocations: @allocations,
error: @status,
meta: @meta,
metrics: @metrics,
Expand Down Expand Up @@ -179,7 +174,6 @@ def pretty_print(q)
q.text "Start: #{start_time}\n"
q.text "End: #{end_time}\n"
q.text "Duration: #{duration.to_f}\n"
q.text "Allocations: #{allocations}\n"
q.group(2, 'Tags: [', "]\n") do
q.breakable
q.seplist @meta.each do |key, value|
Expand Down
7 changes: 3 additions & 4 deletions lib/ddtrace/span_operation.rb
Original file line number Diff line number Diff line change
Expand Up @@ -182,6 +182,8 @@ def stop(stop_time = nil)

@allocation_count_stop = now_allocations

set_metric('allocations', allocations)

now = Utils::Time.now.utc

# Provide a default start_time if unset.
Expand Down Expand Up @@ -261,7 +263,6 @@ def to_s
# Return the hash representation of the current span.
def to_hash
h = {
allocations: allocations,
error: @status,
id: @id,
meta: meta,
Expand Down Expand Up @@ -299,7 +300,6 @@ def pretty_print(q)
q.text "Start: #{start_time}\n"
q.text "End: #{end_time}\n"
q.text "Duration: #{duration.to_f if stopped?}\n"
q.text "Allocations: #{allocations}\n"
q.group(2, 'Tags: [', "]\n") do
q.breakable
q.seplist meta.each do |key, value|
Expand Down Expand Up @@ -408,7 +408,6 @@ def message
def build_span
Span.new(
@name && @name.dup,
allocations: allocations,
duration: duration,
end_time: @end_time,
id: @id,
Expand Down Expand Up @@ -462,7 +461,7 @@ def duration_nano
(duration * 1e9).to_i
end

if defined?(JRUBY_VERSION) || Gem::Version.new(RUBY_VERSION) < Gem::Version.new(VERSION::MINIMUM_RUBY_VERSION)
if defined?(JRUBY_VERSION)
def now_allocations
0
end
Expand Down
8 changes: 4 additions & 4 deletions lib/ddtrace/transport/serializable_trace.rb
Original file line number Diff line number Diff line change
Expand Up @@ -53,16 +53,18 @@ def initialize(span)
def to_msgpack(packer = nil)
packer ||= MessagePack::Packer.new

number_of_elements_to_write = 10

if span.stopped?
packer.write_map_header(13) # Set header with how many elements in the map
packer.write_map_header(number_of_elements_to_write + 2) # Set header with how many elements in the map

packer.write('start')
packer.write(time_nano(span.start_time))

packer.write('duration')
packer.write(duration_nano(span.duration))
else
packer.write_map_header(11) # Set header with how many elements in the map
packer.write_map_header(number_of_elements_to_write) # Set header with how many elements in the map
end

# DEV: We use strings as keys here, instead of symbols, as
Expand All @@ -86,8 +88,6 @@ def to_msgpack(packer = nil)
packer.write(span.meta)
packer.write('metrics')
packer.write(span.metrics)
packer.write('allocations')
packer.write(span.allocations)
packer.write('error')
packer.write(span.status)
packer
Expand Down
17 changes: 14 additions & 3 deletions spec/ddtrace/span_operation_spec.rb
Original file line number Diff line number Diff line change
Expand Up @@ -511,6 +511,14 @@
context 'then #stop' do
before { start }
it { expect { span_op.stop }.to change { span_op.duration }.from(nil).to(kind_of(Float)) }

it 'sets the measured number of allocations as a metric' do
skip 'Measuring allocations is not supported on JRuby' if PlatformHelpers.jruby?

span_op.stop

expect(span_op.to_hash[:metrics]).to include('allocations' => a_value > 0)
end
end

context 'and callbacks have been configured' do
Expand Down Expand Up @@ -879,14 +887,17 @@
end

describe '#allocations' do
before do
skip 'Measuring allocations is not supported on JRuby' if PlatformHelpers.jruby?
end

subject(:allocations) { span_op.allocations }

it { is_expected.to be 0 }

context 'when span measures an operation' do
before do
skip 'Test unstable; improve stability before re-enabling.'
span_op.measure {}
span_op.measure { Object.new }
end

it { is_expected.to be > 0 }
Expand All @@ -895,7 +906,7 @@
let(:span_op_two) { described_class.new('span_op_two') }

before do
span_op_two.measure { Object.new }
span_op_two.measure { 10_000.times { Object.new } }
end

it { is_expected.to be < span_op_two.allocations }
Expand Down
1 change: 0 additions & 1 deletion spec/ddtrace/span_spec.rb
Original file line number Diff line number Diff line change
Expand Up @@ -213,7 +213,6 @@
type: nil,
meta: {},
metrics: {},
allocations: 0,
error: 0
)
end
Expand Down

0 comments on commit 59e8449

Please sign in to comment.