pump/: Accelerat transaction status queries throught GetMvccByEncodeKey #632

july2993 · 2019-06-10T10:02:09Z

What problem does this PR solve?

Avoid some case that we wait 10 minutes after the transaction and call GetTxnStatus which send the CleanupRequest that will get the commit ts of transaction or rollback the transaction.

What is changed and how it works?

Query txn info by GetMvccByEncodeKey.
we can know if the txn if committed or rollback as quick as possible.

If we can't get the status we will fallback to the case call GetTxnStatus after 10 minute of the transaction.

Check List

Tests

Unit test
Integration test
Manual test (add detailed scripts or steps below)
- using sysbench tps = 10k
- kill -9 tidb
  log of the pump with this pr

[tidb@ip-172-16-4-74 tikv]$ tail  -f log/pump.log | grep "known txn"
[2019/06/10 17:24:59.192 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244264] ["commit ts"=408986240913244423]
[2019/06/10 17:25:02.192 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244269] ["commit ts"=408986240913244494]
[2019/06/10 17:25:05.192 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244275] ["commit ts"=408986240913244488]
[2019/06/10 17:25:08.193 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244292] ["commit ts"=408986240913244482]
[2019/06/10 17:25:11.193 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244298] ["commit ts"=408986240913244518]
[2019/06/10 17:25:14.195 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244344] ["commit ts"=408986240913244468]
[2019/06/10 17:25:17.194 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244362] ["commit ts"=408986240913244485]
[2019/06/10 17:25:20.194 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244336] ["commit ts"=408986240913244517]
[2019/06/10 17:25:23.199 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244363] ["commit ts"=408986240913244419]
[2019/06/10 17:25:26.197 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244364] ["commit ts"=408986240913244447]
[2019/06/10 17:25:29.197 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244342] ["commit ts"=408986240913244489]
[2019/06/10 17:25:32.197 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244314] ["commit ts"=408986240913244448]
[2019/06/10 17:25:35.201 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244379] ["commit ts"=408986240913244450]
[2019/06/10 17:25:38.200 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244391] ["commit ts"=408986240913244506]
[2019/06/10 17:25:41.200 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244384] ["commit ts"=408986240913244528]
[2019/06/10 17:25:44.200 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244397] ["commit ts"=408986240913244505]
[2019/06/10 17:26:16.494 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244401] ["commit ts"=0]
[2019/06/10 17:26:17.497 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244406] ["commit ts"=0]
[2019/06/10 17:30:21.015 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244404] ["commit ts"=0]
[2019/06/10 17:30:22.017 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244410] ["commit ts"=408986240913244542]
[2019/06/10 17:30:23.023 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244412] ["commit ts"=0]
[2019/06/10 17:30:24.026 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244418] ["commit ts"=408986240913244531]
[2019/06/10 17:30:25.028 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244428] ["commit ts"=0]
[2019/06/10 17:34:55.403 +08:00] [INFO] [storage.go:468] ["known txn is committed from tikv"] ["start ts"=408986240913244441] ["commit ts"=0]
[2019/06/10 17:34:56.406 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244455] ["commit ts"=0]
[2019/06/10 17:34:57.408 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244463] ["commit ts"=0]
[2019/06/10 17:34:58.411 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244460] ["commit ts"=0]
[2019/06/10 17:34:59.413 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244454] ["commit ts"=0]
[2019/06/10 17:35:00.415 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244497] ["commit ts"=0]
[2019/06/10 17:35:01.417 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244457] ["commit ts"=0]
[2019/06/10 17:35:02.423 +08:00] [INFO] [storage.go:468] ["known txn is committed from tikv"] ["start ts"=408986240913244474] ["commit ts"=0]
[2019/06/10 17:35:03.425 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244495] ["commit ts"=0]
[2019/06/10 17:35:04.437 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244479] ["commit ts"=0]
[2019/06/10 17:35:05.440 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244490] ["commit ts"=0]
[2019/06/10 17:35:06.442 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244453] ["commit ts"=0]
[2019/06/10 17:35:07.446 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244473] ["commit ts"=0]
[2019/06/10 17:35:08.448 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244512] ["commit ts"=0]
[2019/06/10 17:35:09.451 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244521] ["commit ts"=0]
[2019/06/10 17:35:10.531 +08:00] [INFO] [storage.go:433] ["known txn is committed or rollback from tikv"] ["start ts"=408986240913244523] ["commit ts"=0]

.74 is the version with this pr

Code changes

Side effects

Related changes

Need to cherry-pick to the release branch
Need to be included in the release note

IANTHEREAL · 2019-06-10T10:37:03Z

pump/server.go

+
+	if len(binlog.PrewriteKey) > 0 {
+		tikvStorage := s.tiStore.(tikv.Storage)
+		healper := storage.Helper{


why not one Helper instance?

no performance cost and only use here so I think better just construct here, don't make Server struct complicate

IANTHEREAL · 2019-06-10T10:42:07Z

pump/server.go

+			RegionCache: tikvStorage.GetRegionCache(),
+		}
+
+		resp, err := healper.GetMvccByEncodedKey(binlog.PrewriteKey)


we can extract one function queryTransactionStatus, then just call it. the implementation output too many unless and old mvcc records

for debug just keep all info?

IANTHEREAL · 2019-06-10T10:43:07Z

Good Job!

pump/storage/storage.go

IANTHEREAL · 2019-06-10T10:55:27Z

if item.tp == pb.BinlogType_Prewrite {
	getTime := time.Now()

	for {
		_, ok := s.waitStartTS[item.start]
		if !ok {
			break
		}

		// we may get the C binlog soon at start up time
		if time.Since(getTime) > time.Second {
		        if s.resolver != nil && s.resolver(item.start) {
				break
			}
		}

should we put getTime := time.Now() in the for loop?

pump/storage/storage.go

pump/server.go

suzaku · 2019-06-11T01:45:02Z

pump/storage/helper.go

+	}
+	kvResp, err := h.Store.SendReq(tikv.NewBackoffer(context.Background(), 500), tikvReq, keyLocation.Region, time.Minute)
+	if err != nil {
+		log.Info("get MVCC by encoded key failed",


Suggested change

log.Info("get MVCC by encoded key failed",

log.Error("get MVCC by encoded key failed",

suzaku · 2019-06-11T01:48:33Z

pump/storage/helper.go

+}
+
+// GetMvccByEncodedKey get the MVCC value by the specific encoded key.
+func (h *Helper) GetMvccByEncodedKey(encodedKey kv.Key) (*kvrpcpb.MvccGetByKeyResponse, error) {


How about just define a function GetMVCCByEncodedKey(tikv.Storage, kv.Key) instead? It seems like we have no other use for the Helper struct here.

// Copy from https://github.com/pingcap/tidb/blob/71def9c7263432c0dfa6a5960f6db824775177c9/store/helper/helper.go#L47
// we can use it directly if we upgrade to the latest version of TiDB dependency.

add comment in helper.go
and we may add other myself if not use TiDB code directly.

pump/storage/storage.go

july2993 · 2019-06-12T02:16:39Z

/run-all-tests

july2993 · 2019-06-12T02:50:08Z

/run-all-tests

july2993 · 2019-06-12T02:59:59Z

/run-all-tests

IANTHEREAL · 2019-06-17T02:27:35Z

LGTM

suzaku · 2019-06-17T08:45:59Z

/run-all-tests

suzaku · 2019-06-18T03:24:13Z

/run-all-tests

july2993 · 2019-06-18T04:47:10Z

/run-unit-test

suzaku

LGTM

suzaku · 2019-06-18T06:38:45Z

/run-all-tests

pump/: Query txn info by GetMvccByEncodeKey

af5fec9

july2993 added the status/PTAL label Jun 10, 2019

july2993 added 2 commits June 10, 2019 18:13

Merge branch 'master' into hjh/mvcc

c2365a5

server.go: Fix Fprintf call needs 1 arg but has 2 args

0e49478

IANTHEREAL reviewed Jun 10, 2019

View reviewed changes

IANTHEREAL changed the title ~~pump/: Query txn info by GetMvccByEncodeKey~~ pump/: Accelerat transaction status queries throught GetMvccByEncodeKey Jun 10, 2019

IANTHEREAL reviewed Jun 10, 2019

View reviewed changes

pump/storage/storage.go Outdated Show resolved Hide resolved

IANTHEREAL reviewed Jun 10, 2019

View reviewed changes

pump/storage/storage.go Show resolved Hide resolved

pump: fix log

a35361d

IANTHEREAL reviewed Jun 11, 2019

View reviewed changes

pump/storage/storage.go Show resolved Hide resolved

IANTHEREAL added p0 priority 0 priority/important labels Jun 11, 2019

suzaku reviewed Jun 11, 2019

View reviewed changes

july2993 added 3 commits June 11, 2019 11:03

address trivial comment

c9daf89

Merge remote-tracking branch 'july2993/hjh/mvcc' into hjh/mvcc

d4c3fa0

Merge branch 'master' into hjh/mvcc

3218d24

july2993 added 2 commits June 12, 2019 10:44

storage.go: Init helper only if provide tiStore

403eca6

Merge remote-tracking branch 'july2993/hjh/mvcc' into hjh/mvcc

808a4f9

july2993 requested a review from suzaku June 13, 2019 02:23

IANTHEREAL added status/LGT1 and removed status/PTAL labels Jun 17, 2019

Merge branch 'master' into hjh/mvcc

268497f

Merge branch 'master' into hjh/mvcc

02b586c

suzaku approved these changes Jun 18, 2019

View reviewed changes

Merge branch 'master' into hjh/mvcc

83ecb8b

suzaku added status/LGT2 and removed status/LGT1 labels Jun 18, 2019

suzaku merged commit d54d6b9 into pingcap:master Jun 18, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

pump/: Accelerat transaction status queries throught GetMvccByEncodeKey #632

pump/: Accelerat transaction status queries throught GetMvccByEncodeKey #632

july2993 commented Jun 10, 2019 •

edited by IANTHEREAL

Loading

IANTHEREAL Jun 10, 2019

july2993 Jun 11, 2019 •

edited

Loading

IANTHEREAL Jun 10, 2019

july2993 Jun 11, 2019

IANTHEREAL commented Jun 10, 2019

IANTHEREAL commented Jun 10, 2019

suzaku Jun 11, 2019

suzaku Jun 11, 2019

july2993 Jun 12, 2019

july2993 commented Jun 12, 2019

july2993 commented Jun 12, 2019

july2993 commented Jun 12, 2019

IANTHEREAL commented Jun 17, 2019

suzaku commented Jun 17, 2019

suzaku commented Jun 18, 2019

july2993 commented Jun 18, 2019

suzaku left a comment

suzaku commented Jun 18, 2019

	log.Info("get MVCC by encoded key failed",
	log.Error("get MVCC by encoded key failed",

pump/: Accelerat transaction status queries throught GetMvccByEncodeKey #632

pump/: Accelerat transaction status queries throught GetMvccByEncodeKey #632

Conversation

july2993 commented Jun 10, 2019 • edited by IANTHEREAL Loading

What problem does this PR solve?

What is changed and how it works?

Check List

IANTHEREAL Jun 10, 2019

Choose a reason for hiding this comment

july2993 Jun 11, 2019 • edited Loading

Choose a reason for hiding this comment

IANTHEREAL Jun 10, 2019

Choose a reason for hiding this comment

july2993 Jun 11, 2019

Choose a reason for hiding this comment

IANTHEREAL commented Jun 10, 2019

IANTHEREAL commented Jun 10, 2019

suzaku Jun 11, 2019

Choose a reason for hiding this comment

suzaku Jun 11, 2019

Choose a reason for hiding this comment

july2993 Jun 12, 2019

Choose a reason for hiding this comment

july2993 commented Jun 12, 2019

july2993 commented Jun 12, 2019

july2993 commented Jun 12, 2019

IANTHEREAL commented Jun 17, 2019

suzaku commented Jun 17, 2019

suzaku commented Jun 18, 2019

july2993 commented Jun 18, 2019

suzaku left a comment

Choose a reason for hiding this comment

suzaku commented Jun 18, 2019

july2993 commented Jun 10, 2019 •

edited by IANTHEREAL

Loading

july2993 Jun 11, 2019 •

edited

Loading