Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

unit test TestIsolationMultiInc fails #17699

Closed
SunRunAway opened this issue Jun 5, 2020 · 6 comments
Closed

unit test TestIsolationMultiInc fails #17699

SunRunAway opened this issue Jun 5, 2020 · 6 comments
Assignees
@tiancaiamao
Labels
component/test severity/major

Comments

@SunRunAway
Copy link
Contributor

SunRunAway commented Jun 5, 2020 •
edited by tiancaiamao
Loading

FAIL: store_test.go:612: testKVSuite.TestIsolationMultiInc

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. Minimal reproduce step (Required)

[2020-06-05T03:30:16.934Z] ----------------------------------------------------------------------
[2020-06-05T03:30:16.934Z] FAIL: store_test.go:612: testKVSuite.TestIsolationMultiInc
[2020-06-05T03:30:16.934Z] 
[2020-06-05T03:30:16.934Z] store_test.go:639:
[2020-06-05T03:30:16.934Z]     c.Assert(err, IsNil)
[2020-06-05T03:30:16.934Z] ... value *errors.withStack = [kv:9007]Write conflict, txnStartTS=417157037850624000, conflictStartTS=417157037873692672, conflictCommitTS=417157037919830016, key=[]byte{0x74, 0x65, 0x73, 0x74, 0x5f, 0x6b, 0x65, 0x79, 0x5f, 0x30} primary=[]byte(nil) [try again later] ("[kv:9007]Write conflict, txnStartTS=417157037850624000, conflictStartTS=417157037873692672, conflictCommitTS=417157037919830016, key=[]byte{0x74, 0x65, 0x73, 0x74, 0x5f, 0x6b, 0x65, 0x79, 0x5f, 0x30} primary=[]byte(nil) [try again later]")
[2020-06-05T03:30:16.934Z] 
[2020-06-05T03:30:16.934Z] store_test.go:646:
[2020-06-05T03:30:16.934Z]     err := kv.RunInNewTxn(s.s, false, func(txn kv.Transaction) error {
[2020-06-05T03:30:16.934Z]         for _, key := range keys {
[2020-06-05T03:30:16.934Z]             id, err1 := kv.GetInt64(context.TODO(), txn, key)
[2020-06-05T03:30:16.934Z]             if err1 != nil {
[2020-06-05T03:30:16.934Z]                 return err1
[2020-06-05T03:30:16.934Z]             }
[2020-06-05T03:30:16.934Z]             c.Assert(id, Equals, int64(threadCnt*incCnt))
[2020-06-05T03:30:16.934Z]             txn.Delete(key)
[2020-06-05T03:30:16.934Z]         }
[2020-06-05T03:30:16.934Z]         return nil
[2020-06-05T03:30:16.934Z]     })
[2020-06-05T03:30:16.934Z] store_test.go:652:
[2020-06-05T03:30:16.934Z]     c.Assert(id, Equals, int64(threadCnt*incCnt))
[2020-06-05T03:30:16.934Z] ... obtained int64 = 354
[2020-06-05T03:30:16.934Z] ... expected int64 = 400
[2020-06-05T03:30:16.934Z] 
[2020-06-05T03:30:16.934Z] 
[2020-06-05T03:30:16.934Z] ----------------------------------------------------------------------
[2020-06-05T03:30:16.934Z] PASS: store_test.go:164: testKVSuite.TestNew	0.000s
[2020-06-05T03:30:16.934Z] PASS: store_test.go:672: testKVSuite.TestOpenStore	0.000s
[2020-06-05T03:30:16.934Z] PASS: store_test.go:681: testKVSuite.TestRegister	0.000s
[2020-06-05T03:30:16.934Z] PASS: store_test.go:660: testKVSuite.TestRetryOpenStore	3.001s
[2020-06-05T03:30:16.934Z] PASS: store_test.go:388: testKVSuite.TestRollback	0.002s
[2020-06-05T03:30:16.934Z] 
[2020-06-05T03:30:16.934Z] ----------------------------------------------------------------------
[2020-06-05T03:30:16.934Z] FAIL: store_test.go:190: testKVSuite.TestSeek
[2020-06-05T03:30:16.934Z] 
[2020-06-05T03:30:16.934Z] store_test.go:195:
[2020-06-05T03:30:16.934Z]     checkSeek(c, txn)
[2020-06-05T03:30:16.934Z] store_test.go:133:
[2020-06-05T03:30:16.934Z]     c.Assert(iter.Valid(), IsFalse)
[2020-06-05T03:30:16.934Z] ... obtained bool = true
[2020-06-05T03:30:16.934Z] 
[2020-06-05T03:30:16.934Z] 
[2020-06-05T03:30:16.934Z] ----------------------------------------------------------------------
[2020-06-05T03:30:16.934Z] PASS: store_test.go:415: testKVSuite.TestSeekMin	0.090s
[2020-06-05T03:30:16.934Z] PASS: store_test.go:316: testKVSuite.TestSetNil	0.000s
[2020-06-05T03:30:16.934Z] OOPS: 17 passed, 1 skipped, 2 FAILED
[2020-06-05T03:30:16.934Z] --- FAIL: TestT (49.45s)
[2020-06-05T03:30:16.934Z] FAIL
[2020-06-05T03:30:16.934Z] FAIL	github.com/pingcap/tidb/store	49.496s

2. What did you expect to see? (Required)

3. What did you see instead (Required)

4. Affected version (Required)

release-4.0

https://internal.pingcap.net/idc-jenkins/blue/organizations/jenkins/tidb_ghpr_unit_test/detail/tidb_ghpr_unit_test/38824/pipeline
#17655

5. Root Cause Analysis
@SunRunAway SunRunAway added type/bug The issue is confirmed as a bug. component/test labels Jun 5, 2020
@SunRunAway
Copy link
Contributor Author

@tiancaiamao PTAL

@tiancaiamao
Copy link
Contributor

testKVSuite.TestIsolationMultiInc maybe fail because of the conflict retry goes beyond the maxRetryCnt in RunInNewTxn.

Maybe we can reduce the concurrency or increase maxRetryCnt to make the test more stable, I will handle it if this happen again.

@tiancaiamao
Copy link
Contributor

I haven't seen this happen for quite a long time and there is no report about it anymore, so close it.

@ti-srebot
Copy link
Contributor

ti-srebot commented Nov 11, 2020 •
edited by tiancaiamao
Loading

Please edit this comment to complete the following information

Not a bug

Can't reproduce

@tiancaiamao tiancaiamao removed the type/bug The issue is confirmed as a bug. label Nov 11, 2020
@zz-jason
Copy link
Member

zz-jason commented Nov 30, 2020 •
edited
Loading

it happens now: https://internal.pingcap.net/idc-jenkins/blue/organizations/jenkins/tidb_ghpr_unit_test/detail/tidb_ghpr_unit_test/59648/pipeline

[2020-11-28T13:35:24.319Z] FAIL: store_test.go:612: testKVSuite.TestIsolationMultiInc
[2020-11-28T13:35:24.319Z]
[2020-11-28T13:35:24.319Z] store_test.go:639:
[2020-11-28T13:35:24.319Z]     c.Assert(err, IsNil)
[2020-11-28T13:35:24.319Z] ... value *errors.withStack = [kv:9007]Write conflict, txnStartTS=421152822371549184, conflictStartTS=421152822375743488, conflictCommitTS=421152822400385024, key=[]byte{0x74, 0x65, 0x73, 0x74, 0x5f, 0x6b, 0x65, 0x79, 0x5f, 0x30} primary=[]byte(nil) [try again later] ("[kv:9007]Write       conflict, txnStartTS=421152822371549184, conflictStartTS=421152822375743488, conflictCommitTS=421152822400385024, key=[]byte{0x74, 0x65, 0x73, 0x74, 0x5f, 0x6b, 0x65, 0x79, 0x5f, 0x30} primary=[]byte(nil) [try again later]")
[2020-11-28T13:35:24.319Z]
[2020-11-28T13:35:24.319Z] store_test.go:646:
[2020-11-28T13:35:24.319Z]     err := kv.RunInNewTxn(s.s, false, func(txn kv.Transaction) error {
[2020-11-28T13:35:24.319Z]         for _, key := range keys {
[2020-11-28T13:35:24.319Z]             id, err1 := kv.GetInt64(context.TODO(), txn, key)
[2020-11-28T13:35:24.319Z]             if err1 != nil {
[2020-11-28T13:35:24.319Z]                 return err1
[2020-11-28T13:35:24.319Z]             }
[2020-11-28T13:35:24.319Z]             c.Assert(id, Equals, int64(threadCnt*incCnt))
[2020-11-28T13:35:24.319Z]             txn.Delete(key)
[2020-11-28T13:35:24.319Z]         }
[2020-11-28T13:35:24.319Z]         return nil
[2020-11-28T13:35:24.319Z]     })
[2020-11-28T13:35:24.319Z] store_test.go:652:
[2020-11-28T13:35:24.319Z]     c.Assert(id, Equals, int64(threadCnt*incCnt))
[2020-11-28T13:35:24.319Z] ... obtained int64 = 324
[2020-11-28T13:35:24.319Z] ... expected int64 = 400

@zz-jason zz-jason reopened this Nov 30, 2020
@tiancaiamao
Copy link
Contributor

This issue has been there for quite a long time.
After #30822, I guess it's solved.
Close for now, if it still reproduce, feel free to reopen.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@tiancaiamao tiancaiamao

Labels
component/test severity/major
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@SunRunAway @tiancaiamao @zz-jason @fzhedu @tisonkun @ti-srebot