Skip to content

Commit d53e88e

Browse files
craig[bot]angles-n-daemonsjbowens
committed
143775: structlogging: update hot range logging for app tenants r=angles-n-daemons a=angles-n-daemons structlogging: update hot range logging for app tenants Hot range logging currently runs as a task on each SQL node in the cluster. Its operative is to call its status server, collect the hot ranges from it, and log those ranges. This works well for a traditional deployment, since each sql node corresponds to a status server within the same process, so all of the status servers, and therefore all of the nodes with stores area guaranteed to be covered by this operation. ``` *legend* [] = node sql = sql server status = status server [sql ──────> status] [sql ──────> status] [sql ──────> status] ``` For multi-tenant deployments, this assumption goes out the window. In this topology, sql pods randomly connect to kv pods when making calls to the status server, which means that we can no longer guarantee that sql nodes will exhaustively cover the space they're required to cover. ``` [sql] ──────> [status] [sql] ─┐ [status] └────> [status] [status] [status] ``` To fix this, the changeset proposed changes the hot range logger to a job, which performs a fanout to all the nodes. This solution, while not scaling quite as well, avoids the lossy problem of missing nodes when logging hot ranges. ``` [sql] ┌────> [status] [sql] ─┼────> [status] ├────> [status] ├────> [status] └────> [status] ``` Fixes: #143527 Epic: CRDB-43150 Release note (bug fix): fixes an issue where multi-tenant hot range logging did not log all the hot ranges. 143933: storage: use block properties implementation defined in cockroachkvs r=jbowens a=jbowens The MVCC time interval block properties implementation has been copied into pebble/cockroachkvs so that the Pebble metamorphic tests may make use of it. Use that implementation and remove the pkg/storage copy. Epic: none Release note: none Co-authored-by: Brian Dillmann <[email protected]> Co-authored-by: Jackson Owens <[email protected]>
3 parents aa6267d + f1001c9 + 0cce378 commit d53e88e

File tree

12 files changed

+159
-195
lines changed

12 files changed

+159
-195
lines changed

docs/generated/metrics/metrics.html

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1306,6 +1306,18 @@
13061306
<tr><td>APPLICATION</td><td>jobs.history_retention.resume_completed</td><td>Number of history_retention jobs which successfully resumed to completion</td><td>jobs</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>
13071307
<tr><td>APPLICATION</td><td>jobs.history_retention.resume_failed</td><td>Number of history_retention jobs which failed with a non-retriable error</td><td>jobs</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>
13081308
<tr><td>APPLICATION</td><td>jobs.history_retention.resume_retry_error</td><td>Number of history_retention jobs which failed with a retriable error</td><td>jobs</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>
1309+
<tr><td>APPLICATION</td><td>jobs.hot_ranges_logger.currently_idle</td><td>Number of hot_ranges_logger jobs currently considered Idle and can be freely shut down</td><td>jobs</td><td>GAUGE</td><td>COUNT</td><td>AVG</td><td>NONE</td></tr>
1310+
<tr><td>APPLICATION</td><td>jobs.hot_ranges_logger.currently_paused</td><td>Number of hot_ranges_logger jobs currently considered Paused</td><td>jobs</td><td>GAUGE</td><td>COUNT</td><td>AVG</td><td>NONE</td></tr>
1311+
<tr><td>APPLICATION</td><td>jobs.hot_ranges_logger.currently_running</td><td>Number of hot_ranges_logger jobs currently running in Resume or OnFailOrCancel state</td><td>jobs</td><td>GAUGE</td><td>COUNT</td><td>AVG</td><td>NONE</td></tr>
1312+
<tr><td>APPLICATION</td><td>jobs.hot_ranges_logger.expired_pts_records</td><td>Number of expired protected timestamp records owned by hot_ranges_logger jobs</td><td>records</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>
1313+
<tr><td>APPLICATION</td><td>jobs.hot_ranges_logger.fail_or_cancel_completed</td><td>Number of hot_ranges_logger jobs which successfully completed their failure or cancelation process</td><td>jobs</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>
1314+
<tr><td>APPLICATION</td><td>jobs.hot_ranges_logger.fail_or_cancel_failed</td><td>Number of hot_ranges_logger jobs which failed with a non-retriable error on their failure or cancelation process</td><td>jobs</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>
1315+
<tr><td>APPLICATION</td><td>jobs.hot_ranges_logger.fail_or_cancel_retry_error</td><td>Number of hot_ranges_logger jobs which failed with a retriable error on their failure or cancelation process</td><td>jobs</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>
1316+
<tr><td>APPLICATION</td><td>jobs.hot_ranges_logger.protected_age_sec</td><td>The age of the oldest PTS record protected by hot_ranges_logger jobs</td><td>seconds</td><td>GAUGE</td><td>SECONDS</td><td>AVG</td><td>NONE</td></tr>
1317+
<tr><td>APPLICATION</td><td>jobs.hot_ranges_logger.protected_record_count</td><td>Number of protected timestamp records held by hot_ranges_logger jobs</td><td>records</td><td>GAUGE</td><td>COUNT</td><td>AVG</td><td>NONE</td></tr>
1318+
<tr><td>APPLICATION</td><td>jobs.hot_ranges_logger.resume_completed</td><td>Number of hot_ranges_logger jobs which successfully resumed to completion</td><td>jobs</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>
1319+
<tr><td>APPLICATION</td><td>jobs.hot_ranges_logger.resume_failed</td><td>Number of hot_ranges_logger jobs which failed with a non-retriable error</td><td>jobs</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>
1320+
<tr><td>APPLICATION</td><td>jobs.hot_ranges_logger.resume_retry_error</td><td>Number of hot_ranges_logger jobs which failed with a retriable error</td><td>jobs</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>
13091321
<tr><td>APPLICATION</td><td>jobs.import.currently_idle</td><td>Number of import jobs currently considered Idle and can be freely shut down</td><td>jobs</td><td>GAUGE</td><td>COUNT</td><td>AVG</td><td>NONE</td></tr>
13101322
<tr><td>APPLICATION</td><td>jobs.import.currently_paused</td><td>Number of import jobs currently considered Paused</td><td>jobs</td><td>GAUGE</td><td>COUNT</td><td>AVG</td><td>NONE</td></tr>
13111323
<tr><td>APPLICATION</td><td>jobs.import.currently_running</td><td>Number of import jobs currently running in Resume or OnFailOrCancel state</td><td>jobs</td><td>GAUGE</td><td>COUNT</td><td>AVG</td><td>NONE</td></tr>

pkg/jobs/jobspb/jobs.proto

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1439,6 +1439,10 @@ message StandbyReadTSPollerProgress {
14391439

14401440
}
14411441

1442+
message HotRangesLoggerDetails {
1443+
1444+
}
1445+
14421446
message UpdateTableMetadataCacheDetails {}
14431447
message UpdateTableMetadataCacheProgress {
14441448
enum Status {
@@ -1477,6 +1481,10 @@ message SqlActivityFlushProgress {
14771481

14781482
}
14791483

1484+
message HotRangesLoggerProgress {
1485+
1486+
}
1487+
14801488
message ImportRollbackProgress {}
14811489

14821490
message Payload {
@@ -1548,6 +1556,7 @@ message Payload {
15481556
UpdateTableMetadataCacheDetails update_table_metadata_cache_details = 49;
15491557
StandbyReadTSPollerDetails standby_read_ts_poller_details = 50;
15501558
SqlActivityFlushDetails sql_activity_flush_details = 51;
1559+
HotRangesLoggerDetails hot_ranges_logger_details = 52;
15511560
}
15521561
reserved 26;
15531562
// PauseReason is used to describe the reason that the job is currently paused
@@ -1629,6 +1638,7 @@ message Progress {
16291638
UpdateTableMetadataCacheProgress table_metadata_cache = 37;
16301639
StandbyReadTSPollerProgress standby_read_ts_poller = 38;
16311640
SqlActivityFlushProgress sql_activity_flush = 39;
1641+
HotRangesLoggerProgress hot_ranges_logger = 40;
16321642
}
16331643

16341644
uint64 trace_id = 21 [(gogoproto.nullable) = false, (gogoproto.customname) = "TraceID", (gogoproto.customtype) = "github.com/cockroachdb/cockroach/pkg/util/tracing/tracingpb.TraceID"];
@@ -1672,6 +1682,7 @@ enum Type {
16721682
UPDATE_TABLE_METADATA_CACHE = 29 [(gogoproto.enumvalue_customname) = "TypeUpdateTableMetadataCache"];
16731683
STANDBY_READ_TS_POLLER = 30 [(gogoproto.enumvalue_customname) = "TypeStandbyReadTSPoller"];
16741684
SQL_ACTIVITY_FLUSH = 31 [(gogoproto.enumvalue_customname) = "TypeSQLActivityFlush"];
1685+
HOT_RANGES_LOGGER = 32 [(gogoproto.enumvalue_customname) = "TypeHotRangesLogger"];
16751686
}
16761687

16771688
message Job {

pkg/jobs/jobspb/wrap.go

Lines changed: 12 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -47,6 +47,7 @@ var (
4747
_ Details = UpdateTableMetadataCacheDetails{}
4848
_ Details = StandbyReadTSPollerDetails{}
4949
_ Details = SqlActivityFlushDetails{}
50+
_ Details = HotRangesLoggerDetails{}
5051
)
5152

5253
// ProgressDetails is a marker interface for job progress details proto structs.
@@ -78,6 +79,7 @@ var (
7879
_ ProgressDetails = UpdateTableMetadataCacheProgress{}
7980
_ ProgressDetails = StandbyReadTSPollerProgress{}
8081
_ ProgressDetails = SqlActivityFlushProgress{}
82+
_ ProgressDetails = HotRangesLoggerProgress{}
8183
)
8284

8385
// Type returns the payload's job type and panics if the type is invalid.
@@ -244,6 +246,8 @@ func DetailsType(d isPayload_Details) (Type, error) {
244246
return TypeStandbyReadTSPoller, nil
245247
case *Payload_SqlActivityFlushDetails:
246248
return TypeSQLActivityFlush, nil
249+
case *Payload_HotRangesLoggerDetails:
250+
return TypeHotRangesLogger, nil
247251
default:
248252
return TypeUnspecified, errors.Newf("Payload.Type called on a payload with an unknown details type: %T", d)
249253
}
@@ -298,6 +302,7 @@ var JobDetailsForEveryJobType = map[Type]Details{
298302
TypeUpdateTableMetadataCache: UpdateTableMetadataCacheDetails{},
299303
TypeStandbyReadTSPoller: StandbyReadTSPollerDetails{},
300304
TypeSQLActivityFlush: SqlActivityFlushDetails{},
305+
TypeHotRangesLogger: HotRangesLoggerDetails{},
301306
}
302307

303308
// WrapProgressDetails wraps a ProgressDetails object in the protobuf wrapper
@@ -434,6 +439,8 @@ func (p *Payload) UnwrapDetails() Details {
434439
return *d.StandbyReadTsPollerDetails
435440
case *Payload_SqlActivityFlushDetails:
436441
return *d.SqlActivityFlushDetails
442+
case *Payload_HotRangesLoggerDetails:
443+
return *d.HotRangesLoggerDetails
437444
default:
438445
return nil
439446
}
@@ -501,6 +508,8 @@ func (p *Progress) UnwrapDetails() ProgressDetails {
501508
return *d.StandbyReadTsPoller
502509
case *Progress_SqlActivityFlush:
503510
return *d.SqlActivityFlush
511+
case *Progress_HotRangesLogger:
512+
return *d.HotRangesLogger
504513
default:
505514
return nil
506515
}
@@ -592,6 +601,8 @@ func WrapPayloadDetails(details Details) interface {
592601
return &Payload_StandbyReadTsPollerDetails{StandbyReadTsPollerDetails: &d}
593602
case SqlActivityFlushDetails:
594603
return &Payload_SqlActivityFlushDetails{SqlActivityFlushDetails: &d}
604+
case HotRangesLoggerDetails:
605+
return &Payload_HotRangesLoggerDetails{HotRangesLoggerDetails: &d}
595606
default:
596607
panic(errors.AssertionFailedf("jobs.WrapPayloadDetails: unknown details type %T", d))
597608
}
@@ -627,7 +638,7 @@ const (
627638
func (Type) SafeValue() {}
628639

629640
// NumJobTypes is the number of jobs types.
630-
const NumJobTypes = 32
641+
const NumJobTypes = 33
631642

632643
// ChangefeedDetailsMarshaler allows for dependency injection of
633644
// cloud.SanitizeExternalStorageURI to avoid the dependency from this

pkg/server/server.go

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2316,6 +2316,7 @@ func (s *topLevelServer) AcceptClients(ctx context.Context) error {
23162316
s.status,
23172317
*s.sqlServer.internalExecutor,
23182318
s.ClusterSettings(),
2319+
nil,
23192320
); err != nil {
23202321
return err
23212322
}

pkg/server/structlogging/BUILD.bazel

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2,10 +2,16 @@ load("@io_bazel_rules_go//go:def.bzl", "go_library", "go_test")
22

33
go_library(
44
name = "structlogging",
5-
srcs = ["hot_ranges_log.go"],
5+
srcs = [
6+
"hot_ranges_log.go",
7+
"hot_ranges_log_job.go",
8+
],
69
importpath = "github.com/cockroachdb/cockroach/pkg/server/structlogging",
710
visibility = ["//visibility:public"],
811
deps = [
12+
"//pkg/jobs",
13+
"//pkg/jobs/jobspb",
14+
"//pkg/multitenant/tenantcapabilities",
915
"//pkg/server/serverpb",
1016
"//pkg/settings",
1117
"//pkg/settings/cluster",
@@ -16,6 +22,7 @@ go_library(
1622
"//pkg/util/log/logutil",
1723
"//pkg/util/stop",
1824
"//pkg/util/timeutil",
25+
"@com_github_cockroachdb_errors//:errors",
1926
],
2027
)
2128

pkg/server/structlogging/hot_ranges_log.go

Lines changed: 67 additions & 33 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,9 @@ import (
99
"context"
1010
"time"
1111

12+
"github.com/cockroachdb/cockroach/pkg/jobs"
13+
"github.com/cockroachdb/cockroach/pkg/jobs/jobspb"
14+
"github.com/cockroachdb/cockroach/pkg/multitenant/tenantcapabilities"
1215
"github.com/cockroachdb/cockroach/pkg/server/serverpb"
1316
"github.com/cockroachdb/cockroach/pkg/settings"
1417
"github.com/cockroachdb/cockroach/pkg/settings/cluster"
@@ -50,9 +53,12 @@ var TelemetryHotRangesStatsLoggingDelay = settings.RegisterDurationSetting(
5053
// hotRangesLoggingScheduler is responsible for logging index usage stats
5154
// on a scheduled interval.
5255
type hotRangesLoggingScheduler struct {
53-
ie sql.InternalExecutor
54-
sServer serverpb.TenantStatusServer
55-
st *cluster.Settings
56+
ie sql.InternalExecutor
57+
sServer serverpb.TenantStatusServer
58+
st *cluster.Settings
59+
stopper *stop.Stopper
60+
job *jobs.Job
61+
multiTenant bool
5662
}
5763

5864
// StartHotRangesLoggingScheduler starts the capture index usage statistics logging scheduler.
@@ -62,42 +68,66 @@ func StartHotRangesLoggingScheduler(
6268
sServer serverpb.TenantStatusServer,
6369
ie sql.InternalExecutor,
6470
st *cluster.Settings,
71+
ti *tenantcapabilities.Entry,
6572
) error {
73+
multiTenant := ti != nil && !ti.TenantID.IsSystem()
6674
scheduler := hotRangesLoggingScheduler{
67-
ie: ie,
68-
sServer: sServer,
69-
st: st,
75+
ie: ie,
76+
sServer: sServer,
77+
st: st,
78+
stopper: stopper,
79+
multiTenant: multiTenant,
7080
}
7181

72-
return scheduler.start(ctx, stopper)
82+
if multiTenant {
83+
return scheduler.startJob(ctx, stopper)
84+
}
85+
86+
return scheduler.startTask(ctx, stopper)
7387
}
7488

75-
func (s *hotRangesLoggingScheduler) start(ctx context.Context, stopper *stop.Stopper) error {
89+
func (s *hotRangesLoggingScheduler) startTask(ctx context.Context, stopper *stop.Stopper) error {
7690
return stopper.RunAsyncTask(ctx, "hot-ranges-stats", func(ctx context.Context) {
77-
intervalChangedChan := make(chan struct{})
78-
// We have to register this callback first. Otherwise we may run into
79-
// an unlikely but possible scenario where we've started the ticker,
80-
// and the setting is changed before we register the callback and the
81-
// ticker will not be reset to the new value.
82-
TelemetryHotRangesStatsInterval.SetOnChange(&s.st.SV, func(ctx context.Context) {
83-
intervalChangedChan <- struct{}{}
84-
})
85-
86-
ticker := time.NewTicker(TelemetryHotRangesStatsInterval.Get(&s.st.SV))
87-
88-
for {
89-
select {
90-
case <-stopper.ShouldQuiesce():
91-
return
92-
case <-ctx.Done():
93-
return
94-
case <-ticker.C:
95-
s.maybeLogHotRanges(ctx, stopper)
96-
case <-intervalChangedChan:
97-
ticker.Reset(TelemetryHotRangesStatsInterval.Get(&s.st.SV))
98-
}
99-
}
91+
err := s.start(ctx, stopper)
92+
log.Warningf(ctx, "hot ranges stats logging scheduler stopped: %s", err)
93+
})
94+
}
95+
96+
func (s *hotRangesLoggingScheduler) startJob(ctx context.Context, stopper *stop.Stopper) error {
97+
jobs.RegisterConstructor(
98+
jobspb.TypeHotRangesLogger,
99+
func(job *jobs.Job, settings *cluster.Settings) jobs.Resumer {
100+
return &hotRangesLoggingScheduler{job: job}
101+
},
102+
jobs.DisablesTenantCostControl,
103+
)
104+
return nil
105+
}
106+
107+
func (s *hotRangesLoggingScheduler) start(ctx context.Context, stopper *stop.Stopper) error {
108+
intervalChangedChan := make(chan struct{})
109+
// We have to register this callback first. Otherwise we may run into
110+
// an unlikely but possible scenario where we've started the ticker,
111+
// and the setting is changed before we register the callback and the
112+
// ticker will not be reset to the new value.
113+
TelemetryHotRangesStatsInterval.SetOnChange(&s.st.SV, func(ctx context.Context) {
114+
intervalChangedChan <- struct{}{}
100115
})
116+
117+
ticker := time.NewTicker(TelemetryHotRangesStatsInterval.Get(&s.st.SV))
118+
119+
for {
120+
select {
121+
case <-stopper.ShouldQuiesce():
122+
return nil
123+
case <-ctx.Done():
124+
return nil
125+
case <-ticker.C:
126+
s.maybeLogHotRanges(ctx, stopper)
127+
case <-intervalChangedChan:
128+
ticker.Reset(TelemetryHotRangesStatsInterval.Get(&s.st.SV))
129+
}
130+
}
101131
}
102132

103133
// maybeLogHotRanges is a small helper function which couples the
@@ -117,8 +147,12 @@ func (s *hotRangesLoggingScheduler) shouldLog() bool {
117147
// logHotRanges collects the hot ranges from this node's status server and
118148
// sends them to the TELEMETRY log channel.
119149
func (s *hotRangesLoggingScheduler) logHotRanges(ctx context.Context, stopper *stop.Stopper) {
120-
resp, err := s.sServer.HotRangesV2(ctx,
121-
&serverpb.HotRangesRequest{NodeID: "local", PageSize: ReportTopHottestRanges})
150+
req := &serverpb.HotRangesRequest{NodeID: "local", PageSize: ReportTopHottestRanges}
151+
// if we are running in single tenant mode, only log the ranges on the status server.
152+
if !s.multiTenant {
153+
req.NodeID = "local"
154+
}
155+
resp, err := s.sServer.HotRangesV2(ctx, req)
122156
if err != nil {
123157
log.Warningf(ctx, "failed to get hot ranges: %s", err)
124158
return
Lines changed: 38 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,38 @@
1+
// Copyright 2025 The Cockroach Authors.
2+
//
3+
// Use of this software is governed by the CockroachDB Software License
4+
// included in the /LICENSE file.
5+
6+
package structlogging
7+
8+
import (
9+
"context"
10+
11+
"github.com/cockroachdb/cockroach/pkg/jobs"
12+
"github.com/cockroachdb/cockroach/pkg/util/log"
13+
"github.com/cockroachdb/errors"
14+
)
15+
16+
func (s *hotRangesLoggingScheduler) Resume(ctx context.Context, execCtxI interface{}) error {
17+
// This job is a forever running background job, and it is always safe to
18+
// terminate the SQL pod whenever the job is running, so mark it as idle.
19+
s.job.MarkIdle(true)
20+
21+
return s.start(ctx, s.stopper)
22+
}
23+
24+
func (s *hotRangesLoggingScheduler) OnFailOrCancel(
25+
ctx context.Context, execCtx interface{}, jobErr error,
26+
) error {
27+
if jobs.HasErrJobCanceled(jobErr) {
28+
err := errors.NewAssertionErrorWithWrappedErrf(
29+
jobErr, "hot range logging job is not cancelable",
30+
)
31+
log.Errorf(ctx, "%v", err)
32+
}
33+
return nil
34+
}
35+
36+
func (s *hotRangesLoggingScheduler) CollectProfile(ctx context.Context, execCtx interface{}) error {
37+
return nil
38+
}

pkg/server/tenant.go

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -980,12 +980,14 @@ func (s *SQLServerWrapper) AcceptClients(ctx context.Context) error {
980980
}
981981
}
982982

983+
ti, _ := s.sqlServer.tenantConnect.TenantInfo()
983984
if err := structlogging.StartHotRangesLoggingScheduler(
984985
ctx,
985986
s.stopper,
986987
s.sqlServer.tenantConnect,
987988
*s.sqlServer.internalExecutor,
988989
s.ClusterSettings(),
990+
&ti,
989991
); err != nil {
990992
return err
991993
}

pkg/storage/BUILD.bazel

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -212,6 +212,7 @@ go_test(
212212
"@com_github_cockroachdb_errors//:errors",
213213
"@com_github_cockroachdb_errors//oserror",
214214
"@com_github_cockroachdb_pebble//:pebble",
215+
"@com_github_cockroachdb_pebble//cockroachkvs",
215216
"@com_github_cockroachdb_pebble//objstorage",
216217
"@com_github_cockroachdb_pebble//objstorage/objstorageprovider",
217218
"@com_github_cockroachdb_pebble//sstable",

0 commit comments

Comments
 (0)