panic: slice[2,2) out of bound [1,0] in raft.MemoryStorage

[khanh101]

go version: go version go1.17.5 darwin/arm64 raft version: go.etcd.io/etcd/raft/v3 v3.5.1

minimum reproducible example:

package main

import (
	"context"
	"fmt"
	"go.etcd.io/etcd/raft/v3"
	"go.etcd.io/etcd/raft/v3/raftpb"
	"time"
)

var chMap = make(map[uint64]chan raftpb.Message)

func send(mList []raftpb.Message) {
	for _, m := range mList {
		select {
		case chMap[m.To] <- m:
		}
	}
}

func main() {
	id := uint64(1)
	ch := make(chan raftpb.Message, 1024)
	chMap[id] = ch
	stable := &dummyStorage{}
	node := StartSingletonCluster(stable, send, ch)
	_ = node
	<-context.Background().Done()
	return
}

func loop(node raft.Node, storage Storage, send func([]raftpb.Message), recv <-chan raftpb.Message) {
	ticker := time.NewTicker(100 * time.Millisecond)
	defer ticker.Stop()
	for {
		select {
		case <-ticker.C:
			node.Tick()
		case msg := <-recv:
			err := node.Step(context.Background(), msg)
			if err != nil {
				panic(err)
			}
		case event := <-node.Ready():
			err := storage.Save(event.HardState, event.Entries)
			if err != nil {
				panic(err)
			}
			send(event.Messages)

			if !raft.IsEmptySnap(event.Snapshot) {
				fmt.Println(event.Snapshot)
			}
			for _, entry := range event.CommittedEntries {
				switch entry.Type {
				case raftpb.EntryNormal:
					fmt.Println(entry)
				case raftpb.EntryConfChange:
					cc := &raftpb.ConfChange{}
					err = cc.Unmarshal(entry.Data)
					if err != nil {
						panic(err)
					}
					node.ApplyConfChange(cc)
				}
			}
			node.Advance()
		}
	}
}

func StartSingletonCluster(storage Storage, send func([]raftpb.Message), recv <-chan raftpb.Message) raft.Node {
	memoryStorage := raft.NewMemoryStorage()
	cfg := &raft.Config{
		ID:              0x1,
		ElectionTick:    10,
		HeartbeatTick:   1,
		Storage:         memoryStorage,
		MaxSizePerMsg:   4096,
		MaxInflightMsgs: 256,
	}
	node := raft.StartNode(cfg, []raft.Peer{{ID: 0x1}})
	go loop(node, storage, send, recv)
	return node
}

// Storage : stable storage
type Storage interface {
	Load() (state raftpb.HardState, entries []raftpb.Entry, err error)
	Save(state raftpb.HardState, entries []raftpb.Entry) error
}

type dummyStorage struct {
}

func (s *dummyStorage) Load() (state raftpb.HardState, entries []raftpb.Entry, err error) {
	return raftpb.HardState{}, nil, nil
}
func (s *dummyStorage) Save(state raftpb.HardState, entries []raftpb.Entry) error {
	return nil
}

output log:

GOROOT=/opt/local/lib/go #gosetup
GOPATH=/Users/khanh/go #gosetup
/opt/local/lib/go/bin/go build -o /private/var/folders/mw/wjqb2vs507s8grf_5tsmsr8c0000gn/T/GoLand/___go_build_github_com_khanh_nguyen_code_go_util_cmd_testraft github.com/khanh-nguyen-code/go_util/cmd/testraft #gosetup
/private/var/folders/mw/wjqb2vs507s8grf_5tsmsr8c0000gn/T/GoLand/___go_build_github_com_khanh_nguyen_code_go_util_cmd_testraft
1 <nil>
0 <nil>
raft2022/01/17 05:03:07 INFO: 1 switched to configuration voters=()
raft2022/01/17 05:03:07 INFO: 1 became follower at term 0
raft2022/01/17 05:03:07 INFO: newRaft 1 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
raft2022/01/17 05:03:07 INFO: 1 became follower at term 1
raft2022/01/17 05:03:07 INFO: 1 switched to configuration voters=(1)
raft2022/01/17 05:03:07 INFO: 1 switched to configuration voters=(1)
raft2022/01/17 05:03:09 slice[2,2) out of bound [1,0]
panic: slice[2,2) out of bound [1,0]

goroutine 18 [running]:
log.(*Logger).Panicf(0x1400010c140, {0x104f3a0d2, 0x21}, {0x140000940c0, 0x4, 0x4})
        /opt/local/lib/go/src/log/log.go:231 +0xa0
go.etcd.io/etcd/raft/v3.(*DefaultLogger).Panicf(0x1051e16f0, {0x104f3a0d2, 0x21}, {0x140000940c0, 0x4, 0x4})
        /Users/khanh/Projects/go_util/vendor/go.etcd.io/etcd/raft/v3/logger.go:137 +0x54
go.etcd.io/etcd/raft/v3.(*raftLog).mustCheckOutOfBounds(0x140001527e0, 0x2, 0x2)
        /Users/khanh/Projects/go_util/vendor/go.etcd.io/etcd/raft/v3/log.go:392 +0x2c8
go.etcd.io/etcd/raft/v3.(*raftLog).slice(0x140001527e0, 0x2, 0x2, 0xffffffffffffffff)
        /Users/khanh/Projects/go_util/vendor/go.etcd.io/etcd/raft/v3/log.go:341 +0x38
go.etcd.io/etcd/raft/v3.(*raft).hup(0x140001511e0, {0x104f334bd, 0x10})
        /Users/khanh/Projects/go_util/vendor/go.etcd.io/etcd/raft/v3/raft.go:764 +0x198
go.etcd.io/etcd/raft/v3.(*raft).Step(0x140001511e0, {0x0, 0x0, 0x1, 0x0, 0x0, 0x0, {0x0, 0x0, 0x0}, ...})
        /Users/khanh/Projects/go_util/vendor/go.etcd.io/etcd/raft/v3/raft.go:921 +0xc24
go.etcd.io/etcd/raft/v3.(*raft).tickElection(0x140001511e0)
        /Users/khanh/Projects/go_util/vendor/go.etcd.io/etcd/raft/v3/raft.go:650 +0x11c
go.etcd.io/etcd/raft/v3.(*RawNode).Tick(...)
        /Users/khanh/Projects/go_util/vendor/go.etcd.io/etcd/raft/v3/rawnode.go:59
go.etcd.io/etcd/raft/v3.(*node).run(0x1400012a240)
        /Users/khanh/Projects/go_util/vendor/go.etcd.io/etcd/raft/v3/node.go:390 +0xa14
created by go.etcd.io/etcd/raft/v3.StartNode
        /Users/khanh/Projects/go_util/vendor/go.etcd.io/etcd/raft/v3/node.go:230 +0x274

Process finished with the exit code 2

[zeu5]

In the event loop, you need to call storage.Append(Entries) before calling node.Advance(). The error originates from the storage not having the entries raft is looking for.

[stale[bot]]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed after 21 days if no further activity occurs. Thank you for your contributions.