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.

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

misc: Add isBlockedTiming to PlanNodeStats #11361

Closed
wants to merge 1 commit into from

Conversation

yingsu00
Copy link
Collaborator

In previous commit #10923,
we added isBlockedTiming to OperatorStats. This commit adds it to
PlanNodeStats.

@facebook-github-bot facebook-github-bot added the CLA Signed This label is managed by the Facebook bot. Authors need to sign the CLA before a PR can be reviewed. label Oct 28, 2024
Copy link

netlify bot commented Oct 28, 2024

Deploy Preview for meta-velox canceled.

Name Link
🔨 Latest commit 58d3d32
🔍 Latest deploy log https://app.netlify.com/sites/meta-velox/deploys/674eb1919499050008ee5b71

@yingsu00 yingsu00 force-pushed the PlanNodeStats branch 2 times, most recently from 925f460 to 2b19e96 Compare November 6, 2024 03:02
@yingsu00 yingsu00 force-pushed the PlanNodeStats branch 4 times, most recently from dea9221 to 33b31ab Compare November 13, 2024 22:28
@yingsu00 yingsu00 marked this pull request as ready for review November 14, 2024 01:10
@yingsu00 yingsu00 requested review from xiaoxmeng and Yuhta November 14, 2024 01:10
@yingsu00 yingsu00 requested a review from rui-mo November 15, 2024 03:38
Copy link
Collaborator

@rui-mo rui-mo left a comment

Choose a reason for hiding this comment

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

Looks good to me. Just one question.

{" dataSourceLazyCpuNanos\\s+sum: .+, count: .+, min: .+, max: .+"},
{" dataSourceLazyInputBytes\\s+sum: .+, count: .+, min: .+, max: .+"},
{" dataSourceLazyWallNanos\\s+sum: .+, count: .+, min: .+, max: .+"},
{" distinctKey0\\s+sum: .+, count: 1, min: .+, max: .+"},
{" hashtable.capacity\\s+sum: 1252, count: 1, min: 1252, max: 1252"},
{" hashtable.numDistinct\\s+sum: 835, count: 1, min: 835, max: 835"},
{" hashtable.capacity\\s+sum: (?:1273|1252), count: 1, min: (?:1273|1252), max: (?:1273|1252)"},
Copy link
Collaborator

@rui-mo rui-mo Nov 15, 2024

Choose a reason for hiding this comment

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

Wondering why we need this change. Thanks.

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

Wondering why we need this change. Thanks.

This number depends on the number of unique values in the hash table. It changed to 1273 on MacOS but Linux environment was not affected. I can look deeper why it changed but didn't have enough time. If people think this is important I'll dig deeper

Copy link
Contributor

@xiaoxmeng xiaoxmeng left a comment

Choose a reason for hiding this comment

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

@yingsu00 LGTM. Thanks!

@xiaoxmeng xiaoxmeng added the ready-to-merge PR that have been reviewed and are ready for merging. PRs with this tag notify the Velox Meta oncall label Nov 18, 2024
@facebook-github-bot
Copy link
Contributor

@xiaoxmeng has imported this pull request. If you are a Meta employee, you can view this diff on Phabricator.

@facebook-github-bot
Copy link
Contributor

@xiaoxmeng has imported this pull request. If you are a Meta employee, you can view this diff on Phabricator.

@yingsu00 yingsu00 changed the title Add isBlockedTiming to PlanNodeStats misc: Add isBlockedTiming to PlanNodeStats Dec 3, 2024
In previous commit facebookincubator#10923,
we added isBlockedTiming to OperatorStats. This commit adds it to
PlanNodeStats.
@facebook-github-bot
Copy link
Contributor

@xiaoxmeng has imported this pull request. If you are a Meta employee, you can view this diff on Phabricator.

@facebook-github-bot
Copy link
Contributor

@xiaoxmeng merged this pull request in 2dae23f.

facebook-github-bot pushed a commit that referenced this pull request Dec 4, 2024
Summary:
Add detailed operator level statistics to the output.

Sample output:
```
============================================================================
[...]exec/benchmarks/ExchangeBenchmark.cpp     relative  time/iter   iters/s
============================================================================
exchangeFlat10k                                              4.11s   243.35m
exchangeFlat50                                               9.55s   104.76m
exchangeDeep10k                                             16.24s    61.57m
exchangeDeep50                                              21.31s    46.93m
exchangeStruct1K                                             2.70s   370.03m
localFlat10k                                                53.60s    18.66m
----------------------------------Flat10K----------------------------------
Wall Time (ms): 4.16s
PartitionOutput: Output: 6400064 rows (611.35MB, 1152 batches), Cpu time: 14.71s, Wall time: 23.37s, Blocked wall time: 0ns, Peak memory: 296.00MB, Memory allocations: 102400, Threads: 128, CPU breakdown: B/I/O/F (1.12ms/0ns/14.70s/1.04ms)
Exchange: Output: 6400000 rows (1.56GB, 141 batches), Cpu time: 1.72s, Wall time: 2.81s, Blocked wall time: 11.94s, Peak memory: 248.45MB, Memory allocations: 13796, Threads: 64, Splits: 256, CPU breakdown: B/I/O/F (37.27ms/4.47ms/1.64s/102.50us)
----------------------------------Flat50K----------------------------------
Wall Time (ms): 9.55s
PartitionOutput: Output: 6400064 rows (600.85MB, 1389 batches), Cpu time: 20.59s, Wall time: 28.00s, Blocked wall time: 15.26s, Peak memory: 267.19MB, Memory allocations: 93261, Threads: 128, CPU breakdown: B/I/O/F (47.17ms/0ns/20.45s/48.90ms)
Exchange: Output: 6400000 rows (1.56GB, 141 batches), Cpu time: 1.72s, Wall time: 2.81s, Blocked wall time: 11.94s, Peak memory: 248.45MB, Memory allocations: 13796, Threads: 64, Splits: 256, CPU breakdown: B/I/O/F (37.27ms/4.47ms/1.64s/102.50us)
----------------------------------Deep10K----------------------------------
Wall Time (ms): 16.23s
PartitionOutput: Output: 6400064 rows (2.98GB, 4600 batches), Cpu time: 47.96s, Wall time: 1m 34s, Blocked wall time: 7m 39s, Peak memory: 549.55MB, Memory allocations: 338361, Threads: 123, CPU breakdown: B/I/O/F (2.69ms/0ns/47.95s/1.92ms)
Exchange: Output: 6400000 rows (10.68GB, 720 batches), Cpu time: 11.38s, Wall time: 20.15s, Blocked wall time: 2m 27s, Peak memory: 299.32MB, Memory allocations: 27054, Threads: 59, Splits: 256, CPU breakdown: B/I/O/F (203.09ms/17.81ms/10.96s/3.69ms)
----------------------------------Deep50K----------------------------------
Wall Time (ms): 21.32s
PartitionOutput: Output: 6400064 rows (3.09GB, 5121 batches), Cpu time: 1m 1s, Wall time: 1m 30s, Blocked wall time: 10m 23s, Peak memory: 480.96MB, Memory allocations: 338279, Threads: 128, CPU breakdown: B/I/O/F (59.24ms/0ns/1m 0s/61.37ms)
Exchange: Output: 6400000 rows (9.96GB, 684 batches), Cpu time: 9.99s, Wall time: 15.91s, Blocked wall time: 3m 59s, Peak memory: 291.77MB, Memory allocations: 25606, Threads: 64, Splits: 256, CPU breakdown: B/I/O/F (240.90ms/14.48ms/9.49s/362.83us)
----------------------------------Struct1K---------------------------------
Wall Time (ms): 2.71s
PartitionOutput: Output: 6400064 rows (361.27MB, 1216 batches), Cpu time: 10.11s, Wall time: 14.42s, Blocked wall time: 0ns, Peak memory: 182.81MB, Memory allocations: 66624, Threads: 127, CPU breakdown: B/I/O/F (3.50ms/0ns/10.10s/3.72ms)
Exchange: Output: 6400000 rows (845.37MB, 86 batches), Cpu time: 1.96s, Wall time: 3.85s, Blocked wall time: 7.85s, Peak memory: 247.79MB, Memory allocations: 10584, Threads: 63, Splits: 256, CPU breakdown: B/I/O/F (13.44ms/3.58ms/1.93s/103.42us)
--------------------------------LocalFlat10K-------------------------------
Wall Time (ms):
 Total: 53.59s
 Max: 6483
 Median: 6347
 Min: 6906
LocalPartition: Output: 204802048 rows (27.16GB, 176128 batches), Cpu time: 2m 52s, Wall time: 28m 4s, Blocked wall time: 39m 0s, Peak memory: 11.23MB, Memory allocations: 163840, CPU breakdown: B/I/O/F (220.24ms/2m 49s/1.98s/15.06ms)
Producer Wait Time (ms)
 Total 21m 16s
 Max: sum:8016268000, count:1, min:8016268000, max:8016268000
 Median: sum:16968760000, count:16, min:613686000, max:2176757000
 Min: sum:7695600000, count:16, min:271392000, max:785580000
Consumer Wait Time (ms)
 Total 17m 44s
 Max: sum:23843660000, count:16, min:448579000, max:2245904000
 Median: sum:0, count:0, min:9223372036854775807, max:-9223372036854775808
 Min: sum:0, count:0, min:9223372036854775807, max:-9223372036854775808
```

This PR depends on #11361, which adds `isBlockedTime` to PlanNodeStats.

Pull Request resolved: #11543

Reviewed By: tanjialiang

Differential Revision: D66727100

Pulled By: xiaoxmeng

fbshipit-source-id: d1d488a93e80d01120bd755782da126aa31e1931
TongWei1105 pushed a commit to TongWei1105/velox that referenced this pull request Dec 21, 2024
Summary:
In previous commit facebookincubator#10923,
    we added isBlockedTiming to OperatorStats. This commit adds it to
    PlanNodeStats.

Pull Request resolved: facebookincubator#11361

Reviewed By: gggrace14

Differential Revision: D66692332

Pulled By: xiaoxmeng

fbshipit-source-id: b09ac85408f79c1f77b9685977f9dd696296f71a
athmaja-n pushed a commit to athmaja-n/velox that referenced this pull request Jan 10, 2025
Summary:
In previous commit facebookincubator#10923,
    we added isBlockedTiming to OperatorStats. This commit adds it to
    PlanNodeStats.

Pull Request resolved: facebookincubator#11361

Reviewed By: gggrace14

Differential Revision: D66692332

Pulled By: xiaoxmeng

fbshipit-source-id: b09ac85408f79c1f77b9685977f9dd696296f71a
athmaja-n pushed a commit to athmaja-n/velox that referenced this pull request Jan 10, 2025
Summary:
Add detailed operator level statistics to the output.

Sample output:
```
============================================================================
[...]exec/benchmarks/ExchangeBenchmark.cpp     relative  time/iter   iters/s
============================================================================
exchangeFlat10k                                              4.11s   243.35m
exchangeFlat50                                               9.55s   104.76m
exchangeDeep10k                                             16.24s    61.57m
exchangeDeep50                                              21.31s    46.93m
exchangeStruct1K                                             2.70s   370.03m
localFlat10k                                                53.60s    18.66m
----------------------------------Flat10K----------------------------------
Wall Time (ms): 4.16s
PartitionOutput: Output: 6400064 rows (611.35MB, 1152 batches), Cpu time: 14.71s, Wall time: 23.37s, Blocked wall time: 0ns, Peak memory: 296.00MB, Memory allocations: 102400, Threads: 128, CPU breakdown: B/I/O/F (1.12ms/0ns/14.70s/1.04ms)
Exchange: Output: 6400000 rows (1.56GB, 141 batches), Cpu time: 1.72s, Wall time: 2.81s, Blocked wall time: 11.94s, Peak memory: 248.45MB, Memory allocations: 13796, Threads: 64, Splits: 256, CPU breakdown: B/I/O/F (37.27ms/4.47ms/1.64s/102.50us)
----------------------------------Flat50K----------------------------------
Wall Time (ms): 9.55s
PartitionOutput: Output: 6400064 rows (600.85MB, 1389 batches), Cpu time: 20.59s, Wall time: 28.00s, Blocked wall time: 15.26s, Peak memory: 267.19MB, Memory allocations: 93261, Threads: 128, CPU breakdown: B/I/O/F (47.17ms/0ns/20.45s/48.90ms)
Exchange: Output: 6400000 rows (1.56GB, 141 batches), Cpu time: 1.72s, Wall time: 2.81s, Blocked wall time: 11.94s, Peak memory: 248.45MB, Memory allocations: 13796, Threads: 64, Splits: 256, CPU breakdown: B/I/O/F (37.27ms/4.47ms/1.64s/102.50us)
----------------------------------Deep10K----------------------------------
Wall Time (ms): 16.23s
PartitionOutput: Output: 6400064 rows (2.98GB, 4600 batches), Cpu time: 47.96s, Wall time: 1m 34s, Blocked wall time: 7m 39s, Peak memory: 549.55MB, Memory allocations: 338361, Threads: 123, CPU breakdown: B/I/O/F (2.69ms/0ns/47.95s/1.92ms)
Exchange: Output: 6400000 rows (10.68GB, 720 batches), Cpu time: 11.38s, Wall time: 20.15s, Blocked wall time: 2m 27s, Peak memory: 299.32MB, Memory allocations: 27054, Threads: 59, Splits: 256, CPU breakdown: B/I/O/F (203.09ms/17.81ms/10.96s/3.69ms)
----------------------------------Deep50K----------------------------------
Wall Time (ms): 21.32s
PartitionOutput: Output: 6400064 rows (3.09GB, 5121 batches), Cpu time: 1m 1s, Wall time: 1m 30s, Blocked wall time: 10m 23s, Peak memory: 480.96MB, Memory allocations: 338279, Threads: 128, CPU breakdown: B/I/O/F (59.24ms/0ns/1m 0s/61.37ms)
Exchange: Output: 6400000 rows (9.96GB, 684 batches), Cpu time: 9.99s, Wall time: 15.91s, Blocked wall time: 3m 59s, Peak memory: 291.77MB, Memory allocations: 25606, Threads: 64, Splits: 256, CPU breakdown: B/I/O/F (240.90ms/14.48ms/9.49s/362.83us)
----------------------------------Struct1K---------------------------------
Wall Time (ms): 2.71s
PartitionOutput: Output: 6400064 rows (361.27MB, 1216 batches), Cpu time: 10.11s, Wall time: 14.42s, Blocked wall time: 0ns, Peak memory: 182.81MB, Memory allocations: 66624, Threads: 127, CPU breakdown: B/I/O/F (3.50ms/0ns/10.10s/3.72ms)
Exchange: Output: 6400000 rows (845.37MB, 86 batches), Cpu time: 1.96s, Wall time: 3.85s, Blocked wall time: 7.85s, Peak memory: 247.79MB, Memory allocations: 10584, Threads: 63, Splits: 256, CPU breakdown: B/I/O/F (13.44ms/3.58ms/1.93s/103.42us)
--------------------------------LocalFlat10K-------------------------------
Wall Time (ms):
 Total: 53.59s
 Max: 6483
 Median: 6347
 Min: 6906
LocalPartition: Output: 204802048 rows (27.16GB, 176128 batches), Cpu time: 2m 52s, Wall time: 28m 4s, Blocked wall time: 39m 0s, Peak memory: 11.23MB, Memory allocations: 163840, CPU breakdown: B/I/O/F (220.24ms/2m 49s/1.98s/15.06ms)
Producer Wait Time (ms)
 Total 21m 16s
 Max: sum:8016268000, count:1, min:8016268000, max:8016268000
 Median: sum:16968760000, count:16, min:613686000, max:2176757000
 Min: sum:7695600000, count:16, min:271392000, max:785580000
Consumer Wait Time (ms)
 Total 17m 44s
 Max: sum:23843660000, count:16, min:448579000, max:2245904000
 Median: sum:0, count:0, min:9223372036854775807, max:-9223372036854775808
 Min: sum:0, count:0, min:9223372036854775807, max:-9223372036854775808
```

This PR depends on facebookincubator#11361, which adds `isBlockedTime` to PlanNodeStats.

Pull Request resolved: facebookincubator#11543

Reviewed By: tanjialiang

Differential Revision: D66727100

Pulled By: xiaoxmeng

fbshipit-source-id: d1d488a93e80d01120bd755782da126aa31e1931
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
CLA Signed This label is managed by the Facebook bot. Authors need to sign the CLA before a PR can be reviewed. Merged ready-to-merge PR that have been reviewed and are ready for merging. PRs with this tag notify the Velox Meta oncall
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants