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

fix: update pg instrumentation to handle non primitive argument #1146

Merged
merged 8 commits into from Mar 29, 2022

Conversation

ericmustin
Copy link
Contributor

Summary

Addresses #1139

the pg connection_adapter .execute method can be invoked with arguments that are not a String class, like a Arel::Nodes::SqlLiteral.

While Arel::Nodes::SqlLiteral is a String subclass, Our otlp exporter doesn't gracefully handle Subclasses of accepted attribute types (see here), and instead just returns an error and drops the attribute when attempting to encode a non valid type.

I'm hesitant to fiddle with the portion of our OTLP exporter code that handles encoding, as we'd have to be careful not to introduce a regression.

Instead, since we know which instrumentation is problematic and what attributes, it's more straightforward to just coerce that specific attribute to aString class, which is what this PR does (it calls .to_s defensively).

Copy link
Contributor

@ahayworth ahayworth left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I had a question re: the defensive programming, but I don't think it's anything worth blocking the PR over.

This is a good fix - and thank you to @danielmbarlow for finding the issue! As an avid Arel.sql fan myself, we should have been testing for this from the beginning. 🤦 😆

…s/connection.rb

Co-authored-by: Ariel Valentin <arielvalentin@users.noreply.github.com>
Copy link
Contributor

@plantfansam plantfansam left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👌 lovely! Had a in-line nit that you can take or leave as you wish 😄

@@ -84,7 +84,7 @@ def span_attrs(kind, *args) # rubocop:disable Metrics/AbcSize
end

attrs = { 'db.operation' => validated_operation(operation), 'db.postgresql.prepared_statement_name' => statement_name }
attrs['db.statement'] = sql unless config[:db_statement] == :omit
attrs['db.statement'] = sql.to_s if config[:db_statement] != :omit && sql&.to_s
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nit, but: thoughts on changing to attrs['db.statement'] = sql&.to_s if config[:db_statement] != :omit && !sql.nil? or just attrs['db.statement'] = sql&.to_s if config[:db_statement] != :omit

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

i've updated this to attrs['db.statement'] = sql&.to_s unless config[:db_statement] == :omit

I think this is as concise as i can get and handles all the edge cases and doesnt anger rubocop

@@ -84,7 +84,7 @@ def span_attrs(kind, *args) # rubocop:disable Metrics/AbcSize
end

attrs = { 'db.operation' => validated_operation(operation), 'db.postgresql.prepared_statement_name' => statement_name }
attrs['db.statement'] = sql unless config[:db_statement] == :omit
attrs['db.statement'] = sql&.to_s unless config[:db_statement] == :omit
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is there a circumstance where sql would be nil? That would have been problematic previously, since attribute values have to be non-nil, and validation would have dropped it and logged an error.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note: I realize this has been beaten to death, but I really don't think this level of defensiveness is warranted here.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This test case

# We should have evicted the statement from the cache
_(last_span.attributes['db.statement']).must_be_nil

WIthout the defensiveness it seems it's possible that lru_cache returns nil, which then gets encoded to "" by .to_s. This failed test case is what prompted the defensiveness in the first place https://github.com/open-telemetry/opentelemetry-ruby/runs/5524602649?check_suite_focus=true

I hadn't really looked into the lru cache details or instrumentation implementation other than that it does seem possible, in some cases, for sql to be nil, we are currently testing for that case for some reason, and so we should have a nil check.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It feels like that's more a case of the cache not working correctly. If the lru_cache returns nil, we should handle that cache miss and update the cache rather than papering over the problem with a &..

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The lru_cache is a little unusual here - the expectation is that we write into the cache in the PREPARE case and read from it in the EXECUTE case. I think we should handle the sql.nil? case on line 81, where we read from the cache. By the time we get here, sql should be non-nil.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think the idea, (@ahayworth correct me if i'm wrong) is that this specific case is for handling prepared statements. Reviewing the test here, w/an lru cache of size 50:

  • user prepares 51 statements
  • each time prepare is called, we perform the obfuscation and cache <statement-name>:<obfuscated-prepared-statement> k:v pair.
  • The 51st call evicts the least recently used <statement-name>:<obfuscated-prepared-statement> k:v pair
  • when the user later attempts to execute that already-evicted <statement-name>:<obfuscated-prepared-statement> k:v pair via .execute(<statement-name>), it causes a cache miss and we can't update the cache because we no longer have access to the <obfuscated-prepared-statement> to set as a value, so the lru_cache returns nil.

I don't know what the improvement would be here, this seems like an expected behavior, albeit one with tradeoffs.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤦 we handle nil attributes on the next line. This is complicated and confusing IMO. I think we should .to_s the result from obfuscate_sql, either in that method or on lines 72 and 77. Then we always cache strings.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ok

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ericmustin your understanding of the LRU cache is correct, both in functionality and in purpose.

Copy link
Contributor

@plantfansam plantfansam left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@robertlaurin robertlaurin merged commit 8eac4a1 into main Mar 29, 2022
@robertlaurin robertlaurin deleted the update_ar_instrumentation branch March 29, 2022 14:36
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

PG Instrumentation: Invalid span attribute value type Arel::Nodes::SqlLiteral
6 participants