From bb8af18851a7eda4bc85e50a7dc3508d9132bbba Mon Sep 17 00:00:00 2001 From: Raphael 'kena' Poss Date: Wed, 10 Nov 2021 14:01:24 +0100 Subject: [PATCH 1/2] server: report the SQL instance ID as log tag `sqli` Prior to this patch, the SQL instance ID was not reported in log messages, which made it hard to distinguish log messages coming from different in-memory SQL instance servers (e.g. in tests). This patch fixes it. The patch also changes the log tag for SQL instances from just `sql` to `sqli`, which is easier to search for and recognize. Release note: None --- docs/generated/redact_safe.md | 1 + pkg/base/node_id.go | 49 ++++++++++++++++++++++++++++++++++- pkg/server/tenant.go | 12 +++++++-- 3 files changed, 59 insertions(+), 3 deletions(-) diff --git a/docs/generated/redact_safe.md b/docs/generated/redact_safe.md index 8e3370edba12..b86a6cf83964 100644 --- a/docs/generated/redact_safe.md +++ b/docs/generated/redact_safe.md @@ -3,6 +3,7 @@ The following types are considered always safe for reporting: File | Type --|-- pkg/base/node_id.go | `*NodeIDContainer` +pkg/base/node_id.go | `*SQLIDContainer` pkg/base/node_id.go | `*StoreIDContainer` pkg/cli/exit/exit.go | `Code` pkg/jobs/jobspb/wrap.go | `JobID` diff --git a/pkg/base/node_id.go b/pkg/base/node_id.go index a9fbf0757733..82ca9a04ac5a 100644 --- a/pkg/base/node_id.go +++ b/pkg/base/node_id.go @@ -162,13 +162,21 @@ func (s *StoreIDContainer) Set(ctx context.Context, val int32) { type SQLInstanceID int32 func (s SQLInstanceID) String() string { - return strconv.FormatInt(int64(s), 10) + if s == 0 { + return "?" + } + return strconv.Itoa(int(s)) } // SQLIDContainer wraps a SQLInstanceID and optionally a NodeID. type SQLIDContainer struct { w errorutil.TenantSQLDeprecatedWrapper // NodeID sqlInstanceID SQLInstanceID + + // If the value has been set, str represents the instance ID + // converted to string. We precompute this value to speed up + // String() and keep it from allocating memory dynamically. + str atomic.Value } // NewSQLIDContainer sets up an SQLIDContainer. It is handed either a positive SQLInstanceID @@ -196,6 +204,7 @@ func (c *SQLIDContainer) SetSQLInstanceID(sqlInstanceID SQLInstanceID) error { return errors.New("attempting to initialize instance ID when node ID is set") } c.sqlInstanceID = sqlInstanceID + c.str.Store(strconv.Itoa(int(sqlInstanceID))) return nil } @@ -227,6 +236,44 @@ func (c *SQLIDContainer) SQLInstanceID() SQLInstanceID { return c.sqlInstanceID } +// SafeValue implements the redact.SafeValue interface. +func (c *SQLIDContainer) SafeValue() {} + +func (c *SQLIDContainer) String() string { + st := c.str.Load() + if st == nil { + // This can mean either that: + // - neither the instance ID nor the node ID has been set. + // - only the node ID has been set. + // + // In the latter case, we don't want to return "?" here, as in the + // NodeIDContainer case above: we want to return the node ID + // representation instead. Alas, there is no way to know + // but to open the node ID container box. + // + // TODO(knz): This could be greatly simplified if we accepted to + // use the same data type for both SQL instance ID and node ID + // containers. + v, ok := c.w.Optional() + if !ok { + // This is definitely not a node ID, and since we're in this + // branch of the conditional above, we don't have SQL instance + // ID either (yet). + return "?" + } + nc := v.(*NodeIDContainer) + st = nc.str.Load() + if st == nil { + // We're designating a Node ID, but it was not set yet. + return "?" + } + // Node ID was set. Keep its representation for the instance ID as + // well. + c.str.Store(st) + } + return st.(string) +} + // TestingIDContainer is an SQLIDContainer with hard-coded SQLInstanceID of 10 and // NodeID of 1. var TestingIDContainer = func() *SQLIDContainer { diff --git a/pkg/server/tenant.go b/pkg/server/tenant.go index e51f07885495..707ed1ca12d9 100644 --- a/pkg/server/tenant.go +++ b/pkg/server/tenant.go @@ -358,7 +358,15 @@ func makeTenantSQLServerArgs( stopper *stop.Stopper, kvClusterName string, baseCfg BaseConfig, sqlCfg SQLConfig, ) (sqlServerArgs, error) { st := baseCfg.Settings - baseCfg.AmbientCtx.AddLogTag("sql", nil) + + // We want all log messages issued on behalf of this SQL instance to report + // the instance ID (once known) as a tag. + instanceIDContainer := base.NewSQLIDContainer(0, nil) + // We use the tag "sqli" instead of just "sql" because the latter is + // too generic and would be hard to search if someone was looking at + // a log message and wondering what it stands for. + baseCfg.AmbientCtx.AddLogTag("sqli", instanceIDContainer) + // TODO(tbg): this is needed so that the RPC heartbeats between the testcluster // and this tenant work. // @@ -511,7 +519,7 @@ func makeTenantSQLServerArgs( externalStorageFromURI: externalStorageFromURI, // Set instance ID to 0 and node ID to nil to indicate // that the instance ID will be bound later during preStart. - nodeIDContainer: base.NewSQLIDContainer(0, nil), + nodeIDContainer: instanceIDContainer, }, sqlServerOptionalTenantArgs: sqlServerOptionalTenantArgs{ tenantConnect: tenantConnect, From 5196152644b221f78747b80e226665d3c10a5f1f Mon Sep 17 00:00:00 2001 From: Raphael 'kena' Poss Date: Wed, 10 Nov 2021 14:08:15 +0100 Subject: [PATCH 2/2] base: ensure that a SQL instance ID is not set to conflicting value Prior to this patch, a SQL instance ID container could be assigned successively different values. This would make it possible for erroneous code to mistakenly initialize the instance ID twice, without any evidence that something was amiss. This patch fixes this by using the same prevention logic that we already use for node IDs. Release note: None --- pkg/base/node_id.go | 20 ++++++++++++++++++-- pkg/server/server_sql.go | 2 +- 2 files changed, 19 insertions(+), 3 deletions(-) diff --git a/pkg/base/node_id.go b/pkg/base/node_id.go index 82ca9a04ac5a..c9dc9615051b 100644 --- a/pkg/base/node_id.go +++ b/pkg/base/node_id.go @@ -199,11 +199,27 @@ func NewSQLIDContainer(sqlInstanceID SQLInstanceID, nodeID *NodeIDContainer) *SQ // SetSQLInstanceID sets the SQL instance ID. It returns an error if // we attempt to set an instance ID when the nodeID has already been // initialized. -func (c *SQLIDContainer) SetSQLInstanceID(sqlInstanceID SQLInstanceID) error { +func (c *SQLIDContainer) SetSQLInstanceID(ctx context.Context, sqlInstanceID SQLInstanceID) error { if _, ok := c.OptionalNodeID(); ok { return errors.New("attempting to initialize instance ID when node ID is set") } - c.sqlInstanceID = sqlInstanceID + + // Use the same logic to set the instance ID as for the node ID. + // + // TODO(knz): All this could be advantageously simplified if we agreed + // to use the same type for NodeIDContainer and SQLIDContainer. + if sqlInstanceID <= 0 { + log.Fatalf(ctx, "trying to set invalid SQLInstanceID: %d", sqlInstanceID) + } + oldVal := atomic.SwapInt32((*int32)(&c.sqlInstanceID), int32(sqlInstanceID)) + if oldVal == 0 { + if log.V(2) { + log.Infof(ctx, "SQLInstanceID set to %d", sqlInstanceID) + } + } else if oldVal != int32(sqlInstanceID) { + log.Fatalf(ctx, "different SQLInstanceIDs set: %d, then %d", oldVal, sqlInstanceID) + } + c.str.Store(strconv.Itoa(int(sqlInstanceID))) return nil } diff --git a/pkg/server/server_sql.go b/pkg/server/server_sql.go index e30402b757e0..57cd142aafb3 100644 --- a/pkg/server/server_sql.go +++ b/pkg/server/server_sql.go @@ -974,7 +974,7 @@ func (s *SQLServer) initInstanceID(ctx context.Context) error { if err != nil { return err } - err = s.sqlIDContainer.SetSQLInstanceID(instanceID) + err = s.sqlIDContainer.SetSQLInstanceID(ctx, instanceID) if err != nil { return err }