opentelemetry-ruby icon indicating copy to clipboard operation
opentelemetry-ruby copied to clipboard

support truncating attributes in links and OTEL_ATTRIBUTE_VALUE_LENGTH_LIMIT env var

Open tsloughter opened this issue 2 years ago • 4 comments

This is a draft because the test in span_test.rb fails and I've given up on figuring out why and hoping someone sees what is wrong :). The testin tracer_test.rb works and basically does the same thing, but I felt I shouldn't just drop the other test in case it is finding an actual issue. Hopefully it is instead me just missing something.

tsloughter avatar Mar 01 '22 18:03 tsloughter

Oh, I should have mentioned, the failure isn't that the attribute value is still the long version but that it isn't there at all. The attribute hash is empty in the link on line 495.

tsloughter avatar Mar 01 '22 19:03 tsloughter

The constructor for a Link doesn't accept named parameters: https://github.com/open-telemetry/opentelemetry-ruby/blob/ad51972e9bdc8ead0e69642056a4935683464dfc/api/lib/opentelemetry/trace/link.rb#L35

If you inspect the link object you are creating directly, you can see that we get something unexpected:

opentelemetry-ruby/sdk on  HEAD (8ff19f9) [!] via 💎 v3.0.2
zsh ❯ git diff
diff --git a/sdk/test/opentelemetry/sdk/trace/span_test.rb b/sdk/test/opentelemetry/sdk/trace/span_test.rb
index 26f78070..ca7567e5 100644
--- a/sdk/test/opentelemetry/sdk/trace/span_test.rb
+++ b/sdk/test/opentelemetry/sdk/trace/span_test.rb
@@ -490,6 +490,7 @@ describe OpenTelemetry::SDK::Trace::Span do

     it 'truncate link attributes' do
       links = [OpenTelemetry::Trace::Link.new(context, attributes: { 'foo' => 'oldbaroldbaroldbaroldbaroldbaroldbar' })]
+      pp links.first.attributes
       span = Span.new(context, Context.empty, OpenTelemetry::Trace::Span::INVALID, 'name', SpanKind::INTERNAL, nil, span_limits,
                       [], nil, links, Time.now, nil, nil)
       _(span.links.first.attributes['foo']).must_equal('oldbaroldbaroldbaroldbaroldba...')

opentelemetry-ruby/sdk on  HEAD (8ff19f9) [!] via 💎 v3.0.2
zsh ❯ bundle exec rake test TEST=test/opentelemetry/sdk/trace/span_test.rb TESTOPTS="--name=/truncate/"
Run options: --name=/truncate/ --seed 43992

# Running:

....{:attributes=>{"foo"=>"oldbaroldbaroldbaroldbaroldbaroldbar"}}

When you create the span, that attributes hash is rejected as invalid - see the trim_links method that the sdk span constructor calls, and then finally the valid_attributes? helper that flags it as invalid. That causes us to hit the 'slow path' in the trim_links method and we end up with the empty hash.

It's invalid, because only string keys are allowed, and you're unwittingly passing { attributes: { 'foo' => 'oldbaroldbaroldbaroldbaroldbaroldbar' } } 😆

Of course, if we weren't overriding the logger in our tests, then you might have not been stuck for so long:

opentelemetry-ruby/sdk on  HEAD (8ff19f9) [!] via 💎 v3.0.2
zsh ❯ git diff
diff --git a/sdk/test/test_helper.rb b/sdk/test/test_helper.rb
index 0c58f723..58bdc3ec 100644
--- a/sdk/test/test_helper.rb
+++ b/sdk/test/test_helper.rb
@@ -13,4 +13,4 @@ require 'opentelemetry/sdk'
 require 'minitest/autorun'
 require 'pry'

-OpenTelemetry.logger = Logger.new(File::NULL)
+# OpenTelemetry.logger = Logger.new(File::NULL)

opentelemetry-ruby/sdk on  HEAD (8ff19f9) [!] via 💎 v3.0.2
zsh ❯ bundle exec rake test TEST=test/opentelemetry/sdk/trace/span_test.rb TESTOPTS="--name=/truncate/"
Run options: --name=/truncate/ --seed 29750

# Running:

.E, [2022-03-02T09:12:57.740672 #1552] ERROR -- : OpenTelemetry error: invalid link attribute key type Symbol on span 'name'
F...

Finished in 0.019087s, 261.9584 runs/s, 261.9584 assertions/s.

In any case, if you just pass the hash directly as a positional argument, you start to get somewhere. It's still broken, just ... differently broken:

opentelemetry-ruby/sdk on  HEAD (8ff19f9) [!] via 💎 v3.0.2 took 9s
zsh ❯ git diff
diff --git a/sdk/test/opentelemetry/sdk/trace/span_test.rb b/sdk/test/opentelemetry/sdk/trace/span_test.rb
index 26f78070..25a86fad 100644
--- a/sdk/test/opentelemetry/sdk/trace/span_test.rb
+++ b/sdk/test/opentelemetry/sdk/trace/span_test.rb
@@ -489,7 +489,7 @@ describe OpenTelemetry::SDK::Trace::Span do
     end

     it 'truncate link attributes' do
-      links = [OpenTelemetry::Trace::Link.new(context, attributes: { 'foo' => 'oldbaroldbaroldbaroldbaroldbaroldbar' })]
+      links = [OpenTelemetry::Trace::Link.new(context, { 'foo' => 'oldbaroldbaroldbaroldbaroldbaroldbar' })]
       span = Span.new(context, Context.empty, OpenTelemetry::Trace::Span::INVALID, 'name', SpanKind::INTERNAL, nil, span_limits,
                       [], nil, links, Time.now, nil, nil)
       _(span.links.first.attributes['foo']).must_equal('oldbaroldbaroldbaroldbaroldba...')

opentelemetry-ruby/sdk on  HEAD (8ff19f9) [!] via 💎 v3.0.2
zsh ❯ bundle exec rake test TEST=test/opentelemetry/sdk/trace/span_test.rb TESTOPTS="--name=/truncate/"
Run options: --name=/truncate/ --seed 54611

# Running:

..F..

Finished in 0.008411s, 594.4596 runs/s, 594.4596 assertions/s.

  1) Failure:
OpenTelemetry::SDK::Trace::Span::#initialize#test_0008_truncate link attributes [/Users/andrew/projects/opentelemetry-ruby/sdk/test/opentelemetry/sdk/
trace/span_test.rb:495]:
--- expected
+++ actual
@@ -1 +1 @@
-"oldbaroldbaroldbaroldbaroldba..."
+"oldbaroldbaroldbaroldbaroldbaroldbar"


5 runs, 5 assertions, 1 failures, 0 errors, 0 skips

Sorry for the mess, but hopefully that unsticks you! 😄

ahayworth avatar Mar 02 '22 15:03 ahayworth

hm, rubocop says valid_attributes? is too complex.

tsloughter avatar Mar 08 '22 19:03 tsloughter

Ok, fixed that up by moving the string check into the simple value check.

tsloughter avatar Mar 08 '22 21:03 tsloughter

👋 This pull request has been marked as stale because it has been open with no activity. You can: comment on the issue or remove the stale label to hold stale off for a while, add the keep label to hold stale off permanently, or do nothing. If you do nothing this pull request will be closed eventually by the stale bot

github-actions[bot] avatar Mar 31 '24 01:03 github-actions[bot]