perf(p2p): Delete expensive debug log already slated for deletion by ValarDragon · Pull Request #3412 · cometbft/cometbft

ValarDragon · 2024-07-03T17:15:11Z

Delete an expensive debug log that has already been slated for deletion. On the osmosis fork (with many other debug logs removed), this debug log ended up taking 1.5% of all CPU time when we had many large blocks. (All from outbound gossip curiously enough) This caused 12GB of total memory allocation over an hour in that benchmark (out of 180GB total. With other optimizations in PR's / merged since that benchmark, would have been 12GB / ~120GB total)

I am just making a PR to delete it, since it already had a code comment indicating we should delete it later. (Rather than waiting for #2989

Note that under normal benchmarks (e.g. the last one I did), this is fairly low impact. (68MB over an hour, out of 69 GB, so .1%)

PR checklist

Tests written/updated
Changelog entry added in .changelog (we use unclog to manage our changelog) - didn't add one, since its just deleting a debug log
Updated relevant documentation (docs/ or spec/) and code comments
Title follows the Conventional Commits spec

hvanz

👍

cason · 2024-07-04T07:48:09Z

How often this code is hit? Because in most-cases we assume that the channel is present in both sender or receivers.

ValarDragon · 2024-07-04T09:25:48Z

This is used in every single packet send! Would be great if we can avoid even needing this check in the future, this map access is actually still showing in CPU profiles after the debug log is removed, since there are so many packets.

cason · 2024-07-04T15:45:45Z

Actually, this code is only run if we don't return true, which means that the channel does not exist.

ValarDragon · 2024-07-04T17:23:01Z

Ah your right. Here is a profile where we are seeing it taking a large amount of total osmosis load:

This is the same profile where we saw gossipDataRoutine taking shockingly long amounts of time (and I suspected busy waiting) #3414 , maybe this helps us tell us the problem?

melekes

Thanks @ValarDragon ❤️

melekes · 2024-07-05T06:08:47Z

Actually, this code is only run if we don't return true, which means that the channel does not exist.

I don't understand it either. If all nodes have the same set of channels, then this debug line shouldn't ever be reached.

hvanz · 2024-07-05T08:47:40Z

I would also change channels []byte to channels map[byte]struct{} so we don't have to traverse the array every time we send.

cason · 2024-07-05T09:47:36Z

I would also change channels []byte to channels map[byte]struct{} so we don't have to traverse the array every time we send.

I am pretty sure that traversing a byte array is faster than using a map. Almost 100% sure. We could use the bytes package though.

melekes · 2024-07-08T08:52:03Z

I'm going to merge this, but we still need to understand where inefficiency is coming from #3412 (comment)

melekes · 2024-07-10T11:58:49Z

@mergify backport v1.x

mergify · 2024-07-10T11:59:05Z

backport v1.x

✅ Backports have been created

Details

#3488 perf(p2p): Delete expensive debug log already slated for deletion (backport #3412) has been created for branch v1.x

) Delete an expensive debug log that has already been slated for deletion. On the osmosis fork (with many other debug logs removed), this debug log ended up taking 1.5% of all CPU time when we had many large blocks. (All from outbound gossip curiously enough) This caused 12GB of total memory allocation over an hour in that benchmark (out of 180GB total. With other optimizations in PR's / merged since that benchmark, would have been 12GB / ~120GB total) I am just making a PR to delete it, since it already had a code comment indicating we should delete it later. (Rather than waiting for #2989 Note that under normal benchmarks (e.g. the last one I did), this is fairly low impact. (68MB over an hour, out of 69 GB, so .1%) --- #### PR checklist - [x] Tests written/updated - [ ] Changelog entry added in `.changelog` (we use [unclog](https://github.com/informalsystems/unclog) to manage our changelog) - didn't add one, since its just deleting a debug log - [x] Updated relevant documentation (`docs/` or `spec/`) and code comments - [x] Title follows the [Conventional Commits](https://www.conventionalcommits.org/en/v1.0.0/) spec (cherry picked from commit 1964898)

…ckport #3412) (#3488) Delete an expensive debug log that has already been slated for deletion. On the osmosis fork (with many other debug logs removed), this debug log ended up taking 1.5% of all CPU time when we had many large blocks. (All from outbound gossip curiously enough) This caused 12GB of total memory allocation over an hour in that benchmark (out of 180GB total. With other optimizations in PR's / merged since that benchmark, would have been 12GB / ~120GB total) I am just making a PR to delete it, since it already had a code comment indicating we should delete it later. (Rather than waiting for #2989 Note that under normal benchmarks (e.g. the last one I did), this is fairly low impact. (68MB over an hour, out of 69 GB, so .1%) --- #### PR checklist - [x] Tests written/updated - [ ] Changelog entry added in `.changelog` (we use [unclog](https://github.com/informalsystems/unclog) to manage our changelog) - didn't add one, since its just deleting a debug log - [x] Updated relevant documentation (`docs/` or `spec/`) and code comments - [x] Title follows the [Conventional Commits](https://www.conventionalcommits.org/en/v1.0.0/) spec <hr>This is an automatic backport of pull request #3412 done by [Mergify](https://mergify.com). Co-authored-by: Dev Ojha <ValarDragon@users.noreply.github.com> Co-authored-by: Anton Kaliaev <anton.kalyaev@gmail.com>

) Delete an expensive debug log that has already been slated for deletion. On the osmosis fork (with many other debug logs removed), this debug log ended up taking 1.5% of all CPU time when we had many large blocks. (All from outbound gossip curiously enough) This caused 12GB of total memory allocation over an hour in that benchmark (out of 180GB total. With other optimizations in PR's / merged since that benchmark, would have been 12GB / ~120GB total) I am just making a PR to delete it, since it already had a code comment indicating we should delete it later. (Rather than waiting for #2989 Note that under normal benchmarks (e.g. the last one I did), this is fairly low impact. (68MB over an hour, out of 69 GB, so .1%) --- #### PR checklist - [x] Tests written/updated - [ ] Changelog entry added in `.changelog` (we use [unclog](https://github.com/informalsystems/unclog) to manage our changelog) - didn't add one, since its just deleting a debug log - [x] Updated relevant documentation (`docs/` or `spec/`) and code comments - [x] Title follows the [Conventional Commits](https://www.conventionalcommits.org/en/v1.0.0/) spec

Delete expensive debug log

d7ced31

ValarDragon requested a review from a team as a code owner July 3, 2024 17:15

ValarDragon requested a review from a team July 3, 2024 17:15

ValarDragon added the backport-to-v0.38.x Tell Mergify to backport the PR to v0.38.x label Jul 3, 2024

hvanz approved these changes Jul 3, 2024

View reviewed changes

hvanz added the backport-to-v1.x label Jul 4, 2024

ValarDragon mentioned this pull request Jul 4, 2024

Prevent busy-waiting in consensus gossip routines, when Send fails #3414

Closed

2 tasks

melekes approved these changes Jul 5, 2024

View reviewed changes

melekes removed backport-to-v0.38.x Tell Mergify to backport the PR to v0.38.x backport-to-v1.x labels Jul 8, 2024

melekes added this pull request to the merge queue Jul 8, 2024

Merged via the queue into main with commit 1964898 Jul 8, 2024

melekes deleted the dev/delete_debug_log branch July 8, 2024 08:54

mergify bot mentioned this pull request Jul 10, 2024

perf(p2p): Delete expensive debug log already slated for deletion (backport #3412) #3488

Merged

4 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

perf(p2p): Delete expensive debug log already slated for deletion#3412

perf(p2p): Delete expensive debug log already slated for deletion#3412
melekes merged 1 commit intomainfrom
dev/delete_debug_log

ValarDragon commented Jul 3, 2024 •

edited

Loading

Uh oh!

hvanz left a comment

Uh oh!

cason commented Jul 4, 2024

Uh oh!

ValarDragon commented Jul 4, 2024 •

edited

Loading

Uh oh!

cason commented Jul 4, 2024

Uh oh!

ValarDragon commented Jul 4, 2024

Uh oh!

melekes left a comment

Uh oh!

melekes commented Jul 5, 2024

Uh oh!

hvanz commented Jul 5, 2024

Uh oh!

cason commented Jul 5, 2024

Uh oh!

melekes commented Jul 8, 2024

Uh oh!

melekes commented Jul 10, 2024

Uh oh!

mergify bot commented Jul 10, 2024 •

edited

Loading

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

Conversation

ValarDragon commented Jul 3, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

PR checklist

Uh oh!

hvanz left a comment

Choose a reason for hiding this comment

Uh oh!

cason commented Jul 4, 2024

Uh oh!

ValarDragon commented Jul 4, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

cason commented Jul 4, 2024

Uh oh!

ValarDragon commented Jul 4, 2024

Uh oh!

melekes left a comment

Choose a reason for hiding this comment

Uh oh!

melekes commented Jul 5, 2024

Uh oh!

hvanz commented Jul 5, 2024

Uh oh!

cason commented Jul 5, 2024

Uh oh!

melekes commented Jul 8, 2024

Uh oh!

melekes commented Jul 10, 2024

Uh oh!

mergify bot commented Jul 10, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

✅ Backports have been created

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

ValarDragon commented Jul 3, 2024 •

edited

Loading

ValarDragon commented Jul 4, 2024 •

edited

Loading

mergify bot commented Jul 10, 2024 •

edited

Loading