From 707705a8209727f2c0c9f5c9fae44d53b83dcf18 Mon Sep 17 00:00:00 2001 From: Weizhen Wang Date: Mon, 27 May 2024 12:23:28 +0800 Subject: [PATCH 1/4] statistics: print the process of init stats Signed-off-by: Weizhen Wang --- pkg/statistics/handle/bootstrap.go | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/pkg/statistics/handle/bootstrap.go b/pkg/statistics/handle/bootstrap.go index 6acd746bd26d0..43111039ce1ce 100644 --- a/pkg/statistics/handle/bootstrap.go +++ b/pkg/statistics/handle/bootstrap.go @@ -30,6 +30,7 @@ import ( "github.com/pingcap/tidb/pkg/statistics" "github.com/pingcap/tidb/pkg/statistics/handle/cache" "github.com/pingcap/tidb/pkg/statistics/handle/initstats" + statslogutil "github.com/pingcap/tidb/pkg/statistics/handle/logutil" statstypes "github.com/pingcap/tidb/pkg/statistics/handle/types" "github.com/pingcap/tidb/pkg/statistics/handle/util" "github.com/pingcap/tidb/pkg/types" @@ -724,11 +725,13 @@ func (h *Handle) InitStats(is infoschema.InfoSchema) (err error) { if err != nil { return errors.Trace(err) } + statslogutil.StatsLogger().Info("complete to load the meta") if config.GetGlobalConfig().Performance.ConcurrentlyInitStats { err = h.initStatsHistogramsConcurrency(is, cache) } else { err = h.initStatsHistograms(is, cache) } + statslogutil.StatsLogger().Info("complete to load the histogram") if err != nil { return errors.Trace(err) } @@ -737,6 +740,7 @@ func (h *Handle) InitStats(is infoschema.InfoSchema) (err error) { } else { err = h.initStatsTopN(cache) } + statslogutil.StatsLogger().Info("complete to load the topn") if err != nil { return err } @@ -745,8 +749,10 @@ func (h *Handle) InitStats(is infoschema.InfoSchema) (err error) { if err != nil { return err } + statslogutil.StatsLogger().Info("complete to load the FM Sketch") } err = h.initStatsBuckets(cache) + statslogutil.StatsLogger().Info("complete to load the bucket") if err != nil { return errors.Trace(err) } From 9f591f5040794b816ed38e4a122af79b97a09759 Mon Sep 17 00:00:00 2001 From: Weizhen Wang Date: Mon, 27 May 2024 15:19:02 +0800 Subject: [PATCH 2/4] statistics: print the process of init stats Signed-off-by: Weizhen Wang --- pkg/statistics/handle/bootstrap.go | 12 ++-- pkg/statistics/handle/initstats/BUILD.bazel | 2 + .../handle/initstats/load_stats_page.go | 60 +++++++++++++++++-- 3 files changed, 62 insertions(+), 12 deletions(-) diff --git a/pkg/statistics/handle/bootstrap.go b/pkg/statistics/handle/bootstrap.go index 43111039ce1ce..2f29a1199327f 100644 --- a/pkg/statistics/handle/bootstrap.go +++ b/pkg/statistics/handle/bootstrap.go @@ -351,9 +351,9 @@ func (h *Handle) initStatsHistogramsByPaging(is infoschema.InfoSchema, cache sta func (h *Handle) initStatsHistogramsConcurrency(is infoschema.InfoSchema, cache statstypes.StatsCache) error { var maxTid = maxTidRecord.tid.Load() tid := int64(0) - ls := initstats.NewRangeWorker(func(task initstats.Task) error { + ls := initstats.NewRangeWorker("histogram", func(task initstats.Task) error { return h.initStatsHistogramsByPaging(is, cache, task) - }) + }, uint64(maxTid), uint64(initStatsStep)) ls.LoadStats() for tid <= maxTid { ls.SendTask(initstats.Task{ @@ -461,9 +461,9 @@ func (h *Handle) initStatsTopNByPaging(cache statstypes.StatsCache, task initsta func (h *Handle) initStatsTopNConcurrency(cache statstypes.StatsCache) error { var maxTid = maxTidRecord.tid.Load() tid := int64(0) - ls := initstats.NewRangeWorker(func(task initstats.Task) error { + ls := initstats.NewRangeWorker("TopN", func(task initstats.Task) error { return h.initStatsTopNByPaging(cache, task) - }) + }, uint64(maxTid), uint64(initStatsStep)) ls.LoadStats() for tid <= maxTid { ls.SendTask(initstats.Task{ @@ -664,9 +664,9 @@ func (h *Handle) initStatsBucketsByPaging(cache statstypes.StatsCache, task init func (h *Handle) initStatsBucketsConcurrency(cache statstypes.StatsCache) error { var maxTid = maxTidRecord.tid.Load() tid := int64(0) - ls := initstats.NewRangeWorker(func(task initstats.Task) error { + ls := initstats.NewRangeWorker("bucket", func(task initstats.Task) error { return h.initStatsBucketsByPaging(cache, task) - }) + }, uint64(maxTid), uint64(initStatsStep)) ls.LoadStats() for tid <= maxTid { ls.SendTask(initstats.Task{ diff --git a/pkg/statistics/handle/initstats/BUILD.bazel b/pkg/statistics/handle/initstats/BUILD.bazel index af81cfe96d408..5dd9c299a5dcd 100644 --- a/pkg/statistics/handle/initstats/BUILD.bazel +++ b/pkg/statistics/handle/initstats/BUILD.bazel @@ -10,8 +10,10 @@ go_library( visibility = ["//visibility:public"], deps = [ "//pkg/config", + "//pkg/statistics/handle/logutil", "//pkg/util", "//pkg/util/logutil", "@org_uber_go_zap//:zap", + "@org_uber_go_zap//zapcore", ], ) diff --git a/pkg/statistics/handle/initstats/load_stats_page.go b/pkg/statistics/handle/initstats/load_stats_page.go index 31694f293e75a..ba1bad649f0b6 100644 --- a/pkg/statistics/handle/initstats/load_stats_page.go +++ b/pkg/statistics/handle/initstats/load_stats_page.go @@ -15,11 +15,44 @@ package initstats import ( + "fmt" + "sync" + "sync/atomic" + "time" + + statslogutil "github.com/pingcap/tidb/pkg/statistics/handle/logutil" "github.com/pingcap/tidb/pkg/util" "github.com/pingcap/tidb/pkg/util/logutil" "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +var ( + initSamplerLoggerOnce sync.Once + samplerLogger *zap.Logger ) +// SingletonStatsSamplerLogger with category "stats" is used to log statistic related messages. +// It is used to sample the log to avoid too many logs. +// NOTE: Do not create a new logger for each log, it will cause the sampler not work. +// Because we need to record the log count with the same level and message in this specific logger. +// Do not use it to log the message that is not related to statistics. +func singletonStatsSamplerLogger() *zap.Logger { + init := func() { + if samplerLogger == nil { + // Create a new zapcore sampler with options + // This will log the first log entries with the same level and message in 1 minutes and ignore the rest of the logs. + sampler := zap.WrapCore(func(core zapcore.Core) zapcore.Core { + return zapcore.NewSamplerWithOptions(core, time.Minute, 1, 0) + }) + samplerLogger = statslogutil.StatsLogger().WithOptions(sampler) + } + } + + initSamplerLoggerOnce.Do(init) + return samplerLogger +} + // Task represents the range of the table for loading stats. type Task struct { StartTid int64 @@ -28,18 +61,29 @@ type Task struct { // RangeWorker is used to load stats concurrently by the range of table id. type RangeWorker struct { - dealFunc func(task Task) error - taskChan chan Task - - wg util.WaitGroupWrapper + dealFunc func(task Task) error + taskChan chan Task + logger *zap.Logger + taskName string + wg util.WaitGroupWrapper + taskCnt uint64 + completeTaskCnt atomic.Uint64 } // NewRangeWorker creates a new RangeWorker. -func NewRangeWorker(dealFunc func(task Task) error) *RangeWorker { - return &RangeWorker{ +func NewRangeWorker(taskName string, dealFunc func(task Task) error, maxTid, initStatsStep uint64) *RangeWorker { + taskCnt := uint64(1) + if maxTid > initStatsStep*2 { + taskCnt = maxTid / initStatsStep + } + worker := &RangeWorker{ + taskName: taskName, dealFunc: dealFunc, taskChan: make(chan Task, 1), + taskCnt: taskCnt, } + worker.logger = singletonStatsSamplerLogger() + return worker } // LoadStats loads stats concurrently when to init stats @@ -57,6 +101,10 @@ func (ls *RangeWorker) loadStats() { if err := ls.dealFunc(task); err != nil { logutil.BgLogger().Error("load stats failed", zap.Error(err)) } + if ls.logger != nil { + completeTaskCnt := ls.completeTaskCnt.Add(1) + ls.logger.Info(fmt.Sprintf("load %s [%d/%d]", ls.taskName, completeTaskCnt, ls.taskCnt)) + } } } From 03b2aae1135f2201274f808f2d0a1e46f3389a16 Mon Sep 17 00:00:00 2001 From: Weizhen Wang Date: Wed, 29 May 2024 15:33:10 +0800 Subject: [PATCH 3/4] * Signed-off-by: Weizhen Wang --- pkg/statistics/handle/bootstrap.go | 2 ++ 1 file changed, 2 insertions(+) diff --git a/pkg/statistics/handle/bootstrap.go b/pkg/statistics/handle/bootstrap.go index 2f29a1199327f..b61bc0e4c3f4e 100644 --- a/pkg/statistics/handle/bootstrap.go +++ b/pkg/statistics/handle/bootstrap.go @@ -698,10 +698,12 @@ func (h *Handle) InitStatsLite(is infoschema.InfoSchema) (err error) { if err != nil { return errors.Trace(err) } + statslogutil.StatsLogger().Info("complete to load the meta") err = h.initStatsHistogramsLite(is, cache) if err != nil { return errors.Trace(err) } + statslogutil.StatsLogger().Info("complete to load the histogram") h.Replace(cache) return nil } From 7d7125c6a2c984ea466facc742111575c434d3cd Mon Sep 17 00:00:00 2001 From: Weizhen Wang Date: Wed, 29 May 2024 22:36:40 +0800 Subject: [PATCH 4/4] fix linter --- pkg/statistics/handle/bootstrap.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/pkg/statistics/handle/bootstrap.go b/pkg/statistics/handle/bootstrap.go index b61bc0e4c3f4e..17218b98d4aee 100644 --- a/pkg/statistics/handle/bootstrap.go +++ b/pkg/statistics/handle/bootstrap.go @@ -698,12 +698,12 @@ func (h *Handle) InitStatsLite(is infoschema.InfoSchema) (err error) { if err != nil { return errors.Trace(err) } - statslogutil.StatsLogger().Info("complete to load the meta") + statslogutil.StatsLogger().Info("complete to load the meta in the lite mode") err = h.initStatsHistogramsLite(is, cache) if err != nil { return errors.Trace(err) } - statslogutil.StatsLogger().Info("complete to load the histogram") + statslogutil.StatsLogger().Info("complete to load the histogram in the lite mode") h.Replace(cache) return nil }