panic.out

=== RUN TestRaftSnapshotRestoreOld
2016/02/13 12:38:35 [INFO] raft: Node at d75fd391-50c0-8c2f-2e7c-944bc53d89c6 [Follower] entering Follower state
2016/02/13 12:38:35 [WARN] raft: Heartbeat timeout reached, starting election
2016/02/13 12:38:35 [INFO] raft: Node at d75fd391-50c0-8c2f-2e7c-944bc53d89c6 [Candidate] entering Candidate state
2016/02/13 12:38:35 [DEBUG] raft: Votes needed: 1
2016/02/13 12:38:35 [DEBUG] raft: Vote granted from d75fd391-50c0-8c2f-2e7c-944bc53d89c6. Tally: 1
2016/02/13 12:38:35 [INFO] raft: Election won. Tally: 1
2016/02/13 12:38:35 [INFO] raft: Node at d75fd391-50c0-8c2f-2e7c-944bc53d89c6 [Leader] entering Leader state
2016/02/13 12:38:35 [DEBUG] raft: Node d75fd391-50c0-8c2f-2e7c-944bc53d89c6 updated peer set (2): [d75fd391-50c0-8c2f-2e7c-944bc53d89c6]
2016/02/13 12:38:35 [INFO] raft: Starting snapshot up to 101
2016/02/13 12:38:35 [INFO] raft: Compacting logs from 1 to 100
2016/02/13 12:38:35 [INFO] raft: Snapshot to 101 complete
2016/02/13 12:38:35 [INFO] raft: Starting snapshot up to 201
2016/02/13 12:38:35 [INFO] raft: Compacting logs from 101 to 200
2016/02/13 12:38:35 [INFO] raft: Snapshot to 201 complete
2016/02/13 12:38:35 [INFO] raft: Restored from snapshot 1-101-1455395915128
2016/02/13 12:38:35 [INFO] raft: Node at d75fd391-50c0-8c2f-2e7c-944bc53d89c6 [Follower] entering Follower state
2016/02/13 12:38:35 [WARN] raft: Heartbeat timeout reached, starting election
2016/02/13 12:38:35 [INFO] raft: Node at d75fd391-50c0-8c2f-2e7c-944bc53d89c6 [Candidate] entering Candidate state
2016/02/13 12:38:35 [DEBUG] raft: Votes needed: 1
2016/02/13 12:38:35 [DEBUG] raft: Vote granted from d75fd391-50c0-8c2f-2e7c-944bc53d89c6. Tally: 1
2016/02/13 12:38:35 [INFO] raft: Election won. Tally: 1
2016/02/13 12:38:35 [INFO] raft: Node at d75fd391-50c0-8c2f-2e7c-944bc53d89c6 [Leader] entering Leader state
2016/02/13 12:38:35 [ERR] raft: Failed to get log at 102: log not found
panic: log not found

goroutine 12 [running]:
github.com/hashicorp/raft.(*Raft).processLogs(0xc2080be540, 0xca, 0xc2080820a0)
	/home/fahad/go/src/github.com/hashicorp/raft/raft.go:1157 +0x412
github.com/hashicorp/raft.(*Raft).leaderLoop(0xc2080be540)
	/home/fahad/go/src/github.com/hashicorp/raft/raft.go:892 +0x3d7
github.com/hashicorp/raft.(*Raft).runLeader(0xc2080be540)
	/home/fahad/go/src/github.com/hashicorp/raft/raft.go:838 +0x876
github.com/hashicorp/raft.(*Raft).run(0xc2080be540)
	/home/fahad/go/src/github.com/hashicorp/raft/raft.go:602 +0xc9
github.com/hashicorp/raft.*Raft.(github.com/hashicorp/raft.run)·fm()
	/home/fahad/go/src/github.com/hashicorp/raft/raft.go:252 +0x27
github.com/hashicorp/raft.func·011()
	/home/fahad/go/src/github.com/hashicorp/raft/state.go:152 +0x51
created by github.com/hashicorp/raft.(*raftState).goFunc
	/home/fahad/go/src/github.com/hashicorp/raft/state.go:153 +0xe3

goroutine 1 [chan receive]:
testing.RunTests(0x969fd0, 0xabec80, 0x4b, 0x4b, 0x1)
	/usr/lib/go/src/testing/testing.go:556 +0xad6
testing.(*M).Run(0xc208030910, 0xaca440)
	/usr/lib/go/src/testing/testing.go:485 +0x6c
main.main()
	github.com/hashicorp/raft/_test/_testmain.go:200 +0x1d5

goroutine 5 [syscall]:
os/signal.loop()
	/usr/lib/go/src/os/signal/signal_unix.go:21 +0x1f
created by os/signal.init·1
	/usr/lib/go/src/os/signal/signal_unix.go:27 +0x35

goroutine 7 [sleep]:
github.com/hashicorp/raft.(*cluster).Leader(0xc20805abe0, 0x0)
	/home/fahad/go/src/github.com/hashicorp/raft/raft_test.go:159 +0xa5
github.com/hashicorp/raft.TestRaftSnapshotRestoreOld(0xc208078480)
	/home/fahad/go/src/github.com/hashicorp/raft/raft_test.go:1732 +0xb5c
testing.tRunner(0xc208078480, 0xabf220)
	/usr/lib/go/src/testing/testing.go:447 +0xbf
created by testing.RunTests
	/usr/lib/go/src/testing/testing.go:555 +0xa8b

goroutine 14 [select]:
github.com/hashicorp/raft.(*Raft).runSnapshots(0xc2080be540)
	/home/fahad/go/src/github.com/hashicorp/raft/raft.go:1705 +0x466
github.com/hashicorp/raft.*Raft.(github.com/hashicorp/raft.runSnapshots)·fm()
	/home/fahad/go/src/github.com/hashicorp/raft/raft.go:254 +0x27
github.com/hashicorp/raft.func·011()
	/home/fahad/go/src/github.com/hashicorp/raft/state.go:152 +0x51
created by github.com/hashicorp/raft.(*raftState).goFunc
	/home/fahad/go/src/github.com/hashicorp/raft/state.go:153 +0xe3

goroutine 13 [select]:
github.com/hashicorp/raft.(*Raft).runFSM(0xc2080be540)
	/home/fahad/go/src/github.com/hashicorp/raft/raft.go:509 +0x1043
github.com/hashicorp/raft.*Raft.(github.com/hashicorp/raft.runFSM)·fm()
	/home/fahad/go/src/github.com/hashicorp/raft/raft.go:253 +0x27
github.com/hashicorp/raft.func·011()
	/home/fahad/go/src/github.com/hashicorp/raft/state.go:152 +0x51
created by github.com/hashicorp/raft.(*raftState).goFunc
	/home/fahad/go/src/github.com/hashicorp/raft/state.go:153 +0xe3
exit status 2
FAIL	github.com/hashicorp/raft	0.146s

restore_old.diff

diff --git a/raft_test.go b/raft_test.go
index dc7a948..fdf03f4 100644
--- a/raft_test.go
+++ b/raft_test.go
@@ -7,6 +7,7 @@ import (
 	"io/ioutil"
 	"log"
 	"os"
+	"path/filepath"
 	"reflect"
 	"sync"
 	"sync/atomic"
@@ -1651,3 +1652,87 @@ func TestRaft_Voting(t *testing.T) {
 		t.Fatalf("expected vote not to be granted, but was %+v", resp)
 	}
 }
+
+func TestRaftSnapshotRestoreOld(t *testing.T) {
+	// Make the cluster
+	conf := inmemConfig(t)
+	// Keep single node boostrap enabled since we restart the raft node
+	conf.DisableBootstrapAfterElect = false
+	conf.TrailingLogs = 1
+	c := MakeCluster(1, t, conf)
+	defer c.Close()
+
+	leader := c.Leader()
+
+	// Commit some entries and verify
+	apply := func() {
+		var future Future
+		for i := 0; i < 100; i++ {
+			future = leader.Apply([]byte(fmt.Sprintf("test%d", i)), 0)
+		}
+		// Wait for the last future to apply
+		if err := future.Error(); err != nil {
+			t.Fatalf("err: %v", err)
+		}
+	}
+	// Take a snapshot and verify the new index after compaction
+	snapshot := func(numSnaps int, newFirstIndex uint64) {
+		snapFuture := leader.Snapshot()
+		if err := snapFuture.Error(); err != nil {
+			t.Fatalf("err: %v", err)
+		}
+		// Check for snapshot
+		if snaps, _ := leader.snapshots.List(); len(snaps) != numSnaps {
+			t.Fatalf("should have a snapshot")
+		}
+		// Logs should be trimmed
+		if idx, _ := leader.logs.FirstIndex(); idx != newFirstIndex {
+			t.Fatalf("should trim logs to %d: %d", newFirstIndex, idx)
+		}
+	}
+
+	// Commit data and take snapshots twice
+	apply()
+	snapshot(1, 101)
+	apply()
+	snapshot(2, 201)
+
+	// Emulate corrupted/missing snapshot by deleting it
+	snaps, _ := leader.snapshots.List()
+	path := filepath.Join(c.dirs[1], snapPath, snaps[0].ID)
+	if err := os.RemoveAll(path); err != nil {
+		t.Fatalf("can't delete snapshot at %v", path)
+	}
+	t.Logf("Deleted snapshot at %v", path)
+
+	// Shutdown
+	shutdown := leader.Shutdown()
+	if err := shutdown.Error(); err != nil {
+		t.Fatalf("err: %v", err)
+	}
+
+	// Restart the Raft
+	r := leader
+	r, err := NewRaft(r.conf, r.fsm, r.logs, r.stable,
+		r.snapshots, r.peerStore, r.trans)
+	if err != nil {
+		t.Fatalf("err: %v", err)
+	}
+	c.rafts[0] = r
+
+	// We should have restored from the oldest snapshot
+	if applied := r.getLastApplied(); applied != 101 {
+		t.Fatalf("bad applied: %v", applied)
+	}
+	// The last index comes from the append log
+	if last := r.getLastIndex(); last != 201 {
+		t.Fatalf("bad last: %v", last)
+	}
+
+	leader = c.Leader()
+	future := leader.Apply([]byte("testonce"), 0)
+	// Wait for the last future to apply
+	if err := future.Error(); err != nil {
+		t.Fatalf("err: %v", err)
+	}
+}