chain: add optional logging

chain/chain_test.go

@@ -1,12 +1,18 @@
 package chain_test
 
 import (
+	"context"
+	"net"
 	"testing"
 	"time"
 
+	"go.sia.tech/core/gateway"
 	"go.sia.tech/core/types"
 	"go.sia.tech/coreutils"
 	"go.sia.tech/coreutils/chain"
+	"go.sia.tech/coreutils/syncer"
+	"go.sia.tech/coreutils/testutil"
+	"go.uber.org/zap/zaptest"
 	"lukechampine.com/frand"
 )
 
@@ -316,3 +322,37 @@ func TestV2Attestations(t *testing.T) {
 		ms.Sync(t, cm)
 	})
 }
+
+func TestZen(t *testing.T) {
+	log := zaptest.NewLogger(t)
+	n, genesisBlock := chain.TestnetZen()
+
+	store, tipState, err := chain.NewDBStore(chain.NewMemDB(), n, genesisBlock)
+	if err != nil {
+		t.Fatal(err)
+	}
+	cm := chain.NewManager(store, tipState, chain.WithLog(log.Named("chain")))
+
+	l, err := net.Listen("tcp", "localhost:0")
+	if err != nil {
+		t.Fatal(err)
+	}
+	defer l.Close()
+
+	peerStore := testutil.NewMemPeerStore()
+	for _, peer := range syncer.ZenBootstrapPeers {
+		peerStore.AddPeer(peer)
+	}
+	s := syncer.New(l, cm, peerStore, gateway.Header{
+		GenesisID:  genesisBlock.ID(),
+		UniqueID:   gateway.GenerateUniqueID(),
+		NetAddress: "127.0.0.1:9880",
+	}, syncer.WithLogger(log.Named("syncer")))
+	defer s.Close()
+	go s.Run(context.Background())
+
+	ctx, cancel := context.WithCancel(context.Background())
+	defer cancel()
+
+	<-ctx.Done()
+}

chain/manager.go

@@ -9,6 +9,7 @@ import (
 
 	"go.sia.tech/core/consensus"
 	"go.sia.tech/core/types"
+	"go.uber.org/zap"
 	"lukechampine.com/frand"
 )
 
@@ -73,6 +74,7 @@ func blockAndChild(s Store, id types.BlockID) (types.Block, *consensus.V1BlockSu
 // A Manager tracks multiple blockchains and identifies the best valid
 // chain.
 type Manager struct {
+	log           *zap.Logger
 	store         Store
 	tipState      consensus.State
 	onReorg       map[[16]byte]func(types.ChainIndex)
@@ -199,6 +201,8 @@ func (m *Manager) AddBlocks(blocks []types.Block) error {
 		return nil
 	}
 
+	log := m.log.Named("AddBlocks")
+
 	cs := m.tipState
 	for _, b := range blocks {
 		bid := b.ID()
@@ -226,11 +230,13 @@ func (m *Manager) AddBlocks(blocks []types.Block) error {
 		cs = consensus.ApplyOrphan(cs, b, ancestorTimestamp)
 		m.store.AddState(cs)
 		m.store.AddBlock(b, nil)
+		log.Debug("added block", zap.Uint64("height", cs.Index.Height), zap.Stringer("id", bid))
 	}
 
 	// if this chain is now the best chain, trigger a reorg
 	if cs.SufficientlyHeavierThan(m.tipState) {
 		oldTip := m.tipState.Index
+		log.Debug("reorging to", zap.Stringer("current", oldTip), zap.Stringer("target", cs.Index))
 		if err := m.reorgTo(cs.Index); err != nil {
 			if err := m.reorgTo(oldTip); err != nil {
 				return fmt.Errorf("failed to revert failed reorg: %w", err)
@@ -456,6 +462,7 @@ func (m *Manager) OnReorg(fn func(types.ChainIndex)) (cancel func()) {
 }
 
 func (m *Manager) revalidatePool() {
+	log := m.log.Named("revalidatePool")
 	txpoolMaxWeight := m.tipState.MaxBlockWeight() * 10
 	if m.txpool.ms != nil && m.txpool.weight < txpoolMaxWeight {
 		return
@@ -516,24 +523,28 @@ func (m *Manager) revalidatePool() {
 	filtered := m.txpool.txns[:0]
 	for _, txn := range m.txpool.txns {
 		ts := m.store.SupplementTipTransaction(txn)
-		if consensus.ValidateTransaction(m.txpool.ms, txn, ts) == nil {
-			m.txpool.ms.ApplyTransaction(txn, ts)
-			m.txpool.indices[txn.ID()] = len(m.txpool.txns)
-			m.txpool.weight += m.tipState.TransactionWeight(txn)
-			filtered = append(filtered, txn)
+		if err := consensus.ValidateTransaction(m.txpool.ms, txn, ts); err != nil {
+			log.Debug("dropping invalid pool transaction", zap.Stringer("id", txn.ID()), zap.Error(err))
+			continue
 		}
+		m.txpool.ms.ApplyTransaction(txn, ts)
+		m.txpool.indices[txn.ID()] = len(m.txpool.txns)
+		m.txpool.weight += m.tipState.TransactionWeight(txn)
+		filtered = append(filtered, txn)
 	}
 	m.txpool.txns = filtered
 
 	m.txpool.v2txns = append(m.txpool.v2txns, m.txpool.lastRevertedV2...)
 	v2filtered := m.txpool.v2txns[:0]
 	for _, txn := range m.txpool.v2txns {
-		if consensus.ValidateV2Transaction(m.txpool.ms, txn) == nil {
-			m.txpool.ms.ApplyV2Transaction(txn)
-			m.txpool.indices[txn.ID()] = len(m.txpool.v2txns)
-			m.txpool.weight += m.tipState.V2TransactionWeight(txn)
-			v2filtered = append(v2filtered, txn)
+		if err := consensus.ValidateV2Transaction(m.txpool.ms, txn); err != nil {
+			log.Debug("dropping invalid pool v2 transaction", zap.Stringer("id", txn.ID()), zap.Error(err))
+			continue
 		}
+		m.txpool.ms.ApplyV2Transaction(txn)
+		m.txpool.indices[txn.ID()] = len(m.txpool.v2txns)
+		m.txpool.weight += m.tipState.V2TransactionWeight(txn)
+		v2filtered = append(v2filtered, txn)
 	}
 	m.txpool.v2txns = v2filtered
 }
@@ -1243,13 +1254,17 @@ func (m *Manager) AddV2PoolTransactions(basis types.ChainIndex, txns []types.V2T
 }
 
 // NewManager returns a Manager initialized with the provided Store and State.
-func NewManager(store Store, cs consensus.State) *Manager {
+func NewManager(store Store, cs consensus.State, opts ...ManagerOption) *Manager {
 	m := &Manager{
+		log:           zap.NewNop(),
 		store:         store,
 		tipState:      cs,
 		onReorg:       make(map[[16]byte]func(types.ChainIndex)),
 		invalidBlocks: make(map[types.BlockID]error),
 	}
+	for _, opt := range opts {
+		opt(m)
+	}
 	m.txpool.indices = make(map[types.TransactionID]int)
 	m.txpool.invalidTxnSets = make(map[types.Hash256]error)
 	return m

chain/options.go

@@ -0,0 +1,13 @@
+package chain
+
+import "go.uber.org/zap"
+
+// A ManagerOption sets an optional parameter on a Manager.
+type ManagerOption func(*Manager)
+
+// WithLog sets the logger used by the Manager.
+func WithLog(l *zap.Logger) ManagerOption {
+	return func(m *Manager) {
+		m.log = l
+	}
+}

go.mod

@@ -6,7 +6,7 @@ toolchain go1.23.0
 
 require (
 	go.etcd.io/bbolt v1.3.11
-	go.sia.tech/core v0.4.4
+	go.sia.tech/core v0.4.5
 	go.uber.org/zap v1.27.0
 	golang.org/x/crypto v0.26.0
 	lukechampine.com/frand v1.4.2
@@ -15,6 +15,6 @@ require (
 require (
 	github.com/aead/chacha20 v0.0.0-20180709150244-8b13a72661da // indirect
 	go.sia.tech/mux v1.2.0 // indirect
-	go.uber.org/multierr v1.10.0 // indirect
+	go.uber.org/multierr v1.11.0 // indirect
 	golang.org/x/sys v0.24.0 // indirect
 )

go.sum

@@ -8,14 +8,14 @@ github.com/stretchr/testify v1.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKs
 github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4=
 go.etcd.io/bbolt v1.3.11 h1:yGEzV1wPz2yVCLsD8ZAiGHhHVlczyC9d1rP43/VCRJ0=
 go.etcd.io/bbolt v1.3.11/go.mod h1:dksAq7YMXoljX0xu6VF5DMZGbhYYoLUalEiSySYAS4I=
-go.sia.tech/core v0.4.4 h1:DYb0/DxgACstJUGgsRJIVtrsTC0mk6GfA6pTxQwzKV0=
-go.sia.tech/core v0.4.4/go.mod h1:Zuq0Tn2aIXJyO0bjGu8cMeVWe+vwQnUfZhG1LCmjD5c=
+go.sia.tech/core v0.4.5 h1:w2D3Mx29UmK1aFd9R7uHFo5JUSTqu3+92NHoRFv3CaU=
+go.sia.tech/core v0.4.5/go.mod h1:Zuq0Tn2aIXJyO0bjGu8cMeVWe+vwQnUfZhG1LCmjD5c=
 go.sia.tech/mux v1.2.0 h1:ofa1Us9mdymBbGMY2XH/lSpY8itFsKIo/Aq8zwe+GHU=
 go.sia.tech/mux v1.2.0/go.mod h1:Yyo6wZelOYTyvrHmJZ6aQfRoer3o4xyKQ4NmQLJrBSo=
 go.uber.org/goleak v1.3.0 h1:2K3zAYmnTNqV73imy9J1T3WC+gmCePx2hEGkimedGto=
 go.uber.org/goleak v1.3.0/go.mod h1:CoHD4mav9JJNrW/WLlf7HGZPjdw8EucARQHekz1X6bE=
-go.uber.org/multierr v1.10.0 h1:S0h4aNzvfcFsC3dRF1jLoaov7oRaKqRGC/pUEJ2yvPQ=
-go.uber.org/multierr v1.10.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y=
+go.uber.org/multierr v1.11.0 h1:blXXJkSxSSfBVBlC76pxqeO+LN3aDfLQo+309xJstO0=
+go.uber.org/multierr v1.11.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y=
 go.uber.org/zap v1.27.0 h1:aJMhYGrd5QSmlpLMr2MftRKl7t8J8PTZPA732ud/XR8=
 go.uber.org/zap v1.27.0/go.mod h1:GB2qFLM7cTU87MWRP2mPIjqfIDnGu+VIO4V/SdhGo2E=
 golang.org/x/crypto v0.26.0 h1:RrRspgV4mU+YwB4FYnuBoKsUapNIL5cohGAmSH3azsw=