This repository has been archived by the owner on Nov 15, 2023. It is now read-only.
Speed up timestamp generation when logging #9933
Merged
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
koute
added
A0-please_review
koute
added
the
D3-trivial 🧸
gilescope
reviewed
Oct 5, 2021
koute
force-pushed
the
master_faster_timestamps
branch
from
772aac8
to
7938f4b
Compare
|
bot merge |
|
Trying merge. |
ghost
merged commit
ordian
added a commit
that referenced
this pull request
Oct 5, 2021
* master: (125 commits) Update multiple dependencies (#9936) Speed up timestamp generation when logging (#9933) First word should be Substrate not Polkadot (#9935) Improved file not found error message (#9931) don't read events in elections anymore. (#9898) Remove incorrect sanity check (#9924) Require crypto scheme for `insert-key` (#9909) chore: refresh of the substrate_builder image (#9808) Introduce block authorship soft deadline (#9663) Rework Transaction Priority calculation (#9834) Do not propagate host RUSTFLAGS when checking for WASM toolchain (#9926) Small quoting comment fix (#9927) add clippy to CI (#9694) Ensure BeforeBestBlockBy voting rule accounts for base (#9920) rm `.maintain` lock (#9919) Downstream `node-template` pull (#9915) Implement core::fmt::Debug for BoundedVec (#9914) Quickly skip invalid transactions during block authorship. (#9789) Add SS58 prefix for Automata (#9805) Clean up sc-peerset (#9806) ...
This pull request was closed.
Sign up for free
to subscribe to this conversation on GitHub.
Already have an account?
Sign in.
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
This PR speeds up how we generate timestamps when logging; instead of regenerating them from scratch all the time we now cache part of the timestamp in TLS.
Here's the performance of the original implementation as measured on my machine:
And here's the performance of the new one:
So the overhead was cut down to less than 10%.
Seems like this was pretty cheap in the first place; does this actually matter?
This will not help in normal cases where we're not logging much, but anytime someone turns on a spammy trace log (which does happen on our staking ops' nodes) the costs of logging starts to balloon. Yes, we shouldn't be logging this much. But if we do then it shouldn't bog down the CPU as much as it does.
Even though this might seem like it shouldn't make much difference the issue here is that at this scale we're experiencing a case of a death by a thousand cuts, where even though doing it only once is very cheap we're doing it so much that once you add everything together you end up in a situation where logging can take a whopping 30% of the total CPU time. This is one of the easier and most straightforward improvements we can make, which represented ~6.6% of the total CPU used in this particular profiling run, which now should be cut down to less than ~1%.