-
Notifications
You must be signed in to change notification settings - Fork 3.8k
Commit
This commit does not belong to any branch on this repository, and may belong to a fork outside of the repository.
59110: sql: convert SQL audit and execution log to a structured format r=jordanlewis a=knz First commit from #59108. Fixes #59105. Fixes #58999. Example new format for the query log: ``` I210118 17:20:32.675052 2009 10@util/log/event_log.go:32 [n1,client=127.0.0.1:11362,hostssl,user=demo] Structured entry: {"Timestamp":1610990432674339786, "EventType":"slow_query", "Statement":"SELECT * FROM \"\".\"\".t WHERE x = 10", "User":"demo", "ApplicationName":"$ cockroach demo", "ExecMode":"exec", "Age":0.790742, "FullTableScan":true} ``` Example new format, for audit events: ``` I210122 16:33:01.297735 2012 8@util/log/event_log.go:32 [n1,client=127.0.0.1:59820,hostssl,user=demo] Structured entry: {"Timestamp":1611333181296915618, "EventType":"sensitive_table_access", "Statement":"INSERT INTO \"\".\"\".helloworld(abc) VALUES (1)", "User":"demo", "DescriptorID":53, "ApplicationName":"$ cockroach demo", "ExecMode":"exec", "NumRows":1, "Age":0.895012, "TableName":"t.public.helloworld", "AccessMode":"rw"} ``` (Audit events have more fields, specifically `DescriptorID`, `TableName` and `AccessMode`, because they pertain to specific objects for which audit logging has been triggered.) Release note (sql change): CockroachDB now uses a structured logging format for the SQL audit, execution and query logs. See the reference documentation for details. Of note, audit and execution logs now also include information about whether a query plan contain full index scans. Previously, this information was only included in theslow query log. Release note (backward-incompatible change): The logging format for SQL audit, execution and query logs has changed, from a crude space-delimited format to JSON. To opt out of this new behavior and restore the pre-v21.1 logging format, you can set the cluster setting `sql.log.unstructured_entries.enabled` to true. Co-authored-by: Raphael 'kena' Poss <[email protected]>
- Loading branch information
Showing
19 changed files
with
2,587 additions
and
132 deletions.
There are no files selected for viewing
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Large diffs are not rendered by default.
Oops, something went wrong.
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,100 @@ | ||
| // Copyright 2020 The Cockroach Authors. | ||
| // | ||
| // Use of this software is governed by the Business Source License | ||
| // included in the file licenses/BSL.txt. | ||
| // | ||
| // As of the Change Date specified in that file, in accordance with | ||
| // the Business Source License, use of this software will be governed | ||
| // by the Apache License, Version 2.0, included in the file | ||
| // licenses/APL.txt. | ||
|
|
||
| package sql_test | ||
|
|
||
| import ( | ||
| "context" | ||
| "encoding/json" | ||
| "math" | ||
| "reflect" | ||
| "regexp" | ||
| "strings" | ||
| "testing" | ||
|
|
||
| "github.com/cockroachdb/cockroach/pkg/base" | ||
| "github.com/cockroachdb/cockroach/pkg/testutils/serverutils" | ||
| "github.com/cockroachdb/cockroach/pkg/util/leaktest" | ||
| "github.com/cockroachdb/cockroach/pkg/util/log" | ||
| "github.com/cockroachdb/cockroach/pkg/util/log/eventpb" | ||
| "github.com/cockroachdb/cockroach/pkg/util/timeutil" | ||
| "github.com/cockroachdb/redact" | ||
| ) | ||
|
|
||
| func TestStructuredEventLogging(t *testing.T) { | ||
| defer leaktest.AfterTest(t)() | ||
|
|
||
| // We really need to have the logs go to files, so that -show-logs | ||
| // does not break the "authlog" directives. | ||
| sc := log.ScopeWithoutShowLogs(t) | ||
| defer sc.Close(t) | ||
|
|
||
| ctx := context.Background() | ||
|
|
||
| s, conn, _ := serverutils.StartServer(t, base.TestServerArgs{}) | ||
| defer s.Stopper().Stop(ctx) | ||
|
|
||
| testStartTs := timeutil.Now() | ||
|
|
||
| // Make a prepared statement that changes a cluster setting: | ||
| // - we want a prepared statement to verify that the reporting of | ||
| // placeholders works during EXECUTE. | ||
| // - we don't care about the particular cluster setting; any | ||
| // setting that does not otherwise impact the test's semantics | ||
| // will do. | ||
| const setStmt = `SET CLUSTER SETTING "sql.defaults.default_int_size" = $1` | ||
| if _, err := conn.ExecContext(ctx, | ||
| `PREPARE a(INT) AS `+setStmt, | ||
| ); err != nil { | ||
| t.Fatal(err) | ||
| } | ||
| // Run the prepared statement. This triggers a structured entry | ||
| // for the cluster setting change. | ||
| if _, err := conn.ExecContext(ctx, `EXECUTE a(8)`); err != nil { | ||
| t.Fatal(err) | ||
| } | ||
|
|
||
| // Ensure that the entries hit the OS so they can be read back below. | ||
| log.Flush() | ||
|
|
||
| entries, err := log.FetchEntriesFromFiles(testStartTs.UnixNano(), | ||
| math.MaxInt64, 10000, execLogRe, log.WithMarkedSensitiveData) | ||
| if err != nil { | ||
| t.Fatal(err) | ||
| } | ||
|
|
||
| foundEntry := false | ||
| for _, e := range entries { | ||
| if !strings.Contains(e.Message, "set_cluster_setting") { | ||
| continue | ||
| } | ||
| foundEntry = true | ||
| // TODO(knz): Remove this when crdb-v2 becomes the new format. | ||
| e.Message = strings.TrimPrefix(e.Message, "Structured entry:") | ||
| // crdb-v2 starts json with an equal sign. | ||
| e.Message = strings.TrimPrefix(e.Message, "=") | ||
| jsonPayload := []byte(e.Message) | ||
| var ev eventpb.SetClusterSetting | ||
| if err := json.Unmarshal(jsonPayload, &ev); err != nil { | ||
| t.Errorf("unmarshalling %q: %v", e.Message, err) | ||
| } | ||
| if expected := string(redact.Sprint(setStmt)); ev.Statement != expected { | ||
| t.Errorf("wrong statement: expected %q, got %q", expected, ev.Statement) | ||
| } | ||
| if expected := []string{string(redact.Sprint("8"))}; !reflect.DeepEqual(expected, ev.PlaceholderValues) { | ||
| t.Errorf("wrong placeholders: expected %+v, got %+v", expected, ev.PlaceholderValues) | ||
| } | ||
| } | ||
| if !foundEntry { | ||
| t.Error("structured entry for set_cluster_setting not found in log") | ||
| } | ||
| } | ||
|
|
||
| var execLogRe = regexp.MustCompile(`event_log.go`) |
Oops, something went wrong.