hashicorp/raft

Use pebbledb as raft logstore & stablestore, restart raft cluster nodes all pebbledb data will be lost?

xkeyideal opened this issue · 13 comments

xkeyideal commented 
./raft-example --raft_bootstrap --raft_id=nodeA --grpc_addr=localhost:40051 --raft_addr=localhost:50051 --raft_data_dir /Users/xkey/test
2023-09-19T17:07:54.556+0800 [INFO]  raft: initial configuration: index=0 servers=[]
2023-09-19T17:07:54.557+0800 [INFO]  raft: entering follower state: follower="Node at 127.0.0.1:50051 [Follower]" leader-address= leader-id=
2023-09-19T17:07:56.552+0800 [WARN]  raft: heartbeat timeout reached, starting election: last-leader-addr= last-leader-id=
2023-09-19T17:07:56.552+0800 [INFO]  raft: entering candidate state: node="Node at 127.0.0.1:50051 [Candidate]" term=2
2023-09-19T17:07:56.556+0800 [DEBUG] raft: voting for self: term=2 id=nodeA
2023-09-19T17:07:56.569+0800 [DEBUG] raft: calculated votes needed: needed=1 term=2
2023-09-19T17:07:56.569+0800 [DEBUG] raft: vote granted: from=nodeA term=2 tally=1
2023-09-19T17:07:56.569+0800 [INFO]  raft: election won: term=2 tally=1
2023-09-19T17:07:56.569+0800 [INFO]  raft: entering leader state: leader="Node at 127.0.0.1:50051 [Leader]"
2023-09-19T17:08:21.714+0800 [INFO]  raft: updating configuration: command=AddVoter server-id=nodeC server-addr=localhost:50053 servers="[{Suffrage:Voter ID:nodeA Address:localhost:50051} {Suffrage:Voter ID:nodeC Address:localhost:50053}]"
2023-09-19T17:08:21.740+0800 [INFO]  raft: added peer, starting replication: peer=nodeC
2023-09-19T17:08:21.760+0800 [WARN]  raft: appendEntries rejected, sending older logs: peer="{Voter nodeC localhost:50053}" next=1
2023-09-19T17:08:21.795+0800 [INFO]  raft: pipelining replication: peer="{Voter nodeC localhost:50053}"
2023-09-19T17:08:28.845+0800 [INFO]  raft: updating configuration: command=AddVoter server-id=nodeB server-addr=localhost:50052 servers="[{Suffrage:Voter ID:nodeA Address:localhost:50051} {Suffrage:Voter ID:nodeC Address:localhost:50053} {Suffrage:Voter ID:nodeB Address:localhost:50052}]"
2023-09-19T17:08:28.878+0800 [INFO]  raft: added peer, starting replication: peer=nodeB
2023-09-19T17:08:28.901+0800 [WARN]  raft: appendEntries rejected, sending older logs: peer="{Voter nodeB localhost:50052}" next=1
2023-09-19T17:08:28.960+0800 [INFO]  raft: pipelining replication: peer="{Voter nodeB localhost:50052}"

 ./raft-example --raft_id=nodeB --grpc_addr=localhost:40052 --raft_addr=localhost:50052 --raft_data_dir /Users/xkey/test
2023-09-19T17:08:01.896+0800 [INFO]  raft: initial configuration: index=0 servers=[]
2023-09-19T17:08:01.896+0800 [INFO]  raft: entering follower state: follower="Node at 127.0.0.1:50052 [Follower]" leader-address= leader-id=
2023-09-19T17:08:03.614+0800 [WARN]  raft: no known peers, aborting election
2023-09-19T17:08:28.901+0800 [WARN]  raft: failed to get previous log: previous-index=4 last-index=0 error="log not found"

./raft-example --raft_id=nodeC --grpc_addr=localhost:40053 --raft_addr=localhost:50053 --raft_data_dir /Users/xkey/test
2023-09-19T17:08:11.399+0800 [INFO]  raft: initial configuration: index=0 servers=[]
2023-09-19T17:08:11.399+0800 [INFO]  raft: entering follower state: follower="Node at 127.0.0.1:50053 [Follower]" leader-address= leader-id=
2023-09-19T17:08:12.668+0800 [WARN]  raft: no known peers, aborting election
2023-09-19T17:08:21.760+0800 [WARN]  raft: failed to get previous log: previous-index=3 last-index=0 error="log not found"

The nodeA, nodeB, nodeC be cluster. Then Ctrl-C stop the three cluster nodes. Restart them.

./raft-example --raft_id=nodeC --grpc_addr=localhost:40053 --raft_addr=localhost:50053 --raft_data_dir /Users/xkey/test
2023-09-19T17:11:13.270+0800 [INFO]  raft: initial configuration: index=0 servers=[]
2023-09-19T17:11:13.271+0800 [INFO]  raft: entering follower state: follower="Node at 127.0.0.1:50053 [Follower]" leader-address= leader-id=
2023-09-19T17:11:14.411+0800 [WARN]  raft: no known peers, aborting election

./raft-example --raft_id=nodeB --grpc_addr=localhost:40052 --raft_addr=localhost:50052 --raft_data_dir /Users/xkey/test
2023-09-19T17:11:25.589+0800 [INFO]  raft: initial configuration: index=0 servers=[]
2023-09-19T17:11:25.589+0800 [INFO]  raft: entering follower state: follower="Node at 127.0.0.1:50052 [Follower]" leader-address= leader-id=
2023-09-19T17:11:27.541+0800 [WARN]  raft: no known peers, aborting election

./raft-example --raft_id=nodeA --grpc_addr=localhost:40051 --raft_addr=localhost:50051 --raft_data_dir /Users/xkey/test
2023-09-19T17:11:48.310+0800 [INFO]  raft: initial configuration: index=0 servers=[]
2023-09-19T17:11:48.310+0800 [INFO]  raft: entering follower state: follower="Node at 127.0.0.1:50051 [Follower]" leader-address= leader-id=
2023-09-19T17:11:50.119+0800 [WARN]  raft: no known peers, aborting election

So I want to know what happenned it?

banks commented

Hi @xkeyideal I think we'd need a bit more information to be able to help here. I'm not sure what your raft-example program is actually doing here but I note that raft when it restarts doesn't have any configuration raft: initial configuration: index=0 servers=[] so I I'd guess your example program is not setting up raft correctly, or if that is an example that works with other backends, then your pebble backend seems not to be persisting state correctly? It's hard to be more help when I'm not even sure what code you are running though!

xkeyideal commented

@banks https://github.com/xkeyideal/raft-example app.go is bootstrap file.

I use hashicorp raft-boltdb as store, restart it all will be OK.

Please see my codes, I refer to https://github.com/Jille/raft-grpc-example/blob/master/main.go

xkeyideal commented

@banks I see the pebbledb data dir, the set datas be lost actually.

banks commented

I see the pebbledb data dir, the set datas be lost actually.

Seems like an issue with your pebble store then. I'm not an expert with that library so you may need to talk to the authors if you have followed the instructions and still aren't seeing data persisted.

I'd be fascinated to see how this turns out, but I don't think it's likely to be a bug in the raft library given that it works correctly with other stores.

xkeyideal commented

But I test pebbledb get/set kv datas, it's working.

package main

import (
	"log"
	"path/filepath"

	"github.com/hashicorp/raft"
	"github.com/xkeyideal/raft-example/fsm"
	pebbledb "github.com/xkeyideal/raft-pebbledb"
)

func testRaftLog(idx uint64, data string) *raft.Log {
	return &raft.Log{
		Data:  []byte(data),
		Index: idx,
	}
}

func main() {
	store, err := pebbledb.NewPebbleStore(filepath.Join("/Users/xkey/test/", "pebble-logdb"), &fsm.Logger{}, pebbledb.DefaultPebbleDBConfig())
	if err != nil {
		panic(err)
	}
	defer store.Close()

	// Should get 0 index on empty log
	idx, err := store.LastIndex()
	if err != nil {
		panic(err)
	}
	if idx != 0 {
		log.Println("getLastIndex", idx)
	}

	rlog := &raft.Log{}
	store.GetLog(2, rlog)
	log.Println(rlog.Index, string(rlog.Data))

	// Set a mock raft log
	logs := []*raft.Log{
		testRaftLog(1, "log1"),
		testRaftLog(2, "log2"),
		testRaftLog(3, "log3"),
	}
	if err := store.StoreLogs(logs); err != nil {
		panic(err)
	}

	// Fetch the last Raft index
	idx, err = store.LastIndex()
	if err != nil {
		panic(err)
	}

	log.Println(idx)
}
banks commented
raskchanky commented

@xkeyideal I implemented something similar to what it sounds like you're doing here https://github.com/raskchanky/raft-pebble. Maybe there's something useful in there that would help?

xkeyideal commented

@raskchanky it doesn't work. I test several other's raft-pebble, they are also lost data when cluster nodes stop then restart.
but use raft-boltdb it works.

xkeyideal commented

@banks
Q: Does that database you write in that test program still have the data in
when you re-open it and read it back in a separate process?

A: Yes, I use pebbledb as database by using dragonboat multi raft framework https://github.com/lni/dragonboat, and the project had running in product environment. So I guess pebbledb is works.

Q: Did you also test reading the logs back after restarting the process? Did
you test the StableStore interface too - that's critical to Raft as well?

A: Yes, I test reading the logs back after restarting the process. Pebbledb maybe lost some wal logs, if you don't flush db when it crash suddenly. And I deliberate delete the code of defer store.Close(), the pebbledb will be lost data. But I add db.Flush() in StoreLogs(), even though I delete the code of defer store.Close(), it will not be lost data.
The StableStore interface is similar to LogStore interface, so I think just test LogStore interface is enough. My raft-pebbledb programs had passed all tests.

I test https://github.com/raskchanky/raft-pebble, it doesn't work too.

So I guess hashicorp raft raft.NewRaft() do something on LogStore and StableStore.

The pebbledb database stores datas in data and wal directory, the boltdb stores datas in a single file.

karliszigurs commented

  • Your original logs suggest that you never had a working configuration to start with - the self-elected master sees nodeB and C, attempts to start replicating to them, fails

  • It appears you are using same data directory for all 3 instances on localhost. Sharing underlying data store is unlikely to work as expected.

I suggest you first see a working local cluster without errors in logs before you can attempt to check rejoin and log recovery.

xkeyideal commented
  • Your original logs suggest that you never had a working configuration to start with - the self-elected master sees nodeB and C, attempts to start replicating to them, fails
  • It appears you are using same data directory for all 3 instances on localhost. Sharing underlying data store is unlikely to work as expected.

I suggest you first see a working local cluster without errors in logs before you can attempt to check rejoin and log recovery.

Per node's storage directory is prefix/node{A,B,C}/

xkeyideal commented

I found the reason. Other project also write the directory, and it will remove dirs if check 'dirty' dirs.

Thanks @raskchanky @banks @karliszigurs