RAFT membership can fail to remove peers

Users Dgraph
1

Continuing the discussion from Raft group cannot pass leader election:

Our production system has encountered the precursor to the above linked issue again, where the raftwal implementation in dgraph has some issue that can cause members to not be removed correctly after /removeNode is called to remove a dgraph node.

It appears to stem from the call to /removeNode, which causes the other nodes to drop their full-mesh grpc connections to that node. Then, the raftwal implementation will panic:

W1106 17:40:07.398988      24 pool.go:130] DISCONNECTING from graphdb-a-dgraph-alpha-10.graphdb-a-dgraph-alpha-headless.data-engine.svc.cluster.local:7080
W1106 17:40:07.399019      24 pool.go:204] Shutting down extra connection to graphdb-a-dgraph-alpha-10.graphdb-a-dgraph-alpha-headless.data-engine.svc.cluster.l
ocal:7080
W1106 17:40:07.899721      24 node.go:420] Unable to send message to peer: 0x1e. Error: context canceled
W1106 17:40:09.050903      24 node.go:420] Unable to send message to peer: 0x1e. Error: No connection exists
I1106 17:40:10.444659      24 log.go:34] 15 is starting a new election at term 264
I1106 17:40:10.444687      24 log.go:34] 15 became pre-candidate at term 264
I1106 17:40:10.444693      24 log.go:34] 15 received MsgPreVoteResp from 15 at term 264
I1106 17:40:10.444708      24 log.go:34] 15 [logterm: 264, index: 59743866] sent MsgPreVote request to b at term 264
I1106 17:40:10.444716      24 log.go:34] 15 [logterm: 264, index: 59743866] sent MsgPreVote request to 1e at term 264
I1106 17:40:10.444727      24 log.go:34] raft.node: 15 lost leader 1e at term 264
I1106 17:40:12.446671      24 log.go:34] 15 received MsgPreVoteResp from b at term 264
I1106 17:40:12.446695      24 log.go:34] 15 [quorum:2] has received 2 MsgPreVoteResp votes and 0 vote rejections
I1106 17:40:12.446705      24 log.go:34] 15 became candidate at term 265
I1106 17:40:12.446708      24 log.go:34] 15 received MsgVoteResp from 15 at term 265
I1106 17:40:12.446714      24 log.go:34] 15 [logterm: 264, index: 59743866] sent MsgVote request to b at term 265
I1106 17:40:12.446719      24 log.go:34] 15 [logterm: 264, index: 59743866] sent MsgVote request to 1e at term 265
I1106 17:40:12.446731      24 log.go:34] 15 [logterm: 264, index: 59743866, vote: 15] rejected MsgPreVote from b [logterm: 264, index: 59743866] at term 265
I1106 17:40:12.447306      24 log.go:34] 15 received MsgVoteResp from b at term 265
I1106 17:40:12.447325      24 log.go:34] 15 [quorum:2] has received 2 MsgVoteResp votes and 0 vote rejections
I1106 17:40:12.447335      24 log.go:34] 15 became leader at term 265
I1106 17:40:12.447342      24 log.go:34] raft.node: 15 elected leader 15 at term 265
I1106 17:40:13.344454      24 groups.go:906] Leader idx=0x15 of group=4 is connecting to Zero for txn updates
I1106 17:40:13.344481      24 groups.go:918] Got Zero leader: graphdb-a-dgraph-zero-2.graphdb-a-dgraph-zero-headless.data-engine.svc.cluster.local:5080
panic: field raftpb.Entry.Type has invalid type: got raftpb.EntryType, want pointer

goroutine 8690 [running]:
google.golang.org/protobuf/internal/impl.fieldInfoForScalar(0x240d6f8, 0xc00795e000, 0x1e87157, 0x4, 0x0, 0x0, 0x240d808, 0x1efc160, 0x1e8715d, 0x43, ...)
        /go/pkg/mod/google.golang.org/protobuf@v1.25.0/internal/impl/message_reflect_field.go:228 +0x7f7
google.golang.org/protobuf/internal/impl.(*MessageInfo).makeKnownFieldsFunc(0xc00063c000, 0xffffffffffffffff, 0xffffffffffffffff, 0x30, 0xffffffffffffffff, 0xc0
37476db0, 0xc037476de0, 0xc037476f00, 0xc037476f30)
        /go/pkg/mod/google.golang.org/protobuf@v1.25.0/internal/impl/message_reflect.go:67 +0x99d
google.golang.org/protobuf/internal/impl.(*MessageInfo).makeReflectFuncs(0xc00063c000, 0x240d808, 0x1ff02a0, 0xffffffffffffffff, 0xffffffffffffffff, 0x30, 0xfff
fffffffffffff, 0xc037476db0, 0xc037476de0, 0xc037476f00, ...)
        /go/pkg/mod/google.golang.org/protobuf@v1.25.0/internal/impl/message_reflect.go:36 +0x65
google.golang.org/protobuf/internal/impl.(*MessageInfo).initOnce(0xc00063c000)
        /go/pkg/mod/google.golang.org/protobuf@v1.25.0/internal/impl/message.go:90 +0x195
google.golang.org/protobuf/internal/impl.(*MessageInfo).init(...)
        /go/pkg/mod/google.golang.org/protobuf@v1.25.0/internal/impl/message.go:72
google.golang.org/protobuf/internal/impl.(*messageReflectWrapper).Has(0xc02baebe00, 0x240d6f8, 0xc00795e000, 0xc00795e000)
        /go/pkg/mod/google.golang.org/protobuf@v1.25.0/internal/impl/message_reflect_gen.go:185 +0xf9
github.com/golang/protobuf/proto.(*textWriter).writeMessage(0xc037476d50, 0x24055f0, 0xc02baebe00, 0x0, 0x0)
        /go/pkg/mod/github.com/golang/protobuf@v1.4.1/proto/text_encode.go:278 +0x131e
github.com/golang/protobuf/proto.(*TextMarshaler).marshal(0x2f8b03e, 0x23e54e8, 0xc00e06b8b0, 0xc000132ef0, 0xb49501, 0xc011b1bcc8, 0x0, 0x0)
        /go/pkg/mod/github.com/golang/protobuf@v1.4.1/proto/text_encode.go:86 +0x193
github.com/golang/protobuf/proto.(*TextMarshaler).Text(...)
        /go/pkg/mod/github.com/golang/protobuf@v1.4.1/proto/text_encode.go:44
github.com/golang/protobuf/proto.CompactTextString(...)
        /go/pkg/mod/github.com/golang/protobuf@v1.4.1/proto/text_encode.go:106
go.etcd.io/etcd/raft/raftpb.(*Entry).String(...)
        /go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190228193606-a943ad0ee4c9/raft/raftpb/raft.pb.go:212
go.etcd.io/etcd/raft.stepLeader(0xc0009b4500, 0x2, 0x0, 0x15, 0x0, 0x0, 0x0, 0xc00ecb3e50, 0x1, 0x1, ...)
        /go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190228193606-a943ad0ee4c9/raft/raft.go:1012 +0x230
go.etcd.io/etcd/raft.(*raft).Step(0xc0009b4500, 0x2, 0x0, 0x15, 0x0, 0x0, 0x0, 0xc00ecb3e50, 0x1, 0x1, ...)
        /go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190228193606-a943ad0ee4c9/raft/raft.go:971 +0x1235
go.etcd.io/etcd/raft.(*node).run(0xc0085125a0, 0xc0009b4500)
        /go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190228193606-a943ad0ee4c9/raft/node.go:349 +0xb98
created by go.etcd.io/etcd/raft.RestartNode
        /go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190228193606-a943ad0ee4c9/raft/node.go:246 +0x326

When this piece of code in etcd/raft panics, it will not remove that node correctly from the raftwal and when it restarts will act as if that removed node should participate in elections, failing to contact him with:

W1106 18:56:49.811625      22 node.go:420] Unable to send message to peer: 0x1e. Error: Do not have address of peer 0x1e

If this happens twice with a raft group size of 3, then the raft group is broken forever.

Dgraph version   : v21.03.1
Dgraph codename  : rocket-1
Dgraph SHA-256   : a00b73d583a720aa787171e43b4cb4dbbf75b38e522f66c9943ab2f0263007fe
Commit SHA-1     : ea1cb5f35
Commit timestamp : 2021-06-17 20:38:11 +0530
Branch           : HEAD
Go version       : go1.16.2
jemalloc enabled : true
1 Like
2

I just found this post by @Naman that tracked this down earlier this year to the use of gogo/protobuf with golang/protobuf. Has this been resolved in a newer version?

Edit: I see this commit to upgrade protobuf to v1.5.2 - which happened in v21.03.2 (one patch version past what I am running). Sounds like I need to upgrade - can someone confirm when they have time?

1 Like
3

I know this reply is seven months later, but I did successfully test Alpha node removal and replacement with v21.03.2 today.

v21.03.1 always resulted in the error “panic: field raftpb.Entry.Type has invalid type: got raftpb.EntryType, want pointer” when swapping in a second node because the removing the first node didn’t seem to completely remove.

Zero node removal/replacement seemed to work for me in 21.03.1, but also confirmed with 21.03.2.

I still see an issue though where the Zero nodes are trying to connect to nodes that have been removed (and clearly appear marked as removed using the state API). I don’t see this causing any issues other than the overhead and the increase in logfile size.

1 Like