github.com/line/ostracon@v1.0.10-0.20230328032236-7f20145f065d/consensus/replay.go (about)

     1  package consensus
     2  
     3  import (
     4  	"bytes"
     5  	"fmt"
     6  	"hash/crc32"
     7  	"io"
     8  	"reflect"
     9  	"time"
    10  
    11  	abci "github.com/tendermint/tendermint/abci/types"
    12  
    13  	"github.com/line/ostracon/crypto/merkle"
    14  	"github.com/line/ostracon/libs/log"
    15  	"github.com/line/ostracon/proxy"
    16  	sm "github.com/line/ostracon/state"
    17  	"github.com/line/ostracon/types"
    18  )
    19  
    20  var crc32c = crc32.MakeTable(crc32.Castagnoli)
    21  
    22  // Functionality to replay blocks and messages on recovery from a crash.
    23  // There are two general failure scenarios:
    24  //
    25  //  1. failure during consensus
    26  //  2. failure while applying the block
    27  //
    28  // The former is handled by the WAL, the latter by the proxyApp Handshake on
    29  // restart, which ultimately hands off the work to the WAL.
    30  
    31  //-----------------------------------------
    32  // 1. Recover from failure during consensus
    33  // (by replaying messages from the WAL)
    34  //-----------------------------------------
    35  
    36  // Unmarshal and apply a single message to the consensus state as if it were
    37  // received in receiveRoutine.  Lines that start with "#" are ignored.
    38  // NOTE: receiveRoutine should not be running.
    39  func (cs *State) readReplayMessage(msg *TimedWALMessage, newStepSub types.Subscription) error {
    40  	// Skip meta messages which exist for demarcating boundaries.
    41  	if _, ok := msg.Msg.(EndHeightMessage); ok {
    42  		return nil
    43  	}
    44  
    45  	// for logging
    46  	switch m := msg.Msg.(type) {
    47  	case types.EventDataRoundState:
    48  		cs.Logger.Info("Replay: New Step", "height", m.Height, "round", m.Round, "step", m.Step)
    49  		// these are playback checks
    50  		ticker := time.After(time.Second * 2)
    51  		if newStepSub != nil {
    52  			select {
    53  			case stepMsg := <-newStepSub.Out():
    54  				m2 := stepMsg.Data().(types.EventDataRoundState)
    55  				if m.Height != m2.Height || m.Round != m2.Round || m.Step != m2.Step {
    56  					return fmt.Errorf("roundState mismatch. Got %v; Expected %v", m2, m)
    57  				}
    58  			case <-newStepSub.Cancelled():
    59  				return fmt.Errorf("failed to read off newStepSub.Out(). newStepSub was cancelled")
    60  			case <-ticker:
    61  				return fmt.Errorf("failed to read off newStepSub.Out()")
    62  			}
    63  		}
    64  	case msgInfo:
    65  		peerID := m.PeerID
    66  		if peerID == "" {
    67  			peerID = "local"
    68  		}
    69  		switch msg := m.Msg.(type) {
    70  		case *ProposalMessage:
    71  			p := msg.Proposal
    72  			cs.Logger.Info("Replay: Proposal", "height", p.Height, "round", p.Round, "header",
    73  				p.BlockID.PartSetHeader, "pol", p.POLRound, "peer", peerID)
    74  		case *BlockPartMessage:
    75  			cs.Logger.Info("Replay: BlockPart", "height", msg.Height, "round", msg.Round, "peer", peerID)
    76  		case *VoteMessage:
    77  			v := msg.Vote
    78  			cs.Logger.Info("Replay: Vote", "height", v.Height, "round", v.Round, "type", v.Type,
    79  				"blockID", v.BlockID, "peer", peerID)
    80  		}
    81  
    82  		cs.handleMsg(m)
    83  	case timeoutInfo:
    84  		cs.Logger.Info("Replay: Timeout", "height", m.Height, "round", m.Round, "step", m.Step, "dur", m.Duration)
    85  		cs.handleTimeout(m, cs.RoundState)
    86  	default:
    87  		return fmt.Errorf("replay: Unknown TimedWALMessage type: %v", reflect.TypeOf(msg.Msg))
    88  	}
    89  	return nil
    90  }
    91  
    92  // Replay only those messages since the last block.  `timeoutRoutine` should
    93  // run concurrently to read off tickChan.
    94  func (cs *State) catchupReplay(csHeight int64) error {
    95  
    96  	// Set replayMode to true so we don't log signing errors.
    97  	cs.replayMode = true
    98  	defer func() { cs.replayMode = false }()
    99  
   100  	// Ensure that #ENDHEIGHT for this height doesn't exist.
   101  	// NOTE: This is just a sanity check. As far as we know things work fine
   102  	// without it, and Handshake could reuse State if it weren't for
   103  	// this check (since we can crash after writing #ENDHEIGHT).
   104  	//
   105  	// Ignore data corruption errors since this is a sanity check.
   106  	gr, found, err := cs.wal.SearchForEndHeight(csHeight, &WALSearchOptions{IgnoreDataCorruptionErrors: true})
   107  	if err != nil {
   108  		return err
   109  	}
   110  	if gr != nil {
   111  		if err := gr.Close(); err != nil {
   112  			return err
   113  		}
   114  	}
   115  	if found {
   116  		return fmt.Errorf("wal should not contain #ENDHEIGHT %d", csHeight)
   117  	}
   118  
   119  	// Search for last height marker.
   120  	//
   121  	// Ignore data corruption errors in previous heights because we only care about last height
   122  	if csHeight < cs.state.InitialHeight {
   123  		return fmt.Errorf("cannot replay height %v, below initial height %v", csHeight, cs.state.InitialHeight)
   124  	}
   125  	endHeight := csHeight - 1
   126  	if csHeight == cs.state.InitialHeight {
   127  		endHeight = 0
   128  	}
   129  	gr, found, err = cs.wal.SearchForEndHeight(endHeight, &WALSearchOptions{IgnoreDataCorruptionErrors: true})
   130  	if err == io.EOF {
   131  		cs.Logger.Error("Replay: wal.group.Search returned EOF", "#ENDHEIGHT", endHeight)
   132  	} else if err != nil {
   133  		return err
   134  	}
   135  	if !found {
   136  		return fmt.Errorf("cannot replay height %d. WAL does not contain #ENDHEIGHT for %d", csHeight, endHeight)
   137  	}
   138  	defer gr.Close()
   139  
   140  	cs.Logger.Info("Catchup by replaying consensus messages", "height", csHeight)
   141  
   142  	var msg *TimedWALMessage
   143  	dec := WALDecoder{gr}
   144  
   145  LOOP:
   146  	for {
   147  		msg, err = dec.Decode()
   148  		switch {
   149  		case err == io.EOF:
   150  			break LOOP
   151  		case IsDataCorruptionError(err):
   152  			cs.Logger.Error("data has been corrupted in last height of consensus WAL", "err", err, "height", csHeight)
   153  			return err
   154  		case err != nil:
   155  			return err
   156  		}
   157  
   158  		// NOTE: since the priv key is set when the msgs are received
   159  		// it will attempt to eg double sign but we can just ignore it
   160  		// since the votes will be replayed and we'll get to the next step
   161  		if err := cs.readReplayMessage(msg, nil); err != nil {
   162  			return err
   163  		}
   164  	}
   165  	cs.Logger.Info("Replay: Done")
   166  	return nil
   167  }
   168  
   169  //--------------------------------------------------------------------------------
   170  
   171  // Parses marker lines of the form:
   172  // #ENDHEIGHT: 12345
   173  /*
   174  func makeHeightSearchFunc(height int64) auto.SearchFunc {
   175  	return func(line string) (int, error) {
   176  		line = strings.TrimRight(line, "\n")
   177  		parts := strings.Split(line, " ")
   178  		if len(parts) != 2 {
   179  			return -1, errors.New("line did not have 2 parts")
   180  		}
   181  		i, err := strconv.Atoi(parts[1])
   182  		if err != nil {
   183  			return -1, errors.New("failed to parse INFO: " + err.Error())
   184  		}
   185  		if height < i {
   186  			return 1, nil
   187  		} else if height == i {
   188  			return 0, nil
   189  		} else {
   190  			return -1, nil
   191  		}
   192  	}
   193  }*/
   194  
   195  //---------------------------------------------------
   196  // 2. Recover from failure while applying the block.
   197  // (by handshaking with the app to figure out where
   198  // we were last, and using the WAL to recover there.)
   199  //---------------------------------------------------
   200  
   201  type Handshaker struct {
   202  	stateStore   sm.Store
   203  	initialState sm.State
   204  	store        sm.BlockStore
   205  	eventBus     types.BlockEventPublisher
   206  	genDoc       *types.GenesisDoc
   207  	logger       log.Logger
   208  
   209  	nBlocks int // number of blocks applied to the state
   210  }
   211  
   212  func NewHandshaker(stateStore sm.Store, state sm.State,
   213  	store sm.BlockStore, genDoc *types.GenesisDoc) *Handshaker {
   214  
   215  	return &Handshaker{
   216  		stateStore:   stateStore,
   217  		initialState: state,
   218  		store:        store,
   219  		eventBus:     types.NopEventBus{},
   220  		genDoc:       genDoc,
   221  		logger:       log.NewNopLogger(),
   222  		nBlocks:      0,
   223  	}
   224  }
   225  
   226  func (h *Handshaker) SetLogger(l log.Logger) {
   227  	h.logger = l
   228  }
   229  
   230  // SetEventBus - sets the event bus for publishing block related events.
   231  // If not called, it defaults to types.NopEventBus.
   232  func (h *Handshaker) SetEventBus(eventBus types.BlockEventPublisher) {
   233  	h.eventBus = eventBus
   234  }
   235  
   236  // NBlocks returns the number of blocks applied to the state.
   237  func (h *Handshaker) NBlocks() int {
   238  	return h.nBlocks
   239  }
   240  
   241  // TODO: retry the handshake/replay if it fails ?
   242  func (h *Handshaker) Handshake(proxyApp proxy.AppConns) error {
   243  
   244  	// Handshake is done via ABCI Info on the query conn.
   245  	res, err := proxyApp.Query().InfoSync(proxy.RequestInfo)
   246  	if err != nil {
   247  		return fmt.Errorf("error calling Info: %v", err)
   248  	}
   249  
   250  	blockHeight := res.LastBlockHeight
   251  	if blockHeight < 0 {
   252  		return fmt.Errorf("got a negative last block height (%d) from the app", blockHeight)
   253  	}
   254  	appHash := res.LastBlockAppHash
   255  
   256  	h.logger.Info("ABCI Handshake App Info",
   257  		"height", blockHeight,
   258  		"hash", appHash,
   259  		"software-version", res.Version,
   260  		"protocol-version", res.AppVersion,
   261  	)
   262  
   263  	// Only set the version if there is no existing state.
   264  	if h.initialState.LastBlockHeight == 0 {
   265  		h.initialState.ConsensusParams.Version.AppVersion = res.AppVersion
   266  		h.initialState.Version.Consensus.App = res.AppVersion
   267  	}
   268  
   269  	// Replay blocks up to the latest in the blockstore.
   270  	_, err = h.ReplayBlocks(h.initialState, appHash, blockHeight, proxyApp)
   271  	if err != nil {
   272  		return fmt.Errorf("error on replay: %v", err)
   273  	}
   274  
   275  	h.logger.Info("Completed ABCI Handshake - Ostracon and App are synced",
   276  		"appHeight", blockHeight, "appHash", appHash)
   277  
   278  	// TODO: (on restart) replay mempool
   279  
   280  	return nil
   281  }
   282  
   283  // ReplayBlocks replays all blocks since appBlockHeight and ensures the result
   284  // matches the current state.
   285  // Returns the final AppHash or an error.
   286  func (h *Handshaker) ReplayBlocks(
   287  	state sm.State,
   288  	appHash []byte,
   289  	appBlockHeight int64,
   290  	proxyApp proxy.AppConns,
   291  ) ([]byte, error) {
   292  	storeBlockBase := h.store.Base()
   293  	storeBlockHeight := h.store.Height()
   294  	stateBlockHeight := state.LastBlockHeight
   295  	h.logger.Info(
   296  		"ABCI Replay Blocks",
   297  		"appHeight",
   298  		appBlockHeight,
   299  		"storeHeight",
   300  		storeBlockHeight,
   301  		"stateHeight",
   302  		stateBlockHeight)
   303  
   304  	// If appBlockHeight == 0 it means that we are at genesis and hence should send InitChain.
   305  	if appBlockHeight == 0 {
   306  		validators := make([]*types.Validator, len(h.genDoc.Validators))
   307  		for i, val := range h.genDoc.Validators {
   308  			validators[i] = types.NewValidator(val.PubKey, val.Power)
   309  		}
   310  		validatorSet := types.NewValidatorSet(validators)
   311  		nextVals := types.OC2PB.ValidatorUpdates(validatorSet)
   312  		csParams := types.OC2PB.ConsensusParams(h.genDoc.ConsensusParams)
   313  		req := abci.RequestInitChain{
   314  			Time:            h.genDoc.GenesisTime,
   315  			ChainId:         h.genDoc.ChainID,
   316  			InitialHeight:   h.genDoc.InitialHeight,
   317  			ConsensusParams: csParams,
   318  			Validators:      nextVals,
   319  			AppStateBytes:   h.genDoc.AppState,
   320  		}
   321  		res, err := proxyApp.Consensus().InitChainSync(req)
   322  		if err != nil {
   323  			return nil, err
   324  		}
   325  
   326  		appHash = res.AppHash
   327  
   328  		if stateBlockHeight == 0 { // we only update state when we are in initial state
   329  			// If the app did not return an app hash, we keep the one set from the genesis doc in
   330  			// the state. We don't set appHash since we don't want the genesis doc app hash
   331  			// recorded in the genesis block. We should probably just remove GenesisDoc.AppHash.
   332  			if len(res.AppHash) > 0 {
   333  				state.AppHash = res.AppHash
   334  			}
   335  			// If the app returned validators or consensus params, update the state.
   336  			if len(res.Validators) > 0 {
   337  				vals, err := types.PB2OC.ValidatorUpdates(res.Validators)
   338  				if err != nil {
   339  					return nil, err
   340  				}
   341  				state.Validators = types.NewValidatorSet(vals)
   342  				state.NextValidators = types.NewValidatorSet(vals)
   343  			} else if len(h.genDoc.Validators) == 0 {
   344  				// If validator set is not set in genesis and still empty after InitChain, exit.
   345  				return nil, fmt.Errorf("validator set is nil in genesis and still empty after InitChain")
   346  			}
   347  
   348  			if res.ConsensusParams != nil {
   349  				state.ConsensusParams = types.UpdateConsensusParams(state.ConsensusParams, res.ConsensusParams)
   350  				state.Version.Consensus.App = state.ConsensusParams.Version.AppVersion
   351  			}
   352  			// We update the last results hash with the empty hash, to conform with RFC-6962.
   353  			state.LastResultsHash = merkle.HashFromByteSlices(nil)
   354  			if err := h.stateStore.Save(state); err != nil {
   355  				return nil, err
   356  			}
   357  		}
   358  	}
   359  
   360  	// First handle edge cases and constraints on the storeBlockHeight and storeBlockBase.
   361  	switch {
   362  	case storeBlockHeight == 0:
   363  		assertAppHashEqualsOneFromState(appHash, state)
   364  		return appHash, nil
   365  
   366  	case appBlockHeight == 0 && state.InitialHeight < storeBlockBase:
   367  		// the app has no state, and the block store is truncated above the initial height
   368  		return appHash, sm.ErrAppBlockHeightTooLow{AppHeight: appBlockHeight, StoreBase: storeBlockBase}
   369  
   370  	case appBlockHeight > 0 && appBlockHeight < storeBlockBase-1:
   371  		// the app is too far behind truncated store (can be 1 behind since we replay the next)
   372  		return appHash, sm.ErrAppBlockHeightTooLow{AppHeight: appBlockHeight, StoreBase: storeBlockBase}
   373  
   374  	case storeBlockHeight < appBlockHeight:
   375  		// the app should never be ahead of the store (but this is under app's control)
   376  		return appHash, sm.ErrAppBlockHeightTooHigh{CoreHeight: storeBlockHeight, AppHeight: appBlockHeight}
   377  
   378  	case storeBlockHeight < stateBlockHeight:
   379  		// the state should never be ahead of the store (this is under ostracon's control)
   380  		panic(fmt.Sprintf("StateBlockHeight (%d) > StoreBlockHeight (%d)", stateBlockHeight, storeBlockHeight))
   381  
   382  	case storeBlockHeight > stateBlockHeight+1:
   383  		// store should be at most one ahead of the state (this is under ostracon's control)
   384  		panic(fmt.Sprintf("StoreBlockHeight (%d) > StateBlockHeight + 1 (%d)", storeBlockHeight, stateBlockHeight+1))
   385  	}
   386  
   387  	var err error
   388  	// Now either store is equal to state, or one ahead.
   389  	// For each, consider all cases of where the app could be, given app <= store
   390  	if storeBlockHeight == stateBlockHeight {
   391  		// Ostracon ran Commit and saved the state.
   392  		// Either the app is asking for replay, or we're all synced up.
   393  		if appBlockHeight < storeBlockHeight {
   394  			// the app is behind, so replay blocks, but no need to go through WAL (state is already synced to store)
   395  			return h.replayBlocks(state, proxyApp, appBlockHeight, storeBlockHeight, false)
   396  
   397  		} else if appBlockHeight == storeBlockHeight {
   398  			// We're good!
   399  			assertAppHashEqualsOneFromState(appHash, state)
   400  			return appHash, nil
   401  		}
   402  
   403  	} else if storeBlockHeight == stateBlockHeight+1 {
   404  		// We saved the block in the store but haven't updated the state,
   405  		// so we'll need to replay a block using the WAL.
   406  		switch {
   407  		case appBlockHeight < stateBlockHeight:
   408  			// the app is further behind than it should be, so replay blocks
   409  			// but leave the last block to go through the WAL
   410  			return h.replayBlocks(state, proxyApp, appBlockHeight, storeBlockHeight, true)
   411  
   412  		case appBlockHeight == stateBlockHeight:
   413  			// We haven't run Commit (both the state and app are one block behind),
   414  			// so replayBlock with the real app.
   415  			// NOTE: We could instead use the cs.WAL on cs.Start,
   416  			// but we'd have to allow the WAL to replay a block that wrote it's #ENDHEIGHT
   417  			h.logger.Info("Replay last block using real app")
   418  			state, err = h.replayBlock(state, storeBlockHeight, proxyApp.Consensus())
   419  			return state.AppHash, err
   420  
   421  		case appBlockHeight == storeBlockHeight:
   422  			// We ran Commit, but didn't save the state, so replayBlock with mock app.
   423  			abciResponses, err := h.stateStore.LoadABCIResponses(storeBlockHeight)
   424  			if err != nil {
   425  				return nil, err
   426  			}
   427  			mockApp := newMockProxyApp(appHash, abciResponses)
   428  			h.logger.Info("Replay last block using mock app")
   429  			state, err = h.replayBlock(state, storeBlockHeight, mockApp)
   430  			return state.AppHash, err
   431  		}
   432  
   433  	}
   434  
   435  	panic(fmt.Sprintf("uncovered case! appHeight: %d, storeHeight: %d, stateHeight: %d",
   436  		appBlockHeight, storeBlockHeight, stateBlockHeight))
   437  }
   438  
   439  func (h *Handshaker) replayBlocks(
   440  	state sm.State,
   441  	proxyApp proxy.AppConns,
   442  	appBlockHeight,
   443  	storeBlockHeight int64,
   444  	mutateState bool) ([]byte, error) {
   445  	// App is further behind than it should be, so we need to replay blocks.
   446  	// We replay all blocks from appBlockHeight+1.
   447  	//
   448  	// Note that we don't have an old version of the state,
   449  	// so we by-pass state validation/mutation using sm.ExecCommitBlock.
   450  	// This also means we won't be saving validator sets if they change during this period.
   451  	// TODO: Load the historical information to fix this and just use state.ApplyBlock
   452  	//
   453  	// If mutateState == true, the final block is replayed with h.replayBlock()
   454  
   455  	var appHash []byte
   456  	var err error
   457  	finalBlock := storeBlockHeight
   458  	if mutateState {
   459  		finalBlock--
   460  	}
   461  	firstBlock := appBlockHeight + 1
   462  	if firstBlock == 1 {
   463  		firstBlock = state.InitialHeight
   464  	}
   465  	for i := firstBlock; i <= finalBlock; i++ {
   466  		h.logger.Info("Applying block", "height", i)
   467  		block := h.store.LoadBlock(i)
   468  		// Extra check to ensure the app was not changed in a way it shouldn't have.
   469  		if len(appHash) > 0 {
   470  			assertAppHashEqualsOneFromBlock(appHash, block)
   471  		}
   472  
   473  		appHash, err = sm.ExecCommitBlock(
   474  			proxyApp.Consensus(),
   475  			block,
   476  			h.logger,
   477  			h.stateStore,
   478  			h.genDoc.InitialHeight,
   479  		)
   480  		if err != nil {
   481  			return nil, err
   482  		}
   483  
   484  		h.nBlocks++
   485  	}
   486  
   487  	if mutateState {
   488  		// sync the final block
   489  		h.logger.Info("Replaying final block using real app", "height", storeBlockHeight)
   490  		state, err = h.replayBlock(state, storeBlockHeight, proxyApp.Consensus())
   491  		if err != nil {
   492  			return nil, err
   493  		}
   494  		appHash = state.AppHash
   495  	}
   496  
   497  	assertAppHashEqualsOneFromState(appHash, state)
   498  	return appHash, nil
   499  }
   500  
   501  // ApplyBlock on the proxyApp with the last block.
   502  func (h *Handshaker) replayBlock(state sm.State, height int64, proxyApp proxy.AppConnConsensus) (sm.State, error) {
   503  	block := h.store.LoadBlock(height)
   504  	meta := h.store.LoadBlockMeta(height)
   505  	var err error
   506  	consensusParams, err := h.stateStore.LoadConsensusParams(height)
   507  	if err != nil {
   508  		return sm.State{}, err
   509  	}
   510  	state.ConsensusParams = consensusParams
   511  	state.Version.Consensus.App = consensusParams.Version.AppVersion
   512  
   513  	// Use stubs for both mempool and evidence pool since no transactions nor
   514  	// evidence are needed here - block already exists.
   515  	blockExec := sm.NewBlockExecutor(h.stateStore, h.logger, proxyApp, emptyMempool{}, sm.EmptyEvidencePool{})
   516  	blockExec.SetEventBus(h.eventBus)
   517  
   518  	state, _, err = blockExec.ApplyBlock(state, meta.BlockID, block, nil)
   519  	if err != nil {
   520  		return sm.State{}, err
   521  	}
   522  
   523  	h.nBlocks++
   524  
   525  	return state, nil
   526  }
   527  
   528  func assertAppHashEqualsOneFromBlock(appHash []byte, block *types.Block) {
   529  	if !bytes.Equal(appHash, block.AppHash) {
   530  		panic(fmt.Sprintf(`block.AppHash does not match AppHash after replay. Got %X, expected %X.
   531  
   532  Block: %v
   533  `,
   534  			appHash, block.AppHash, block))
   535  	}
   536  }
   537  
   538  func assertAppHashEqualsOneFromState(appHash []byte, state sm.State) {
   539  	if !bytes.Equal(appHash, state.AppHash) {
   540  		panic(fmt.Sprintf(`state.AppHash does not match AppHash after replay. Got
   541  %X, expected %X.
   542  
   543  State: %v
   544  
   545  Did you reset Ostracon without resetting your application's data?`,
   546  			appHash, state.AppHash, state))
   547  	}
   548  }