TestGetTxnStatus failed in integration_common_test #13397

wjhuang2016 · 2019-11-12T09:18:40Z

FAIL: lock_test.go:187: testLockSuite.TestGetTxnStatus

Bug Report

Please answer these questions before submitting your issue. Thanks!

What did you do?
If possible, provide a recipe for reproducing the error.

[2019-11-12T07:25:34.407Z] [2019/11/12 15:25:21.113 +08:00] [INFO] [lock_resolver.go:524] ["resolveLock rollback"] [lock="key: []byte{0x74}, primary: []byte{0x74}, txnStartTS: 412494992781082670, ttl: 3, type: Put"]
[2019-11-12T07:25:34.407Z] [2019/11/12 15:25:21.114 +08:00] [INFO] [lock_resolver.go:524] ["resolveLock rollback"] [lock="key: []byte{0x75}, primary: []byte{0x75}, txnStartTS: 412494992781082671, ttl: 3, type: Put"]
[2019-11-12T07:25:34.407Z] [2019/11/12 15:25:21.114 +08:00] [INFO] [lock_resolver.go:524] ["resolveLock rollback"] [lock="key: []byte{0x76}, primary: []byte{0x76}, txnStartTS: 412494992781082672, ttl: 3, type: Put"]
[2019-11-12T07:25:34.407Z] [2019/11/12 15:25:21.115 +08:00] [INFO] [lock_resolver.go:524] ["resolveLock rollback"] [lock="key: []byte{0x77}, primary: []byte{0x77}, txnStartTS: 412494992781082674, ttl: 3, type: Put"]
[2019-11-12T07:25:34.407Z] [2019/11/12 15:25:21.116 +08:00] [INFO] [lock_resolver.go:524] ["resolveLock rollback"] [lock="key: []byte{0x78}, primary: []byte{0x78}, txnStartTS: 412494992781082675, ttl: 3, type: Put"]
[2019-11-12T07:25:34.407Z] [2019/11/12 15:25:21.116 +08:00] [INFO] [lock_resolver.go:524] ["resolveLock rollback"] [lock="key: []byte{0x79}, primary: []byte{0x79}, txnStartTS: 412494992781082676, ttl: 3, type: Put"]
[2019-11-12T07:25:34.407Z] [2019/11/12 15:25:21.117 +08:00] [INFO] [lock_resolver.go:524] ["resolveLock rollback"] [lock="key: []byte{0x7a}, primary: []byte{0x7a}, txnStartTS: 412494992781082677, ttl: 3, type: Put"]
[2019-11-12T07:25:34.407Z] PASS: lock_test.go:172: testLockSuite.TestCleanLock	0.048s
[2019-11-12T07:25:34.407Z] [2019/11/12 15:25:21.120 +08:00] [INFO] [client.go:144] ["[pd] create pd client with endpoints"] [pd-address="[127.0.0.1:2379]"]
[2019-11-12T07:25:34.407Z] [2019/11/12 15:25:21.122 +08:00] [INFO] [client.go:252] ["[pd] switch leader"] [new-leader=http://127.0.0.1:2379] [old-leader=]
[2019-11-12T07:25:34.407Z] [2019/11/12 15:25:21.122 +08:00] [INFO] [client.go:163] ["[pd] init cluster id"] [cluster-id=6758317773105027983]
[2019-11-12T07:25:34.407Z] 
[2019-11-12T07:25:34.407Z] ----------------------------------------------------------------------
[2019-11-12T07:25:34.407Z] FAIL: lock_test.go:187: testLockSuite.TestGetTxnStatus
[2019-11-12T07:25:34.407Z] 
[2019-11-12T07:25:34.407Z] lock_test.go:204:
[2019-11-12T07:25:34.407Z]     c.Assert(status.ttl, Greater, uint64(0))
[2019-11-12T07:25:34.407Z] ... compare_one uint64 = 0x0
[2019-11-12T07:25:34.407Z] ... compare_two uint64 = 0x0
[2019-11-12T07:25:34.407Z] 
[2019-11-12T07:25:34.408Z] [2019/11/12 15:25:21.150 +08:00] [ERROR] [pd.go:129] ["updateTS error"] [error="rpc error: code = Canceled desc = context canceled"] [errorVerbose="rpc error: code = Canceled desc = context canceled\ngithub.com/pingcap/pd/client.(*client).processTSORequests\n\t/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/pkg/mod/github.com/pingcap/pd@v1.1.0-beta.0.20190923032047-5c648dc365e0/client/client.go:444\ngithub.com/pingcap/pd/client.(*client).tsLoop\n\t/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/pkg/mod/github.com/pingcap/pd@v1.1.0-beta.0.20190923032047-5c648dc365e0/client/client.go:393\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1357\ngithub.com/pingcap/pd/client.(*tsoRequest).Wait\n\t/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/pkg/mod/github.com/pingcap/pd@v1.1.0-beta.0.20190923032047-5c648dc365e0/client/client.go:564\ngithub.com/pingcap/pd/client.(*client).GetTS\n\t/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/pkg/mod/github.com/pingcap/pd@v1.1.0-beta.0.20190923032047-5c648dc365e0/client/client.go:582\ngithub.com/pingcap/tidb/store/tikv/oracle/oracles.(*pdOracle).getTimestamp\n\t/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/src/github.com/pingcap/tidb/store/tikv/oracle/oracles/pd.go:103\ngithub.com/pingcap/tidb/store/tikv/oracle/oracles.(*pdOracle).updateTS\n\t/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/src/github.com/pingcap/tidb/store/tikv/oracle/oracles/pd.go:127\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1357\ngithub.com/pingcap/errors.AddStack\n\t/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/pkg/mod/github.com/pingcap/errors@v0.11.4/errors.go:174\ngithub.com/pingcap/errors.Trace\n\t/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/pkg/mod/github.com/pingcap/errors@v0.11.4/juju_adaptor.go:15\ngithub.com/pingcap/tidb/store/tikv/oracle/oracles.(*pdOracle).getTimestamp\n\t/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/src/github.com/pingcap/tidb/store/tikv/oracle/oracles/pd.go:105\ngithub.com/pingcap/tidb/store/tikv/oracle/oracles.(*pdOracle).updateTS\n\t/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/src/github.com/pingcap/tidb/store/tikv/oracle/oracles/pd.go:127\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1357"] [stack="github.com/pingcap/tidb/store/tikv/oracle/oracles.(*pdOracle).updateTS\n\t/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/src/github.com/pingcap/tidb/store/tikv/oracle/oracles/pd.go:129"]
[2019-11-12T07:25:34.408Z] [2019/11/12 15:25:21.151 +08:00] [INFO] [client.go:144] ["[pd] create pd client with endpoints"] [pd-address="[127.0.0.1:2379]"]
[2019-11-12T07:25:34.408Z] [2019/11/12 15:25:21.154 +08:00] [INFO] [client.go:252] ["[pd] switch leader"] [new-leader=http://127.0.0.1:2379] [old-leader=]
[2019-11-12T07:25:34.408Z] [2019/11/12 15:25:21.154 +08:00] [INFO] [client.go:163] ["[pd] init cluster id"] [cluster-id=6758317773105027983]
[2019-11-12T07:25:34.408Z] [2019/11/12 15:25:21.359 +08:00] [INFO] [2pc.go:313] ["[BIG_TXN]"] [con=0] ["table ID"=0] [size=4194312] [keys=2049] [puts=2049] [dels=0] [locks=0] [txnStartTS=412494992807297038]
[2019-11-12T07:25:34.408Z] [2019/11/12 15:25:21.521 +08:00] [INFO] [client_batch.go:298] ["batchRecvLoop re-create streaming fail"] [target=127.0.0.1:40000] [error="context deadline exceeded"]
[2019-11-12T07:25:34.408Z] [2019/11/12 15:25:22.198 +08:00] [INFO] [lock_resolver.go:524] ["resolveLock rollback"] [lock="key: []byte{0x6b, 0x65, 0x79}, primary: []byte{0x6b, 0x65, 0x79}, txnStartTS: 412494992807297034, ttl: 1001, type: Put"]
[2019-11-12T07:25:34.408Z]

https://internal.pingcap.net/idc-jenkins/blue/rest/organizations/jenkins/pipelines/tidb_ghpr_integration_common_test/runs/7234/nodes/119/steps/308/log/?start=0

The text was updated successfully, but these errors were encountered:

SunRunAway · 2020-09-17T06:23:09Z

Another occurrence in the release-3.0 branch

https://internal.pingcap.net/idc-jenkins/blue/organizations/jenkins/tidb_ghpr_integration_common_test/detail/tidb_ghpr_integration_common_test/19080/pipeline

@tiancaiamao PTAL

tiancaiamao · 2020-09-17T08:47:13Z

From the stack information, something is wrong with PD:

rpc error: code = Canceled desc = context canceled
github.com/pingcap/pd/client.(*client).processTSORequests
	/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/pkg/mod/github.com/pingcap/pd@v1.1.0-beta.0.20191223090411-ea2b748f6ee2/client/client.go:484
github.com/pingcap/pd/client.(*client).tsLoop
	/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/pkg/mod/github.com/pingcap/pd@v1.1.0-beta.0.20191223090411-ea2b748f6ee2/client/client.go:433
runtime.goexit
	/usr/local/go/src/runtime/asm_amd64.s:1357
github.com/pingcap/pd/client.(*tsoRequest).Wait
	/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/pkg/mod/github.com/pingcap/pd@v1.1.0-beta.0.20191223090411-ea2b748f6ee2/client/client.go:601
github.com/pingcap/pd/client.(*client).GetTS
	/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/pkg/mod/github.com/pingcap/pd@v1.1.0-beta.0.20191223090411-ea2b748f6ee2/client/client.go:617
github.com/pingcap/tidb/store/tikv/oracle/oracles.(*pdOracle).getTimestamp
	/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/src/github.com/pingcap/tidb/store/tikv/oracle/oracles/pd.go:103
github.com/pingcap/tidb/store/tikv/oracle/oracles.(*pdOracle).updateTS
	/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/src/github.com/pingcap/tidb/store/tikv/oracle/oracles/pd.go:127
runtime.goexit
	/usr/local/go/src/runtime/asm_amd64.s:1357
github.com/pingcap/errors.AddStack
	/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/pkg/mod/github.com/pingcap/errors@v0.11.4/errors.go:174
github.com/pingcap/errors.Trace
	/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/pkg/mod/github.com/pingcap/errors@v0.11.4/juju_adaptor.go:15
github.com/pingcap/tidb/store/tikv/oracle/oracles.(*pdOracle).getTimestamp
	/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/src/github.com/pingcap/tidb/store/tikv/oracle/oracles/pd.go:105
github.com/pingcap/tidb/store/tikv/oracle/oracles.(*pdOracle).updateTS
	/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/src/github.com/pingcap/tidb/store/tikv/oracle/oracles/pd.go:127
runtime.goexit
	/usr/local/go/src/runtime/asm_amd64.s:1357"] [stack="github.com/pingcap/tidb/store/tikv/oracle/oracles.(*pdOracle).updateTS
	/home/jenkins/agent/workspace/tidb_ghpr_integration_common_test/go/src/github.com/pingcap/tidb/store/tikv/oracle/oracles/pd.go:129"

tiancaiamao · 2020-12-02T03:45:45Z

This issue is old and maybe the PD or environment problem has gone, so I'll close it.

ti-srebot · 2020-12-02T03:45:49Z

Please edit this comment or add a new comment to complete the following information

Not a bug

Remove the 'type/bug' label
Add notes to indicate why it is not a bug

Duplicate bug

Add the 'type/duplicate' label
Add the link to the original bug

Bug

Note: Make Sure that 'component', and 'severity' labels are added
Example for how to fill out the template: #20100

1. Root Cause Analysis (RCA) (optional)

2. Symptom (optional)

3. All Trigger Conditions (optional)

4. Workaround (optional)

5. Affected versions

6. Fixed versions

wjhuang2016 added the type/bug The issue is confirmed as a bug. label Nov 12, 2019

SunRunAway added the component/test label Nov 12, 2019

tiancaiamao self-assigned this Nov 13, 2019

This was referenced Nov 13, 2019

kvrpcpb: record rollback reason in the CheckTxnStatus response pingcap/kvproto#491

Merged

store: update kvproto.CheckTxnStatus response #13432

Merged

qw4990 added the severity/moderate label Aug 25, 2020

tiancaiamao closed this as completed Dec 2, 2020

ti-srebot added the need-more-info label Dec 2, 2020

tiancaiamao added the status/can't-reproduce label Dec 2, 2020

ti-srebot removed the need-more-info label Dec 2, 2020

tisonkun added the invalid label Sep 12, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

TestGetTxnStatus failed in integration_common_test #13397

TestGetTxnStatus failed in integration_common_test #13397

wjhuang2016 commented Nov 12, 2019 •

edited by SunRunAway

Loading

SunRunAway commented Sep 17, 2020

tiancaiamao commented Sep 17, 2020

tiancaiamao commented Dec 2, 2020

ti-srebot commented Dec 2, 2020

TestGetTxnStatus failed in integration_common_test #13397

TestGetTxnStatus failed in integration_common_test #13397

Comments

wjhuang2016 commented Nov 12, 2019 • edited by SunRunAway Loading

Bug Report

SunRunAway commented Sep 17, 2020

tiancaiamao commented Sep 17, 2020

tiancaiamao commented Dec 2, 2020

ti-srebot commented Dec 2, 2020

Please edit this comment or add a new comment to complete the following information

Not a bug

Duplicate bug

Bug

1. Root Cause Analysis (RCA) (optional)

2. Symptom (optional)

3. All Trigger Conditions (optional)

4. Workaround (optional)

5. Affected versions

6. Fixed versions

wjhuang2016 commented Nov 12, 2019 •

edited by SunRunAway

Loading