Range failed to find revision pair #10713

nolouch · 2019-05-09T06:38:34Z

Version: etcd master + commit:77d4b742cdbf
The stack:

[2019/05/06 14:07:16.998 +00:00] [FATAL] [kvstore_txn.go:148] ["range failed to find revision pair"] [revision-main=0] [revision-sub=0] 
[stack="go.etcd.io/etcd/mvcc.(*storeTxnRead).rangeKeys
/home/jenkins/workspace/build_pd_master/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/mvcc/kvstore_txn.go:148
go.etcd.io/etcd/mvcc.(*storeTxnRead).Range
/home/jenkins/workspace/build_pd_master/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/mvcc/kvstore_txn.go:50
go.etcd.io/etcd/mvcc.(*metricsTxnWrite).Range
/home/jenkins/workspace/build_pd_master/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/mvcc/metrics_txn.go:36
go.etcd.io/etcd/etcdserver.(*applierV3backend).Range
/home/jenkins/workspace/build_pd_master/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/apply.go:275
go.etcd.io/etcd/etcdserver.(*EtcdServer).Range.func3
/home/jenkins/workspace/build_pd_master/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/v3_server.go:104
go.etcd.io/etcd/etcdserver.(*EtcdServer).doSerialize
/home/jenkins/workspace/build_pd_master/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/v3_server.go:554
go.etcd.io/etcd/etcdserver.(*EtcdServer).Range
/home/jenkins/workspace/build_pd_master/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/v3_server.go:105
go.etcd.io/etcd/etcdserver/api/v3rpc.(*kvServer).Range
/home/jenkins/workspace/build_pd_master/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/api/v3rpc/key.go:52
go.etcd.io/etcd/etcdserver/etcdserverpb._KV_Range_Handler.func1
/home/jenkins/workspace/build_pd_master/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/etcdserverpb/rpc.pb.go:3473
github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1
/home/jenkins/workspace/build_pd_master/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.0.1-0.20190118093823-f849b5445de4/chain.go:31
github.com/grpc-ecosystem/go-grpc-prometheus.(*ServerMetrics).UnaryServerInterceptor.func1
/home/jenkins/workspace/build_pd_master/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-prometheus@v1.2.0/server_metrics.go:107
github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1
/home/jenkins/workspace/build_pd_master/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.0.1-0.20190118093823-f849b5445de4/chain.go:34
go.etcd.io/etcd/etcdserver/api/v3rpc.newUnaryInterceptor.func1
/home/jenkins/workspace/build_pd_master/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/api/v3rpc/interceptor.go:60
github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1
/home/jenkins/workspace/build_pd_master/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.0.1-0.20190118093823-f849b5445de4/chain.go:34
go.etcd.io/etcd/etcdserver/api/v3rpc.newLogUnaryInterceptor.func1
/home/jenkins/workspace/build_pd_master/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/api/v3rpc/interceptor.go:67
github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1
/home/jenkins/workspace/build_pd_master/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.0.1-0.20190118093823-f849b5445de4/chain.go:39
go.etcd.io/etcd/etcdserver/etcdserverpb._KV_Range_Handler
/home/jenkins/workspace/build_pd_master/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/etcdserverpb/rpc.pb.go:3475
google.golang.org/grpc.(*Server).processUnaryRPC
/home/jenkins/workspace/build_pd_master/go/pkg/mod/google.golang.org/grpc@v1.14.0/server.go:1026
google.golang.org/grpc.(*Server).handleStream
/home/jenkins/workspace/build_pd_master/go/pkg/mod/google.golang.org/grpc@v1.14.0/server.go:1252
google.golang.org/grpc.(*Server).serveStreams.func1.1
/home/jenkins/workspace/build_pd_master/go/pkg/mod/google.golang.org/grpc@v1.14.0/server.go:699"]
2019/05/06 14:07:17 daemon.go:225: [warning] daemon pd exit with error exit status 1

What situation will this error occur, is this normal?

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

jingyih · 2019-05-09T20:21:00Z

[2019/05/06 14:07:16.998 +00:00] [FATAL] [kvstore_txn.go:148] ["range failed to find revision pair"] [revision-main=0] [revision-sub=0]

Is this reproducible? Can you enable --debug flag so we can trace which request ended up looking for [revision-main=0] [revision-sub=0]?
The backend store starts with main revision 1 (see [1]). It will be increased if there is mutating request, but should never decrease.

[1]

etcd/mvcc/kvstore.go

Line 119 in e899023

currentRev: 1,

spzala · 2019-05-09T20:44:56Z

[2019/05/06 14:07:16.998 +00:00] [FATAL] [kvstore_txn.go:148] ["range failed to find revision pair"] [revision-main=0] [revision-sub=0]

Is this reproducible? Can you enable --debug flag so we can trace which request ended up looking for [revision-main=0] [revision-sub=0]?
The backend store starts with main revision 1 (see [1]). It will be increased if there is mutating request, but should never decrease.

[1]

etcd/mvcc/kvstore.go

Line 119 in e899023

currentRev: 1,

Thanks @jingyih I also tried reproduce it but I couldn't so far with normal txn operations.

shafreeck · 2019-12-12T07:19:54Z

backtrace for the same error.

[2019/12/12 02:10:12.305 +08:00] [FATAL] [kvstore_txn.go:148] ["range failed to find revision pair"] [revision-main=101406223] [revision-sub=0]
go.etcd.io/etcd/mvcc.(*storeTxnRead).rangeKeys
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/mvcc/kvstore_txn.go:148
go.etcd.io/etcd/mvcc.(*storeTxnRead).Range
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/mvcc/kvstore_txn.go:50
go.etcd.io/etcd/mvcc.(*metricsTxnWrite).Range
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/mvcc/metrics_txn.go:36
go.etcd.io/etcd/etcdserver.(*applierV3backend).Range
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/apply.go:275
go.etcd.io/etcd/etcdserver.(*EtcdServer).Range.func3
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/v3_server.go:104
go.etcd.io/etcd/etcdserver.(*EtcdServer).doSerialize
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/v3_server.go:554
go.etcd.io/etcd/etcdserver.(*EtcdServer).Range
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/v3_server.go:105
go.etcd.io/etcd/etcdserver/api/v3rpc.(*kvServer).Range
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/api/v3rpc/key.go:52
go.etcd.io/etcd/etcdserver/etcdserverpb._KV_Range_Handler.func1
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/etcdserverpb/rpc.pb.go:3473
github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.0.1-0.20190118093823-f849b5445de4/chain.go:31
github.com/grpc-ecosystem/go-grpc-prometheus.(*ServerMetrics).UnaryServerInterceptor.func1
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-prometheus@v1.2.0/server_metrics.go:107
github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.0.1-0.20190118093823-f849b5445de4/chain.go:34
go.etcd.io/etcd/etcdserver/api/v3rpc.newUnaryInterceptor.func1
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/api/v3rpc/interceptor.go:60
github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1.1
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.0.1-0.20190118093823-f849b5445de4/chain.go:34
go.etcd.io/etcd/etcdserver/api/v3rpc.newLogUnaryInterceptor.func1
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/api/v3rpc/interceptor.go:67
github.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryServer.func1
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/github.com/grpc-ecosystem/go-grpc-middleware@v1.0.1-0.20190118093823-f849b5445de4/chain.go:39
go.etcd.io/etcd/etcdserver/etcdserverpb._KV_Range_Handler
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190320044326-77d4b742cdbf/etcdserver/etcdserverpb/rpc.pb.go:3475
google.golang.org/grpc.(*Server).processUnaryRPC
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/google.golang.org/grpc@v1.14.0/server.go:1026
google.golang.org/grpc.(*Server).handleStream
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/google.golang.org/grpc@v1.14.0/server.go:1252
google.golang.org/grpc.(*Server).serveStreams.func1.1
        /home/jenkins/workspace/release_tidb_3.0/go/pkg/mod/google.golang.org/grpc@v1.14.0/server.go:699

xiang90 · 2019-12-14T00:59:23Z

what is the version of etcd?

nolouch · 2019-12-15T16:35:16Z

Hi @xiang90 , the commit is 77d4b7, recently we meet it twice.

etcd Version: 3.3.0+git
Git SHA: 77d4b742c
Go Version: go1.13.4

shafreeck · 2019-12-18T06:30:35Z

@xiang90 In which case will this happen? It is really a terrible problem when the etcd is used in critical services.

shafreeck · 2019-12-18T10:31:44Z

I am wondering if this PR(#10772) fixed the problem? @xiang90 @jingyih Do you guys have any ideas about this?

jingyih · 2019-12-18T18:41:34Z

I am wondering if this PR(#10772) fixed the problem? @xiang90 @jingyih Do you guys have any ideas about this?

Commits reverted in #10772 were never released. They were reverted before 3.4 release.

shafreeck · 2019-12-19T03:30:25Z

@jingyih We used the version: etcd master + commit:77d4b742cdbf, so the bug is included.

xiang90 · 2019-12-20T04:14:11Z

@shafreeck possibly. so please switch a released version of etcd.

shafreeck · 2019-12-20T08:25:19Z

@xiang90 Thanks, I am going to reproduce this bug first.

shafreeck · 2019-12-25T11:16:48Z

Problem reproduced when issuing PUT/DELETE/RANGE requests concurrently, DELETE maybe not necessary.

# 1. Install fperf for etcd benchmark
go get github.com/fperf/etcd/bin/fperf

# 2. Run etcd with compaction enabled
bin/etcd --auto-compaction-mode=revision --auto-compaction-retention=1000

# 3. Run these commands concurrently
fperf -server http://127.0.0.1:2379 -tick 1s -connection 256 etcd -key-size 2 put
fperf -server http://127.0.0.1:2379 -tick 1s -connection 256 etcd -key-size 2 range
fperf -server http://127.0.0.1:2379 -tick 1s -connection 256 etcd -key-size 2 delete

etcd fatal error caused.

2019-12-24 11:13:41.580505 I | etcdserver: start to snapshot (applied: 1405428622, lastsnap: 1405328544)
2019-12-24 11:13:41.591700 I | etcdserver: saved snapshot at index 1405428622
2019-12-24 11:13:41.592093 I | etcdserver: compacted raft log at 1405423622
2019-12-24 11:13:46.715227 I | etcdserver: start to snapshot (applied: 1405528670, lastsnap: 1405428622)
2019-12-24 11:13:46.735011 I | etcdserver: saved snapshot at index 1405528670
2019-12-24 11:13:46.735204 I | etcdserver: compacted raft log at 1405523670
2019-12-24 11:13:47.773566 C | mvcc: range cannot find rev (0,0)

shafreeck · 2019-12-25T13:36:49Z

@xiang90 @jingyih
Although #10772 fixed the problem, it didn't describe the bug correctly. There are two problems in the Clone version.

Clone is not thread-safe, it is Lock not RLock that should be used.
keyIndex is not thread-safe, race condition occurs even if the Clone is locked.

xiang90 · 2020-01-02T16:14:36Z

cloning since the root cause is found and already fixed

xiang90 closed this as completed Jan 2, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Range failed to find revision pair #10713

Range failed to find revision pair #10713

nolouch commented May 9, 2019 •

edited

Loading

jingyih commented May 9, 2019

spzala commented May 9, 2019

shafreeck commented Dec 12, 2019 •

edited

Loading

xiang90 commented Dec 14, 2019

nolouch commented Dec 15, 2019 •

edited

Loading

shafreeck commented Dec 18, 2019

shafreeck commented Dec 18, 2019 •

edited

Loading

jingyih commented Dec 18, 2019 •

edited

Loading

shafreeck commented Dec 19, 2019

xiang90 commented Dec 20, 2019

shafreeck commented Dec 20, 2019

shafreeck commented Dec 25, 2019 •

edited

Loading

shafreeck commented Dec 25, 2019

xiang90 commented Jan 2, 2020

Range failed to find revision pair #10713

Range failed to find revision pair #10713

Comments

nolouch commented May 9, 2019 • edited Loading

jingyih commented May 9, 2019

spzala commented May 9, 2019

shafreeck commented Dec 12, 2019 • edited Loading

xiang90 commented Dec 14, 2019

nolouch commented Dec 15, 2019 • edited Loading

shafreeck commented Dec 18, 2019

shafreeck commented Dec 18, 2019 • edited Loading

jingyih commented Dec 18, 2019 • edited Loading

shafreeck commented Dec 19, 2019

xiang90 commented Dec 20, 2019

shafreeck commented Dec 20, 2019

shafreeck commented Dec 25, 2019 • edited Loading

shafreeck commented Dec 25, 2019

xiang90 commented Jan 2, 2020

nolouch commented May 9, 2019 •

edited

Loading

shafreeck commented Dec 12, 2019 •

edited

Loading

nolouch commented Dec 15, 2019 •

edited

Loading

shafreeck commented Dec 18, 2019 •

edited

Loading

jingyih commented Dec 18, 2019 •

edited

Loading

shafreeck commented Dec 25, 2019 •

edited

Loading