From 0e6abb5778079f9560eae51b33979654c0894639 Mon Sep 17 00:00:00 2001 From: Raphael 'kena' Poss Date: Tue, 30 Nov 2021 16:42:02 +0000 Subject: [PATCH] log,server: avoid global variables to log/trace server IDs Prior to this change, the server identifiers (cluster ID, node ID etc) were stored in global variables in the `log` package. This was problematic when a single process contains multiple servers, e.g. in tests, `demo` and multi-tenant CockroachDB. This change switches the mechanism to use identifiers stored in the go context. The disadvantage is that the server IDs are not any more logged at the beginning of each log file (since a given log file could report data from multiple servers). Release note (cli change): The server identifiers (cluster ID, node ID, tenant ID, instance ID) are not any more duplicated at the start of every new log file (during log file rotations). They are now only logged when known during server start-up. (The copy of the identifiers is still included in per-event envelopes for the various `json` output logging formats.) --- pkg/ccl/backupccl/backup_test.go | 22 --- pkg/ccl/changefeedccl/helpers_test.go | 1 - pkg/ccl/importccl/import_stmt_test.go | 3 - .../kvccl/kvtenantccl/tenant_upgrade_test.go | 8 -- pkg/ccl/serverccl/statusccl/BUILD.bazel | 1 - .../serverccl/statusccl/tenant_grpc_test.go | 2 - .../serverccl/statusccl/tenant_test_utils.go | 2 - pkg/ccl/sqlproxyccl/proxy_handler_test.go | 1 - pkg/ccl/sqlproxyccl/tenant/directory_test.go | 1 - .../streamingest/stream_ingestion_job_test.go | 3 - .../testccl/sqlccl/temp_table_clean_test.go | 8 +- pkg/cli/democluster/BUILD.bazel | 1 - pkg/cli/democluster/demo_cluster.go | 2 - .../interactive_tests/test_log_config_msg.tcl | 21 +-- pkg/cli/start.go | 6 - pkg/cmd/roachtest/tests/multitenant.go | 8 +- pkg/server/config.go | 125 +++++++++++++++++- pkg/server/tenant.go | 15 +-- .../spanconfigtestcluster/BUILD.bazel | 1 - .../spanconfigtestcluster/cluster.go | 5 - pkg/sql/exec_util.go | 4 - pkg/sql/logictest/logic.go | 3 - pkg/sql/sqltestutils/BUILD.bazel | 1 - pkg/sql/sqltestutils/telemetry.go | 4 - pkg/util/log/BUILD.bazel | 1 + pkg/util/log/ambient_context.go | 13 ++ pkg/util/log/clog.go | 70 ---------- pkg/util/log/clog_test.go | 4 +- pkg/util/log/flags.go | 10 -- pkg/util/log/format_json.go | 15 +-- pkg/util/log/format_json_test.go | 4 +- pkg/util/log/log_entry.go | 16 +-- pkg/util/log/server_ident.go | 70 ++++++++++ pkg/util/log/test_log_scope.go | 4 - pkg/util/log/testdata/json | 8 +- 35 files changed, 237 insertions(+), 226 deletions(-) create mode 100644 pkg/util/log/server_ident.go diff --git a/pkg/ccl/backupccl/backup_test.go b/pkg/ccl/backupccl/backup_test.go index d04d156ff763..1c54d3ee8813 100644 --- a/pkg/ccl/backupccl/backup_test.go +++ b/pkg/ccl/backupccl/backup_test.go @@ -6873,9 +6873,6 @@ func TestBackupRestoreInsideTenant(t *testing.T) { defer log.Scope(t).Close(t) makeTenant := func(srv serverutils.TestServerInterface, tenant uint64) (*sqlutils.SQLRunner, func()) { - // Prevent a logging assertion that the server ID is initialized multiple times. - log.TestingClearServerIdentifiers() - _, conn := serverutils.StartTenant(t, srv, base.TestTenantArgs{TenantID: roachpb.MakeTenantID(tenant)}) cleanup := func() { conn.Close() } return sqlutils.MakeSQLRunner(conn), cleanup @@ -7031,16 +7028,11 @@ func TestBackupRestoreTenant(t *testing.T) { systemDB.Exec(t, `BACKUP system.users TO 'nodelocal://1/users'`) systemDB.CheckQueryResults(t, `SELECT manifest->>'tenants' FROM [SHOW BACKUP 'nodelocal://1/users' WITH as_json]`, [][]string{{"[]"}}) - // Prevent a logging assertion that the server ID is initialized multiple times. - log.TestingClearServerIdentifiers() - _, conn11 := serverutils.StartTenant(t, srv, base.TestTenantArgs{TenantID: roachpb.MakeTenantID(11)}) defer conn11.Close() tenant11 := sqlutils.MakeSQLRunner(conn11) tenant11.Exec(t, `CREATE DATABASE foo; CREATE TABLE foo.baz(i int primary key); INSERT INTO foo.baz VALUES (111), (211)`) - log.TestingClearServerIdentifiers() - _, conn20 := serverutils.StartTenant(t, srv, base.TestTenantArgs{TenantID: roachpb.MakeTenantID(20)}) defer conn20.Close() tenant20 := sqlutils.MakeSQLRunner(conn20) @@ -7100,8 +7092,6 @@ func TestBackupRestoreTenant(t *testing.T) { [][]string{{`100`, `0`, `0`, `0`}}, ) - log.TestingClearServerIdentifiers() - ten10Stopper := stop.NewStopper() _, restoreConn10 := serverutils.StartTenant( t, restoreTC.Server(0), base.TestTenantArgs{ @@ -7146,8 +7136,6 @@ func TestBackupRestoreTenant(t *testing.T) { [][]string{{`10`, `true`, `{"id": "10", "state": "ACTIVE"}`}}, ) - log.TestingClearServerIdentifiers() - _, restoreConn10 = serverutils.StartTenant( t, restoreTC.Server(0), base.TestTenantArgs{TenantID: roachpb.MakeTenantID(10), Existing: true}, ) @@ -7187,8 +7175,6 @@ func TestBackupRestoreTenant(t *testing.T) { [][]string{{`10`, `true`, `{"id": "10", "state": "ACTIVE"}`}}, ) - log.TestingClearServerIdentifiers() - _, restoreConn10 := serverutils.StartTenant( t, restoreTC.Server(0), base.TestTenantArgs{TenantID: roachpb.MakeTenantID(10), Existing: true}, ) @@ -7218,8 +7204,6 @@ func TestBackupRestoreTenant(t *testing.T) { }, ) - log.TestingClearServerIdentifiers() - _, restoreConn10 := serverutils.StartTenant( t, restoreTC.Server(0), base.TestTenantArgs{TenantID: roachpb.MakeTenantID(10), Existing: true}, ) @@ -7229,8 +7213,6 @@ func TestBackupRestoreTenant(t *testing.T) { restoreTenant10.CheckQueryResults(t, `select * from foo.bar`, tenant10.QueryStr(t, `select * from foo.bar`)) restoreTenant10.CheckQueryResults(t, `select * from foo.bar2`, tenant10.QueryStr(t, `select * from foo.bar2`)) - log.TestingClearServerIdentifiers() - _, restoreConn11 := serverutils.StartTenant( t, restoreTC.Server(0), base.TestTenantArgs{TenantID: roachpb.MakeTenantID(11), Existing: true}, ) @@ -7249,8 +7231,6 @@ func TestBackupRestoreTenant(t *testing.T) { restoreDB.Exec(t, `RESTORE TENANT 10 FROM 'nodelocal://1/t10' AS OF SYSTEM TIME `+ts1) - log.TestingClearServerIdentifiers() - _, restoreConn10 := serverutils.StartTenant( t, restoreTC.Server(0), base.TestTenantArgs{TenantID: roachpb.MakeTenantID(10), Existing: true}, ) @@ -7269,8 +7249,6 @@ func TestBackupRestoreTenant(t *testing.T) { restoreDB.Exec(t, `RESTORE TENANT 20 FROM 'nodelocal://1/t20'`) - log.TestingClearServerIdentifiers() - _, restoreConn20 := serverutils.StartTenant( t, restoreTC.Server(0), base.TestTenantArgs{TenantID: roachpb.MakeTenantID(20), Existing: true}, ) diff --git a/pkg/ccl/changefeedccl/helpers_test.go b/pkg/ccl/changefeedccl/helpers_test.go index f6bce4d1ee5b..a1c0a911f0f3 100644 --- a/pkg/ccl/changefeedccl/helpers_test.go +++ b/pkg/ccl/changefeedccl/helpers_test.go @@ -410,7 +410,6 @@ func startTestCluster(t testing.TB) (serverutils.TestClusterInterface, *gosql.DB func startTestTenant( t testing.TB, options feedTestOptions, ) (serverutils.TestServerInterface, *gosql.DB, func()) { - log.TestingClearServerIdentifiers() ctx := context.Background() kvServer, _, cleanup := startTestFullServer(t, options) diff --git a/pkg/ccl/importccl/import_stmt_test.go b/pkg/ccl/importccl/import_stmt_test.go index 5a411925e707..fb432171cde8 100644 --- a/pkg/ccl/importccl/import_stmt_test.go +++ b/pkg/ccl/importccl/import_stmt_test.go @@ -6875,9 +6875,6 @@ func TestImportInTenant(t *testing.T) { defer conn10.Close() t10 := sqlutils.MakeSQLRunner(conn10) - // Prevent a logging assertion that the server ID is initialized multiple times. - log.TestingClearServerIdentifiers() - // Setup a few tenants, each with a different table. _, conn11 := serverutils.StartTenant(t, tc.Server(0), base.TestTenantArgs{TenantID: roachpb.MakeTenantID(11)}) defer conn11.Close() diff --git a/pkg/ccl/kvccl/kvtenantccl/tenant_upgrade_test.go b/pkg/ccl/kvccl/kvtenantccl/tenant_upgrade_test.go index 7e333084cc7d..ce7e9094a7dd 100644 --- a/pkg/ccl/kvccl/kvtenantccl/tenant_upgrade_test.go +++ b/pkg/ccl/kvccl/kvtenantccl/tenant_upgrade_test.go @@ -26,7 +26,6 @@ import ( "github.com/cockroachdb/cockroach/pkg/testutils/sqlutils" "github.com/cockroachdb/cockroach/pkg/testutils/testcluster" "github.com/cockroachdb/cockroach/pkg/util/leaktest" - "github.com/cockroachdb/cockroach/pkg/util/log" "github.com/cockroachdb/cockroach/pkg/util/stop" "github.com/stretchr/testify/require" ) @@ -90,8 +89,6 @@ func TestTenantUpgrade(t *testing.T) { TestingKnobs: base.TestingKnobs{}, Settings: settings, } - // Prevent a logging assertion that the server ID is initialized multiple times. - log.TestingClearServerIdentifiers() tenant, err := tc.Server(0).StartTenant(ctx, tenantArgs) require.NoError(t, err) return connectToTenant(t, tenant.SQLAddr()) @@ -130,7 +127,6 @@ func TestTenantUpgrade(t *testing.T) { // Restart the tenant and ensure that the version is correct. cleanup() { - log.TestingClearServerIdentifiers() tenantServer, err := tc.Server(0).StartTenant(ctx, base.TestTenantArgs{ TenantID: roachpb.MakeTenantID(initialTenantID), Existing: true, @@ -156,7 +152,6 @@ func TestTenantUpgrade(t *testing.T) { // Restart the new tenant and ensure it has the right version. cleanup() { - log.TestingClearServerIdentifiers() tenantServer, err := tc.Server(0).StartTenant(ctx, base.TestTenantArgs{ TenantID: roachpb.MakeTenantID(postUpgradeTenantID), Existing: true, @@ -286,8 +281,6 @@ func TestTenantUpgradeFailure(t *testing.T) { }, Settings: settings, } - // Prevent a logging assertion that the server ID is initialized multiple times. - log.TestingClearServerIdentifiers() return &tenantInfo{tenantArgs: &tenantArgs, v2onMigrationStopper: v2onMigrationStopper} } @@ -334,7 +327,6 @@ func TestTenantUpgradeFailure(t *testing.T) { // Restart the tenant and ensure that the version is correct. cleanup() { - log.TestingClearServerIdentifiers() tca, cleanup := startAndConnectToTenant(t, tenantInfo) defer cleanup() initialTenantRunner = sqlutils.MakeSQLRunner(tca) diff --git a/pkg/ccl/serverccl/statusccl/BUILD.bazel b/pkg/ccl/serverccl/statusccl/BUILD.bazel index ac07d654f687..6dc238131364 100644 --- a/pkg/ccl/serverccl/statusccl/BUILD.bazel +++ b/pkg/ccl/serverccl/statusccl/BUILD.bazel @@ -16,7 +16,6 @@ go_library( "//pkg/testutils/serverutils", "//pkg/testutils/sqlutils", "//pkg/util/httputil", - "//pkg/util/log", "//pkg/util/protoutil", "@com_github_stretchr_testify//require", ], diff --git a/pkg/ccl/serverccl/statusccl/tenant_grpc_test.go b/pkg/ccl/serverccl/statusccl/tenant_grpc_test.go index 8868fdf69648..524ff64c9598 100644 --- a/pkg/ccl/serverccl/statusccl/tenant_grpc_test.go +++ b/pkg/ccl/serverccl/statusccl/tenant_grpc_test.go @@ -91,7 +91,6 @@ func TestTenantGRPCServices(t *testing.T) { sqlRunner.Exec(t, "CREATE TABLE test (id int)") sqlRunner.Exec(t, "INSERT INTO test VALUES (1)") - log.TestingClearServerIdentifiers() tenant2, connTenant2 := serverutils.StartTenant(t, server, base.TestTenantArgs{ TenantID: tenantID, Existing: true, @@ -110,7 +109,6 @@ func TestTenantGRPCServices(t *testing.T) { require.Contains(t, string(body), "INSERT INTO test VALUES") }) - log.TestingClearServerIdentifiers() tenant3, connTenant3 := serverutils.StartTenant(t, server, base.TestTenantArgs{ TenantID: roachpb.MakeTenantID(11), TestingKnobs: testingKnobs, diff --git a/pkg/ccl/serverccl/statusccl/tenant_test_utils.go b/pkg/ccl/serverccl/statusccl/tenant_test_utils.go index 871bde2c215f..71463b44cec8 100644 --- a/pkg/ccl/serverccl/statusccl/tenant_test_utils.go +++ b/pkg/ccl/serverccl/statusccl/tenant_test_utils.go @@ -25,7 +25,6 @@ import ( "github.com/cockroachdb/cockroach/pkg/testutils/serverutils" "github.com/cockroachdb/cockroach/pkg/testutils/sqlutils" "github.com/cockroachdb/cockroach/pkg/util/httputil" - "github.com/cockroachdb/cockroach/pkg/util/log" "github.com/cockroachdb/cockroach/pkg/util/protoutil" "github.com/stretchr/testify/require" ) @@ -58,7 +57,6 @@ func newTestTenant( tenantParams.Existing = existing tenantParams.TestingKnobs = knobs - log.TestingClearServerIdentifiers() tenant, tenantConn := serverutils.StartTenant(t, server, tenantParams) sqlDB := sqlutils.MakeSQLRunner(tenantConn) status := tenant.StatusServer().(serverpb.SQLStatusServer) diff --git a/pkg/ccl/sqlproxyccl/proxy_handler_test.go b/pkg/ccl/sqlproxyccl/proxy_handler_test.go index e980e16d6ae7..f3af06fa83be 100644 --- a/pkg/ccl/sqlproxyccl/proxy_handler_test.go +++ b/pkg/ccl/sqlproxyccl/proxy_handler_test.go @@ -1160,7 +1160,6 @@ func newDirectoryServer( return nil, status.Error(codes.NotFound, "tenant not found") } - log.TestingClearServerIdentifiers() tenantStopper := tenantdirsvr.NewSubStopper(tdsStopper) ten, err := srv.StartTenant(ctx, base.TestTenantArgs{ Existing: true, diff --git a/pkg/ccl/sqlproxyccl/tenant/directory_test.go b/pkg/ccl/sqlproxyccl/tenant/directory_test.go index 62c49b45e9e9..d480f809e3ea 100644 --- a/pkg/ccl/sqlproxyccl/tenant/directory_test.go +++ b/pkg/ccl/sqlproxyccl/tenant/directory_test.go @@ -486,7 +486,6 @@ func destroyTenant(tc serverutils.TestClusterInterface, id roachpb.TenantID) err func startTenant( ctx context.Context, srv serverutils.TestServerInterface, id uint64, ) (*tenantdirsvr.Process, error) { - log.TestingClearServerIdentifiers() tenantStopper := tenantdirsvr.NewSubStopper(srv.Stopper()) t, err := srv.StartTenant( ctx, diff --git a/pkg/ccl/streamingccl/streamingest/stream_ingestion_job_test.go b/pkg/ccl/streamingccl/streamingest/stream_ingestion_job_test.go index 80c290898aa3..81df7e9710d2 100644 --- a/pkg/ccl/streamingccl/streamingest/stream_ingestion_job_test.go +++ b/pkg/ccl/streamingccl/streamingest/stream_ingestion_job_test.go @@ -69,9 +69,6 @@ SET CLUSTER SETTING changefeed.experimental_poll_interval = '10ms' `) require.NoError(t, err) - // Prevent a logging assertion that the server ID is initialized multiple times. - log.TestingClearServerIdentifiers() - // Start the destination server. hDest, cleanupDest := streamingtest.NewReplicationHelper(t, base.TestServerArgs{}) defer cleanupDest() diff --git a/pkg/ccl/testccl/sqlccl/temp_table_clean_test.go b/pkg/ccl/testccl/sqlccl/temp_table_clean_test.go index ca6bcaa777dd..4d1848ff9e7b 100644 --- a/pkg/ccl/testccl/sqlccl/temp_table_clean_test.go +++ b/pkg/ccl/testccl/sqlccl/temp_table_clean_test.go @@ -20,7 +20,6 @@ import ( "github.com/cockroachdb/cockroach/pkg/testutils/serverutils" "github.com/cockroachdb/cockroach/pkg/testutils/sqlutils" "github.com/cockroachdb/cockroach/pkg/util/leaktest" - "github.com/cockroachdb/cockroach/pkg/util/log" "github.com/cockroachdb/cockroach/pkg/util/stop" "github.com/cockroachdb/cockroach/pkg/util/syncutil" ) @@ -100,7 +99,6 @@ func TestTenantTempTableCleanup(t *testing.T) { }, }, ) - log.TestingClearServerIdentifiers() tenantStoppers := []*stop.Stopper{stop.NewStopper(), stop.NewStopper()} _, tenantPrimaryDB := serverutils.StartTenant(t, tc.Server(0), base.TestTenantArgs{ @@ -118,8 +116,7 @@ func TestTenantTempTableCleanup(t *testing.T) { tenantSQL.Exec(t, "SET experimental_enable_temp_tables = 'on'") tenantSQL.Exec(t, "set cluster setting sql.temp_object_cleaner.cleanup_interval='1 seconds'") tenantSQL.Exec(t, "CREATE TEMP TABLE temp_table (x INT PRIMARY KEY, y INT);") - // Prevent a logging assertion that the server ID is initialized multiple times. - log.TestingClearServerIdentifiers() + _, tenantSecondDB := serverutils.StartTenant(t, tc.Server(1), base.TestTenantArgs{ Existing: true, @@ -127,7 +124,6 @@ func TestTenantTempTableCleanup(t *testing.T) { Settings: settings, Stopper: tenantStoppers[1], }) - log.TestingClearServerIdentifiers() tenantSecondSQL := sqlutils.MakeSQLRunner(tenantSecondDB) tenantSecondSQL.CheckQueryResults(t, "SELECT table_name FROM [SHOW TABLES]", [][]string{ @@ -160,8 +156,6 @@ func TestTenantTempTableCleanup(t *testing.T) { // Enable our hook to allow the database to be // brought up. pause() - // Prevent a logging assertion that the server ID is initialized multiple times. - log.TestingClearServerIdentifiers() // Once we restart the tenant, no sessions should exist // so all temporary tables should be cleaned up. tenantStoppers[0] = stop.NewStopper() diff --git a/pkg/cli/democluster/BUILD.bazel b/pkg/cli/democluster/BUILD.bazel index b9decb4d733e..495285b8bd70 100644 --- a/pkg/cli/democluster/BUILD.bazel +++ b/pkg/cli/democluster/BUILD.bazel @@ -30,7 +30,6 @@ go_library( "//pkg/server/serverpb", "//pkg/server/status", "//pkg/settings", - "//pkg/sql", "//pkg/sql/catalog/catalogkeys", "//pkg/sql/catalog/catconstants", "//pkg/sql/distsql", diff --git a/pkg/cli/democluster/demo_cluster.go b/pkg/cli/democluster/demo_cluster.go index 3cc726548f78..a897d0229e32 100644 --- a/pkg/cli/democluster/demo_cluster.go +++ b/pkg/cli/democluster/demo_cluster.go @@ -37,7 +37,6 @@ import ( "github.com/cockroachdb/cockroach/pkg/server/serverpb" "github.com/cockroachdb/cockroach/pkg/server/status" "github.com/cockroachdb/cockroach/pkg/settings" - "github.com/cockroachdb/cockroach/pkg/sql" "github.com/cockroachdb/cockroach/pkg/sql/catalog/catalogkeys" "github.com/cockroachdb/cockroach/pkg/sql/catalog/catconstants" "github.com/cockroachdb/cockroach/pkg/sql/distsql" @@ -407,7 +406,6 @@ func (c *transientCluster) Start( StartingHTTPPort: c.demoCtx.HTTPPort - 2, Locality: c.demoCtx.Localities[i], TestingKnobs: base.TestingKnobs{ - TenantTestingKnobs: &sql.TenantTestingKnobs{DisableLogTags: true}, Server: &server.TestingKnobs{ ContextTestingKnobs: rpc.ContextTestingKnobs{ ArtificialLatencyMap: latencyMap, diff --git a/pkg/cli/interactive_tests/test_log_config_msg.tcl b/pkg/cli/interactive_tests/test_log_config_msg.tcl index 8749f6da974c..dd81593f8734 100644 --- a/pkg/cli/interactive_tests/test_log_config_msg.tcl +++ b/pkg/cli/interactive_tests/test_log_config_msg.tcl @@ -9,30 +9,23 @@ start_server $argv start_test "Check that the cluster and node ID is reported at the start of the first log file." spawn tail -n 1000 -F logs/db/logs/cockroach.log -eexpect "\\\[config\\\] * clusterID:" -eexpect "\\\[config\\\] * nodeID:" eexpect "node startup completed" +eexpect "start.go*clusterID:" +eexpect "start.go*nodeID:" end_test stop_server $argv -# Make a server with a tiny log buffer so as to force frequent log rotation. -system "$argv start-single-node --insecure --pid-file=server_pid --background -s=path=logs/db --log-file-max-size=2k >>logs/expect-cmd.log 2>&1; - $argv sql --insecure -e 'select 1'" -# Stop the server, which also flushes and closes the log files. +# Restart the server, to check that the server identifiers are also reported after restarts. +start_server $argv stop_server $argv start_test "Check that the cluster and node ID is reported at the start of new log files." # Verify that the string "restarted pre-existing node" can be found -# somewhere. This ensures that if this string ever changes, the test -# below won't report a false negative. +# somewhere. system "grep -q 'restarted pre-existing node' logs/db/logs/*.log" -# Verify that "cockroach.log" is not the file where the server reports -# it just started. -system "if grep -q 'restarted pre-existing node' logs/db/logs/cockroach.log; then false; fi" # Verify that the last log file does contain the cluster ID. -system "grep -qF '\[config\] clusterID:' logs/db/logs/cockroach.log" -system "grep -qF '\[config\] nodeID:' logs/db/logs/cockroach.log" +system "grep -q 'start\.go.*clusterID:' logs/db/logs/cockroach.log" +system "grep -q 'start\.go.*nodeID:' logs/db/logs/cockroach.log" end_test - diff --git a/pkg/cli/start.go b/pkg/cli/start.go index 231d7b28a35a..beb4103bebf4 100644 --- a/pkg/cli/start.go +++ b/pkg/cli/start.go @@ -682,12 +682,6 @@ If problems persist, please see %s.` return err } - // Remember the server identifiers for logging. - // TODO(knz): Remove this. - nodeID := s.NodeID() - clusterID := s.ClusterID().String() - log.SetNodeIDs(clusterID, int32(nodeID)) - // Now inform the user that the server is running and tell the // user about its run-time derived parameters. return reportServerInfo(ctx, tBegin, &serverCfg, s.ClusterSettings(), true /* isHostNode */, initialStart) diff --git a/pkg/cmd/roachtest/tests/multitenant.go b/pkg/cmd/roachtest/tests/multitenant.go index b14c1abae5a8..3b06b7f8701f 100644 --- a/pkg/cmd/roachtest/tests/multitenant.go +++ b/pkg/cmd/roachtest/tests/multitenant.go @@ -58,17 +58,17 @@ func runAcceptanceMultitenant(ctx context.Context, t test.Test, c cluster.Cluste t.Status("checking log file contents") // Check that the server identifiers are present in the tenant log file. - logFile := filepath.Join(tenant.logDir(), "cockroach.log") + logFile := filepath.Join(tenant.logDir(), "*.log") if err := c.RunE(ctx, c.Node(1), - "grep", "-q", "'\\[config\\] .* clusterID:'", logFile); err != nil { + "grep", "-q", "'start\\.go.*clusterID:'", logFile); err != nil { t.Fatal(errors.Wrap(err, "cluster ID not found in log file")) } if err := c.RunE(ctx, c.Node(1), - "grep", "-q", "'\\[config\\] .* tenantID:'", logFile); err != nil { + "grep", "-q", "'start\\.go.*tenantID:'", logFile); err != nil { t.Fatal(errors.Wrap(err, "tenant ID not found in log file")) } if err := c.RunE(ctx, c.Node(1), - "grep", "-q", "'\\[config\\] .* instanceID:'", logFile); err != nil { + "grep", "-q", "'start\\.go.*instanceID:'", logFile); err != nil { t.Fatal(errors.Wrap(err, "SQL instance ID not found in log file")) } } diff --git a/pkg/server/config.go b/pkg/server/config.go index b16ccb983756..df43f258cae8 100644 --- a/pkg/server/config.go +++ b/pkg/server/config.go @@ -16,7 +16,9 @@ import ( "fmt" "net" "runtime" + "strconv" "strings" + "sync/atomic" "text/tabwriter" "time" @@ -38,6 +40,7 @@ import ( "github.com/cockroachdb/cockroach/pkg/util/netutil" "github.com/cockroachdb/cockroach/pkg/util/retry" "github.com/cockroachdb/cockroach/pkg/util/tracing" + "github.com/cockroachdb/cockroach/pkg/util/uuid" "github.com/cockroachdb/errors" "github.com/cockroachdb/pebble" "github.com/cockroachdb/pebble/vfs" @@ -117,6 +120,10 @@ type BaseConfig struct { Tracer *tracing.Tracer + // idProvider is an interface that makes the logging package + // able to peek into the server IDs defined by this configuration. + idProvider *idProvider + // IDContainer is the Node ID / SQL Instance ID container // that will contain the ID for the server to instantiate. IDContainer *base.NodeIDContainer @@ -177,11 +184,17 @@ func MakeBaseConfig(st *cluster.Settings, tr *tracing.Tracer) BaseConfig { if tr == nil { panic("nil Tracer") } + idsProvider := &idProvider{ + clusterID: &base.ClusterIDContainer{}, + serverID: &base.NodeIDContainer{}, + } + baseCfg := BaseConfig{ Tracer: tr, - IDContainer: &base.NodeIDContainer{}, - ClusterIDContainer: &base.ClusterIDContainer{}, - AmbientCtx: log.AmbientContext{Tracer: tr}, + idProvider: idsProvider, + IDContainer: idsProvider.serverID, + ClusterIDContainer: idsProvider.clusterID, + AmbientCtx: log.AmbientContext{Tracer: tr, ServerIDs: idsProvider}, Config: new(base.Config), Settings: st, MaxOffset: MaxOffsetType(base.DefaultMaxClockOffset), @@ -760,3 +773,109 @@ func parseAttributes(attrsStr string) roachpb.Attributes { } return roachpb.Attributes{Attrs: filtered} } + +// idProvider connects the server ID containers in this +// package to the logging package. +// +// For each of the "main" data items, it also memoizes its +// representation as a string (the one needed by the +// log.ServerIdentificationPayload interface) as soon as the value is +// initialized. This saves on conversion costs. +type idProvider struct { + // clusterID contains the cluster ID (initialized late). + clusterID *base.ClusterIDContainer + // clusterStr is the memoized representation of clusterID, once known. + clusterStr atomic.Value + + // tenantID is the tenant ID for this server. + tenantID roachpb.TenantID + // tenantStr is the memoized representation of tenantID. + tenantStr atomic.Value + + // serverID contains the node ID for KV nodes (when tenantID.IsSet() == + // false), or the SQL instance ID for SQL-only servers (when + // tenantID.IsSet() == true). + serverID *base.NodeIDContainer + // serverStr is the memoized representation of serverID. + serverStr atomic.Value +} + +var _ log.ServerIdentificationPayload = (*idProvider)(nil) + +// ServerIdentityString implements the log.ServerIdentificationPayload interface. +func (s *idProvider) ServerIdentityString(key log.ServerIdentificationKey) string { + switch key { + case log.IdentifyClusterID: + c := s.clusterStr.Load() + cs, ok := c.(string) + if !ok { + cid := s.clusterID.Get() + if cid != uuid.Nil { + cs = cid.String() + s.clusterStr.Store(cs) + } + } + return cs + + case log.IdentifyTenantID: + t := s.tenantStr.Load() + ts, ok := t.(string) + if !ok { + tid := s.tenantID + if tid.IsSet() { + ts = strconv.FormatUint(tid.ToUint64(), 10) + s.tenantStr.Store(ts) + } + } + return ts + + case log.IdentifyInstanceID: + // If tenantID is not set, this is a KV node and it has no SQL + // instance ID. + if !s.tenantID.IsSet() { + return "" + } + return s.maybeMemoizeServerID() + + case log.IdentifyKVNodeID: + // If tenantID is set, this is a SQL-only server and it has no + // node ID. + if s.tenantID.IsSet() { + return "" + } + return s.maybeMemoizeServerID() + } + + return "" +} + +// SetTenant informs the provider that it provides data for +// a SQL server. +// +// Note: this should not be called concurrently with logging which may +// invoke the method from the log.ServerIdentificationPayload +// interface. +func (s *idProvider) SetTenant(tenantID roachpb.TenantID) { + if !tenantID.IsSet() { + panic("programming error: invalid tenant ID") + } + if s.tenantID.IsSet() { + panic("programming error: provider already set for tenant server") + } + s.tenantID = tenantID +} + +// maybeMemoizeServerID saves the representation of serverID to +// serverStr if the former is initialized. +func (s *idProvider) maybeMemoizeServerID() string { + si := s.serverStr.Load() + sis, ok := si.(string) + if !ok { + sid := s.serverID.Get() + if sid != 0 { + sis = strconv.FormatUint(uint64(sid), 10) + s.serverStr.Store(sis) + } + } + return sis +} diff --git a/pkg/server/tenant.go b/pkg/server/tenant.go index bcac5943ac39..e234c8902830 100644 --- a/pkg/server/tenant.go +++ b/pkg/server/tenant.go @@ -65,6 +65,10 @@ func StartTenant( return nil, "", "", err } + // Inform the server identity provider that we're operating + // for a tenant server. + baseCfg.idProvider.SetTenant(sqlCfg.TenantID) + args, err := makeTenantSQLServerArgs(ctx, stopper, kvClusterName, baseCfg, sqlCfg) if err != nil { return nil, "", "", err @@ -262,17 +266,6 @@ func StartTenant( return nil, "", "", err } - if knobs, ok := baseCfg.TestingKnobs.TenantTestingKnobs.(*sql.TenantTestingKnobs); !ok || !knobs.DisableLogTags { - // Register the server's identifiers so that log events are - // decorated with the server's identity. This helps when gathering - // log events from multiple servers into the same log collector. - // - // We do this only here, as the identifiers may not be known before this point. - clusterID := args.rpcContext.ClusterID.Get().String() - log.SetNodeIDs(clusterID, 0 /* nodeID is not known for a SQL-only server. */) - log.SetTenantIDs(args.TenantID.String(), int32(s.SQLInstanceID())) - } - externalUsageFn := func(ctx context.Context) multitenant.ExternalUsage { userTimeMillis, _, err := status.GetCPUTime(ctx) if err != nil { diff --git a/pkg/spanconfig/spanconfigtestutils/spanconfigtestcluster/BUILD.bazel b/pkg/spanconfig/spanconfigtestutils/spanconfigtestcluster/BUILD.bazel index f0ee625179be..cdfacdf2d062 100644 --- a/pkg/spanconfig/spanconfigtestutils/spanconfigtestcluster/BUILD.bazel +++ b/pkg/spanconfig/spanconfigtestutils/spanconfigtestcluster/BUILD.bazel @@ -21,7 +21,6 @@ go_library( "//pkg/testutils/serverutils", "//pkg/testutils/sqlutils", "//pkg/testutils/testcluster", - "//pkg/util/log", "@com_github_stretchr_testify//require", ], ) diff --git a/pkg/spanconfig/spanconfigtestutils/spanconfigtestcluster/cluster.go b/pkg/spanconfig/spanconfigtestutils/spanconfigtestcluster/cluster.go index 6e06f97b885b..478fb77f9de4 100644 --- a/pkg/spanconfig/spanconfigtestutils/spanconfigtestcluster/cluster.go +++ b/pkg/spanconfig/spanconfigtestutils/spanconfigtestcluster/cluster.go @@ -21,7 +21,6 @@ import ( "github.com/cockroachdb/cockroach/pkg/security" "github.com/cockroachdb/cockroach/pkg/testutils/sqlutils" "github.com/cockroachdb/cockroach/pkg/testutils/testcluster" - "github.com/cockroachdb/cockroach/pkg/util/log" "github.com/stretchr/testify/require" ) @@ -46,10 +45,6 @@ func NewHandle(t *testing.T, tc *testcluster.TestCluster) *Handle { // InitializeTenant initializes a tenant with the given ID, returning the // relevant tenant state. func (h *Handle) InitializeTenant(ctx context.Context, tenID roachpb.TenantID) *Tenant { - // Prevent a logging assertion that the server ID is initialized multiple - // times. - log.TestingClearServerIdentifiers() - testServer := h.tc.Server(0) tenantState := &Tenant{t: h.t} if tenID == roachpb.SystemTenantID { diff --git a/pkg/sql/exec_util.go b/pkg/sql/exec_util.go index b7bbd8843c46..cee543922d41 100644 --- a/pkg/sql/exec_util.go +++ b/pkg/sql/exec_util.go @@ -1347,10 +1347,6 @@ type TenantTestingKnobs struct { // OverrideTokenBucketProvider allows a test-only TokenBucketProvider (which // can optionally forward requests to the real provider). OverrideTokenBucketProvider func(origProvider kvtenant.TokenBucketProvider) kvtenant.TokenBucketProvider - - // DisableLogTags can be set to true to cause the tenant server to avoid - // setting any global log tags for cluster id or node id. - DisableLogTags bool } var _ base.ModuleTestingKnobs = &TenantTestingKnobs{} diff --git a/pkg/sql/logictest/logic.go b/pkg/sql/logictest/logic.go index fe2403516394..11ae086c8434 100644 --- a/pkg/sql/logictest/logic.go +++ b/pkg/sql/logictest/logic.go @@ -1547,9 +1547,6 @@ func (t *logicTest) newCluster(serverArgs TestServerArgs, opts []clusterOpt) { TracingDefault: params.ServerArgs.TracingDefault, } - // Prevent a logging assertion that the server ID is initialized multiple times. - log.TestingClearServerIdentifiers() - tenant, err := t.cluster.Server(i).StartTenant(context.Background(), tenantArgs) if err != nil { t.rootT.Fatalf("%+v", err) diff --git a/pkg/sql/sqltestutils/BUILD.bazel b/pkg/sql/sqltestutils/BUILD.bazel index c2667814b97e..10cb2718c01f 100644 --- a/pkg/sql/sqltestutils/BUILD.bazel +++ b/pkg/sql/sqltestutils/BUILD.bazel @@ -30,7 +30,6 @@ go_library( "//pkg/testutils/skip", "//pkg/testutils/sqlutils", "//pkg/util/cloudinfo", - "//pkg/util/log", "//pkg/util/protoutil", "//pkg/util/treeprinter", "@com_github_cockroachdb_datadriven//:datadriven", diff --git a/pkg/sql/sqltestutils/telemetry.go b/pkg/sql/sqltestutils/telemetry.go index da354fc6b7ba..3403b29aba82 100644 --- a/pkg/sql/sqltestutils/telemetry.go +++ b/pkg/sql/sqltestutils/telemetry.go @@ -34,7 +34,6 @@ import ( "github.com/cockroachdb/cockroach/pkg/testutils/skip" "github.com/cockroachdb/cockroach/pkg/testutils/sqlutils" "github.com/cockroachdb/cockroach/pkg/util/cloudinfo" - "github.com/cockroachdb/cockroach/pkg/util/log" "github.com/cockroachdb/cockroach/pkg/util/treeprinter" "github.com/cockroachdb/datadriven" "github.com/cockroachdb/errors" @@ -156,9 +155,6 @@ func (tt *telemetryTest) Start(t *testing.T, serverArgs []base.TestServerArgs) { tt.serverDB = tt.cluster.ServerConn(0) tt.prepareCluster(tt.serverDB) - // Prevent a logging assertion that the server ID is initialized multiple times. - log.TestingClearServerIdentifiers() - tt.tenant, tt.tenantDB = serverutils.StartTenant(tt.t, tt.server, base.TestTenantArgs{ TenantID: serverutils.TestTenantID(), AllowSettingClusterSettings: true, diff --git a/pkg/util/log/BUILD.bazel b/pkg/util/log/BUILD.bazel index 4541c4cc94c7..64eee95868fa 100644 --- a/pkg/util/log/BUILD.bazel +++ b/pkg/util/log/BUILD.bazel @@ -37,6 +37,7 @@ go_library( "log_flush.go", "redact.go", "registry.go", + "server_ident.go", "sinks.go", "stderr_redirect.go", "stderr_redirect_unix.go", diff --git a/pkg/util/log/ambient_context.go b/pkg/util/log/ambient_context.go index c90393a4b6c3..e92c19dfc7ae 100644 --- a/pkg/util/log/ambient_context.go +++ b/pkg/util/log/ambient_context.go @@ -54,6 +54,10 @@ type AmbientContext struct { // Tracer is used to open spans (see AnnotateCtxWithSpan). Tracer *tracing.Tracer + // ServerIDs will be embedded into contexts that don't already have + // one. + ServerIDs ServerIdentificationPayload + // eventLog will be embedded into contexts that don't already have an event // log or an open span (if not nil). eventLog *ctxEventLog @@ -136,6 +140,9 @@ func (ac *AmbientContext) ResetAndAnnotateCtx(ctx context.Context) context.Conte if ac.tags != nil { ctx = logtags.WithTags(ctx, ac.tags) } + if ac.ServerIDs != nil { + ctx = context.WithValue(ctx, ServerIdentificationContextKey{}, ac.ServerIDs) + } return ctx } } @@ -147,6 +154,9 @@ func (ac *AmbientContext) annotateCtxInternal(ctx context.Context) context.Conte if ac.tags != nil { ctx = logtags.AddTags(ctx, ac.tags) } + if ac.ServerIDs != nil && ctx.Value(ServerIdentificationContextKey{}) == nil { + ctx = context.WithValue(ctx, ServerIdentificationContextKey{}, ac.ServerIDs) + } return ctx } @@ -171,6 +181,9 @@ func (ac *AmbientContext) AnnotateCtxWithSpan( if ac.tags != nil { ctx = logtags.AddTags(ctx, ac.tags) } + if ac.ServerIDs != nil && ctx.Value(ServerIdentificationContextKey{}) == nil { + ctx = context.WithValue(ctx, ServerIdentificationContextKey{}, ac.ServerIDs) + } } return tracing.EnsureChildSpan(ctx, ac.Tracer, opName) diff --git a/pkg/util/log/clog.go b/pkg/util/log/clog.go index 909153e78ba4..6542840cb425 100644 --- a/pkg/util/log/clog.go +++ b/pkg/util/log/clog.go @@ -21,12 +21,10 @@ import ( "time" "github.com/cockroachdb/cockroach/pkg/cli/exit" - "github.com/cockroachdb/cockroach/pkg/util/log/channel" "github.com/cockroachdb/cockroach/pkg/util/log/logpb" "github.com/cockroachdb/cockroach/pkg/util/log/severity" "github.com/cockroachdb/cockroach/pkg/util/syncutil" "github.com/cockroachdb/errors" - "github.com/cockroachdb/logtags" ) // logging is the global state of the logging setup. @@ -102,28 +100,10 @@ type loggingT struct { firstUseStack string } - idMu struct { - syncutil.RWMutex - idPayload - } - allSinkInfos sinkInfoRegistry allLoggers loggerRegistry } -type idPayload struct { - // the Cluster ID is reported on every new log file so as to ease - // the correlation of panic reports with self-reported log files. - clusterID string - // the node ID is reported like the cluster ID, for the same reasons. - // We avoid using roahcpb.NodeID to avoid a circular reference. - nodeID int32 - // ditto for the tenant ID. - tenantID string - // ditto for the SQL instance ID. - sqlInstanceID int32 -} - func init() { logging.bufPool.New = newBuffer logging.bufSlicePool.New = newBufferSlice @@ -221,12 +201,6 @@ func FatalChan() <-chan struct{} { return logging.mu.fatalCh } -func (l *loggingT) idPayload() idPayload { - l.idMu.RLock() - defer l.idMu.RUnlock() - return l.idMu.idPayload -} - // s ignalFatalCh signals the listeners of l.mu.fatalCh by closing the // channel. // l.mu is not held. @@ -242,50 +216,6 @@ func (l *loggingT) signalFatalCh() { } } -// SetNodeIDs stores the Node and Cluster ID for further reference. -func SetNodeIDs(clusterID string, nodeID int32) { - // Ensure that the IDs are logged with the same format as for - // new log files, even on the first log file. This ensures that grep - // will always find it. - ctx := logtags.AddTag(context.Background(), "config", nil) - logfDepth(ctx, 1, severity.INFO, channel.OPS, "clusterID: %s", clusterID) - if nodeID != 0 { - logfDepth(ctx, 1, severity.INFO, channel.OPS, "nodeID: n%d", nodeID) - } - - // Perform the change proper. - logging.idMu.Lock() - defer logging.idMu.Unlock() - - if logging.idMu.clusterID != "" { - panic("clusterID already set") - } - - logging.idMu.clusterID = clusterID - logging.idMu.nodeID = nodeID -} - -// SetTenantIDs stores the tenant ID and instance ID for further reference. -func SetTenantIDs(tenantID string, sqlInstanceID int32) { - // Ensure that the IDs are logged with the same format as for - // new log files, even on the first log file. This ensures that grep - // will always find it. - ctx := logtags.AddTag(context.Background(), "config", nil) - logfDepth(ctx, 1, severity.INFO, channel.OPS, "tenantID: %s", tenantID) - logfDepth(ctx, 1, severity.INFO, channel.OPS, "instanceID: %d", sqlInstanceID) - - // Perform the change proper. - logging.idMu.Lock() - defer logging.idMu.Unlock() - - if logging.idMu.tenantID != "" { - panic("tenantID already set") - } - - logging.idMu.tenantID = tenantID - logging.idMu.sqlInstanceID = sqlInstanceID -} - // outputLogEntry marshals a log entry proto into bytes, and writes // the data to the log files. If a trace location is set, stack traces // are added to the entry before marshaling. diff --git a/pkg/util/log/clog_test.go b/pkg/util/log/clog_test.go index b15a1df847f7..dfe4b47ec942 100644 --- a/pkg/util/log/clog_test.go +++ b/pkg/util/log/clog_test.go @@ -742,9 +742,9 @@ func BenchmarkLogEntry_String(b *testing.B) { entry := &logEntry{ idPayload: idPayload{ clusterID: "fooo", - nodeID: 10, + nodeID: "10", tenantID: "12", - sqlInstanceID: 9, + sqlInstanceID: "9", }, ts: timeutil.Now().UnixNano(), header: false, diff --git a/pkg/util/log/flags.go b/pkg/util/log/flags.go index 34b476bbc697..22c76439445c 100644 --- a/pkg/util/log/flags.go +++ b/pkg/util/log/flags.go @@ -461,16 +461,6 @@ func (l *sinkInfo) describeAppliedConfig() (c logconfig.CommonSinkConfig) { return c } -// TestingClearServerIdentifiers clears the server identity from the -// logging system. This is for use in tests that start multiple -// servers with conflicting identities subsequently. -// See discussion here: https://github.com/cockroachdb/cockroach/issues/58938 -func TestingClearServerIdentifiers() { - logging.idMu.Lock() - logging.idMu.idPayload = idPayload{} - logging.idMu.Unlock() -} - // TestingResetActive clears the active bit. This is for use in tests // that use stderr redirection alongside other tests that use // logging. diff --git a/pkg/util/log/format_json.go b/pkg/util/log/format_json.go index dcbf4d82fbdf..a324b9ae8fe9 100644 --- a/pkg/util/log/format_json.go +++ b/pkg/util/log/format_json.go @@ -274,26 +274,23 @@ func formatJSON(entry logEntry, forFluent bool, tags tagChoice) *buffer { escapeString(buf, entry.clusterID) buf.WriteByte('"') } - if entry.nodeID != 0 { + if entry.nodeID != "" { buf.WriteString(`,"`) buf.WriteString(jtags['N'].tags[tags]) buf.WriteString(`":`) - n = buf.someDigits(0, int(entry.nodeID)) - buf.Write(buf.tmp[:n]) + buf.WriteString(entry.nodeID) } if entry.tenantID != "" { buf.WriteString(`,"`) buf.WriteString(jtags['T'].tags[tags]) - buf.WriteString(`":"`) - escapeString(buf, entry.tenantID) - buf.WriteByte('"') + buf.WriteString(`":`) + buf.WriteString(entry.tenantID) } - if entry.sqlInstanceID != 0 { + if entry.sqlInstanceID != "" { buf.WriteString(`,"`) buf.WriteString(jtags['q'].tags[tags]) buf.WriteString(`":`) - n = buf.someDigits(0, int(entry.sqlInstanceID)) - buf.Write(buf.tmp[:n]) + buf.WriteString(entry.sqlInstanceID) } // The binary version. diff --git a/pkg/util/log/format_json_test.go b/pkg/util/log/format_json_test.go index b847748f0f98..51dc50ab12f0 100644 --- a/pkg/util/log/format_json_test.go +++ b/pkg/util/log/format_json_test.go @@ -49,8 +49,8 @@ func TestJSONFormats(t *testing.T) { }(), // Normal (non-header) entries. {}, - {idPayload: idPayload{clusterID: "abc", nodeID: 123}}, - {idPayload: idPayload{tenantID: "abc", sqlInstanceID: 123}}, + {idPayload: idPayload{clusterID: "abc", nodeID: "123"}}, + {idPayload: idPayload{tenantID: "456", sqlInstanceID: "123"}}, makeStructuredEntry(ctx, severity.INFO, channel.DEV, 0, &eventpb.RenameDatabase{ CommonEventDetails: eventpb.CommonEventDetails{ Timestamp: 123, diff --git a/pkg/util/log/log_entry.go b/pkg/util/log/log_entry.go index 3bc3c7282d0f..a8d411fee5c3 100644 --- a/pkg/util/log/log_entry.go +++ b/pkg/util/log/log_entry.go @@ -191,7 +191,7 @@ func makeUnsafePayload(m string) entryPayload { // makeEntry creates a logEntry. func makeEntry(ctx context.Context, s Severity, c Channel, depth int) (res logEntry) { - ids := logging.idPayload() + ids := getIdentificationPayload(ctx) res = logEntry{ idPayload: ids, @@ -285,20 +285,6 @@ func (l *sinkInfo) getStartLines(now time.Time) []*buffer { makeStartLine(f, "arguments: %s", os.Args), ) - ids := logging.idPayload() - if ids.clusterID != "" { - messages = append(messages, makeStartLine(f, "clusterID: %s", logging.idMu.clusterID)) - } - if ids.nodeID != 0 { - messages = append(messages, makeStartLine(f, "nodeID: n%d", logging.idMu.nodeID)) - } - if ids.tenantID != "" { - messages = append(messages, makeStartLine(f, "tenantID: %s", logging.idMu.tenantID)) - } - if ids.sqlInstanceID != 0 { - messages = append(messages, makeStartLine(f, "instanceID: %d", logging.idMu.sqlInstanceID)) - } - // Including a non-ascii character in the first 1024 bytes of the log helps // viewers that attempt to guess the character encoding. messages = append(messages, makeStartLine(f, "log format (utf8=\u2713): %s", Safe(f.formatterName()))) diff --git a/pkg/util/log/server_ident.go b/pkg/util/log/server_ident.go new file mode 100644 index 000000000000..6767925f142a --- /dev/null +++ b/pkg/util/log/server_ident.go @@ -0,0 +1,70 @@ +// 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 log + +import "context" + +// ServerIdentificationContextKey is the type of a context.Value key +// used to carry ServerIdentificationPayload values. +type ServerIdentificationContextKey struct{} + +// ServerIdentificationPayload is the type of a context.Value payload +// associated with a ServerIdentificationContextKey. +type ServerIdentificationPayload interface { + // ServerIdentityString retrieves an identifier corresponding to the + // given retrieval key. If there is no value known for a given key, + // the method can return the empty string. + ServerIdentityString(key ServerIdentificationKey) string +} + +// ServerIdentificationKey represents a possible parameter to the +// ServerIdentityString() method in ServerIdentificationPayload. +type ServerIdentificationKey int + +const ( + // IdentifyClusterID retrieves the cluster ID of the server. + IdentifyClusterID ServerIdentificationKey = iota + // IdentifyKVNodeID retrieves the KV node ID of the server. + IdentifyKVNodeID + // IdentifyInstanceID retrieves the SQL instance ID of the server. + IdentifyInstanceID + // IdentifyTenantID retrieves the tenant ID of the server. + IdentifyTenantID +) + +type idPayload struct { + // the Cluster ID is reported on every new log file so as to ease + // the correlation of panic reports with self-reported log files. + clusterID string + // the node ID is reported like the cluster ID, for the same reasons. + // We avoid using roahcpb.NodeID to avoid a circular reference. + nodeID string + // ditto for the tenant ID. + tenantID string + // ditto for the SQL instance ID. + sqlInstanceID string +} + +func getIdentificationPayload(ctx context.Context) (res idPayload) { + r := ctx.Value(ServerIdentificationContextKey{}) + if r == nil { + return res + } + si, ok := r.(ServerIdentificationPayload) + if !ok { + return res + } + res.clusterID = si.ServerIdentityString(IdentifyClusterID) + res.nodeID = si.ServerIdentityString(IdentifyKVNodeID) + res.sqlInstanceID = si.ServerIdentityString(IdentifyInstanceID) + res.tenantID = si.ServerIdentityString(IdentifyTenantID) + return res +} diff --git a/pkg/util/log/test_log_scope.go b/pkg/util/log/test_log_scope.go index d2164b97db17..c5e0d1d0ffc5 100644 --- a/pkg/util/log/test_log_scope.go +++ b/pkg/util/log/test_log_scope.go @@ -160,10 +160,6 @@ func newLogScope(t tShim, mostlyInline bool) (sc *TestLogScope) { // destination directory. cfg := getTestConfig(&sc.logDir, mostlyInline) - // Reset the server identifiers, so that new servers - // can report their IDs through logging. - TestingClearServerIdentifiers() - // Switch to the new configuration. TestingResetActive() sc.cleanupFn, err = ApplyConfig(cfg) diff --git a/pkg/util/log/testdata/json b/pkg/util/log/testdata/json index 51ab443e24e9..e3c388daba3d 100644 --- a/pkg/util/log/testdata/json +++ b/pkg/util/log/testdata/json @@ -16,10 +16,10 @@ json-fluent-compact: {"tag":"logtest.dev","c":0,"t":"1136214245.654321000","x":" json-compact: {"c":0,"t":"1136214245.654321000","x":"abc","N":123,"s":0,"g":11,"f":"","l":123,"n":0,"r":0,"message":""} json: {"channel_numeric":0,"channel":"DEV","timestamp":"1136214245.654321000","cluster_id":"abc","node_id":123,"severity_numeric":0,"severity":"UNKNOWN","goroutine":11,"file":"","line":123,"entry_counter":0,"redactable":0,"message":""} # -json-fluent-compact: {"tag":"logtest.dev","c":0,"t":"1136214245.654321000","T":"abc","q":123,"s":0,"g":11,"f":"","l":123,"n":0,"r":0,"message":""} - json-fluent: {"tag":"logtest.dev","channel_numeric":0,"channel":"DEV","timestamp":"1136214245.654321000","tenant_id":"abc","instance_id":123,"severity_numeric":0,"severity":"UNKNOWN","goroutine":11,"file":"","line":123,"entry_counter":0,"redactable":0,"message":""} - json-compact: {"c":0,"t":"1136214245.654321000","T":"abc","q":123,"s":0,"g":11,"f":"","l":123,"n":0,"r":0,"message":""} - json: {"channel_numeric":0,"channel":"DEV","timestamp":"1136214245.654321000","tenant_id":"abc","instance_id":123,"severity_numeric":0,"severity":"UNKNOWN","goroutine":11,"file":"","line":123,"entry_counter":0,"redactable":0,"message":""} +json-fluent-compact: {"tag":"logtest.dev","c":0,"t":"1136214245.654321000","T":456,"q":123,"s":0,"g":11,"f":"","l":123,"n":0,"r":0,"message":""} + json-fluent: {"tag":"logtest.dev","channel_numeric":0,"channel":"DEV","timestamp":"1136214245.654321000","tenant_id":456,"instance_id":123,"severity_numeric":0,"severity":"UNKNOWN","goroutine":11,"file":"","line":123,"entry_counter":0,"redactable":0,"message":""} + json-compact: {"c":0,"t":"1136214245.654321000","T":456,"q":123,"s":0,"g":11,"f":"","l":123,"n":0,"r":0,"message":""} + json: {"channel_numeric":0,"channel":"DEV","timestamp":"1136214245.654321000","tenant_id":456,"instance_id":123,"severity_numeric":0,"severity":"UNKNOWN","goroutine":11,"file":"","line":123,"entry_counter":0,"redactable":0,"message":""} # json-fluent-compact: {"tag":"logtest.dev","c":0,"t":"1136214245.654321000","v":"v999.0.0","s":1,"sev":"I","g":11,"f":"util/log/format_json_test.go","l":123,"n":0,"r":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"event":{"Timestamp":123,"EventType":"rename_database","DatabaseName":"‹hello›","NewDatabaseName":"‹world›"}} json-fluent: {"tag":"logtest.dev","channel_numeric":0,"channel":"DEV","timestamp":"1136214245.654321000","version":"v999.0.0","severity_numeric":1,"severity":"INFO","goroutine":11,"file":"util/log/format_json_test.go","line":123,"entry_counter":0,"redactable":1,"tags":{"noval":"","s":"‹1›","long":"‹2›"},"event":{"Timestamp":123,"EventType":"rename_database","DatabaseName":"‹hello›","NewDatabaseName":"‹world›"}}