raftstore: Add slow log for peer and store msg #16605

Connor1996 · 2024-03-05T12:51:04Z

What is changed and how it works?

Issue Number: Ref #16600

What's Changed:

Add slow log for peer and store msg

Related changes

PR to update pingcap/docs/pingcap/docs-cn:
Need to cherry-pick to the release branch

Check List

Tests

Unit test
Integration test
Manual test (add detailed scripts or steps below)
No code

Side effects

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

Release note

Add slow log for peer and store msg

Signed-off-by: Connor1996 <zbk602423539@gmail.com>

ti-chi-bot · 2024-03-05T12:51:07Z

[REVIEW NOTIFICATION]

This pull request has been approved by:

SpadeA-Tang
overvenus

To complete the pull request process, please ask the reviewers in the list to review by filling /cc @reviewer in the comment.
After your PR has acquired the required number of LGTMs, you can assign this pull request to the committer in the list by filling /assign @committer in the comment to help you merge this pull request.

The full list of commands accepted by this bot can be found here.

Reviewer can indicate their review by submitting an approval review.
Reviewer can cancel approval by submitting a request changes review.

LykxSassinator · 2024-03-06T03:18:13Z

components/raftstore/src/store/fsm/peer.rs

@@ -710,12 +716,20 @@ where
            }
        }
        self.on_loop_finished();
+        let elapsed = timer.saturating_elapsed();
+        slow_log!(


Using slow_log is a better choice ? Why not use metrics ?

The default threshold for slow logging is 1s, which is too long to output slow PeerMsg.

We have to get the duration for each message if using metrics, which may have some overhead in the hot path.

Let me change the slow threshold for this

The output of distribution ought to be something like this [x, y, z, ...,], maybe we can wrap it and implements a fmt to make it read friendly?

How about adding to metrics if an event exceeds 100ms?

It already has been observed in the below metric

overvenus · 2024-03-06T05:28:42Z

components/raftstore/src/store/fsm/peer.rs

@@ -619,7 +620,12 @@ where
    pub fn handle_msgs(&mut self, msgs: &mut Vec<PeerMsg<EK>>) {
        let timer = TiInstant::now_coarse();
        let count = msgs.len();
+        let mut distribution = hash_map_with_capacity(std::mem::variant_count::<PeerMsg<EK>>());


How about putting it to PollContext? So that we can save frequent hashmap creation.
Also it could be an fixed size array as variant_count::<PeerMsg> is a constant number.

Using a fixed size array instead, as it's should be allocated on stack, I don't put it in PollContext

overvenus · 2024-03-06T05:37:07Z

components/raftstore/src/store/msg.rs

+    pub fn discriminant(&self) -> u8 {
+        unsafe { *(self as *const Self as *const u8) }
+    }


Could you add some comments about how it works?

Signed-off-by: Connor1996 <zbk602423539@gmail.com>

components/raftstore/src/store/msg.rs

overvenus · 2024-03-08T09:34:57Z

components/raftstore/src/store/fsm/peer.rs

@@ -710,12 +716,20 @@ where
            }
        }
        self.on_loop_finished();
+        let elapsed = timer.saturating_elapsed();
+        slow_log!(


How about adding to metrics if an event exceeds 100ms?

Signed-off-by: Connor1996 <zbk602423539@gmail.com>

overvenus

Rest LGTM

components/raftstore/src/store/msg.rs

Connor1996 · 2024-03-12T07:08:34Z

/merge

ti-chi-bot · 2024-03-12T07:08:37Z

@Connor1996: It seems you want to merge this PR, I will help you trigger all the tests:

/run-all-tests

You only need to trigger /merge once, and 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.

If you have any questions about the PR merge process, please refer to pr process.

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-03-12T07:08:38Z

This pull request has been accepted and is ready to merge.

Commit hash: aaba689

Signed-off-by: Connor1996 <zbk602423539@gmail.com>

Connor1996 · 2024-03-12T07:48:59Z

/merge

ti-chi-bot · 2024-03-12T07:49:01Z

@Connor1996: It seems you want to merge this PR, I will help you trigger all the tests:

/run-all-tests

You only need to trigger /merge once, and 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.

If you have any questions about the PR merge process, please refer to pr process.

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-03-12T07:49:03Z

This pull request has been accepted and is ready to merge.

Commit hash: 2398fee

ref tikv#16600 Add slow log for peer and store msg Signed-off-by: Connor1996 <zbk602423539@gmail.com> Co-authored-by: ti-chi-bot[bot] <108142056+ti-chi-bot[bot]@users.noreply.github.com> Signed-off-by: dbsid <chenhuansheng@pingcap.com>

ref tikv#16600 Signed-off-by: ti-chi-bot <ti-community-prow-bot@tidb.io>

ti-chi-bot · 2024-03-25T05:35:42Z

In response to a cherrypick label: new pull request created to branch release-6.5: #16692.

ref #16600 Add slow log for peer and store msg Signed-off-by: Connor <zbk602423539@gmail.com> Signed-off-by: Connor1996 <zbk602423539@gmail.com> Co-authored-by: Connor <zbk602423539@gmail.com> Co-authored-by: Connor1996 <zbk602423539@gmail.com>

ti-chi-bot · 2024-04-11T06:16:06Z

In response to a cherrypick label: new pull request created to branch release-7.1: #16803.

ref tikv#16600 Signed-off-by: ti-chi-bot <ti-community-prow-bot@tidb.io>

ref #16600 Add slow log for peer and store msg Signed-off-by: ti-chi-bot <ti-community-prow-bot@tidb.io> Signed-off-by: Qi Xu <tonyxuqqi@outlook.com> Co-authored-by: Connor <zbk602423539@gmail.com> Co-authored-by: Qi Xu <tonyxuqqi@outlook.com> Co-authored-by: tonyxuqqi <tonyxuqi@outlook.com>

ti-chi-bot · 2024-05-07T05:49:37Z

In response to a cherrypick label: new pull request could not be created: failed to create pull request against tikv/tikv#release-7.5 from head ti-chi-bot:cherry-pick-16605-to-release-7.5: the GitHub API request returns a 403 error: {"message":"You have exceeded a secondary rate limit and have been temporarily blocked from content creation. Please retry your request again later. If you reach out to GitHub Support for help, please include the request ID 98EE:21F144:4FEBA32:80A6538:6639C0F0 and timestamp 2024-05-07 05:49:36 UTC.","documentation_url":"https://docs.github.com/rest/overview/rate-limits-for-the-rest-api#about-secondary-rate-limits"}

ref tikv#16600 Signed-off-by: ti-chi-bot <ti-community-prow-bot@tidb.io>

wuhuizuo · 2024-05-21T02:37:51Z

/cherry-pick release-7.5

ti-chi-bot · 2024-05-21T02:38:29Z

@wuhuizuo: new pull request created to branch release-7.5: #17035.

In response to this:

/cherry-pick 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.

ref tikv#16600 Signed-off-by: ti-chi-bot <ti-community-prow-bot@tidb.io>

ref #16600 Add slow log for peer and store msg Signed-off-by: ti-chi-bot <ti-community-prow-bot@tidb.io> Signed-off-by: Connor1996 <zbk602423539@gmail.com> Co-authored-by: Connor <zbk602423539@gmail.com> Co-authored-by: Connor1996 <zbk602423539@gmail.com> Co-authored-by: ti-chi-bot[bot] <108142056+ti-chi-bot[bot]@users.noreply.github.com>

add slow log for peer and store msg

2ad8f1a

Signed-off-by: Connor1996 <zbk602423539@gmail.com>

ti-chi-bot bot added do-not-merge/needs-triage-completed release-note labels Mar 5, 2024

Connor1996 requested review from overvenus, glorv and tonyxuqqi March 5, 2024 12:51

ti-chi-bot bot added the size/M label Mar 5, 2024

Connor1996 requested review from SpadeA-Tang and LykxSassinator March 5, 2024 12:51

LykxSassinator reviewed Mar 6, 2024

View reviewed changes

overvenus reviewed Mar 6, 2024

View reviewed changes

Connor1996 added 3 commits March 7, 2024 13:45

address comment

6a0f225

Signed-off-by: Connor1996 <zbk602423539@gmail.com>

clean

dc3677b

Signed-off-by: Connor1996 <zbk602423539@gmail.com>

Merge remote-tracking branch 'upstream/master' into slow-log

56a2f87

overvenus reviewed Mar 8, 2024

View reviewed changes

ti-chi-bot bot added size/L and removed size/M labels Mar 11, 2024

address comment

6fd6d45

Signed-off-by: Connor1996 <zbk602423539@gmail.com>

Connor1996 force-pushed the slow-log branch from 8ea1c6d to 6fd6d45 Compare March 11, 2024 10:48

SpadeA-Tang approved these changes Mar 11, 2024

View reviewed changes

ti-chi-bot bot added the status/LGT1 Status: PR - There is already 1 approval label Mar 11, 2024

overvenus approved these changes Mar 12, 2024

View reviewed changes

components/raftstore/src/store/msg.rs Show resolved Hide resolved

components/raftstore/src/store/msg.rs Show resolved Hide resolved

ti-chi-bot bot added status/LGT2 Status: PR - There are already 2 approvals and removed status/LGT1 Status: PR - There is already 1 approval labels Mar 12, 2024

ti-chi-bot bot added the status/can-merge Status: Can merge to base branch label Mar 12, 2024

make format

2398fee

Signed-off-by: Connor1996 <zbk602423539@gmail.com>

ti-chi-bot bot removed the status/can-merge Status: Can merge to base branch label Mar 12, 2024

ti-chi-bot bot added status/can-merge Status: Can merge to base branch and removed do-not-merge/needs-triage-completed labels Mar 12, 2024

ti-chi-bot bot added 3 commits March 12, 2024 08:05

Merge branch 'master' into slow-log

974e8ae

Merge branch 'master' into slow-log

7353604

Merge branch 'master' into slow-log

826fbd2

ti-chi-bot bot merged commit 8ab7350 into tikv:master Mar 12, 2024
7 checks passed

ti-chi-bot bot added this to the Pool milestone Mar 12, 2024

ti-chi-bot added the needs-cherry-pick-release-6.5 label Mar 25, 2024

ti-chi-bot pushed a commit to ti-chi-bot/tikv that referenced this pull request Mar 25, 2024

This is an automated cherry-pick of tikv#16605

b5cfaed

ref tikv#16600 Signed-off-by: ti-chi-bot <ti-community-prow-bot@tidb.io>

ti-chi-bot mentioned this pull request Mar 25, 2024

raftstore: Add slow log for peer and store msg (#16605) #16692

Merged

9 tasks

ti-chi-bot added the needs-cherry-pick-release-7.1 label Apr 11, 2024

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

This is an automated cherry-pick of tikv#16605

1cd0d6f

ref tikv#16600 Signed-off-by: ti-chi-bot <ti-community-prow-bot@tidb.io>

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

raftstore: Add slow log for peer and store msg (#16605) #16803

Merged

9 tasks

ti-chi-bot added the needs-cherry-pick-release-7.5 label May 7, 2024

ti-chi-bot pushed a commit to ti-chi-bot/tikv that referenced this pull request May 7, 2024

This is an automated cherry-pick of tikv#16605

fc92d1f

ref tikv#16600 Signed-off-by: ti-chi-bot <ti-community-prow-bot@tidb.io>

ti-chi-bot pushed a commit to ti-chi-bot/tikv that referenced this pull request May 21, 2024

This is an automated cherry-pick of tikv#16605

495091b

ref tikv#16600 Signed-off-by: ti-chi-bot <ti-community-prow-bot@tidb.io>

ti-chi-bot mentioned this pull request May 21, 2024

raftstore: Add slow log for peer and store msg (#16605) #17035

Merged

9 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

raftstore: Add slow log for peer and store msg #16605

raftstore: Add slow log for peer and store msg #16605

Connor1996 commented Mar 5, 2024

ti-chi-bot bot commented Mar 5, 2024 •

edited

Loading

LykxSassinator Mar 6, 2024 •

edited

Loading

Connor1996 Mar 6, 2024

Connor1996 Mar 6, 2024

SpadeA-Tang Mar 7, 2024

overvenus Mar 8, 2024

Connor1996 Mar 11, 2024

overvenus Mar 6, 2024

Connor1996 Mar 7, 2024

overvenus Mar 6, 2024

Connor1996 Mar 7, 2024

overvenus Mar 8, 2024

overvenus left a comment

Connor1996 commented Mar 12, 2024

ti-chi-bot bot commented Mar 12, 2024

ti-chi-bot bot commented Mar 12, 2024

Connor1996 commented Mar 12, 2024

ti-chi-bot bot commented Mar 12, 2024

ti-chi-bot bot commented Mar 12, 2024

ti-chi-bot commented Mar 25, 2024

ti-chi-bot commented Apr 11, 2024

ti-chi-bot commented May 7, 2024

wuhuizuo commented May 21, 2024

ti-chi-bot commented May 21, 2024

raftstore: Add slow log for peer and store msg #16605

raftstore: Add slow log for peer and store msg #16605

Conversation

Connor1996 commented Mar 5, 2024

What is changed and how it works?

Related changes

Check List

Release note

ti-chi-bot bot commented Mar 5, 2024 • edited Loading

LykxSassinator Mar 6, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

overvenus left a comment

Choose a reason for hiding this comment

Connor1996 commented Mar 12, 2024

ti-chi-bot bot commented Mar 12, 2024

ti-chi-bot bot commented Mar 12, 2024

Connor1996 commented Mar 12, 2024

ti-chi-bot bot commented Mar 12, 2024

ti-chi-bot bot commented Mar 12, 2024

ti-chi-bot commented Mar 25, 2024

ti-chi-bot commented Apr 11, 2024

ti-chi-bot commented May 7, 2024

wuhuizuo commented May 21, 2024

ti-chi-bot commented May 21, 2024

ti-chi-bot bot commented Mar 5, 2024 •

edited

Loading

LykxSassinator Mar 6, 2024 •

edited

Loading