statistics: print the process of init stats #53560

hawkingrei · 2024-05-27T04:23:52Z

What problem does this PR solve?

Issue Number: close #53564

Problem Summary:

What changed and how does it work?

it sometimes takes too much time for tidb to init stats. we should print the process info to tell the users.

Check List

Tests

Unit test
Integration test
Manual test (add detailed scripts or steps below)

if we have several tables, it will print

[2024/05/27 18:21:39.093 +08:00] [INFO] [bootstrap.go:734] ["complete to load the histogram"] [category=stats]
[2024/05/27 18:21:39.094 +08:00] [INFO] [bootstrap.go:743] ["complete to load the topn"] [category=stats]
[2024/05/27 18:21:39.097 +08:00] [INFO] [bootstrap.go:755] ["complete to load the bucket"] [category=stats]
[2024/05/27 18:21:39.098 +08:00] [INFO] [domain.go:2318] ["init stats info time"] [lite=false] ["take time"=13.208834ms]

But if TiDB has enough tables, it will print.

...
[2024/05/27 19:54:10.516 +08:00] [INFO] [load_stats_page.go:83] ["load bucket [1080/2391]"] [category=stats]
[2024/05/27 19:55:10.516 +08:00] [INFO] [load_stats_page.go:83] ["load bucket [1781/2391]"] [category=stats]
...

No need to test
- I checked and no code files have been changed.

Side effects

Performance regression: Consumes more CPU
Performance regression: Consumes more Memory
Breaking backward compatibility

Documentation

Release note

Please refer to Release Notes Language Style Guide to write a quality release note.

init stats 时显示进度
statistics: print the process of init stats

codecov · 2024-05-27T04:49:09Z

Codecov Report

Attention: Patch coverage is 81.57895% with 7 lines in your changes are missing coverage. Please review.

Project coverage is 74.7782%. Comparing base (df64c34) to head (7d7125c).
Report is 33 commits behind head on master.

Additional details and impacted files

@@               Coverage Diff                @@
##             master     #53560        +/-   ##
================================================
+ Coverage   72.4222%   74.7782%   +2.3560%     
================================================
  Files          1505       1507         +2     
  Lines        430553     439922      +9369     
================================================
+ Hits         311816     328966     +17150     
+ Misses        99427      90766      -8661     
- Partials      19310      20190       +880

Flag	Coverage Δ
integration	`49.4542% <0.0000%> (?)`
unit	`71.4592% <81.5789%> (+0.0577%)`	⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

Components	Coverage Δ
dumpling	`53.9957% <ø> (ø)`
parser	`∅ <ø> (∅)`
br	`50.4770% <ø> (+9.0899%)`	⬆️

Signed-off-by: Weizhen Wang <[email protected]>

hawkingrei · 2024-05-27T09:33:15Z

/retest

hawkingrei · 2024-05-27T10:16:19Z

/retest

Signed-off-by: Weizhen Wang <[email protected]>

hawkingrei · 2024-05-28T02:23:09Z

/retest

AilinKid

Rest LGTM

AilinKid · 2024-05-28T05:45:35Z

pkg/statistics/handle/initstats/load_stats_page.go

@@ -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))


seems it's sampling output
1% 50% 90% 100%
if 100% is missed， will the log msg look wired as unfinished/hang?

If it is complete, It must print complete.

load xxxx [completed task count / total task count]

hawkingrei · 2024-05-28T12:33:40Z

@winoros @hi-rustin PTAL

Signed-off-by: Weizhen Wang <[email protected]>

elsa0520 · 2024-05-29T07:42:56Z

pkg/statistics/handle/bootstrap.go

 	err = h.initStatsHistogramsLite(is, cache)
 	if err != nil {
 		return errors.Trace(err)
 	}
+	statslogutil.StatsLogger().Info("complete to load the histogram")


Suggested change

statslogutil.StatsLogger().Info("complete to load the histogram")

statslogutil.StatsLogger().Info("complete to load the lite histogram")

ti-chi-bot · 2024-05-29T10:19:15Z

[LGTM Timeline notifier]

Timeline:

2024-05-28 05:45:52.28889873 +0000 UTC m=+2755306.046034295: ☑️ agreed by AilinKid.
2024-05-29 10:19:14.104927128 +0000 UTC m=+2858107.862062699: ☑️ agreed by winoros.

hawkingrei · 2024-05-29T13:56:09Z

/hold

hawkingrei · 2024-05-30T06:33:42Z

@elsa0520 Please confirm one last time.

elsa0520

LGTM

ti-chi-bot · 2024-05-30T06:42:11Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: AilinKid, elsa0520, winoros

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

~~pkg/statistics/OWNERS~~ [AilinKid,elsa0520,winoros]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

hawkingrei · 2024-05-30T07:20:21Z

/unhold

hawkingrei · 2024-05-30T07:46:32Z

/retest

ti-chi-bot bot added do-not-merge/needs-linked-issue do-not-merge/needs-tests-checked release-note-none Denotes a PR that doesn't merit a release note. sig/planner SIG: Planner size/XS Denotes a PR that changes 0-9 lines, ignoring generated files. labels May 27, 2024

hawkingrei force-pushed the print_log branch from 9b56e8a to b4dcb8c Compare May 27, 2024 06:36

ti-chi-bot bot added size/M Denotes a PR that changes 30-99 lines, ignoring generated files. and removed do-not-merge/needs-tests-checked do-not-merge/needs-linked-issue size/XS Denotes a PR that changes 0-9 lines, ignoring generated files. labels May 27, 2024

statistics: print the process of init stats

707705a

Signed-off-by: Weizhen Wang <[email protected]>

hawkingrei force-pushed the print_log branch from 8fe3ac9 to e893e08 Compare May 27, 2024 07:46

ti-chi-bot bot added release-note Denotes a PR that will be considered when it comes time to generate release notes. and removed release-note-none Denotes a PR that doesn't merit a release note. labels May 27, 2024

hawkingrei requested review from Rustin170506, AilinKid and winoros May 27, 2024 08:20

statistics: print the process of init stats

9f591f5

Signed-off-by: Weizhen Wang <[email protected]>

hawkingrei force-pushed the print_log branch from 96b7c43 to 9f591f5 Compare May 28, 2024 01:29

AilinKid approved these changes May 28, 2024

View reviewed changes

ti-chi-bot bot added approved needs-1-more-lgtm Indicates a PR needs 1 more LGTM. labels May 28, 2024

hawkingrei requested a review from time-and-fate May 29, 2024 07:00

*

03b2aae

Signed-off-by: Weizhen Wang <[email protected]>

elsa0520 reviewed May 29, 2024

View reviewed changes

winoros approved these changes May 29, 2024

View reviewed changes

ti-chi-bot bot added lgtm and removed needs-1-more-lgtm Indicates a PR needs 1 more LGTM. labels May 29, 2024

ti-chi-bot bot added the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label May 29, 2024

fix linter

7d7125c

hawkingrei requested a review from elsa0520 May 30, 2024 02:34

elsa0520 approved these changes May 30, 2024

View reviewed changes

ti-chi-bot bot removed the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label May 30, 2024

ti-chi-bot bot merged commit 5e5326b into pingcap:master May 30, 2024
23 checks passed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

statistics: print the process of init stats #53560

statistics: print the process of init stats #53560

hawkingrei commented May 27, 2024 •

edited

Loading

codecov bot commented May 27, 2024 •

edited

Loading

hawkingrei commented May 27, 2024

hawkingrei commented May 27, 2024

hawkingrei commented May 28, 2024

AilinKid left a comment

AilinKid May 28, 2024 •

edited

Loading

hawkingrei May 28, 2024

hawkingrei May 28, 2024

hawkingrei commented May 28, 2024

elsa0520 May 29, 2024

hawkingrei May 29, 2024

ti-chi-bot bot commented May 29, 2024

hawkingrei commented May 29, 2024

hawkingrei commented May 30, 2024

elsa0520 left a comment

ti-chi-bot bot commented May 30, 2024

hawkingrei commented May 30, 2024

hawkingrei commented May 30, 2024

	statslogutil.StatsLogger().Info("complete to load the histogram")
	statslogutil.StatsLogger().Info("complete to load the lite histogram")

statistics: print the process of init stats #53560

statistics: print the process of init stats #53560

Conversation

hawkingrei commented May 27, 2024 • edited Loading

What problem does this PR solve?

What changed and how does it work?

Check List

Release note

codecov bot commented May 27, 2024 • edited Loading

Codecov Report

hawkingrei commented May 27, 2024

hawkingrei commented May 27, 2024

hawkingrei commented May 28, 2024

AilinKid left a comment

Choose a reason for hiding this comment

AilinKid May 28, 2024 • edited Loading

Choose a reason for hiding this comment

hawkingrei May 28, 2024

Choose a reason for hiding this comment

hawkingrei May 28, 2024

Choose a reason for hiding this comment

hawkingrei commented May 28, 2024

elsa0520 May 29, 2024

Choose a reason for hiding this comment

hawkingrei May 29, 2024

Choose a reason for hiding this comment

ti-chi-bot bot commented May 29, 2024

[LGTM Timeline notifier]

hawkingrei commented May 29, 2024

hawkingrei commented May 30, 2024

elsa0520 left a comment

Choose a reason for hiding this comment

ti-chi-bot bot commented May 30, 2024

hawkingrei commented May 30, 2024

hawkingrei commented May 30, 2024

hawkingrei commented May 27, 2024 •

edited

Loading

codecov bot commented May 27, 2024 •

edited

Loading

AilinKid May 28, 2024 •

edited

Loading