Skip to content

Commit 205e55a

Browse files
craig[bot]bghalwenyihu6
committed
152513: sql: hide ttl column for system.inspect_errors r=bghal a=bghal For consistency with other TTL-configured tables. Epic: CRDB-30356 Fixes: #152115 Part of: #148270 Release note: None 152885: kvserver: allow logs from callbacks up to 15 replicas per updateReplicationGauges r=tbg a=wenyihu6 Part of: #151847 Epic: none --- **kvserver: allow logs from callbacks up to 15 replicas per updateReplicationGauges** Previously, logs from the decommission nudger were not gated by a vmodule and could become spammy when many replicas were decommissioned at a low nudger frequency. This commit introduces a per-store budget, allowing logs from callbacks for up to 15 replicas per updateReplicationGauges call. Drawbacks of this approach: - Replicas are not visited in a sorted order, so we may be opening the floodgates from 15 different replicas each iteration. - Once a replica is permitted to log, its future logs from callbacks are not restricted. - If EnqueueProblemRangeInReplicateQueueInterval is set too low, 1 and 2 may become worse. For 1, we could consider visit the replica set with WithReplicasInOrder. I'm not sure about the overhead here since updateReplicationGauges is called periodically when collecting metrics. Here are the reasons that I think this approach is acceptable for now: - onEnqueueResult is unlikely to be reinvoked for replicas already in the queue unless they are processing or in purgatory (both are short-lived states we want visibility into). Once processed, replicas are removed from the set. onProcessResult should be called at most twice. For replicas merely waiting in the queue, the callback is not invoked, since their priority should not be actively updated. - We could cap logging per maybeEnqueueProblemRange, but granting full logging permission for each replica simplifies reasoning and gives complete visibility for specific replias. - In practice, escalations show that slow decommissioning usually involves <15 ranges, and EnqueueProblemRangeInReplicateQueueInterval is typically large (~15 minutes). --- **kvserver: rename shouldLog to maybeLog and change vlevel to a var** This commit renames shouldLog to maybeLog in maybeEnqueueProblemRange and refactors vmodule logging level to use a dynamic variable instead of an if statement to choose between Info and VInfo. Co-authored-by: Brendan Gerrity <[email protected]> Co-authored-by: wenyihu6 <[email protected]>
3 parents f99a8f6 + 70267ba + e8684fa commit 205e55a

File tree

8 files changed

+55
-45
lines changed

8 files changed

+55
-45
lines changed

‎pkg/kv/kvserver/replica.go‎

Lines changed: 10 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -2918,8 +2918,9 @@ func (r *Replica) TestingRefreshLeaderlessWatcherUnavailableState(
29182918
// manner via the replica scanner, see #130199. This functionality is disabled
29192919
// by default for this reason.
29202920
func (r *Replica) maybeEnqueueProblemRange(
2921-
ctx context.Context, now time.Time, leaseValid, isLeaseholder bool,
2921+
ctx context.Context, now time.Time, leaseValid, isLeaseholder bool, maybeLog bool,
29222922
) {
2923+
29232924
// The method expects the caller to provide whether the lease is valid and
29242925
// the replica is the leaseholder for the range, so that it can avoid
29252926
// unnecessary work. We expect this method to be called in the context of
@@ -2958,26 +2959,27 @@ func (r *Replica) maybeEnqueueProblemRange(
29582959
r.store.metrics.DecommissioningNudgerEnqueue.Inc(1)
29592960
// TODO(dodeca12): Figure out a better way to track the
29602961
// decommissioning nudger enqueue failures/errors.
2962+
level := log.Level(2)
2963+
if maybeLog {
2964+
level = log.Level(0)
2965+
}
29612966
r.store.replicateQueue.AddAsyncWithCallback(ctx, r,
29622967
allocatorimpl.AllocatorReplaceDecommissioningVoter.Priority(), processCallback{
29632968
onEnqueueResult: func(indexOnHeap int, err error) {
29642969
if err != nil {
2965-
// TODO(wenyihu6): if we want to put these logs behind vmodule, move
2966-
// this function to another file so that we can avoid the spam on
2967-
// other logs.
2968-
log.KvDistribution.Infof(ctx,
2970+
log.KvDistribution.VInfof(ctx, level,
29692971
"decommissioning nudger failed to enqueue range %v due to %v", r.Desc(), err)
29702972
} else {
2971-
log.KvDistribution.Infof(ctx,
2973+
log.KvDistribution.VInfof(ctx, level,
29722974
"decommissioning nudger successfully enqueued range %v at index %d", r.Desc(), indexOnHeap)
29732975
}
29742976
},
29752977
onProcessResult: func(err error) {
29762978
if err != nil {
2977-
log.KvDistribution.Infof(ctx,
2979+
log.KvDistribution.VInfof(ctx, level,
29782980
"decommissioning nudger failed to process range %v due to %v", r.Desc(), err)
29792981
} else {
2980-
log.KvDistribution.Infof(ctx,
2982+
log.KvDistribution.VInfof(ctx, level,
29812983
"decommissioning nudger successfully processed replica %s", r.Desc())
29822984
}
29832985
},

‎pkg/kv/kvserver/store.go‎

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -3418,6 +3418,12 @@ func (s *Store) updateReplicationGauges(ctx context.Context) error {
34183418
ioOverload, _ = s.ioThreshold.t.Score()
34193419
s.ioThreshold.Unlock()
34203420

3421+
// TODO(wenyihu6): it would be nicer if we can sort the replicas so that we
3422+
// can always get the nudger story on the same set of replicas, will this
3423+
// introduce a lot of overhead? For now, it seems fine since we usually see <
3424+
// 15 ranges on decommission stall.
3425+
var logBudgetOnDecommissioningNudger = 15
3426+
34213427
// We want to avoid having to read this multiple times during the replica
34223428
// visiting, so load it once up front for all nodes.
34233429
livenessMap := s.cfg.NodeLiveness.ScanNodeVitalityFromCache()
@@ -3488,7 +3494,11 @@ func (s *Store) updateReplicationGauges(ctx context.Context) error {
34883494
if metrics.Decommissioning {
34893495
// NB: Enqueue is disabled by default from here and throttled async if
34903496
// enabled.
3491-
rep.maybeEnqueueProblemRange(ctx, goNow, metrics.LeaseValid, metrics.Leaseholder)
3497+
maybeLog := logBudgetOnDecommissioningNudger > 0
3498+
if maybeLog {
3499+
logBudgetOnDecommissioningNudger--
3500+
}
3501+
rep.maybeEnqueueProblemRange(ctx, goNow, metrics.LeaseValid, metrics.Leaseholder, maybeLog)
34923502
decommissioningRangeCount++
34933503
}
34943504
}

‎pkg/sql/catalog/bootstrap/testdata/testdata‎

Lines changed: 4 additions & 4 deletions
Large diffs are not rendered by default.

‎pkg/sql/catalog/systemschema/system.go‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1338,7 +1338,7 @@ CREATE TABLE public.inspect_errors (
13381338
id OID NOT NULL,
13391339
primary_key STRING NULL,
13401340
details STRING NOT NULL,
1341-
crdb_internal_expiration TIMESTAMPTZ NOT NULL DEFAULT current_timestamp():::TIMESTAMPTZ + '90 days':::INTERVAL ON UPDATE current_timestamp():::TIMESTAMPTZ + '90 days':::INTERVAL,
1341+
crdb_internal_expiration TIMESTAMPTZ NOT VISIBLE NOT NULL DEFAULT current_timestamp():::TIMESTAMPTZ + '90 days':::INTERVAL ON UPDATE current_timestamp():::TIMESTAMPTZ + '90 days':::INTERVAL,
13421342
CONSTRAINT "primary" PRIMARY KEY (error_id ASC),
13431343
INDEX object_idx (id ASC),
13441344
FAMILY "primary" (error_id, job_id, error_type, database_id, schema_id, id, primary_key, details, crdb_internal_expiration)
@@ -5245,7 +5245,7 @@ var (
52455245
{Name: "id", ID: 6, Type: types.Oid},
52465246
{Name: "primary_key", ID: 7, Type: types.String, Nullable: true},
52475247
{Name: "details", ID: 8, Type: types.String},
5248-
{Name: "crdb_internal_expiration", ID: 9, Type: types.TimestampTZ, DefaultExpr: &inspectErrorsExpirationString, OnUpdateExpr: &inspectErrorsExpirationString},
5248+
{Name: "crdb_internal_expiration", ID: 9, Type: types.TimestampTZ, DefaultExpr: &inspectErrorsExpirationString, OnUpdateExpr: &inspectErrorsExpirationString, Hidden: true},
52495249
},
52505250
[]descpb.ColumnFamilyDescriptor{
52515251
{

‎pkg/sql/catalog/systemschema_test/testdata/bootstrap_system‎

Lines changed: 4 additions & 4 deletions
Large diffs are not rendered by default.

‎pkg/sql/catalog/systemschema_test/testdata/bootstrap_tenant‎

Lines changed: 4 additions & 4 deletions
Large diffs are not rendered by default.

‎pkg/sql/logictest/testdata/logic_test/gen_test_objects‎

Lines changed: 20 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -198,26 +198,26 @@ WHERE table_catalog = 'newdb2' AND table_schema = 'public'
198198
ORDER BY table_name, column_name
199199
LIMIT 20
200200
----
201-
"insp""ect_err""ors" "error_id" uuid
202-
"insp""ect_err""ors" "crdb_internal_exp iration" timestamp with time zone
203-
"insp""ect_err""ors" "databas😩e_!id😝" oid
204-
"insp""ect_err""ors" details text
205-
"insp""ect_err""ors" er_ror_type text
206-
"insp""ect_err""ors" "id \v" oid
207-
"insp""ect_err""ors" "j%vob_id͐" bigint
208-
"insp""ect_err""ors" primary_key text
209-
"insp""ect_err""ors" rowid bigint
210-
"insp""ect_err""ors" schema_id oid
211-
jobs claim_instance_id bigint
212-
jobs claim_session_id bytea
213-
jobs "cre\\xa7a%6bted_b,y_type" text
214-
jobs created timestamp without time zone
215-
jobs created_by_id bigint
216-
jobs description text
217-
jobs error_msg text
218-
jobs "finiShed" timestamp with time zone
219-
jobs id bigint
220-
jobs "job._type" text
201+
"insp""ect_err""ors" "error_id" uuid
202+
"insp""ect_err""ors" "databas😩e_!id😝" oid
203+
"insp""ect_err""ors" details text
204+
"insp""ect_err""ors" er_ror_type text
205+
"insp""ect_err""ors" "id \v" oid
206+
"insp""ect_err""ors" "j%vob_id͐" bigint
207+
"insp""ect_err""ors" primary_key text
208+
"insp""ect_err""ors" rowid bigint
209+
"insp""ect_err""ors" schema_id oid
210+
jobs claim_instance_id bigint
211+
jobs claim_session_id bytea
212+
jobs "cre\\xa7a%6bted_b,y_type" text
213+
jobs created timestamp without time zone
214+
jobs created_by_id bigint
215+
jobs description text
216+
jobs error_msg text
217+
jobs "finiShed" timestamp with time zone
218+
jobs id bigint
219+
jobs "job._type" text
220+
jobs "la%55st_run" timestamp without time zone
221221

222222
subtest templates/different_templates_in_each_db
223223

‎pkg/sql/logictest/testdata/logic_test/information_schema‎

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1571,7 +1571,6 @@ system public 29_73_2_not_null
15711571
system public 29_73_3_not_null error_type IS NOT NULL
15721572
system public 29_73_6_not_null id IS NOT NULL
15731573
system public 29_73_8_not_null details IS NOT NULL
1574-
system public 29_73_9_not_null crdb_internal_expiration IS NOT NULL
15751574
system public 29_7_1_not_null value IS NOT NULL
15761575
system public 29_8_1_not_null id IS NOT NULL
15771576
system public 29_9_1_not_null crdb_region IS NOT NULL
@@ -1898,7 +1897,6 @@ system public 29_73_2_not_null
18981897
system public 29_73_3_not_null error_type IS NOT NULL
18991898
system public 29_73_6_not_null id IS NOT NULL
19001899
system public 29_73_8_not_null details IS NOT NULL
1901-
system public 29_73_9_not_null crdb_internal_expiration IS NOT NULL
19021900
system public 29_7_1_not_null value IS NOT NULL
19031901
system public 29_8_1_not_null id IS NOT NULL
19041902
system public 29_9_1_not_null crdb_region IS NOT NULL

0 commit comments

Comments
 (0)