domain: do not start Auto Analyze Worker until statistics initialization is complete #52407

Rustin170506 · 2024-04-08T07:49:38Z

What problem does this PR solve?

Issue Number: close #52346

Problem Summary:

We shouldn't start the auto-analyze worker before we complete the stats initialization. Otherwise, we might have started the auto-analysis before the initialization of the stats was complete without force init turned on. This could waste a lot of resources.

What changed and how does it work?

Wait for the initialization to be finished.

It is important to wait for it in a separate goroutine to avoid blocking the entire bootstrap process.

Check List

Tests

Unit test
Integration test
Manual test (add detailed scripts or steps below)
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.

修复 TiDB 在统计信息初始化完成前就进行自动分析的问题
Fix TiDB auto-analysis before initialization of statistics is complete

…ion is complete

codecov · 2024-04-08T08:14:25Z

Codecov Report

Merging #52407 (1e6e004) into master (6a35d5e) will increase coverage by 2.2154%.
Report is 30 commits behind head on master.
The diff coverage is 100.0000%.

Additional details and impacted files

@@               Coverage Diff                @@
##             master     #52407        +/-   ##
================================================
+ Coverage   72.2252%   74.4406%   +2.2154%     
================================================
  Files          1467       1470         +3     
  Lines        426895     434988      +8093     
================================================
+ Hits         308326     323808     +15482     
+ Misses        99450      91208      -8242     
- Partials      19119      19972       +853

Flag	Coverage Δ
integration	`48.9542% <100.0000%> (?)`
unit	`71.0296% <100.0000%> (-0.0862%)`	⬇️

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

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

Rustin170506 · 2024-04-08T08:42:26Z

/retest

ti-chi-bot · 2024-04-08T09:36:05Z

[LGTM Timeline notifier]

Timeline:

2024-04-08 09:33:35.998802252 +0000 UTC m=+868477.526342797: ☑️ agreed by hawkingrei.
2024-04-08 09:36:04.297802136 +0000 UTC m=+868625.825342678: ☑️ agreed by AilinKid.

Rustin170506 · 2024-04-08T09:51:11Z

/hold

We need to test it.

ti-chi-bot · 2024-04-09T13:09:12Z

@hi-rustin: The following test failed, say /retest to rerun all failed tests or /retest-required to rerun all mandatory failed tests:

Test name	Commit	Details	Required	Rerun command
pull-br-integration-test	`ec53c20`	link	true	`/test pull-br-integration-test`

Full PR test history. Your PR dashboard.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository. I understand the commands that are listed here.

winoros · 2024-04-10T03:36:22Z

The http service seems to be alive after the auto analyze.
so the 10080 port is not alive until the init stats is finished after this pr.
it may be unexpected.

Rustin170506 · 2024-04-11T08:16:57Z

Tested locally:

Set force-init-stats = true and lite-init-stats = false
Restart the TiDB cluster
Check the metrics and logs:

oom_record  slowquery  tidb-2024-04-07T13-39-33.439.log  tidb-2024-04-08T15-27-51.423.log  tidb-2024-04-09T19-55-21.815.log  tidb.log
[root@tc-upstream-tidb-0 log]# tail -f tidb.log 
[2024/04/11 08:04:58.798 +00:00] [INFO] [notifier.go:140] ["new etcd watcher created to watch timer events"] [EtcdKey=/tidb/timer/cluster/1/notify/98a3ba0f-bb5d-4f55-a5be-791505a8c3ff] [watcherID=c5bd0b9c-8d8b-4839-aa36-4bd066342a5d]
[2024/04/11 08:04:58.805 +00:00] [INFO] [slots.go:205] ["initialize slot capacity"] [capacity=8]
[2024/04/11 08:04:58.807 +00:00] [INFO] [scheduler_manager.go:200] ["schedule task loop start"]
[2024/04/11 08:04:58.807 +00:00] [INFO] [scheduler_manager.go:453] ["collect loop start"]
[2024/04/11 08:04:58.807 +00:00] [INFO] [scheduler_manager.go:373] ["cleanup loop start"]
[2024/04/11 08:04:58.807 +00:00] [INFO] [scheduler_manager.go:312] ["subtask table gc loop start"]
[2024/04/11 08:04:59.761 +00:00] [INFO] [info.go:1142] [SetTiFlashGroupConfig]
[2024/04/11 08:05:38.442 +00:00] [INFO] [manager.go:364] ["get owner"] ["owner info"="[log-backup] /tidb/br-stream/owner ownerManager 066c65f2-761c-4510-b0d7-086e3122c686"] ["owner key"=/tidb/br-stream/owner/707b8ea796a75cfa] [ownerID=066c65f2-761c-4510-b0d7-086e3122c686] [op=none]
[2024/04/11 08:05:38.442 +00:00] [INFO] [manager.go:364] ["get owner"] ["owner info"="[bindinfo] /tidb/bindinfo/owner ownerManager 6e2ab1b1-fa73-44f0-be87-7b81673af539"] ["owner key"=/tidb/bindinfo/owner/707b8ea796a75d00] [ownerID=6e2ab1b1-fa73-44f0-be87-7b81673af539] [op=none]
[2024/04/11 08:05:38.442 +00:00] [INFO] [manager.go:364] ["get owner"] ["owner info"="[stats] /tidb/stats/owner ownerManager 6e2ab1b1-fa73-44f0-be87-7b81673af539"] ["owner key"=/tidb/stats/owner/707b8ea796a75d04] [ownerID=6e2ab1b1-fa73-44f0-be87-7b81673af539] [op=none]
[2024/04/11 08:05:45.763 +00:00] [INFO] [owner_daemon.go:56] ["daemon became owner"] [id=066c65f2-761c-4510-b0d7-086e3122c686] [daemon-id=LogBackup::Advancer]
[2024/04/11 08:05:45.763 +00:00] [INFO] [advancer.go:513] ["Subscription handler spawned."] [category="log backup subscription manager"]
[2024/04/11 08:09:03.593 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1074912712] [quota=1073741824]
[2024/04/11 08:09:12.135 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1073969624] [quota=1073741824]
[2024/04/11 08:09:20.231 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1078369784] [quota=1073741824]
[2024/04/11 08:09:28.320 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1076892782] [quota=1073741824]
[2024/04/11 08:09:36.664 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1080952141] [quota=1073741824]
[2024/04/11 08:09:44.982 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1077954586] [quota=1073741824]
[2024/04/11 08:09:51.298 +00:00] [INFO] [domain.go:2872] ["refreshServerIDTTL succeed"] [serverID=309] ["lease id"=707b8ea796a75cd8]
[2024/04/11 08:09:53.185 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1080002579] [quota=1073741824]
[2024/04/11 08:10:01.564 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1078624365] [quota=1073741824]
[2024/04/11 08:10:10.022 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1074501804] [quota=1073741824]
[2024/04/11 08:10:18.663 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1080887748] [quota=1073741824]
[2024/04/11 08:10:27.314 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1076839651] [quota=1073741824]
[2024/04/11 08:10:35.614 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1077619557] [quota=1073741824]
[2024/04/11 08:10:43.842 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1074967358] [quota=1073741824]
[2024/04/11 08:10:52.505 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1074530865] [quota=1073741824]

Wait for 22 minutes

[2024/04/11 08:26:33.615 +00:00] [INFO] [domain.go:2308] ["init stats info time"] [lite=false] ["take time"=21m35.819404493s]
[2024/04/11 08:26:33.616 +00:00] [INFO] [server.go:307] ["server is running MySQL protocol"] [addr=0.0.0.0:4000]
[2024/04/11 08:26:33.616 +00:00] [INFO] [server.go:321] ["server is running MySQL protocol"] [socket=/tmp/tidb-4000.sock]
[2024/04/11 08:26:37.171 +00:00] [INFO] [refresher.go:120] ["No table to analyze"] [category=stats]

Tested it with force-init-stats = false:

Set force-init-stats = false and lite-init-stats = false
Restart the tidb cluser
Check the metrics and logs:

[root@tc-upstream-tidb-0 log]# tail -f tidb.log
[2024/04/11 08:33:22.007 +00:00] [INFO] [scheduler_manager.go:200] ["schedule task loop start"]
[2024/04/11 08:33:22.007 +00:00] [INFO] [scheduler_manager.go:312] ["subtask table gc loop start"]
[2024/04/11 08:33:22.007 +00:00] [INFO] [scheduler_manager.go:453] ["collect loop start"]
[2024/04/11 08:33:22.007 +00:00] [INFO] [scheduler_manager.go:373] ["cleanup loop start"]
[2024/04/11 08:33:22.963 +00:00] [INFO] [info.go:1142] [SetTiFlashGroupConfig]
[2024/04/11 08:34:02.671 +00:00] [INFO] [manager.go:364] ["get owner"] ["owner info"="[stats] /tidb/stats/owner ownerManager 19fa2b0b-8e4d-4447-ab69-a945a8d0ef98"] ["owner key"=/tidb/stats/owner/707b8ea796a77636] [ownerID=19fa2b0b-8e4d-4447-ab69-a945a8d0ef98] [op=none]
[2024/04/11 08:34:02.671 +00:00] [INFO] [manager.go:364] ["get owner"] ["owner info"="[bindinfo] /tidb/bindinfo/owner ownerManager 19fa2b0b-8e4d-4447-ab69-a945a8d0ef98"] ["owner key"=/tidb/bindinfo/owner/707b8ea796a77632] [ownerID=19fa2b0b-8e4d-4447-ab69-a945a8d0ef98] [op=none]
[2024/04/11 08:34:02.671 +00:00] [INFO] [manager.go:364] ["get owner"] ["owner info"="[log-backup] /tidb/br-stream/owner ownerManager e0eca9eb-0f9b-4dd1-894b-0c3d14e3d4a8"] ["owner key"=/tidb/br-stream/owner/707b8ea796a7762b] [ownerID=e0eca9eb-0f9b-4dd1-894b-0c3d14e3d4a8] [op=none]
[2024/04/11 08:34:08.965 +00:00] [INFO] [owner_daemon.go:56] ["daemon became owner"] [id=e0eca9eb-0f9b-4dd1-894b-0c3d14e3d4a8] [daemon-id=LogBackup::Advancer]
[2024/04/11 08:34:08.965 +00:00] [INFO] [advancer.go:513] ["Subscription handler spawned."] [category="log backup subscription manager"]
[2024/04/11 08:37:29.697 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1074512950] [quota=1073741824]
[2024/04/11 08:37:38.264 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1079708086] [quota=1073741824]
[2024/04/11 08:37:46.315 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1080630638] [quota=1073741824]
[2024/04/11 08:37:54.538 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1078068323] [quota=1073741824]
[2024/04/11 08:38:02.926 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1080752507] [quota=1073741824]
[2024/04/11 08:38:11.194 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1080203871] [quota=1073741824]
[2024/04/11 08:38:13.975 +00:00] [INFO] [domain.go:2872] ["refreshServerIDTTL succeed"] [serverID=1093] ["lease id"=707b8ea796a77600]
[2024/04/11 08:38:19.682 +00:00] [INFO] [sort_spill.go:59] ["memory exceeds quota, spill to disk now."] [consumed=1079000055] [quota=1073741824]

Wait for 22 mintus:

[2024/04/11 08:55:10.704 +00:00] [WARN] [pd.go:168] ["get timestamp too slow"] ["cost time"=6.446772747s]
[2024/04/11 08:55:10.706 +00:00] [INFO] [manager.go:364] ["get owner"] ["owner info"="[autoid] tidb/autoid/leader ownerManager tc-upstream-tidb-0.tc-upstream-tidb-peer.stats-test-tps-7502283-1-960.svc:10080"] ["owner key"=tidb/autoid/leader/707b8ea796a7897b] [ownerID=tc-upstream-tidb-0.tc-upstream-tidb-peer.stats-test-tps-7502283-1-960.svc:10080] [op=none]
[2024/04/11 08:55:10.706 +00:00] [INFO] [autoid.go:305] ["leader change of autoid service, this node become owner"] [addr=tc-upstream-tidb-0.tc-upstream-tidb-peer.stats-test-tps-7502283-1-960.svc:10080] [category="autoid service"]
[2024/04/11 08:55:16.541 +00:00] [INFO] [domain.go:2308] ["init stats info time"] [lite=false] ["take time"=21m55.54527945s]
[2024/04/11 08:55:20.084 +00:00] [INFO] [refresher.go:120] ["No table to analyze"] [category=stats]

Rustin170506 · 2024-04-11T09:03:13Z

/unhold

ti-chi-bot · 2024-04-11T09:26:42Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: AilinKid, hawkingrei, zimulala

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/domain/OWNERS~~ [zimulala]

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

hawkingrei · 2024-04-11T10:59:08Z

/cherrypick release-8.1
/cherrypick release-7.5

Signed-off-by: ti-chi-bot <[email protected]>

ti-chi-bot · 2024-04-11T10:59:50Z

@hawkingrei: new pull request created to branch release-7.5: #52512.

In response to this:

/cherrypick release-8.1
/cherrypick release-7.5

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the ti-community-infra/tichi repository.

ti-chi-bot · 2024-04-11T11:00:30Z

@hawkingrei: new pull request created to branch release-8.1: #52513.

In response to this:

/cherrypick release-8.1
/cherrypick release-7.5

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the ti-community-infra/tichi repository.

…ion is complete (#52407) (#52512) close #52346

…ion is complete (#52407) (#52513) close #52346

…ion is complete (pingcap#52407) close pingcap#52346

domain: do not start Auto Analyze Worker until statistics initialisat…

986cfec

…ion is complete

ti-chi-bot bot added release-note Denotes a PR that will be considered when it comes time to generate release notes. size/XS Denotes a PR that changes 0-9 lines, ignoring generated files. labels Apr 8, 2024

hawkingrei approved these changes Apr 8, 2024

View reviewed changes

ti-chi-bot bot added the needs-1-more-lgtm Indicates a PR needs 1 more LGTM. label Apr 8, 2024

AilinKid approved these changes Apr 8, 2024

View reviewed changes

ti-chi-bot bot added lgtm and removed needs-1-more-lgtm Indicates a PR needs 1 more LGTM. labels Apr 8, 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 Apr 8, 2024

Merge branch 'master' into rustin-patch-auto-analyze-worker

1d7e1e8

winoros force-pushed the rustin-patch-auto-analyze-worker branch from 0367070 to 1d7e1e8 Compare April 8, 2024 17:26

docs: more comments

ec53c20

fix: do not block the bootstrap

1e6e004

ti-chi-bot bot added size/S Denotes a PR that changes 10-29 lines, ignoring generated files. and removed size/XS Denotes a PR that changes 0-9 lines, ignoring generated files. labels Apr 11, 2024

hawkingrei approved these changes Apr 11, 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 Apr 11, 2024

zimulala approved these changes Apr 11, 2024

View reviewed changes

ti-chi-bot bot added the approved label Apr 11, 2024

ti-chi-bot bot merged commit 0f23d83 into pingcap:master Apr 11, 2024
23 checks passed

ti-chi-bot pushed a commit to ti-chi-bot/tidb that referenced this pull request Apr 11, 2024

This is an automated cherry-pick of pingcap#52407

3b9a78b

Signed-off-by: ti-chi-bot <[email protected]>

ti-chi-bot mentioned this pull request Apr 11, 2024

domain: do not start Auto Analyze Worker until statistics initialization is complete (#52407) #52512

Merged

13 tasks

ti-chi-bot mentioned this pull request Apr 11, 2024

domain: do not start Auto Analyze Worker until statistics initialization is complete (#52407) #52513

Merged

13 tasks

ti-chi-bot bot pushed a commit that referenced this pull request Apr 15, 2024

domain: do not start Auto Analyze Worker until statistics initializat…

0f584f0

…ion is complete (#52407) (#52512) close #52346

ti-chi-bot bot pushed a commit that referenced this pull request Apr 15, 2024

domain: do not start Auto Analyze Worker until statistics initializat…

9080b6a

…ion is complete (#52407) (#52513) close #52346

3AceShowHand pushed a commit to 3AceShowHand/tidb that referenced this pull request Apr 16, 2024

domain: do not start Auto Analyze Worker until statistics initializat…

81c1b3d

…ion is complete (pingcap#52407) close pingcap#52346

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

domain: do not start Auto Analyze Worker until statistics initialization is complete #52407

domain: do not start Auto Analyze Worker until statistics initialization is complete #52407

Rustin170506 commented Apr 8, 2024 •

edited

Loading

codecov bot commented Apr 8, 2024 •

edited

Loading

Rustin170506 commented Apr 8, 2024

ti-chi-bot bot commented Apr 8, 2024

Rustin170506 commented Apr 8, 2024

ti-chi-bot bot commented Apr 9, 2024

winoros commented Apr 10, 2024

Rustin170506 commented Apr 11, 2024 •

edited

Loading

Rustin170506 commented Apr 11, 2024

ti-chi-bot bot commented Apr 11, 2024

hawkingrei commented Apr 11, 2024

ti-chi-bot commented Apr 11, 2024

ti-chi-bot commented Apr 11, 2024

domain: do not start Auto Analyze Worker until statistics initialization is complete #52407

domain: do not start Auto Analyze Worker until statistics initialization is complete #52407

Conversation

Rustin170506 commented Apr 8, 2024 • edited Loading

What problem does this PR solve?

What changed and how does it work?

Check List

Release note

codecov bot commented Apr 8, 2024 • edited Loading

Codecov Report

Rustin170506 commented Apr 8, 2024

ti-chi-bot bot commented Apr 8, 2024

[LGTM Timeline notifier]

Rustin170506 commented Apr 8, 2024

ti-chi-bot bot commented Apr 9, 2024

winoros commented Apr 10, 2024

Rustin170506 commented Apr 11, 2024 • edited Loading

Rustin170506 commented Apr 11, 2024

ti-chi-bot bot commented Apr 11, 2024

hawkingrei commented Apr 11, 2024

ti-chi-bot commented Apr 11, 2024

ti-chi-bot commented Apr 11, 2024

Rustin170506 commented Apr 8, 2024 •

edited

Loading

codecov bot commented Apr 8, 2024 •

edited

Loading

Rustin170506 commented Apr 11, 2024 •

edited

Loading