Merge remote-tracking branch 'origin/master' into fix/some-fsm-issues

api/test/blockminer.go

@@ -41,7 +41,7 @@ func (bm *BlockMiner) MineBlocks() {
 			nulls := atomic.SwapInt64(&bm.nulls, 0)
 			if err := bm.miner.MineOne(bm.ctx, miner.MineReq{
 				InjectNulls: abi.ChainEpoch(nulls),
-				Done:        func(bool, error) {},
+				Done:        func(bool, abi.ChainEpoch, error) {},
 			}); err != nil {
 				bm.t.Error(err)
 			}

api/test/deals.go

@@ -24,6 +24,7 @@ import (
 	"github.com/filecoin-project/lotus/build"
 	sealing "github.com/filecoin-project/lotus/extern/storage-sealing"
 	"github.com/filecoin-project/lotus/miner"
+	"github.com/filecoin-project/specs-actors/actors/abi"
 	dag "github.com/ipfs/go-merkledag"
 	dstest "github.com/ipfs/go-merkledag/test"
 	unixfile "github.com/ipfs/go-unixfs/file"
@@ -35,7 +36,7 @@ import (
 
 var MineNext = miner.MineReq{
 	InjectNulls: 0,
-	Done:        func(bool, error) {},
+	Done:        func(bool, abi.ChainEpoch, error) {},
 }
 
 func init() {

api/test/mining.go

@@ -31,22 +31,20 @@ func (ts *testSuite) testMining(t *testing.T) {
 	newHeads, err := api.ChainNotify(ctx)
 	require.NoError(t, err)
 	initHead := (<-newHeads)[0]
-	if initHead.Val.Height() != 2 {
+	baseHeight := initHead.Val.Height()
-		<-newHeads
-	}
 
 	h1, err := api.ChainHead(ctx)
 	require.NoError(t, err)
-	require.Equal(t, abi.ChainEpoch(2), h1.Height())
+	require.Equal(t, int64(h1.Height()), int64(baseHeight))
 
-	MineUntilBlock(ctx, t, sn[0], nil)
+	MineUntilBlock(ctx, t, apis[0], sn[0], nil)
 	require.NoError(t, err)
 
 	<-newHeads
 
 	h2, err := api.ChainHead(ctx)
 	require.NoError(t, err)
-	require.Equal(t, abi.ChainEpoch(3), h2.Height())
+	require.Greater(t, int64(h2.Height()), int64(h1.Height()))
 }
 
 func (ts *testSuite) testMiningReal(t *testing.T) {
@@ -70,7 +68,7 @@ func (ts *testSuite) testMiningReal(t *testing.T) {
 	require.NoError(t, err)
 	require.Equal(t, abi.ChainEpoch(2), h1.Height())
 
-	MineUntilBlock(ctx, t, sn[0], nil)
+	MineUntilBlock(ctx, t, apis[0], sn[0], nil)
 	require.NoError(t, err)
 
 	<-newHeads
@@ -79,7 +77,7 @@ func (ts *testSuite) testMiningReal(t *testing.T) {
 	require.NoError(t, err)
 	require.Equal(t, abi.ChainEpoch(3), h2.Height())
 
-	MineUntilBlock(ctx, t, sn[0], nil)
+	MineUntilBlock(ctx, t, apis[0], sn[0], nil)
 	require.NoError(t, err)
 
 	<-newHeads
@@ -144,7 +142,7 @@ func TestDealMining(t *testing.T, b APIBuilder, blocktime time.Duration, carExpo
 		complChan := minedTwo
 		for atomic.LoadInt32(&mine) != 0 {
 			wait := make(chan int)
-			mdone := func(mined bool, err error) {
+			mdone := func(mined bool, _ abi.ChainEpoch, err error) {
 				n := 0
 				if mined {
 					n = 1

api/test/util.go

@@ -3,6 +3,7 @@ package test
 import (
 	"context"
 	"testing"
+	"time"
 
 	"github.com/filecoin-project/specs-actors/actors/abi"
 
@@ -36,15 +37,17 @@ func SendFunds(ctx context.Context, t *testing.T, sender TestNode, addr address.
 	}
 }
 
-func MineUntilBlock(ctx context.Context, t *testing.T, sn TestStorageNode, cb func()) {
+func MineUntilBlock(ctx context.Context, t *testing.T, fn TestNode, sn TestStorageNode, cb func(abi.ChainEpoch)) {
 	for i := 0; i < 1000; i++ {
 		var success bool
 		var err error
+		var epoch abi.ChainEpoch
 		wait := make(chan struct{})
 		mineErr := sn.MineOne(ctx, miner.MineReq{
-			Done: func(win bool, e error) {
+			Done: func(win bool, ep abi.ChainEpoch, e error) {
 				success = win
 				err = e
+				epoch = ep
 				wait <- struct{}{}
 			},
 		})
@@ -56,8 +59,24 @@ func MineUntilBlock(ctx context.Context, t *testing.T, sn TestStorageNode, cb fu
 			t.Fatal(err)
 		}
 		if success {
+			// Wait until it shows up on the given full nodes ChainHead
+			nloops := 50
+			for i := 0; i < nloops; i++ {
+				ts, err := fn.ChainHead(ctx)
+				if err != nil {
+					t.Fatal(err)
+				}
+				if ts.Height() == epoch {
+					break
+				}
+				if i == nloops-1 {
+					t.Fatal("block never managed to sync to node")
+				}
+				time.Sleep(time.Millisecond * 10)
+			}
+
 			if cb != nil {
-				cb()
+				cb(epoch)
 			}
 			return
 		}

api/test/window_post.go

@@ -53,7 +53,7 @@ func TestPledgeSector(t *testing.T, b APIBuilder, blocktime time.Duration, nSect
 		defer close(done)
 		for mine {
 			build.Clock.Sleep(blocktime)
-			if err := sn[0].MineOne(ctx, bminer.MineReq{Done: func(bool, error) {
+			if err := sn[0].MineOne(ctx, bminer.MineReq{Done: func(bool, abi.ChainEpoch, error) {
 
 			}}); err != nil {
 				t.Error(err)

chain/sync.go

@@ -655,7 +655,7 @@ func (syncer *Syncer) ValidateBlock(ctx context.Context, b *types.FullBlock) (er
 	validationStart := build.Clock.Now()
 	defer func() {
 		stats.Record(ctx, metrics.BlockValidationDurationMilliseconds.M(metrics.SinceInMilliseconds(validationStart)))
-		log.Infow("block validation", "took", time.Since(validationStart), "height", b.Header.Height)
+		log.Infow("block validation", "took", time.Since(validationStart), "height", b.Header.Height, "age", time.Since(time.Unix(int64(b.Header.Timestamp), 0)))
 	}()
 
 	ctx, span := trace.StartSpan(ctx, "validateBlock")

go.sum

@@ -41,6 +41,7 @@ github.com/BurntSushi/toml v0.3.1/go.mod h1:xHWCNGjB5oqiDr8zfno3MHue2Ht5sIBksp03
 github.com/BurntSushi/xgb v0.0.0-20160522181843-27f122750802/go.mod h1:IVnqGOEym/WlBOVXweHU+Q+/VP0lqqI8lqeDx9IjBqo=
 github.com/DataDog/zstd v1.4.1 h1:3oxKN3wbHibqx897utPC2LTQU4J+IHWWJO+glkAkpFM=
 github.com/DataDog/zstd v1.4.1/go.mod h1:1jcaCB/ufaK+sKp1NBhlGmpz41jOoPQ35bpF36t7BBo=
+github.com/GeertJohan/go.incremental v1.0.0 h1:7AH+pY1XUgQE4Y1HcXYaMqAI0m9yrFqo/jt0CW30vsg=
 github.com/GeertJohan/go.incremental v1.0.0/go.mod h1:6fAjUhbVuX1KcMD3c8TEgVUqmo4seqhv0i0kdATSkM0=
 github.com/GeertJohan/go.rice v1.0.0 h1:KkI6O9uMaQU3VEKaj01ulavtF7o1fWT7+pk/4voiMLQ=
 github.com/GeertJohan/go.rice v1.0.0/go.mod h1:eH6gbSOAUv07dQuZVnBmoDP8mgsM1rtixis4Tib9if0=
@@ -62,6 +63,7 @@ github.com/acarl005/stripansi v0.0.0-20180116102854-5a71ef0e047d h1:licZJFw2RwpH
 github.com/acarl005/stripansi v0.0.0-20180116102854-5a71ef0e047d/go.mod h1:asat636LX7Bqt5lYEZ27JNDcqxfjdBQuJ/MM4CN/Lzo=
 github.com/aead/siphash v1.0.1/go.mod h1:Nywa3cDsYNNK3gaciGTWPwHt0wlpNV15vwmswBAUSII=
 github.com/afex/hystrix-go v0.0.0-20180502004556-fa1af6a1f4f5/go.mod h1:SkGFH1ia65gfNATL8TAiHDNxPzPdmEL5uirI2Uyuz6c=
+github.com/akavel/rsrc v0.8.0 h1:zjWn7ukO9Kc5Q62DOJCcxGpXC18RawVtYAGdz2aLlfw=
 github.com/akavel/rsrc v0.8.0/go.mod h1:uLoCtb9J+EyAqh+26kdrTgmzRBFPGOolLWKpdxkKq+c=
 github.com/alecthomas/template v0.0.0-20160405071501-a0175ee3bccc/go.mod h1:LOuyumcjzFXgccqObfd/Ljyb9UuFJ6TxHnclSeseNhc=
 github.com/alecthomas/template v0.0.0-20190718012654-fb15b899a751/go.mod h1:LOuyumcjzFXgccqObfd/Ljyb9UuFJ6TxHnclSeseNhc=
@@ -674,6 +676,7 @@ github.com/jbenet/goprocess v0.1.4 h1:DRGOFReOMqqDNXwW70QkacFW0YN9QnwLV0Vqk+3oU0
 github.com/jbenet/goprocess v0.1.4/go.mod h1:5yspPrukOVuOLORacaBi858NqyClJPQxYZlqdZVfqY4=
 github.com/jellevandenhooff/dkim v0.0.0-20150330215556-f50fe3d243e1/go.mod h1:E0B/fFc00Y+Rasa88328GlI/XbtyysCtTHZS8h7IrBU=
 github.com/jessevdk/go-flags v0.0.0-20141203071132-1679536dcc89/go.mod h1:4FA24M0QyGHXBuZZK/XkWh8h0e1EYbRYJSGM75WSRxI=
+github.com/jessevdk/go-flags v1.4.0 h1:4IU2WS7AumrZ/40jfhf4QVDMsQwqA7VEHozFRrGARJA=
 github.com/jessevdk/go-flags v1.4.0/go.mod h1:4FA24M0QyGHXBuZZK/XkWh8h0e1EYbRYJSGM75WSRxI=
 github.com/jmespath/go-jmespath v0.0.0-20180206201540-c2b33e8439af/go.mod h1:Nht3zPeWKUH0NzdCt2Blrr5ys8VGpn0CEB0cQHVjt7k=
 github.com/jmespath/go-jmespath v0.3.0/go.mod h1:9QtRXoHjLGCJ5IBSaohpXITPlowMeeYCZ7fLUTSywik=
@@ -1171,6 +1174,7 @@ github.com/neelance/astrewrite v0.0.0-20160511093645-99348263ae86/go.mod h1:kHJE
 github.com/neelance/sourcemap v0.0.0-20151028013722-8c68805598ab/go.mod h1:Qr6/a/Q4r9LP1IltGz7tA7iOK1WonHEYhu1HRBA7ZiM=
 github.com/nikkolasg/hexjson v0.0.0-20181101101858-78e39397e00c h1:5bFTChQxSKNwy8ALwOebjekYExl9HTT9urdawqC95tA=
 github.com/nikkolasg/hexjson v0.0.0-20181101101858-78e39397e00c/go.mod h1:7qN3Y0BvzRUf4LofcoJplQL10lsFDb4PYlePTVwrP28=
+github.com/nkovacs/streamquote v0.0.0-20170412213628-49af9bddb229 h1:E2B8qYyeSgv5MXpmzZXRNp8IAQ4vjxIjhpAf5hv/tAg=
 github.com/nkovacs/streamquote v0.0.0-20170412213628-49af9bddb229/go.mod h1:0aYXnNPJ8l7uZxf45rWW1a/uME32OF0rhiYGNQ2oF2E=
 github.com/nxadm/tail v1.4.4 h1:DQuhQpB1tVlglWS2hLQ5OV6B5r8aGxSrPc5Qo6uTN78=
 github.com/nxadm/tail v1.4.4/go.mod h1:kenIhsEOeOJmVchQTgglprH7qJGnHDVpk1VPCcaMI8A=
@@ -1387,7 +1391,9 @@ github.com/urfave/cli v1.22.1/go.mod h1:Gos4lmkARVdJ6EkW0WaNv/tZAAMe9V7XWyB60NtX
 github.com/urfave/cli/v2 v2.0.0/go.mod h1:SE9GqnLQmjVa0iPEY0f1w3ygNIYcIJ0OKPMoW2caLfQ=
 github.com/urfave/cli/v2 v2.2.0 h1:JTTnM6wKzdA0Jqodd966MVj4vWbbquZykeX1sKbe2C4=
 github.com/urfave/cli/v2 v2.2.0/go.mod h1:SE9GqnLQmjVa0iPEY0f1w3ygNIYcIJ0OKPMoW2caLfQ=
+github.com/valyala/bytebufferpool v1.0.0 h1:GqA5TC/0021Y/b9FG4Oi9Mr3q7XYx6KllzawFIhcdPw=
 github.com/valyala/bytebufferpool v1.0.0/go.mod h1:6bBcMArwyJ5K/AmCkWv1jt77kVWyCJ6HpOuEn7z0Csc=
+github.com/valyala/fasttemplate v1.0.1 h1:tY9CJiPnMXf1ERmG2EyK7gNUd+c6RKGD0IfU8WdUSz8=
 github.com/valyala/fasttemplate v1.0.1/go.mod h1:UQGH1tvbgY+Nz5t2n7tXsz52dQxojPUpymEIMZ47gx8=
 github.com/viant/assertly v0.4.8/go.mod h1:aGifi++jvCrUaklKEKT0BU95igDNaqkvz+49uaYMPRU=
 github.com/viant/toolbox v0.24.0/go.mod h1:OxMCG57V0PXuIP2HNQrtJf2CjqdmbrOx5EkMILuUhzM=

miner/miner.go

@@ -32,7 +32,7 @@ import (
 var log = logging.Logger("miner")
 
 // returns a callback reporting whether we mined a blocks in this round
-type waitFunc func(ctx context.Context, baseTime uint64) (func(bool, error), abi.ChainEpoch, error)
+type waitFunc func(ctx context.Context, baseTime uint64) (func(bool, abi.ChainEpoch, error), abi.ChainEpoch, error)
 
 func randTimeOffset(width time.Duration) time.Duration {
 	buf := make([]byte, 8)
@@ -52,7 +52,7 @@ func NewMiner(api api.FullNode, epp gen.WinningPoStProver, addr address.Address,
 		api:     api,
 		epp:     epp,
 		address: addr,
-		waitFunc: func(ctx context.Context, baseTime uint64) (func(bool, error), abi.ChainEpoch, error) {
+		waitFunc: func(ctx context.Context, baseTime uint64) (func(bool, abi.ChainEpoch, error), abi.ChainEpoch, error) {
 			// Wait around for half the block time in case other parents come in
 			deadline := baseTime + build.PropagationDelaySecs
 			baseT := time.Unix(int64(deadline), 0)
@@ -61,7 +61,7 @@ func NewMiner(api api.FullNode, epp gen.WinningPoStProver, addr address.Address,
 
 			build.Clock.Sleep(build.Clock.Until(baseT))
 
-			return func(bool, error) {}, 0, nil
+			return func(bool, abi.ChainEpoch, error) {}, 0, nil
 		},
 
 		sf:                sf,
@@ -150,7 +150,7 @@ func (m *Miner) mine(ctx context.Context) {
 		}
 
 		var base *MiningBase
-		var onDone func(bool, error)
+		var onDone func(bool, abi.ChainEpoch, error)
 		var injectNulls abi.ChainEpoch
 
 		for {
@@ -166,7 +166,7 @@ func (m *Miner) mine(ctx context.Context) {
 				break
 			}
 			if base != nil {
-				onDone(false, nil)
+				onDone(false, 0, nil)
 			}
 
 			// TODO: need to change the orchestration here. the problem is that
@@ -205,12 +205,16 @@ func (m *Miner) mine(ctx context.Context) {
 		if err != nil {
 			log.Errorf("mining block failed: %+v", err)
 			m.niceSleep(time.Second)
-			onDone(false, err)
+			onDone(false, 0, err)
 			continue
 		}
 		lastBase = *base
 
-		onDone(b != nil, nil)
+		var h abi.ChainEpoch
+		if b != nil {
+			h = b.Header.Height
+		}
+		onDone(b != nil, h, nil)
 
 		if b != nil {
 			journal.Add("blockMined", map[string]interface{}{

miner/testminer.go

@@ -15,7 +15,7 @@ import (
 
 type MineReq struct {
 	InjectNulls abi.ChainEpoch
-	Done        func(bool, error)
+	Done        func(bool, abi.ChainEpoch, error)
 }
 
 func NewTestMiner(nextCh <-chan MineReq, addr address.Address) func(api.FullNode, gen.WinningPoStProver) *Miner {
@@ -41,8 +41,8 @@ func NewTestMiner(nextCh <-chan MineReq, addr address.Address) func(api.FullNode
 	}
 }
 
-func chanWaiter(next <-chan MineReq) func(ctx context.Context, _ uint64) (func(bool, error), abi.ChainEpoch, error) {
+func chanWaiter(next <-chan MineReq) func(ctx context.Context, _ uint64) (func(bool, abi.ChainEpoch, error), abi.ChainEpoch, error) {
-	return func(ctx context.Context, _ uint64) (func(bool, error), abi.ChainEpoch, error) {
+	return func(ctx context.Context, _ uint64) (func(bool, abi.ChainEpoch, error), abi.ChainEpoch, error) {
 		select {
 		case <-ctx.Done():
 			return nil, 0, ctx.Err()

node/test/builder.go

@@ -270,11 +270,12 @@ func Builder(t *testing.T, nFull int, storage []test.StorageMiner) ([]test.TestN
 		var wait sync.Mutex
 		wait.Lock()
 
-		test.MineUntilBlock(ctx, t, storers[0], func() {
+		test.MineUntilBlock(ctx, t, fulls[0], storers[0], func(epoch abi.ChainEpoch) {
 			wait.Unlock()
 		})
+
 		wait.Lock()
-		test.MineUntilBlock(ctx, t, storers[0], func() {
+		test.MineUntilBlock(ctx, t, fulls[0], storers[0], func(epoch abi.ChainEpoch) {
 			wait.Unlock()
 		})
 		wait.Lock()
@@ -419,11 +420,11 @@ func MockSbBuilder(t *testing.T, nFull int, storage []test.StorageMiner) ([]test
 		var wait sync.Mutex
 		wait.Lock()
 
-		test.MineUntilBlock(ctx, t, storers[0], func() {
+		test.MineUntilBlock(ctx, t, fulls[0], storers[0], func(abi.ChainEpoch) {
 			wait.Unlock()
 		})
 		wait.Lock()
-		test.MineUntilBlock(ctx, t, storers[0], func() {
+		test.MineUntilBlock(ctx, t, fulls[0], storers[0], func(abi.ChainEpoch) {
 			wait.Unlock()
 		})
 		wait.Lock()