Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Storages: Add statistical data of TableScanning in ScanContext #8842

Merged
merged 5 commits into from
Mar 18, 2024
Merged

Storages: Add statistical data of TableScanning in ScanContext #8842

merged 5 commits into from
Mar 18, 2024

Conversation

JinheLin
Copy link
Contributor

@JinheLin JinheLin commented Mar 13, 2024 •
edited by JaySon-Huang
Loading

What problem does this PR solve?

Issue Number: ref #8675, close #8895

What is changed and how it works?

  • Add more statistical data of TableScanning in ScanContext.
  • To distinguish between different stages of scanning files, set a ReadTag when creating DMFileReader.
  • An example:
mysql> explain analyze select max(ol_o_id) from order_line where ol_dist_info < '0Fvf5TLWcqdvYC2IeTcQjgMs';
+--------------------------------+------------+---------+--------------+------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------------------------------------------------------------------------+-----------+------+
| id                             | estRows    | actRows | task         | access object    | execution info                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      | operator info                                                                                     | memory    | disk |
+--------------------------------+------------+---------+--------------+------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------------------------------------------------------------------------+-----------+------+
| StreamAgg_10                   | 1.00       | 1       | root         |                  | time:772.7ms, loops:2, RU:455322.194336                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                             | funcs:max(tpcc.order_line.ol_o_id)->Column#12                                                     | 1.02 KB   | N/A  |
| └─TopN_13                      | 1.00       | 1       | root         |                  | time:772.7ms, loops:2                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               | tpcc.order_line.ol_o_id:desc, offset:0, count:1                                                   | 304 Bytes | N/A  |
|   └─TableReader_25             | 1.00       | 144     | root         |                  | time:772.7ms, loops:3, cop_task: {num: 146, max: 0s, min: 0s, avg: 0s, p95: 0s, copr_cache_hit_ratio: 0.00}                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         | MppVersion: 2, data:ExchangeSender_24                                                             | 571 Bytes | N/A  |
|     └─ExchangeSender_24        | 1.00       | 144     | mpp[tiflash] |                  | tiflash_task:{proc max:770.1ms, min:703.5ms, avg: 736.8ms, p80:770.1ms, p95:770.1ms, iters:144, tasks:2, threads:144}                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               | ExchangeType: PassThrough                                                                         | N/A       | N/A  |
|       └─TopN_23                | 1.00       | 144     | mpp[tiflash] |                  | tiflash_task:{proc max:769.1ms, min:702.5ms, avg: 735.8ms, p80:769.1ms, p95:769.1ms, iters:144, tasks:2, threads:144}                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               | tpcc.order_line.ol_o_id:desc, offset:0, count:1                                                   | N/A       | N/A  |
|         └─TableFullScan_21     | 5259869.34 | 2488186 | mpp[tiflash] | table:order_line | tiflash_task:{proc max:769.1ms, min:702.5ms, avg: 735.8ms, p80:769.1ms, p95:769.1ms, iters:9075, tasks:2, threads:144}, tiflash_scan:{dtfile:{data_scanned_rows:600039322, data_skipped_rows:1355266, mvcc_scanned_rows:551821000, mvcc_skipped_rows:1015522, lm_filter_scanned_rows:601394701, lm_filter_skipped_rows:0, rs_index_check_time: 21ms, read_time: 43143ms, disagg_cache_hit_size: 0, disagg_cache_miss_size: 0}, delta_rows: 259517, delta_bytes: 24654115, mvcc_input_rows: 539026105, mvcc_input_bytes: 9163443785, mvcc_output_rows: 539026105, lm_skip_rows: 1355379, segment_num: 775, create_snapshot_time: 2ms, build_bitmap_time: 44912ms, build_inputstream_time: 54915ms, local_min_stream_cost: 686ms, local_max_stream_cost: 760ms, remote_min_stream_cost: 0ms, remote_max_stream_cost: 0ms, local_region_num: 776, remote_region_num: 0, stale_read_num: 0, learner_read_time: 10ms, region_balance_info: {instance_num: 2, max/min: 396/380=1.042105}} | pushed down filter:lt(tpcc.order_line.ol_dist_info, "0Fvf5TLWcqdvYC2IeTcQjgMs"), keep order:false | N/A       | N/A  |
+--------------------------------+------------+---------+--------------+------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------------------------------------------------------------------------+-----------+------+
6 rows in set (0.78 sec)

tiflash_scan:{
	dtfile:{
		data_scanned_rows:600039322, 
		data_skipped_rows:1355266, 
		mvcc_scanned_rows:551821000, 
		mvcc_skipped_rows:1015522, 
		lm_filter_scanned_rows:601394701, 
		lm_filter_skipped_rows:0, 
		rs_index_check_time: 21ms, 
		read_time: 43143ms, 
		disagg_cache_hit_size: 0, 
		disagg_cache_miss_size: 0
	}, 
	delta_rows: 259517, 
	delta_bytes: 24654115, 
	mvcc_input_rows: 539026105, 
	mvcc_input_bytes: 9163443785, 
	mvcc_output_rows: 539026105, 
	lm_skip_rows: 1355379, 
	segment_num: 775, 
	create_snapshot_time: 2ms, 
	build_bitmap_time: 44912ms, 
	build_inputstream_time: 54915ms, 
	local_min_stream_cost: 686ms, 
	local_max_stream_cost: 760ms, 
	remote_min_stream_cost: 0ms, 
	remote_max_stream_cost: 0ms, 
	local_region_num: 776, 
	remote_region_num: 0, 
	stale_read_num: 0, 
	learner_read_time: 10ms, 
	region_balance_info: {instance_num: 2, max/min: 396/380=1.042105}
}

Check List

Tests

  • Unit test
  • Integration test
  • Manual test (add detailed scripts or steps below)
    • Use explain analyze to check the details of TableScanning.
  • No code

Side effects

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

Documentation

  • Affects user behaviors
  • Contains syntax changes
  • Contains variable changes
  • Contains experimental features
  • Changes MySQL compatibility

Release note

None

@ti-chi-bot ti-chi-bot bot added release-note-none Denotes a PR that doesn't merit a release note. size/XXL Denotes a PR that changes 1000+ lines, ignoring generated files. labels Mar 13, 2024
@JinheLin
Copy link
Contributor Author

/hold

Don't merge this PR until pingcap/tipb#326 merged.

@ti-chi-bot 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 Mar 13, 2024
@JinheLin
Copy link
Contributor Author

/run-all-tests

@JinheLin
Copy link
Contributor Author

/run-unit-test

@JinheLin
Copy link
Contributor Author 

[2024-03-13T05:52:19.273Z] INTERRUPTED TESTS (1/2478):
[2024-03-13T05:52:19.273Z] Interrupted: /tiflash/gtests_dbms AsyncTasksTest.AsyncTasksNormal
script returned exit code 254

@JinheLin
Copy link
Contributor Author

/run-all-tests

@JinheLin JinheLin requested review from JaySon-Huang, Lloyd-Pottiger and CalvinNeo and removed request for JaySon-Huang March 13, 2024 07:32
@Lloyd-Pottiger
Copy link
Contributor

lm_filter_scanned_rows is always equal to mvcc_scanned_rows and lm_filter_skipped_rows is always equal to mvcc_skipped_rows.

@Lloyd-Pottiger
Copy link
Contributor 

build_bitmap_time: 44690ms, 
build_inputstream_time: 48023ms, 
local_min_stream_cost: 1716ms, 
local_max_stream_cost: 1955ms, 
remote_min_stream_cost: 0ms, 
remote_max_stream_cost: 0ms,

build_inputstream_time seems not set, and it is not used. Why local_max_stream_cost is less than build_bitmap_time?

@JinheLin
Copy link
Contributor Author

lm_filter_scanned_rows is always equal to mvcc_scanned_rows and lm_filter_skipped_rows is always equal to mvcc_skipped_rows.

Not always.

mvcc_scanned_rows is the sum of buildBitmap and ensurePlace. scanned_rows of buildBitmap equals to lm_filter_scanned_rows.

skipped_rows is similar.

@JinheLin
Copy link
Contributor Author 

build_bitmap_time: 44690ms, 
build_inputstream_time: 48023ms, 
local_min_stream_cost: 1716ms, 
local_max_stream_cost: 1955ms, 
remote_min_stream_cost: 0ms, 
remote_max_stream_cost: 0ms,

build_inputstream_time seems not set, and it is not used. Why local_max_stream_cost is less than build_bitmap_time?

build_inputstream_time is set in Segment::getInputStream, and it is slightly greater than build_bitmap_time.

build_bitmap_time is the sum of buildBitmap of all segments of a table scanning request. *_stream_cost is the max/min cost of one stream in the perspective of computing-threads. Strictly speaking, these two are not comparable

@Lloyd-Pottiger
Copy link
Contributor 

build_bitmap_time: 44690ms, 
build_inputstream_time: 48023ms, 
local_min_stream_cost: 1716ms, 
local_max_stream_cost: 1955ms, 
remote_min_stream_cost: 0ms, 
remote_max_stream_cost: 0ms,

build_inputstream_time seems not set, and it is not used. Why local_max_stream_cost is less than build_bitmap_time?

build_inputstream_time is set in Segment::getInputStream, and it is slightly greater than build_bitmap_time.

build_bitmap_time is the sum of buildBitmap of all segments of a table scanning request. *_stream_cost is the max/min cost of one stream in the perspective of computing-threads. Strictly speaking, these two are not comparable

IMHO, we do not need build_inputstream_time, and separate build_bitmap_time into min_build_bitmap_time and max_ build_bitmap_time.

@JinheLin
Copy link
Contributor Author 

build_bitmap_time: 44690ms, 
build_inputstream_time: 48023ms, 
local_min_stream_cost: 1716ms, 
local_max_stream_cost: 1955ms, 
remote_min_stream_cost: 0ms, 
remote_max_stream_cost: 0ms,

build_inputstream_time seems not set, and it is not used. Why local_max_stream_cost is less than build_bitmap_time?

build_inputstream_time is set in Segment::getInputStream, and it is slightly greater than build_bitmap_time.
build_bitmap_time is the sum of buildBitmap of all segments of a table scanning request. *_stream_cost is the max/min cost of one stream in the perspective of computing-threads. Strictly speaking, these two are not comparable

IMHO, we do not need build_inputstream_time, and separate build_bitmap_time into min_build_bitmap_time and max_ build_bitmap_time.

build_inputstream_time includes ensurePlace, buildBitmap and some other initialization times, such as initialzation of DMFileReader. ensurePlace may take some time if write workload is heavy. Initialization of DMFileReader may take some time if DMFile is stored in remote storage.

Use build_bitmap_time / segment_num, we can take a average of building bitmap for a segment, so I think min/max of building bitmap is not very neccessary.

@ti-chi-bot ti-chi-bot bot added needs-1-more-lgtm Indicates a PR needs 1 more LGTM. approved labels Mar 14, 2024
breezewish
breezewish reviewed Mar 15, 2024
View reviewed changes
dbms/src/Storages/DeltaMerge/ScanContext.h Outdated
Comment on lines 109 to 110
disagg_read_cache_hit_size = tiflash_scan_context_pb.disagg_read_cache_hit_size();
disagg_read_cache_miss_size = tiflash_scan_context_pb.disagg_read_cache_miss_size();
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

disagg_read_cache_hit_size and disagg_read_cache_miss_size not set?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In RNLocalPageCache.cpp and S3RandomAccessFile.cpp.

@JinheLin
Copy link
Contributor Author

/run-all-tests

@JinheLin JinheLin requested a review from breezewish March 16, 2024 12:23
@ti-chi-bot ti-chi-bot bot added the lgtm label Mar 18, 2024
@ti-chi-bot ti-chi-bot
Copy link
Contributor

ti-chi-bot bot commented Mar 18, 2024

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: JaySon-Huang, Lloyd-Pottiger

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:
  • OWNERS [JaySon-Huang,Lloyd-Pottiger]

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

@ti-chi-bot ti-chi-bot bot removed the needs-1-more-lgtm Indicates a PR needs 1 more LGTM. label Mar 18, 2024
@ti-chi-bot ti-chi-bot
Copy link
Contributor

ti-chi-bot bot commented Mar 18, 2024

[LGTM Timeline notifier]

Timeline:

  • 2024-03-14 06:30:59.069295263 +0000 UTC m=+926286.091541695: ☑️ agreed by Lloyd-Pottiger.
  • 2024-03-18 02:35:50.294152577 +0000 UTC m=+1257777.316398965: ☑️ agreed by JaySon-Huang.

@JinheLin
Copy link
Contributor Author

/unhold

@ti-chi-bot 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 Mar 18, 2024
@JinheLin
Copy link
Contributor Author

/run-all-tests

@ti-chi-bot ti-chi-bot
Copy link
Contributor

ti-chi-bot bot commented Mar 18, 2024

@JinheLin: Your PR was out of date, I have automatically updated it for you.

At the same time I will also trigger all tests for you:

/run-all-tests

trigger some heavy tests which will not run always when PR updated.

If the CI test fails, you just re-trigger the test that failed and the bot will merge the PR for you after the CI passes.

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 ti-chi-bot bot merged commit 596a222 into pingcap:master Mar 18, 2024
6 checks passed
JaySon-Huang pushed a commit to JaySon-Huang/tiflash that referenced this pull request Apr 3, 2024
@JinheLin @JaySon-Huang
Storages: Add statistical data of TableScanning in ScanContext (pingc…
9f496d3 
…ap#8842)

ref pingcap#8675
JaySon-Huang pushed a commit to JaySon-Huang/tiflash that referenced this pull request Apr 3, 2024
@JinheLin @JaySon-Huang
Storages: Add statistical data of TableScanning in ScanContext (pingc…
b4b934c 
…ap#8842)

ref pingcap#8675
@JaySon-Huang JaySon-Huang mentioned this pull request Apr 3, 2024
Merged
12 tasks
@ti-chi-bot ti-chi-bot added needs-cherry-pick-release-7.5 Should cherry pick this PR to release-7.5 branch. needs-cherry-pick-release-7.1 Should cherry pick this PR to release-7.1 branch. labels Apr 3, 2024
@ti-chi-bot
Copy link
Member

In response to a cherrypick label: failed to apply #8842 on top of branch "release-7.5":

[failed to git add conflicting files: exit status 128, failed to git commit: exit status 128]

@ti-chi-bot
Copy link
Member

In response to a cherrypick label: failed to apply #8842 on top of branch "release-7.1":

[failed to git add conflicting files: exit status 128, failed to git commit: exit status 128]

This was referenced Apr 28, 2024
Closed
Closed
@JinheLin JinheLin deleted the scan_ctx2 branch April 28, 2024 07:32
JaySon-Huang pushed a commit to JaySon-Huang/tiflash that referenced this pull request May 7, 2024
@JinheLin @JaySon-Huang
Storages: Add statistical data of TableScanning in ScanContext (pingc…
06fef86 
…ap#8842)

ref pingcap#8675
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@Lloyd-Pottiger Lloyd-Pottiger Lloyd-Pottiger approved these changes

@JaySon-Huang JaySon-Huang JaySon-Huang approved these changes

@CalvinNeo CalvinNeo Awaiting requested review from CalvinNeo

@breezewish breezewish Awaiting requested review from breezewish

Assignees
No one assigned
Labels
approved lgtm needs-cherry-pick-release-7.1 Should cherry pick this PR to release-7.1 branch. needs-cherry-pick-release-7.5 Should cherry pick this PR to release-7.5 branch. release-note-none Denotes a PR that doesn't merit a release note. size/XXL Denotes a PR that changes 1000+ lines, ignoring generated files.
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.

The local_region_num in MPPTaskStatistics logging is wrong
5 participants
@JinheLin @Lloyd-Pottiger @ti-chi-bot @breezewish @JaySon-Huang