tso, election: remove some unnecessary logs from the TSO hot path #4044

JmPotato · 2021-08-27T10:08:45Z

Signed-off-by: JmPotato ghzpotato@gmail.com

What problem does this PR solve?

Remove some unnecessary logs from the TSO hot path.

log.Warn("get timestamp too slow", zap.Duration("cost", elapsed))

This indicator can be observed through metrics, so it is not necessary to hit the log here.

log.Info("this PD is a new leader, but sync hasn't been completed yet, wait for a while")

In past experience, this log has not been very helpful and may be very noisy.

log.Error("invalid timestamp",
				zap.Any("timestamp-physical", currentPhysical),
				zap.Any("timestamp-logical", currentLogical),
				errs.ZapError(errs.ErrInvalidTimestamp))

Ditto.

What is changed and how it works?

Remove some unnecessary logs from the TSO hot path.

Check List

Tests

Unit test
Integration test

Release note

None.

ti-chi-bot · 2021-08-27T10:08:46Z

[REVIEW NOTIFICATION]

This pull request has been approved by:

nolouch
rleungx

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.

Signed-off-by: JmPotato <ghzpotato@gmail.com>

rleungx · 2021-08-27T10:14:07Z

server/grpc_service.go

@@ -166,10 +164,6 @@ func (s *Server) Tso(stream pdpb.PD_TsoServer) error {
 			return status.Errorf(codes.Unknown, err.Error())
 		}

-		elapsed := time.Since(start)
-		if elapsed > slowThreshold {
-			log.Warn("get timestamp too slow", zap.Duration("cost", elapsed))


Why is it useless?

I think we can get it from the metrics also.

I don't find any metrics to record it.

Oh, you mean tsoHandleDuration.Observe(time.Since(start).Seconds())

nolouch · 2021-08-27T10:18:54Z

server/tso/tso.go

@@ -362,7 +362,6 @@ func (t *timestampOracle) getTS(leadership *election.Leadership, count uint32, s
 		if currentPhysical == typeutil.ZeroTime {
 			// If it's leader, maybe SyncTimestamp hasn't completed yet
 			if leadership.Check() {
-				log.Info("this PD is a new leader, but sync hasn't been completed yet, wait for a while")


also this log will be noise:

[2021/06/18 16:15:19.627 +08:00] [ERROR] [tso.go:302] ["invalid timestamp"] [timestamp={}] [2021/06/18 16:15:19.628 +08:00] [ERROR] [tso.go:302] ["invalid timestamp"] [timestamp={}] [2021/06/18 16:15:19.628 +08:00] [ERROR] [tso.go:302] ["invalid timestamp"] [timestamp={}] [2021/06/18 16:15:19.685 +08:00] [ERROR] [tso.go:302] ["invalid timestamp"] [timestamp={}] [2021/06/18 16:15:19.686 +08:00] [ERROR] [tso.go:302] ["invalid timestamp"] [timestamp={}] [2021/06/18 16:15:19.718 +08:00] [ERROR] [tso.go:302] ["invalid timestamp"] [timestamp={}] [2021/06/18 16:15:19.718 +08:00] [ERROR] [tso.go:302] ["invalid timestamp"] [timestamp={}]

Removed. PTAL.

codecov · 2021-08-27T10:23:16Z

Codecov Report

Merging #4044 (8ebb3a4) into master (5d4775b) will decrease coverage by 0.01%.
The diff coverage is 100.00%.

@@            Coverage Diff             @@
##           master    #4044      +/-   ##
==========================================
- Coverage   74.47%   74.45%   -0.02%     
==========================================
  Files         257      257              
  Lines       25980    25972       -8     
==========================================
- Hits        19349    19338      -11     
+ Misses       4898     4896       -2     
- Partials     1733     1738       +5

Flag	Coverage Δ
unittests	`74.45% <100.00%> (-0.02%)`	⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

Impacted Files	Coverage Δ
server/grpc_service.go	`47.27% <ø> (+0.16%)`	⬆️
server/tso/global_allocator.go	`61.90% <ø> (+1.28%)`	⬆️
server/election/leadership.go	`84.61% <100.00%> (+0.70%)`	⬆️
server/tso/tso.go	`64.77% <100.00%> (+6.20%)`	⬆️
server/election/lease.go	`89.83% <0.00%> (-6.78%)`	⬇️
server/tso/local_allocator.go	`71.62% <0.00%> (-6.76%)`	⬇️
server/schedule/region_scatterer.go	`80.70% <0.00%> (-4.39%)`	⬇️
server/region_syncer/client.go	`77.46% <0.00%> (-4.23%)`	⬇️
pkg/etcdutil/etcdutil.go	`84.70% <0.00%> (-3.53%)`	⬇️
client/base_client.go	`82.29% <0.00%> (-2.09%)`	⬇️
... and 13 more

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 5d4775b...8ebb3a4. Read the comment docs.

Signed-off-by: JmPotato <ghzpotato@gmail.com>

JmPotato · 2021-08-27T11:12:40Z

/run-unit-test

nolouch

lgtm

rleungx · 2021-08-31T03:46:02Z

/merge

ti-chi-bot · 2021-08-31T03:46:03Z

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

/run-all-tests

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 · 2021-08-31T03:46:04Z

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

Commit hash: 337f78d

JmPotato · 2021-08-31T05:11:13Z

/run-unit-test

…kv#4044) * Remove some unnecessary logs from the TSO hot path Signed-off-by: JmPotato <ghzpotato@gmail.com> * Remove more unnecessary logs Signed-off-by: JmPotato <ghzpotato@gmail.com> * Fix the test Signed-off-by: JmPotato <ghzpotato@gmail.com> Co-authored-by: Ti Chi Robot <ti-community-prow-bot@tidb.io>

ti-chi-bot added the release-note Denotes a PR that will be considered when it comes time to generate release notes. label Aug 27, 2021

ti-chi-bot requested a review from rleungx August 27, 2021 10:08

ti-chi-bot added release-note-none Denotes a PR that doesn't merit a release note. and removed release-note Denotes a PR that will be considered when it comes time to generate release notes. labels Aug 27, 2021

JmPotato requested review from bufferflies, HunDunDM and nolouch August 27, 2021 10:09

JmPotato added component/election Election related logic. component/tso Timestamp Oracle. labels Aug 27, 2021

Remove some unnecessary logs from the TSO hot path

641394f

Signed-off-by: JmPotato <ghzpotato@gmail.com>

rleungx reviewed Aug 27, 2021

View reviewed changes

nolouch reviewed Aug 27, 2021

View reviewed changes

Remove more unnecessary logs

a443374

Signed-off-by: JmPotato <ghzpotato@gmail.com>

JmPotato force-pushed the clean_tso_log branch from f998947 to a443374 Compare August 27, 2021 10:29

Fix the test

337f78d

Signed-off-by: JmPotato <ghzpotato@gmail.com>

JmPotato requested review from nolouch and rleungx August 27, 2021 14:27

nolouch approved these changes Aug 30, 2021

View reviewed changes

ti-chi-bot added the status/LGT1 Indicates that a PR has LGTM 1. label Aug 30, 2021

rleungx approved these changes Aug 31, 2021

View reviewed changes

ti-chi-bot added status/LGT2 Indicates that a PR has LGTM 2. and removed status/LGT1 Indicates that a PR has LGTM 1. labels Aug 31, 2021

ti-chi-bot added the status/can-merge Indicates a PR has been approved by a committer. label Aug 31, 2021

Merge branch 'master' into clean_tso_log

8ebb3a4

ti-chi-bot merged commit c3c8c47 into tikv:master Aug 31, 2021

JmPotato deleted the clean_tso_log branch August 31, 2021 05:33

JmPotato mentioned this pull request Sep 1, 2021

election: fix the panic bug of lease #4061

Merged

JmPotato mentioned this pull request Sep 14, 2021

election: revert the unnecessary setting of the lease to avoid the panic #4123

Merged

lhy1024 mentioned this pull request Jun 28, 2023

leadership: avoid potential data race #6636

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

tso, election: remove some unnecessary logs from the TSO hot path #4044

tso, election: remove some unnecessary logs from the TSO hot path #4044

JmPotato commented Aug 27, 2021 •

edited

Loading

ti-chi-bot commented Aug 27, 2021 •

edited

Loading

rleungx Aug 27, 2021

JmPotato Aug 27, 2021

rleungx Aug 27, 2021

rleungx Aug 27, 2021

JmPotato Aug 27, 2021

nolouch Aug 27, 2021

JmPotato Aug 27, 2021

codecov bot commented Aug 27, 2021 •

edited

Loading

JmPotato commented Aug 27, 2021

nolouch left a comment

rleungx commented Aug 31, 2021

ti-chi-bot commented Aug 31, 2021

ti-chi-bot commented Aug 31, 2021

JmPotato commented Aug 31, 2021

tso, election: remove some unnecessary logs from the TSO hot path #4044

tso, election: remove some unnecessary logs from the TSO hot path #4044

Conversation

JmPotato commented Aug 27, 2021 • edited Loading

What problem does this PR solve?

What is changed and how it works?

Check List

Release note

ti-chi-bot commented Aug 27, 2021 • edited Loading

rleungx Aug 27, 2021

Choose a reason for hiding this comment

JmPotato Aug 27, 2021

Choose a reason for hiding this comment

rleungx Aug 27, 2021

Choose a reason for hiding this comment

rleungx Aug 27, 2021

Choose a reason for hiding this comment

JmPotato Aug 27, 2021

Choose a reason for hiding this comment

nolouch Aug 27, 2021

Choose a reason for hiding this comment

JmPotato Aug 27, 2021

Choose a reason for hiding this comment

codecov bot commented Aug 27, 2021 • edited Loading

Codecov Report

JmPotato commented Aug 27, 2021

nolouch left a comment

Choose a reason for hiding this comment

rleungx commented Aug 31, 2021

ti-chi-bot commented Aug 31, 2021

ti-chi-bot commented Aug 31, 2021

JmPotato commented Aug 31, 2021

JmPotato commented Aug 27, 2021 •

edited

Loading

ti-chi-bot commented Aug 27, 2021 •

edited

Loading

codecov bot commented Aug 27, 2021 •

edited

Loading