lotus/miner/miner.go

543 lines
14 KiB
Go
Raw Normal View History

package miner
import (
"bytes"
"context"
"crypto/rand"
"encoding/binary"
"fmt"
2019-08-20 16:50:17 +00:00
"sync"
"time"
2020-09-21 23:01:29 +00:00
proof0 "github.com/filecoin-project/specs-actors/actors/runtime/proof"
2020-09-07 06:08:53 +00:00
2020-08-07 00:05:35 +00:00
"github.com/filecoin-project/lotus/chain/gen/slashfilter"
"github.com/filecoin-project/go-address"
2020-09-07 03:49:10 +00:00
"github.com/filecoin-project/go-state-types/abi"
"github.com/filecoin-project/go-state-types/crypto"
2020-02-12 22:12:11 +00:00
lru "github.com/hashicorp/golang-lru"
2019-11-25 04:45:13 +00:00
"github.com/filecoin-project/lotus/api"
"github.com/filecoin-project/lotus/build"
"github.com/filecoin-project/lotus/chain/gen"
2020-08-01 22:54:21 +00:00
"github.com/filecoin-project/lotus/chain/messagepool/gasguess"
2020-04-29 22:25:48 +00:00
"github.com/filecoin-project/lotus/chain/store"
"github.com/filecoin-project/lotus/chain/types"
"github.com/filecoin-project/lotus/journal"
2019-08-20 16:50:17 +00:00
logging "github.com/ipfs/go-log/v2"
2019-08-20 16:50:17 +00:00
"go.opencensus.io/trace"
"golang.org/x/xerrors"
)
var log = logging.Logger("miner")
2020-08-11 12:48:32 +00:00
// Journal event types.
const (
evtTypeBlockMined = iota
)
2020-04-23 21:12:42 +00:00
// returns a callback reporting whether we mined a blocks in this round
type waitFunc func(ctx context.Context, baseTime uint64) (func(bool, abi.ChainEpoch, error), abi.ChainEpoch, error)
2019-09-23 15:27:30 +00:00
func randTimeOffset(width time.Duration) time.Duration {
buf := make([]byte, 8)
rand.Reader.Read(buf) //nolint:errcheck
val := time.Duration(binary.BigEndian.Uint64(buf) % uint64(width))
return val - (width / 2)
}
func NewMiner(api api.FullNode, epp gen.WinningPoStProver, addr address.Address, sf *slashfilter.SlashFilter, j journal.Journal) *Miner {
2020-01-17 07:10:47 +00:00
arc, err := lru.NewARC(10000)
if err != nil {
panic(err)
}
2019-07-11 02:36:43 +00:00
return &Miner{
api: api,
epp: epp,
address: addr,
waitFunc: func(ctx context.Context, baseTime uint64) (func(bool, abi.ChainEpoch, error), abi.ChainEpoch, error) {
2019-10-09 04:38:59 +00:00
// Wait around for half the block time in case other parents come in
2020-06-30 14:01:30 +00:00
deadline := baseTime + build.PropagationDelaySecs
baseT := time.Unix(int64(deadline), 0)
baseT = baseT.Add(randTimeOffset(time.Second))
build.Clock.Sleep(build.Clock.Until(baseT))
2019-12-03 20:00:04 +00:00
return func(bool, abi.ChainEpoch, error) {}, 0, nil
2019-10-09 04:38:59 +00:00
},
2020-08-06 01:14:13 +00:00
2020-08-06 01:16:54 +00:00
sf: sf,
minedBlockHeights: arc,
2020-08-11 12:48:32 +00:00
evtTypes: [...]journal.EventType{
evtTypeBlockMined: j.RegisterEventType("miner", "block_mined"),
2020-08-11 12:48:32 +00:00
},
journal: j,
2019-07-11 02:36:43 +00:00
}
}
type Miner struct {
2019-11-25 04:45:13 +00:00
api api.FullNode
epp gen.WinningPoStProver
2019-11-21 22:21:45 +00:00
lk sync.Mutex
address address.Address
stop chan struct{}
stopping chan struct{}
2019-07-11 02:36:43 +00:00
2019-10-09 04:38:59 +00:00
waitFunc waitFunc
lastWork *MiningBase
2020-08-06 01:16:54 +00:00
sf *slashfilter.SlashFilter
minedBlockHeights *lru.ARCCache
2020-08-11 12:48:32 +00:00
evtTypes [1]journal.EventType
journal journal.Journal
}
func (m *Miner) Address() address.Address {
2019-08-21 15:14:38 +00:00
m.lk.Lock()
defer m.lk.Unlock()
return m.address
2019-08-21 15:14:38 +00:00
}
func (m *Miner) Start(ctx context.Context) error {
2019-08-20 16:50:17 +00:00
m.lk.Lock()
defer m.lk.Unlock()
if m.stop != nil {
return fmt.Errorf("miner already started")
2019-08-20 16:50:17 +00:00
}
m.stop = make(chan struct{})
go m.mine(context.TODO())
2019-08-20 16:50:17 +00:00
return nil
}
func (m *Miner) Stop(ctx context.Context) error {
2019-08-20 18:05:17 +00:00
m.lk.Lock()
m.stopping = make(chan struct{})
stopping := m.stopping
close(m.stop)
2019-08-20 18:05:17 +00:00
2020-07-20 08:15:01 +00:00
m.lk.Unlock()
select {
case <-stopping:
return nil
case <-ctx.Done():
return ctx.Err()
2019-08-20 18:05:17 +00:00
}
}
func (m *Miner) niceSleep(d time.Duration) bool {
select {
2020-07-10 14:43:14 +00:00
case <-build.Clock.After(d):
return true
case <-m.stop:
2020-09-16 20:56:04 +00:00
log.Infow("received interrupt while trying to sleep in mining cycle")
return false
}
}
2019-08-20 16:50:17 +00:00
func (m *Miner) mine(ctx context.Context) {
ctx, span := trace.StartSpan(ctx, "/mine")
defer span.End()
2019-08-20 18:05:17 +00:00
2019-10-10 02:03:42 +00:00
var lastBase MiningBase
2020-09-23 12:24:19 +00:00
minerLoop:
for {
2019-08-20 18:05:17 +00:00
select {
case <-m.stop:
stopping := m.stopping
2019-08-20 18:05:17 +00:00
m.stop = nil
m.stopping = nil
close(stopping)
return
2019-08-20 18:05:17 +00:00
default:
}
2020-08-07 16:09:53 +00:00
var base *MiningBase
var onDone func(bool, abi.ChainEpoch, error)
2020-08-07 16:09:53 +00:00
var injectNulls abi.ChainEpoch
for {
prebase, err := m.GetBestMiningCandidate(ctx)
if err != nil {
log.Errorf("failed to get best mining candidate: %s", err)
if !m.niceSleep(time.Second * 5) {
2020-09-24 14:03:24 +00:00
continue minerLoop
}
2020-08-07 16:09:53 +00:00
continue
}
if base != nil && base.TipSet.Height() == prebase.TipSet.Height() && base.NullRounds == prebase.NullRounds {
base = prebase
break
}
if base != nil {
onDone(false, 0, nil)
2020-08-07 16:09:53 +00:00
}
// TODO: need to change the orchestration here. the problem is that
// we are waiting *after* we enter this loop and selecta mining
// candidate, which is almost certain to change in multiminer
// tests. Instead, we should block before entering the loop, so
// that when the test 'MineOne' function is triggered, we pull our
// best mining candidate at that time.
// Wait until propagation delay period after block we plan to mine on
onDone, injectNulls, err = m.waitFunc(ctx, prebase.TipSet.MinTimestamp())
if err != nil {
log.Error(err)
continue
}
// just wait for the beacon entry to become available before we select our final mining base
_, err = m.api.BeaconGetEntry(ctx, prebase.TipSet.Height()+prebase.NullRounds+1)
if err != nil {
log.Errorf("failed getting beacon entry: %s", err)
if !m.niceSleep(time.Second) {
2020-09-24 14:03:24 +00:00
continue minerLoop
}
2020-08-07 16:09:53 +00:00
continue
}
base = prebase
2019-12-03 20:00:04 +00:00
}
2020-09-27 07:01:42 +00:00
base.NullRounds += injectNulls // testing
2020-04-23 21:12:42 +00:00
if base.TipSet.Equals(lastBase.TipSet) && lastBase.NullRounds == base.NullRounds {
log.Warnf("BestMiningCandidate from the previous round: %s (nulls:%d)", lastBase.TipSet.Cids(), lastBase.NullRounds)
if !m.niceSleep(time.Duration(build.BlockDelaySecs) * time.Second) {
2020-09-24 14:03:24 +00:00
continue minerLoop
}
continue
}
b, err := m.mineOne(ctx, base)
if err != nil {
log.Errorf("mining block failed: %+v", err)
if !m.niceSleep(time.Second) {
2020-09-24 14:03:24 +00:00
continue minerLoop
}
onDone(false, 0, err)
continue
}
lastBase = *base
var h abi.ChainEpoch
if b != nil {
h = b.Header.Height
}
onDone(b != nil, h, nil)
2020-04-23 21:12:42 +00:00
if b != nil {
m.journal.RecordEvent(m.evtTypes[evtTypeBlockMined], func() interface{} {
2020-08-11 12:48:32 +00:00
return map[string]interface{}{
"parents": base.TipSet.Cids(),
"nulls": base.NullRounds,
"epoch": b.Header.Height,
"timestamp": b.Header.Timestamp,
"cid": b.Header.Cid(),
}
})
btime := time.Unix(int64(b.Header.Timestamp), 0)
2020-07-14 16:12:00 +00:00
now := build.Clock.Now()
switch {
case btime == now:
// block timestamp is perfectly aligned with time.
case btime.After(now):
2020-07-10 14:43:14 +00:00
if !m.niceSleep(build.Clock.Until(btime)) {
log.Warnf("received interrupt while waiting to broadcast block, will shutdown after block is sent out")
2020-07-10 14:43:14 +00:00
build.Clock.Sleep(build.Clock.Until(btime))
}
2020-07-14 16:12:00 +00:00
default:
log.Warnw("mined block in the past",
"block-time", btime, "time", build.Clock.Now(), "difference", build.Clock.Since(btime))
2019-10-09 09:11:41 +00:00
}
2020-08-06 01:14:13 +00:00
if err := m.sf.MinedBlock(b.Header, base.TipSet.Height()+base.NullRounds); err != nil {
log.Errorf("<!!> SLASH FILTER ERROR: %s", err)
continue
}
2020-05-05 19:39:43 +00:00
blkKey := fmt.Sprintf("%d", b.Header.Height)
if _, ok := m.minedBlockHeights.Get(blkKey); ok {
log.Warnw("Created a block at the same height as another block we've created", "height", b.Header.Height, "miner", b.Header.Miner, "parents", b.Header.Parents)
continue
}
m.minedBlockHeights.Add(blkKey, true)
2020-08-06 01:14:13 +00:00
if err := m.api.SyncSubmitBlock(ctx, b); err != nil {
log.Errorf("failed to submit newly mined block: %s", err)
}
} else {
2020-06-12 00:11:38 +00:00
base.NullRounds++
// Wait until the next epoch, plus the propagation delay, so a new tipset
// has enough time to form.
//
// See: https://github.com/filecoin-project/lotus/issues/1845
2020-06-30 14:01:30 +00:00
nextRound := time.Unix(int64(base.TipSet.MinTimestamp()+build.BlockDelaySecs*uint64(base.NullRounds))+int64(build.PropagationDelaySecs), 0)
select {
2020-07-10 14:43:14 +00:00
case <-build.Clock.After(build.Clock.Until(nextRound)):
case <-m.stop:
stopping := m.stopping
m.stop = nil
m.stopping = nil
close(stopping)
return
}
}
}
}
type MiningBase struct {
2020-04-23 21:12:42 +00:00
TipSet *types.TipSet
NullRounds abi.ChainEpoch
}
2019-10-15 05:00:30 +00:00
func (m *Miner) GetBestMiningCandidate(ctx context.Context) (*MiningBase, error) {
m.lk.Lock()
defer m.lk.Unlock()
2019-10-15 05:00:30 +00:00
bts, err := m.api.ChainHead(ctx)
if err != nil {
return nil, err
}
if m.lastWork != nil {
2020-04-23 21:12:42 +00:00
if m.lastWork.TipSet.Equals(bts) {
return m.lastWork, nil
}
btsw, err := m.api.ChainTipSetWeight(ctx, bts.Key())
2019-10-15 05:00:30 +00:00
if err != nil {
return nil, err
}
2020-04-23 21:12:42 +00:00
ltsw, err := m.api.ChainTipSetWeight(ctx, m.lastWork.TipSet.Key())
2019-10-15 05:00:30 +00:00
if err != nil {
m.lastWork = nil
2019-10-15 05:00:30 +00:00
return nil, err
}
if types.BigCmp(btsw, ltsw) <= 0 {
return m.lastWork, nil
}
}
2020-04-23 21:12:42 +00:00
m.lastWork = &MiningBase{TipSet: bts}
2019-12-03 07:58:38 +00:00
return m.lastWork, nil
}
// mineOne attempts to mine a single block, and does so synchronously, if and
// only if we are eligible to mine.
2020-06-23 21:51:25 +00:00
//
// {hint/landmark}: This method coordinates all the steps involved in mining a
// block, including the condition of whether mine or not at all depending on
// whether we win the round or not.
//
// This method does the following:
//
// 1.
func (m *Miner) mineOne(ctx context.Context, base *MiningBase) (*types.BlockMsg, error) {
2020-04-23 21:12:42 +00:00
log.Debugw("attempting to mine a block", "tipset", types.LogCids(base.TipSet.Cids()))
2020-07-10 14:43:14 +00:00
start := build.Clock.Now()
2019-11-27 14:18:51 +00:00
2020-04-23 21:12:42 +00:00
round := base.TipSet.Height() + base.NullRounds + 1
mbi, err := m.api.MinerGetBaseInfo(ctx, m.address, round, base.TipSet.Key())
2020-04-08 15:11:42 +00:00
if err != nil {
2020-04-09 17:13:09 +00:00
return nil, xerrors.Errorf("failed to get mining base info: %w", err)
2020-04-08 15:11:42 +00:00
}
2020-04-23 21:12:42 +00:00
if mbi == nil {
return nil, nil
}
if !mbi.EligibleForMining {
// slashed or just have no power yet
return nil, nil
}
2020-04-08 15:11:42 +00:00
2020-07-10 14:43:14 +00:00
tMBI := build.Clock.Now()
2020-05-15 09:17:13 +00:00
2020-04-09 17:13:09 +00:00
beaconPrev := mbi.PrevBeaconEntry
2020-07-10 14:43:14 +00:00
tDrand := build.Clock.Now()
bvals := mbi.BeaconEntries
2020-05-15 09:17:13 +00:00
2020-07-10 14:43:14 +00:00
tPowercheck := build.Clock.Now()
2020-05-15 09:17:13 +00:00
2020-07-10 14:43:14 +00:00
log.Infof("Time delta between now and our mining base: %ds (nulls: %d)", uint64(build.Clock.Now().Unix())-base.TipSet.MinTimestamp(), base.NullRounds)
2020-04-09 17:13:09 +00:00
rbase := beaconPrev
2020-04-08 15:11:42 +00:00
if len(bvals) > 0 {
rbase = bvals[len(bvals)-1]
}
ticket, err := m.computeTicket(ctx, &rbase, base)
if err != nil {
return nil, xerrors.Errorf("scratching ticket failed: %w", err)
}
winner, err := gen.IsRoundWinner(ctx, base.TipSet, round, m.address, rbase, mbi, m.api)
if err != nil {
2019-11-25 04:45:13 +00:00
return nil, xerrors.Errorf("failed to check if we win next round: %w", err)
}
if winner == nil {
return nil, nil
}
2020-07-10 14:43:14 +00:00
tTicket := build.Clock.Now()
2020-05-15 09:17:13 +00:00
2020-04-30 20:21:46 +00:00
buf := new(bytes.Buffer)
if err := m.address.MarshalCBOR(buf); err != nil {
2020-04-30 20:21:46 +00:00
return nil, xerrors.Errorf("failed to marshal miner address: %w", err)
}
rand, err := store.DrawRandomness(rbase.Data, crypto.DomainSeparationTag_WinningPoStChallengeSeed, base.TipSet.Height()+base.NullRounds+1, buf.Bytes())
if err != nil {
return nil, xerrors.Errorf("failed to get randomness for winning post: %w", err)
}
prand := abi.PoStRandomness(rand)
2020-07-10 14:43:14 +00:00
tSeed := build.Clock.Now()
2020-05-15 09:17:13 +00:00
postProof, err := m.epp.ComputeProof(ctx, mbi.Sectors, prand)
if err != nil {
return nil, xerrors.Errorf("failed to compute winning post proof: %w", err)
}
2019-12-03 18:25:56 +00:00
// get pending messages early,
msgs, err := m.api.MpoolSelect(context.TODO(), base.TipSet.Key(), ticket.Quality())
2019-12-03 18:25:56 +00:00
if err != nil {
2020-08-05 20:17:14 +00:00
return nil, xerrors.Errorf("failed to select messages for block: %w", err)
2019-12-03 18:25:56 +00:00
}
2020-07-10 14:43:14 +00:00
tPending := build.Clock.Now()
2020-05-15 09:17:13 +00:00
2020-04-08 15:11:42 +00:00
// TODO: winning post proof
2020-08-05 20:17:14 +00:00
b, err := m.createBlock(base, m.address, ticket, winner, bvals, postProof, msgs)
if err != nil {
return nil, xerrors.Errorf("failed to create block: %w", err)
}
2020-07-10 14:43:14 +00:00
tCreateBlock := build.Clock.Now()
2020-05-15 09:17:13 +00:00
dur := tCreateBlock.Sub(start)
2020-08-07 15:36:15 +00:00
parentMiners := make([]address.Address, len(base.TipSet.Blocks()))
for i, header := range base.TipSet.Blocks() {
parentMiners[i] = header.Miner
}
log.Infow("mined new block", "cid", b.Cid(), "height", b.Header.Height, "miner", b.Header.Miner, "parents", parentMiners, "took", dur)
if dur > time.Second*time.Duration(build.BlockDelaySecs) {
2020-07-29 21:20:07 +00:00
log.Warnw("CAUTION: block production took longer than the block delay. Your computer may not be fast enough to keep up",
"tMinerBaseInfo ", tMBI.Sub(start),
"tDrand ", tDrand.Sub(tMBI),
"tPowercheck ", tPowercheck.Sub(tDrand),
"tTicket ", tTicket.Sub(tPowercheck),
"tSeed ", tSeed.Sub(tTicket),
"tPending ", tPending.Sub(tSeed),
"tCreateBlock ", tCreateBlock.Sub(tPending))
2019-12-03 00:08:08 +00:00
}
2019-11-27 14:18:51 +00:00
return b, nil
}
func (m *Miner) computeTicket(ctx context.Context, brand *types.BeaconEntry, base *MiningBase) (*types.Ticket, error) {
mi, err := m.api.StateMinerInfo(ctx, m.address, types.EmptyTSK)
2019-08-15 02:30:21 +00:00
if err != nil {
return nil, err
}
2020-04-16 20:38:42 +00:00
worker, err := m.api.StateAccountKey(ctx, mi.Worker, types.EmptyTSK)
if err != nil {
return nil, err
}
2019-08-15 02:30:21 +00:00
buf := new(bytes.Buffer)
if err := m.address.MarshalCBOR(buf); err != nil {
return nil, xerrors.Errorf("failed to marshal address to cbor: %w", err)
}
2020-04-29 22:25:48 +00:00
round := base.TipSet.Height() + base.NullRounds + 1
if round > build.UpgradeSmokeHeight {
2020-04-29 22:25:48 +00:00
buf.Write(base.TipSet.MinTicket().VRFProof)
}
input, err := store.DrawRandomness(brand.Data, crypto.DomainSeparationTag_TicketProduction, round-build.TicketRandomnessLookback, buf.Bytes())
2020-02-23 20:00:47 +00:00
if err != nil {
return nil, err
}
2020-04-16 20:38:42 +00:00
vrfOut, err := gen.ComputeVRF(ctx, m.api.WalletSign, worker, input)
2019-08-15 02:30:21 +00:00
if err != nil {
return nil, err
}
return &types.Ticket{
2019-10-09 04:38:59 +00:00
VRFProof: vrfOut,
2019-08-15 02:30:21 +00:00
}, nil
}
func (m *Miner) createBlock(base *MiningBase, addr address.Address, ticket *types.Ticket,
2020-09-21 23:01:29 +00:00
eproof *types.ElectionProof, bvals []types.BeaconEntry, wpostProof []proof0.PoStProof, msgs []*types.SignedMessage) (*types.BlockMsg, error) {
uts := base.TipSet.MinTimestamp() + build.BlockDelaySecs*(uint64(base.NullRounds)+1)
2020-04-23 21:12:42 +00:00
nheight := base.TipSet.Height() + base.NullRounds + 1
2019-09-06 17:44:09 +00:00
// why even return this? that api call could just submit it for us
2020-04-09 00:24:10 +00:00
return m.api.MinerCreateBlock(context.TODO(), &api.BlockTemplate{
Miner: addr,
2020-04-23 21:12:42 +00:00
Parents: base.TipSet.Key(),
Ticket: ticket,
Eproof: eproof,
BeaconValues: bvals,
Messages: msgs,
Epoch: nheight,
Timestamp: uts,
WinningPoStProof: wpostProof,
2020-04-09 00:24:10 +00:00
})
}
2020-05-15 09:17:13 +00:00
type actCacheEntry struct {
act *types.Actor
err error
}
type cachedActorLookup struct {
tsk types.TipSetKey
cache map[address.Address]actCacheEntry
2020-08-01 22:54:21 +00:00
fallback gasguess.ActorLookup
2020-05-15 09:17:13 +00:00
}
func (c *cachedActorLookup) StateGetActor(ctx context.Context, a address.Address, tsk types.TipSetKey) (*types.Actor, error) {
if c.tsk == tsk {
e, has := c.cache[a]
if has {
return e.act, e.err
}
}
e, err := c.fallback(ctx, a, tsk)
if c.tsk == tsk {
c.cache[a] = actCacheEntry{
act: e, err: err,
}
}
return e, err
}
type ActorLookup func(context.Context, address.Address, types.TipSetKey) (*types.Actor, error)