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

sql, telemetry: show correctly redacted error message #83807

Merged

Conversation

dhartunian
Copy link
Collaborator

Previously, the error string from an executed SQL statement was treated
as a string type which would get fully redacted on its way out to the
telemetry log.

This change writes the error type into a RedactableString which
preserves the redaction in the error as intended. This will preserve the
template string which we consider safe by default, for instance.

The CommonSQLExecDetails type in sql_audit_events.proto has been
modified to have the error_text field represented as a
RedactableString which helps us maintain the preservation of redaction
markers.

Resolves: #78353

Release note (ops change): Telemetry logs will now display more finely
redacted error messages from sql execution. Previously, the entire error
string was fully redacted.

@dhartunian dhartunian requested review from a team July 5, 2022 13:24
@cockroach-teamcity
Copy link
Member

This change is Reviewable

Copy link
Contributor

@abarganier abarganier left a comment

Choose a reason for hiding this comment

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

:lgtm:

Reviewable status: :shipit: complete! 1 of 0 LGTMs obtained

Copy link
Contributor

@andreimatei andreimatei left a comment

Choose a reason for hiding this comment

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

Reviewable status: :shipit: complete! 1 of 0 LGTMs obtained (waiting on @andreimatei and @dhartunian)


pkg/util/log/eventpb/sql_audit_events.proto line 33 at r1 (raw file):

  string sqlstate = 3 [(gogoproto.customname) = "SQLSTATE", (gogoproto.jsontag) = ",omitempty", (gogoproto.moretags) = "redact:\"nonsensitive\""];
  // The text of the error if any.
  string error_text = 4 [(gogoproto.jsontag) = ",omitempty", (gogoproto.customtype) = "github.com/cockroachdb/redact.RedactableString", (gogoproto.nullable) = false, (gogoproto.moretags) = "redact:\"mixed\""];

is there a way to test this field? The test you've modified doesn't seems to deal with it... or, does it?


pkg/sql/telemetry_logging_test.go line 117 at r1 (raw file):

		expectedUnredactedTags  []string
		expectedApplicationName string
		expectedErr             string

nit: comment that empty means no error, and, if you're so inclined, take the opportunity to turn all the "unkeyed literals" below into "keyed literals" (i.e. {name: "truncate-table-query", query: ""...}) - as they should have been from the beginning - and then elide the "" for the error.


pkg/sql/telemetry_logging_test.go line 193 at r1 (raw file):

			stubTime := timeutil.FromUnixMicros(int64(execTimestamp * 1e6))
			st.setTime(stubTime)
			_, _ = db.DB.ExecContext(context.Background(), tc.query)

shouldn't we fail here for test cases where we're not expecting an error?

@rafiss
Copy link
Collaborator

rafiss commented Jul 6, 2022

thanks for the fix! is this getting backported?

@vy-ton
Copy link
Contributor

vy-ton commented Jul 11, 2022

thanks for the fix! is this getting backported?
+1, I need this backported to analyze IMPORT errors

@dhartunian dhartunian force-pushed the redact-error-messages-in-sql-telemetry branch from 2112453 to c398f15 Compare July 18, 2022 15:09
Copy link
Collaborator Author

@dhartunian dhartunian left a comment

Choose a reason for hiding this comment

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

yep, I'll backport. thanks for the reminder.
def for 22.1, and I will also attempt 21.2.

Reviewable status: :shipit: complete! 0 of 0 LGTMs obtained (and 1 stale) (waiting on @andreimatei)


pkg/util/log/eventpb/sql_audit_events.proto line 33 at r1 (raw file):

Previously, andreimatei (Andrei Matei) wrote…

is there a way to test this field? The test you've modified doesn't seems to deal with it... or, does it?

yes, I've added an error text with partial redaction that's verified to return in the newly added test case.
If I don't make the change, the error will have redaction markers around the whole string like this:

    telemetry_logging_test.go:268: sql-error: missing error a role/user named ‹root› already exists in message {"Timestamp":1658157157275859295,"EventType":"sampled_query","Statement":"CREATE USER root","Tag":"CREATE ROLE","User":"root","ApplicationName":"telemetry-logging-test","ExecMode":"exec","SQLSTATE":"42710","ErrorText":"‹a role/user named root already exists›","Age":1.031134,"TxnCounter":19,"CostEstimate":0.02,"Distribution":"local","PlanGist":"Ais="}

pkg/sql/telemetry_logging_test.go line 117 at r1 (raw file):

Previously, andreimatei (Andrei Matei) wrote…

nit: comment that empty means no error, and, if you're so inclined, take the opportunity to turn all the "unkeyed literals" below into "keyed literals" (i.e. {name: "truncate-table-query", query: ""...}) - as they should have been from the beginning - and then elide the "" for the error.

done.


pkg/sql/telemetry_logging_test.go line 193 at r1 (raw file):

Previously, andreimatei (Andrei Matei) wrote…

shouldn't we fail here for test cases where we're not expecting an error?

yep! done.

@dhartunian dhartunian force-pushed the redact-error-messages-in-sql-telemetry branch from c398f15 to 3530cbf Compare July 20, 2022 16:26
@dhartunian dhartunian force-pushed the redact-error-messages-in-sql-telemetry branch from 3530cbf to ae18b5d Compare July 31, 2022 17:44
Previously, the error string from an executed SQL statement was treated
as a `string` type which would get fully redacted on its way out to the
telemetry log.

This change writes the `error` type into a `RedactableString` which
preserves the redaction in the error as intended. This will preserve the
template string which we consider safe by default, for instance.

The `CommonSQLExecDetails` type in `sql_audit_events.proto` has been
modified to have the `error_text` field represented as a
`RedactableString` which helps us maintain the preservation of redaction
markers.

Resolves: cockroachdb#78353

Release note (ops change): Telemetry logs will now display more finely
redacted error messages from sql execution. Previously, the entire error
string was fully redacted.
@dhartunian dhartunian force-pushed the redact-error-messages-in-sql-telemetry branch from ae18b5d to 53f6a05 Compare July 31, 2022 18:29
@dhartunian
Copy link
Collaborator Author

TFTRs

bors r=andreimatei,rafiss,abarganier

@craig
Copy link
Contributor

craig bot commented Aug 1, 2022

Build succeeded:

@craig craig bot merged commit 94b9091 into cockroachdb:master Aug 1, 2022
@blathers-crl
Copy link

blathers-crl bot commented Aug 1, 2022

Encountered an error creating backports. Some common things that can go wrong:

  1. The backport branch might have already existed.
  2. There was a merge conflict.
  3. The backport branch contained merge commits.

You might need to create your backport manually using the backport tool.


error creating merge commit from 53f6a05 to blathers/backport-release-21.2-83807: POST https://api.github.com/repos/cockroachdb/cockroach/merges: 409 Merge conflict []

you may need to manually resolve merge conflicts with the backport tool.

Backport to branch 21.2.x failed. See errors above.


🦉 Hoot! I am a Blathers, a bot for CockroachDB. My owner is otan.

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.

telemetry: do not redact error text names in telemetry logs
6 participants