go_study/fabric-main/orderer/consensus/etcdraft/eviction_test.go

272 lines
8.6 KiB
Go

/*
Copyright IBM Corp. All Rights Reserved.
SPDX-License-Identifier: Apache-2.0
*/
package etcdraft
import (
"strings"
"sync/atomic"
"testing"
"time"
"github.com/hyperledger/fabric-protos-go/common"
"github.com/hyperledger/fabric/common/flogging"
"github.com/hyperledger/fabric/orderer/common/cluster"
"github.com/hyperledger/fabric/orderer/common/cluster/mocks"
"github.com/hyperledger/fabric/protoutil"
"github.com/onsi/gomega"
"github.com/pkg/errors"
"github.com/stretchr/testify/require"
"go.etcd.io/etcd/raft/v3/raftpb"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
)
func TestPeriodicCheck(t *testing.T) {
t.Parallel()
g := gomega.NewGomegaWithT(t)
var cond uint32
var checkNum uint32
fiveChecks := func() bool {
return atomic.LoadUint32(&checkNum) > uint32(5)
}
condition := func() bool {
atomic.AddUint32(&checkNum, 1)
return atomic.LoadUint32(&cond) == uint32(1)
}
reports := make(chan time.Duration, 1000)
report := func(duration time.Duration) {
reports <- duration
}
clears := make(chan struct{}, 1000)
reportCleared := func() {
clears <- struct{}{}
}
check := &PeriodicCheck{
Logger: flogging.MustGetLogger("test"),
Condition: condition,
CheckInterval: time.Millisecond,
Report: report,
ReportCleared: reportCleared,
}
go check.Run()
g.Eventually(fiveChecks, time.Minute, time.Millisecond).Should(gomega.BeTrue())
// trigger condition to be true
atomic.StoreUint32(&cond, 1)
g.Eventually(reports, time.Minute, time.Millisecond).Should(gomega.Not(gomega.BeEmpty()))
// read first report
firstReport := <-reports
g.Eventually(reports, time.Minute, time.Millisecond).Should(gomega.Not(gomega.BeEmpty()))
// read second report
secondReport := <-reports
// time increases between reports
g.Expect(secondReport).To(gomega.BeNumerically(">", firstReport))
// wait for the reports channel to be full
g.Eventually(func() int { return len(reports) }, time.Minute, time.Millisecond).Should(gomega.BeNumerically("==", 1000))
// trigger condition to be false
atomic.StoreUint32(&cond, 0)
var lastReport time.Duration
// drain the reports channel
for len(reports) > 0 {
select {
case report := <-reports:
lastReport = report
default:
}
}
g.Eventually(clears).Should(gomega.Receive())
g.Consistently(clears).ShouldNot(gomega.Receive())
// ensure the checks have been made
checksDoneSoFar := atomic.LoadUint32(&checkNum)
g.Consistently(reports, time.Second*2, time.Millisecond).Should(gomega.BeEmpty())
checksDoneAfter := atomic.LoadUint32(&checkNum)
g.Expect(checksDoneAfter).To(gomega.BeNumerically(">", checksDoneSoFar))
// but nothing has been reported
g.Expect(reports).To(gomega.BeEmpty())
// trigger the condition again
atomic.StoreUint32(&cond, 1)
g.Eventually(reports, time.Minute, time.Millisecond).Should(gomega.Not(gomega.BeEmpty()))
// The first report is smaller than the last report,
// so the countdown has been reset when the condition was reset
firstReport = <-reports
g.Expect(lastReport).To(gomega.BeNumerically(">", firstReport))
// Stop the periodic check.
check.Stop()
checkCountAfterStop := atomic.LoadUint32(&checkNum)
// Wait 50 times the check interval.
time.Sleep(check.CheckInterval * 50)
// Ensure that we cease checking the condition, hence the PeriodicCheck is stopped.
g.Expect(atomic.LoadUint32(&checkNum)).To(gomega.BeNumerically("<", checkCountAfterStop+2))
g.Consistently(clears).ShouldNot(gomega.Receive())
}
func TestEvictionSuspector(t *testing.T) {
configBlock := &common.Block{
Header: &common.BlockHeader{Number: 9},
Metadata: &common.BlockMetadata{
Metadata: [][]byte{{}, {}, {}, {}},
},
}
configBlock.Metadata.Metadata[common.BlockMetadataIndex_SIGNATURES] = protoutil.MarshalOrPanic(&common.Metadata{
Value: protoutil.MarshalOrPanic(&common.OrdererBlockMetadata{
LastConfig: &common.LastConfig{Index: 9},
}),
})
puller := &mocks.ChainPuller{}
puller.On("Close")
puller.On("HeightsByEndpoints").Return(map[string]uint64{"foo": 10}, nil)
puller.On("PullBlock", uint64(9)).Return(configBlock)
for _, testCase := range []struct {
description string
expectedPanic string
expectedLog string
expectedCommittedBlockCount int
amIInChannelReturns error
evictionSuspicionThreshold time.Duration
blockPuller BlockPuller
blockPullerErr error
height uint64
timesTriggered int
halt func()
}{
{
description: "suspected time is lower than threshold",
evictionSuspicionThreshold: 11 * time.Minute,
halt: t.Fail,
},
{
description: "timesTriggered multiplier prevents threshold",
evictionSuspicionThreshold: 6 * time.Minute,
timesTriggered: 1,
halt: t.Fail,
},
{
description: "puller creation fails",
evictionSuspicionThreshold: 10*time.Minute - time.Second,
blockPullerErr: errors.New("oops"),
expectedPanic: "Failed creating a block puller: oops",
halt: t.Fail,
},
{
description: "failed pulling the block",
expectedLog: "Cannot confirm our own eviction from the channel: bad block",
evictionSuspicionThreshold: 10*time.Minute - time.Second,
amIInChannelReturns: errors.New("bad block"),
blockPuller: puller,
height: 9,
halt: t.Fail,
},
{
description: "we are still in the channel",
expectedLog: "Cannot confirm our own eviction from the channel, our certificate was found in config block with sequence 9",
evictionSuspicionThreshold: 10*time.Minute - time.Second,
amIInChannelReturns: nil,
blockPuller: puller,
height: 9,
halt: t.Fail,
},
{
description: "our height is the highest",
expectedLog: "Our height is higher or equal than the height of the orderer we pulled the last block from, aborting",
evictionSuspicionThreshold: 10*time.Minute - time.Second,
amIInChannelReturns: cluster.ErrNotInChannel,
blockPuller: puller,
height: 10,
halt: func() {},
},
{
description: "we are not in the channel",
expectedLog: "Detected our own eviction from the channel in block [9]",
evictionSuspicionThreshold: 10*time.Minute - time.Second,
amIInChannelReturns: cluster.ErrNotInChannel,
blockPuller: puller,
height: 8,
expectedCommittedBlockCount: 2,
halt: func() {
puller.On("PullBlock", uint64(8)).Return(&common.Block{
Header: &common.BlockHeader{Number: 8},
Metadata: &common.BlockMetadata{
Metadata: [][]byte{{}, {}, {}, {}},
},
})
},
},
} {
testCase := testCase
t.Run(testCase.description, func(t *testing.T) {
committedBlocks := make(chan *common.Block, 2)
commitBlock := func(block *common.Block) error {
committedBlocks <- block
return nil
}
es := &evictionSuspector{
halt: testCase.halt,
amIInChannel: func(_ *common.Block) error {
return testCase.amIInChannelReturns
},
evictionSuspicionThreshold: testCase.evictionSuspicionThreshold,
createPuller: func() (BlockPuller, error) {
return testCase.blockPuller, testCase.blockPullerErr
},
writeBlock: commitBlock,
height: func() uint64 {
return testCase.height
},
logger: flogging.MustGetLogger("test"),
triggerCatchUp: func(sn *raftpb.Snapshot) {},
timesTriggered: testCase.timesTriggered,
}
foundExpectedLog := testCase.expectedLog == ""
es.logger = es.logger.WithOptions(zap.Hooks(func(entry zapcore.Entry) error {
if strings.Contains(entry.Message, testCase.expectedLog) {
foundExpectedLog = true
}
return nil
}))
runTestCase := func() {
es.confirmSuspicion(time.Minute * 10)
}
if testCase.expectedPanic != "" {
require.PanicsWithValue(t, testCase.expectedPanic, runTestCase)
} else {
runTestCase()
// Run the test case again.
// Conditions that do not lead to a conclusion of a chain eviction
// should be idempotent.
// Conditions that do lead to conclusion of a chain eviction
// in the second time - should result in a no-op.
runTestCase()
}
require.True(t, foundExpectedLog, "expected to find %s but didn't", testCase.expectedLog)
require.Equal(t, testCase.expectedCommittedBlockCount, len(committedBlocks))
})
}
}