diff --git a/.gitignore b/.gitignore index 1795c8d..47f5367 100644 --- a/.gitignore +++ b/.gitignore @@ -1 +1,2 @@ -.history \ No newline at end of file +.history +.idea diff --git a/Peer.go b/Peer.go index e1d453d..827e4d4 100644 --- a/Peer.go +++ b/Peer.go @@ -2,10 +2,11 @@ package p2p import ( "bufio" + "encoding/hex" "errors" "fmt" "io" - "log" + "log/slog" "net" "strconv" "strings" @@ -16,10 +17,8 @@ import ( "github.com/libsv/go-p2p/bsvutil" "github.com/libsv/go-p2p/chaincfg/chainhash" "github.com/libsv/go-p2p/wire" - "github.com/ordishs/go-utils/batcher" - "github.com/ordishs/go-utils" - "github.com/ordishs/gocore" + "github.com/ordishs/go-utils/batcher" ) var ( @@ -27,7 +26,16 @@ var ( ) const ( - defaultMaximumMessageSize = 32 * 1024 * 1024 + defaultMaximumMessageSize = 32 * 1024 * 1024 + defaultBatchDelayMilliseconds = 200 + + commandKey = "cmd" + hashKey = "hash" + errKey = "err" + typeKey = "type" + + sentMsg = "Sent" + receivedMsg = "Recv" ) type Block struct { @@ -50,7 +58,7 @@ type Peer struct { peerHandler PeerHandlerI writeChan chan wire.Message quit chan struct{} - logger utils.Logger + logger *slog.Logger sentVerAck atomic.Bool receivedVerAck atomic.Bool batchDelay time.Duration @@ -60,23 +68,38 @@ type Peer struct { } // NewPeer returns a new bitcoin peer for the provided address and configuration. -func NewPeer(logger utils.Logger, address string, peerHandler PeerHandlerI, network wire.BitcoinNet, options ...PeerOptions) (*Peer, error) { +func NewPeer(logger *slog.Logger, address string, peerHandler PeerHandlerI, network wire.BitcoinNet, options ...PeerOptions) (*Peer, error) { writeChan := make(chan wire.Message, 10000) + peerLogger := logger.With( + slog.Group("peer", + slog.String("network", network.String()), + slog.String("address", address), + ), + ) + p := &Peer{ network: network, address: address, writeChan: writeChan, peerHandler: peerHandler, - logger: logger, + logger: peerLogger, dial: net.Dial, maximumMessageSize: defaultMaximumMessageSize, + batchDelay: defaultBatchDelayMilliseconds * time.Millisecond, } for _, option := range options { option(p) } + p.initialize() + + return p, nil +} + +func (p *Peer) initialize() { + go p.pingHandler() for i := 0; i < 10; i++ { // start 10 workers that will write to the peer @@ -88,35 +111,28 @@ func NewPeer(logger utils.Logger, address string, peerHandler PeerHandlerI, netw go func() { err := p.connect() if err != nil { - logger.Warnf("Failed to connect to peer %s: %v", address, err) + p.logger.Warn("Failed to connect to peer", slog.String(errKey, err.Error())) } }() if p.incomingConn != nil { - p.logger.Infof("[%s] Incoming connection from peer on %s", p.address, p.network) + p.logger.Info("Incoming connection from peer") } else { // reconnect if disconnected, but only on outgoing connections go func() { for range time.NewTicker(10 * time.Second).C { - // logger.Debugf("checking connection to peer %s, connected = %t, connecting = %t", address, p.Connected(), p.Connecting()) if !p.Connected() && !p.Connecting() { err := p.connect() if err != nil { - logger.Warnf("Failed to connect to peer %s: %v", address, err) + p.logger.Warn("Failed to connect to peer", slog.String(errKey, err.Error())) } } } }() } - if p.batchDelay == 0 { - batchDelayMillis, _ := gocore.Config().GetInt("peerManager_batchDelay_millis", 200) - p.batchDelay = time.Duration(batchDelayMillis) * time.Millisecond - } p.invBatcher = batcher.New(500, p.batchDelay, p.sendInvBatch, true) p.dataBatcher = batcher.New(500, p.batchDelay, p.sendDataBatch, true) - - return p, nil } func (p *Peer) disconnect() { @@ -154,10 +170,10 @@ func (p *Peer) connect() error { if p.incomingConn != nil { p.readConn = p.incomingConn } else { - p.logger.Infof("[%s] Connecting to peer on %s", p.address, p.network) + p.logger.Info("Connecting") conn, err := p.dial("tcp", p.address) if err != nil { - return fmt.Errorf("could not dial node [%s]: %v", p.address, err) + return fmt.Errorf("could not dial node: %v", err) } // open the read connection, so we can receive messages @@ -175,7 +191,7 @@ func (p *Peer) connect() error { if err := wire.WriteMessage(p.readConn, msg, wire.ProtocolVersion, p.network); err != nil { return fmt.Errorf("failed to write message: %v", err) } - p.logger.Debugf("[%s] Sent %s", p.address, strings.ToUpper(msg.Command())) + p.logger.Debug(sentMsg, slog.String(commandKey, strings.ToUpper(msg.Command()))) startWaitTime := time.Now() for { @@ -192,7 +208,7 @@ func (p *Peer) connect() error { // set the connection which allows us to send messages p.writeConn = p.readConn - p.logger.Infof("[%s] Connected to peer on %s", p.address, p.network) + p.logger.Info("Connection established") return nil } @@ -228,7 +244,7 @@ func (p *Peer) readHandler() { readConn := p.readConn if readConn == nil { - p.logger.Errorf("no connection") + p.logger.Error("no connection") return } @@ -237,84 +253,93 @@ func (p *Peer) readHandler() { msg, b, err := wire.ReadMessage(reader, wire.ProtocolVersion, p.network) if err != nil { if errors.Is(err, io.EOF) { - p.logger.Errorf(fmt.Sprintf("READ EOF whilst reading from %s [%d bytes], bytes = %s, err = %v", p.address, len(b), string(b), err)) + p.logger.Error("failed to read message: EOF", slog.Int("bytes", len(b)), slog.String("rawMessage", string(b)), slog.String(errKey, err.Error())) p.disconnect() break } - p.logger.Errorf("[%s] Failed to read message: %v", p.address, err) + + p.logger.Error("failed to read message", slog.Int("bytes", len(b)), slog.String("rawMessage", string(b)), slog.String(errKey, err.Error())) continue } + commandLogger := p.logger.With(slog.String(commandKey, strings.ToUpper(msg.Command()))) + // we could check this based on type (switch msg.(type)) but that would not allow // us to override the default behaviour for a specific message type switch msg.Command() { case wire.CmdVersion: - p.logger.Debugf("[%s] Recv %s", p.address, strings.ToUpper(msg.Command())) + commandLogger.Debug(receivedMsg) if p.sentVerAck.Load() { - p.logger.Warnf("[%s] Received version message after sending verack", p.address) + commandLogger.Warn("Received version message after sending verack") continue } verackMsg := wire.NewMsgVerAck() if err = wire.WriteMessage(readConn, verackMsg, wire.ProtocolVersion, p.network); err != nil { - p.logger.Errorf("[%s] failed to write message: %v", p.address, err) + commandLogger.Error("failed to write message", slog.String(errKey, err.Error())) } - p.logger.Debugf("[%s] Sent %s", p.address, strings.ToUpper(verackMsg.Command())) + commandLogger.Debug(sentMsg, slog.String(commandKey, strings.ToUpper(verackMsg.Command()))) p.sentVerAck.Store(true) case wire.CmdPing: - pingMsg := msg.(*wire.MsgPing) + pingMsg, ok := msg.(*wire.MsgPing) + if !ok { + continue + } p.writeChan <- wire.NewMsgPong(pingMsg.Nonce) case wire.CmdInv: - invMsg := msg.(*wire.MsgInv) - if p.logger.LogLevel() == int(gocore.DEBUG) { - p.logger.Debugf("[%s] Recv INV (%d items)", p.address, len(invMsg.InvList)) - for _, inv := range invMsg.InvList { - p.logger.Debugf(" [%s] %s", p.address, inv.Hash.String()) - } + invMsg, ok := msg.(*wire.MsgInv) + if !ok { + continue + } + for _, inv := range invMsg.InvList { + commandLogger.Debug(receivedMsg, slog.String(hashKey, inv.Hash.String()), slog.String(typeKey, inv.Type.String())) } - go func(invList []*wire.InvVect) { + go func(invList []*wire.InvVect, routineLogger *slog.Logger) { for _, invVect := range invList { switch invVect.Type { case wire.InvTypeTx: if err = p.peerHandler.HandleTransactionAnnouncement(invVect, p); err != nil { - p.logger.Errorf("[%s] Unable to process tx %s: %v", p.address, invVect.Hash.String(), err) + commandLogger.Error("Unable to process tx", slog.String(hashKey, invVect.Hash.String()), slog.String(typeKey, invVect.Type.String()), slog.String(errKey, err.Error())) } case wire.InvTypeBlock: if err = p.peerHandler.HandleBlockAnnouncement(invVect, p); err != nil { - p.logger.Errorf("[%s] Unable to process block %s: %v", p.address, invVect.Hash.String(), err) + commandLogger.Error("Unable to process block", slog.String(hashKey, invVect.Hash.String()), slog.String(typeKey, invVect.Type.String()), slog.String(errKey, err.Error())) } } } - }(invMsg.InvList) + }(invMsg.InvList, commandLogger) case wire.CmdGetData: - dataMsg := msg.(*wire.MsgGetData) - p.logger.Infof("[%s] Recv GETDATA (%d items)", p.address, len(dataMsg.InvList)) - if p.logger.LogLevel() == int(gocore.DEBUG) { - for _, inv := range dataMsg.InvList { - p.logger.Debugf(" [%s] %s", p.address, inv.Hash.String()) - } + dataMsg, ok := msg.(*wire.MsgGetData) + if !ok { + continue + } + for _, inv := range dataMsg.InvList { + commandLogger.Debug(receivedMsg, slog.String(hashKey, inv.Hash.String()), slog.String(typeKey, inv.Type.String())) } - p.handleGetDataMsg(dataMsg) + p.handleGetDataMsg(dataMsg, commandLogger) case wire.CmdTx: - txMsg := msg.(*wire.MsgTx) - p.logger.Debugf("Recv TX %s (%d bytes)", txMsg.TxHash().String(), txMsg.SerializeSize()) + txMsg, ok := msg.(*wire.MsgTx) + if !ok { + continue + } + commandLogger.Debug(receivedMsg, slog.String(hashKey, txMsg.TxHash().String()), slog.Int("size", txMsg.SerializeSize())) if err = p.peerHandler.HandleTransaction(txMsg, p); err != nil { - p.logger.Errorf("Unable to process tx %s: %v", txMsg.TxHash().String(), err) + commandLogger.Error("Unable to process tx", slog.String(hashKey, txMsg.TxHash().String()), slog.String(errKey, err.Error())) } case wire.CmdBlock: msgBlock, ok := msg.(*wire.MsgBlock) if ok { - p.logger.Infof("[%s] Recv %s: %s", p.address, strings.ToUpper(msg.Command()), msgBlock.Header.BlockHash().String()) + commandLogger.Info(receivedMsg, slog.String(hashKey, msgBlock.Header.BlockHash().String())) err = p.peerHandler.HandleBlock(msgBlock, p) if err != nil { - p.logger.Errorf("[%s] Unable to process block %s: %v", p.address, msgBlock.Header.BlockHash().String(), err) + commandLogger.Error("Unable to process block", slog.String(hashKey, msgBlock.Header.BlockHash().String()), slog.String(errKey, err.Error())) } continue } @@ -322,68 +347,70 @@ func (p *Peer) readHandler() { // Please note that this is the BlockMessage, not the wire.MsgBlock blockMsg, ok := msg.(*BlockMessage) if !ok { - p.logger.Errorf("Unable to cast block message, calling with generic wire.Message") + commandLogger.Error("Unable to cast block message, calling with generic wire.Message") err = p.peerHandler.HandleBlock(msg, p) if err != nil { - p.logger.Errorf("[%s] Unable to process block message: %v", p.address, err) + commandLogger.Error("Unable to process block message", slog.String(errKey, err.Error())) } continue } - p.logger.Infof("[%s] Recv %s: %s", p.address, strings.ToUpper(msg.Command()), blockMsg.Header.BlockHash().String()) + commandLogger.Info(receivedMsg, slog.String(hashKey, blockMsg.Header.BlockHash().String())) err = p.peerHandler.HandleBlock(blockMsg, p) if err != nil { - p.logger.Errorf("[%s] Unable to process block %s: %v", p.address, blockMsg.Header.BlockHash().String(), err) + commandLogger.Error("Unable to process block", slog.String(hashKey, blockMsg.Header.BlockHash().String()), slog.String(errKey, err.Error())) } case wire.CmdReject: - rejMsg := msg.(*wire.MsgReject) + rejMsg, ok := msg.(*wire.MsgReject) + if !ok { + continue + } if err = p.peerHandler.HandleTransactionRejection(rejMsg, p); err != nil { - p.logger.Errorf("[%s] Unable to process block %s: %v", p.address, rejMsg.Hash.String(), err) + commandLogger.Error("Unable to process block", slog.String(hashKey, rejMsg.Hash.String()), slog.String(errKey, err.Error())) } case wire.CmdVerAck: - p.logger.Debugf("[%s] Recv %s", p.address, strings.ToUpper(msg.Command())) + commandLogger.Debug(receivedMsg) p.receivedVerAck.Store(true) default: - p.logger.Debugf("[%s] Ignored %s", p.address, strings.ToUpper(msg.Command())) + commandLogger.Debug("command ignored") } } - } -func (p *Peer) handleGetDataMsg(dataMsg *wire.MsgGetData) { +func (p *Peer) handleGetDataMsg(dataMsg *wire.MsgGetData, logger *slog.Logger) { for _, invVect := range dataMsg.InvList { switch invVect.Type { case wire.InvTypeTx: - p.logger.Debugf("[%s] Request for TX: %s\n", p.address, invVect.Hash.String()) + logger.Debug("Request for TX", slog.String(hashKey, invVect.Hash.String())) txBytes, err := p.peerHandler.HandleTransactionGet(invVect, p) if err != nil { - p.logger.Warnf("[%s] Unable to fetch tx %s from store: %v", p.address, invVect.Hash.String(), err) + logger.Warn("Unable to fetch tx from store", slog.String(hashKey, invVect.Hash.String()), slog.String(typeKey, invVect.Type.String()), slog.String(errKey, err.Error())) continue } if txBytes == nil { - p.logger.Warnf("[%s] Unable to fetch tx %s from store: %v", p.address, invVect.Hash.String(), err) + logger.Warn("tx does not exist", slog.String(hashKey, invVect.Hash.String()), slog.String(typeKey, invVect.Type.String()), slog.String(errKey, err.Error())) continue } tx, err := bsvutil.NewTxFromBytes(txBytes) if err != nil { - log.Print(err) // Log and handle the error + logger.Error("failed to parse tx", slog.String(hashKey, invVect.Hash.String()), slog.String(typeKey, invVect.Type.String()), slog.String("rawHex", hex.EncodeToString(txBytes)), slog.String(errKey, err.Error())) continue } p.writeChan <- tx.MsgTx() case wire.InvTypeBlock: - p.logger.Infof("[%s] Request for Block: %s\n", p.address, invVect.Hash.String()) + logger.Info("Request for block", slog.String(hashKey, invVect.Hash.String()), slog.String(typeKey, invVect.Type.String())) default: - p.logger.Warnf("[%s] Unknown type: %d\n", p.address, invVect.Type) + logger.Warn("Unknown type", slog.String(hashKey, invVect.Hash.String()), slog.String(typeKey, invVect.Type.String())) } } } @@ -401,14 +428,14 @@ func (p *Peer) AnnounceBlock(blockHash *chainhash.Hash) { iv := wire.NewInvVect(wire.InvTypeBlock, blockHash) if err := invMsg.AddInvVect(iv); err != nil { - p.logger.Infof("ERROR adding invVect to INV message: %v", err) + p.logger.Error("failed to add invVect to INV message", slog.String(typeKey, iv.Type.String()), slog.String(hashKey, blockHash.String()), slog.String(errKey, err.Error())) return } if err := p.WriteMsg(invMsg); err != nil { - p.logger.Infof("[%s] ERROR sending INV for block: %v", p.String(), err) + p.logger.Error("failed to send INV message", slog.String(typeKey, iv.Type.String()), slog.String(hashKey, blockHash.String()), slog.String(errKey, err.Error())) } else { - p.logger.Infof("[%s] Sent INV for block %v", p.String(), blockHash) + p.logger.Info("Sent INV", slog.String(typeKey, iv.Type.String()), slog.String(hashKey, blockHash.String())) } } @@ -417,14 +444,14 @@ func (p *Peer) RequestBlock(blockHash *chainhash.Hash) { iv := wire.NewInvVect(wire.InvTypeBlock, blockHash) if err := dataMsg.AddInvVect(iv); err != nil { - p.logger.Infof("ERROR adding invVect to GETDATA message: %v", err) + p.logger.Error("failed to add invVect to GETDATA message", slog.String(typeKey, iv.Type.String()), slog.String(hashKey, blockHash.String()), slog.String(errKey, err.Error())) return } if err := p.WriteMsg(dataMsg); err != nil { - p.logger.Infof("[%s] ERROR sending block data message: %v", p.String(), err) + p.logger.Error("failed to send GETDATA message", slog.String(hashKey, blockHash.String()), slog.String(typeKey, iv.Type.String()), slog.String(errKey, err.Error())) } else { - p.logger.Infof("[%s] Sent GETDATA for block %v", p.String(), blockHash) + p.logger.Info("Sent GETDATA", slog.String(hashKey, blockHash.String()), slog.String(typeKey, iv.Type.String())) } } @@ -434,14 +461,10 @@ func (p *Peer) sendInvBatch(batch []*chainhash.Hash) { for _, hash := range batch { iv := wire.NewInvVect(wire.InvTypeTx, hash) _ = invMsg.AddInvVect(iv) + p.logger.Debug("Sent INV", slog.String(hashKey, hash.String()), slog.String(typeKey, wire.InvTypeTx.String())) } p.writeChan <- invMsg - - p.logger.Infof("[%s] Sent INV (%d items)", p.String(), len(batch)) - for _, hash := range batch { - p.logger.Debugf(" %v", hash) - } } func (p *Peer) sendDataBatch(batch []*chainhash.Hash) { @@ -450,12 +473,13 @@ func (p *Peer) sendDataBatch(batch []*chainhash.Hash) { for _, hash := range batch { iv := wire.NewInvVect(wire.InvTypeTx, hash) _ = dataMsg.AddInvVect(iv) + p.logger.Debug("Sent GETDATA", slog.String(hashKey, hash.String()), slog.String(typeKey, wire.InvTypeTx.String())) } if err := p.WriteMsg(dataMsg); err != nil { - p.logger.Infof("[%s] ERROR sending tx data message: %v", p.String(), err) + p.logger.Error("failed to send tx data message", slog.String(errKey, err.Error())) } else { - p.logger.Infof("[%s] Sent GETDATA (%d items)", p.String(), len(batch)) + p.logger.Info("Sent GETDATA", slog.Int("items", len(batch))) } } @@ -477,27 +501,31 @@ func (p *Peer) writeChannelHandler() { if errors.Is(err, io.EOF) { panic("WRITE EOF") } - p.logger.Errorf("[%s] Failed to write message: %v", p.address, err) + p.logger.Error("Failed to write message", slog.String(errKey, err.Error())) } - go func(msg wire.Message) { - if msg.Command() == wire.CmdTx { - hash := msg.(*wire.MsgTx).TxHash() - if err := p.peerHandler.HandleTransactionSent(msg.(*wire.MsgTx), p); err != nil { - p.logger.Errorf("[%s] Unable to process tx %s: %v", p.address, hash.String(), err) + go func(message wire.Message) { + if message.Command() == wire.CmdTx { + msgTx, ok := message.(*wire.MsgTx) + if !ok { + return + } + hash := msgTx.TxHash() + if err := p.peerHandler.HandleTransactionSent(msgTx, p); err != nil { + p.logger.Error("Unable to process tx", slog.String(hashKey, hash.String()), slog.String(errKey, err.Error())) } } - switch m := msg.(type) { + switch m := message.(type) { case *wire.MsgTx: - p.logger.Debugf("[%s] Sent %s: %s", p.address, strings.ToUpper(msg.Command()), m.TxHash().String()) + p.logger.Debug(sentMsg, slog.String(commandKey, strings.ToUpper(message.Command())), slog.String(hashKey, m.TxHash().String()), slog.String(typeKey, "tx")) case *wire.MsgBlock: - p.logger.Debugf("[%s] Sent %s: %s", p.address, strings.ToUpper(msg.Command()), m.BlockHash().String()) + p.logger.Debug(sentMsg, slog.String(commandKey, strings.ToUpper(message.Command())), slog.String(hashKey, m.BlockHash().String()), slog.String(typeKey, "block")) case *wire.MsgGetData: - p.logger.Debugf("[%s] Sent %s: %s", p.address, strings.ToUpper(msg.Command()), m.InvList[0].Hash.String()) + p.logger.Debug(sentMsg, slog.String(commandKey, strings.ToUpper(message.Command())), slog.String(hashKey, m.InvList[0].Hash.String()), slog.String(typeKey, "getdata")) case *wire.MsgInv: default: - p.logger.Debugf("[%s] Sent %s", p.address, strings.ToUpper(msg.Command())) + p.logger.Debug(sentMsg, slog.String(commandKey, strings.ToUpper(message.Command())), slog.String(typeKey, "unknown")) } }(msg) } @@ -524,7 +552,7 @@ func (p *Peer) versionMessage(address string) *wire.MsgVersion { nonce, err := wire.RandomUint64() if err != nil { - p.logger.Errorf("[%s] RandomUint64: error generating nonce: %v", p.address, err) + p.logger.Error("RandomUint64: failed to generate nonce", slog.String(errKey, err.Error())) } msg := wire.NewMsgVersion(me, you, nonce, lastBlock) @@ -543,7 +571,7 @@ out: case <-pingTicker.C: nonce, err := wire.RandomUint64() if err != nil { - p.logger.Errorf("[%s] Not sending ping to %s: %v", p.address, p, err) + p.logger.Error("Not sending ping", slog.String(errKey, err.Error())) continue } p.writeChan <- wire.NewMsgPing(nonce) diff --git a/PeerManager.go b/PeerManager.go index 7492f2d..524309a 100644 --- a/PeerManager.go +++ b/PeerManager.go @@ -1,13 +1,13 @@ package p2p import ( + "log/slog" "sort" "sync" "time" "github.com/libsv/go-p2p/chaincfg/chainhash" "github.com/libsv/go-p2p/wire" - "github.com/ordishs/go-utils" ) const defaultExcessiveBlockSize = 4000000000 @@ -17,7 +17,7 @@ type PeerManager struct { peers []PeerI network wire.BitcoinNet batchDelay time.Duration - logger utils.Logger + logger *slog.Logger ebs int64 } @@ -25,7 +25,7 @@ type PeerManager struct { // messageCh is a channel that will be used to send messages from peers to the parent process // this is used to pass INV messages from the bitcoin network peers to the parent process // at the moment this is only used for Inv tx message for "seen", "sent" and "rejected" transactions -func NewPeerManager(logger utils.Logger, network wire.BitcoinNet, options ...PeerManagerOptions) PeerManagerI { +func NewPeerManager(logger *slog.Logger, network wire.BitcoinNet, options ...PeerManagerOptions) PeerManagerI { pm := &PeerManager{ peers: make([]PeerI, 0), @@ -38,7 +38,7 @@ func NewPeerManager(logger utils.Logger, network wire.BitcoinNet, options ...Pee option(pm) } - logger.Infof("Excessive block size set to %d", pm.ebs) + logger.Info("Excessive block size set to", slog.Int64("block size", pm.ebs)) wire.SetLimits(uint64(pm.ebs)) return pm diff --git a/PeerManager_Mock.go b/PeerManager_Mock.go index ac2b376..18bc16b 100644 --- a/PeerManager_Mock.go +++ b/PeerManager_Mock.go @@ -1,17 +1,34 @@ package p2p -import "github.com/libsv/go-p2p/chaincfg/chainhash" +import ( + "context" + "log/slog" -type TestLogger struct{} + "github.com/libsv/go-p2p/chaincfg/chainhash" +) -func (l TestLogger) LogLevel() int { - return 0 +type TestLogger struct { +} + +func (h *TestLogger) Enabled(_ context.Context, _ slog.Level) bool { + return false +} + +func (h *TestLogger) Handle(_ context.Context, _ slog.Record) error { + return nil +} + +func (h *TestLogger) WithAttrs(_ []slog.Attr) slog.Handler { + return &TestLogger{} +} + +func (h *TestLogger) WithGroup(_ string) slog.Handler { + return &TestLogger{} +} + +func (h *TestLogger) Handler() slog.Handler { + return &TestLogger{} } -func (l TestLogger) Debugf(format string, args ...interface{}) {} -func (l TestLogger) Infof(format string, args ...interface{}) {} -func (l TestLogger) Warnf(format string, args ...interface{}) {} -func (l TestLogger) Errorf(format string, args ...interface{}) {} -func (l TestLogger) Fatalf(format string, args ...interface{}) {} type PeerManagerMock struct { Peers []PeerI diff --git a/PeerManager_test.go b/PeerManager_test.go index a5bc460..d935a38 100644 --- a/PeerManager_test.go +++ b/PeerManager_test.go @@ -2,6 +2,7 @@ package p2p import ( "fmt" + "log/slog" "testing" "time" @@ -14,10 +15,12 @@ import ( var ( tx1 = "b042f298deabcebbf15355aa3a13c7d7cfe96c44ac4f492735f936f8e50d06f6" tx1Hash, _ = chainhash.NewHashFromStr(tx1) - logger = TestLogger{} ) func TestNewPeerManager(t *testing.T) { + + logger := slog.New(&TestLogger{}) + t.Run("nil peers no error", func(t *testing.T) { pm := NewPeerManager(logger, wire.TestNet) require.NotNil(t, pm) @@ -61,7 +64,7 @@ func TestNewPeerManager(t *testing.T) { func TestAnnounceNewTransaction(t *testing.T) { t.Run("announce tx", func(t *testing.T) { - + logger := slog.New(&TestLogger{}) pm := NewPeerManager(logger, wire.TestNet, WithBatchDuration(1*time.Millisecond)) require.NotNil(t, pm) @@ -82,6 +85,7 @@ func TestAnnounceNewTransaction(t *testing.T) { }) t.Run("announce tx - multiple peers", func(t *testing.T) { + logger := slog.New(&TestLogger{}) pm := NewPeerManager(logger, wire.TestNet, WithBatchDuration(1*time.Millisecond)) require.NotNil(t, pm) diff --git a/Peer_test.go b/Peer_test.go index 25f0ce6..51e0d54 100644 --- a/Peer_test.go +++ b/Peer_test.go @@ -3,6 +3,7 @@ package p2p import ( "bytes" "encoding/binary" + "log/slog" "net" "testing" "time" @@ -250,9 +251,9 @@ func newTestPeer(t *testing.T) (net.Conn, *Peer, *MockPeerHandler) { peerConn, myConn := connutil.AsyncPipe() peerHandler := NewMockPeerHandler() - + logger := slog.New(&TestLogger{}) p, err := NewPeer( - &TestLogger{}, + logger, "MockPeerHandler:0000", peerHandler, wire.MainNet, @@ -283,8 +284,9 @@ func newTestPeer(t *testing.T) (net.Conn, *Peer, *MockPeerHandler) { func newIncomingTestPeer(t *testing.T) (net.Conn, *Peer, *MockPeerHandler) { peerConn, myConn := connutil.AsyncPipe() peerHandler := NewMockPeerHandler() + logger := slog.New(&TestLogger{}) p, err := NewPeer( - &TestLogger{}, + logger, "MockPeerHandler:0000", peerHandler, wire.MainNet, diff --git a/examples/simple/handler.go b/examples/simple/handler.go index 0b7c4d8..0991738 100644 --- a/examples/simple/handler.go +++ b/examples/simple/handler.go @@ -3,49 +3,50 @@ package main import ( "fmt" + "log/slog" + "github.com/libsv/go-p2p" "github.com/libsv/go-p2p/wire" - "github.com/ordishs/go-utils" ) // SimplePeerHandler is a simple implementation of the PeerHandler interface. // This is how you can customize the behaviour of the peer. type SimplePeerHandler struct { - logger utils.Logger + logger *slog.Logger } func (s *SimplePeerHandler) HandleTransactionGet(msg *wire.InvVect, peer p2p.PeerI) ([]byte, error) { - s.logger.Infof("Peer %s requested transaction %s", peer.String(), msg.Hash.String()) + s.logger.Info("Peer requested transaction", slog.String("hash", msg.Hash.String()), slog.String("peer", peer.String())) // You should implement a store and return the transaction bytes here. return nil, fmt.Errorf("transaction not found") } func (s *SimplePeerHandler) HandleTransactionSent(msg *wire.MsgTx, peer p2p.PeerI) error { - s.logger.Infof("Sent transaction %s to peer %s", msg.TxHash().String(), peer.String()) + s.logger.Info("Sent transaction to peer", slog.String("hash", msg.TxHash().String()), slog.String("peer", peer.String())) // This is called when a transaction is sent to a peer. You could save this to your store here. return nil } func (s *SimplePeerHandler) HandleTransactionAnnouncement(msg *wire.InvVect, peer p2p.PeerI) error { - s.logger.Infof("Peer %s announced transaction %s", peer.String(), msg.Hash.String()) + s.logger.Info("Peer announced transaction", slog.String("hash", msg.Hash.String()), slog.String("peer", peer.String())) // This is called when a transaction is announced by a peer. Handle this as you wish. return nil } func (s *SimplePeerHandler) HandleTransactionRejection(rejMsg *wire.MsgReject, peer p2p.PeerI) error { - s.logger.Infof("Peer %s rejected transaction %s", peer.String(), rejMsg.Hash.String()) + s.logger.Info("Peer rejected transaction", slog.String("hash", rejMsg.Hash.String()), slog.String("peer", peer.String())) // This is called when a transaction is rejected by a peer. Handle this as you wish. return nil } func (s *SimplePeerHandler) HandleTransaction(msg *wire.MsgTx, peer p2p.PeerI) error { - s.logger.Infof("Received transaction %s from peer %s", msg.TxHash().String(), peer.String()) + s.logger.Info("Received transaction from peer", slog.String("hash", msg.TxHash().String()), slog.String("peer", peer.String())) // This is called when a transaction is received from a peer. Handle this as you wish. return nil } func (s *SimplePeerHandler) HandleBlockAnnouncement(msg *wire.InvVect, peer p2p.PeerI) error { - s.logger.Infof("Peer %s announced block %s", peer.String(), msg.Hash.String()) + s.logger.Info("Peer announced block", slog.String("hash", msg.Hash.String()), slog.String("peer", peer.String())) // This is called when a block is announced by a peer. Handle this as you wish. return nil } @@ -56,7 +57,7 @@ func (s *SimplePeerHandler) HandleBlock(msg wire.Message, peer p2p.PeerI) error return fmt.Errorf("failed to cast message to block message") } - s.logger.Infof("Received block %s from peer %s", blockMsg.Header.BlockHash().String(), peer.String()) + s.logger.Info("Received block from peer", slog.String("hash", blockMsg.Header.BlockHash().String()), slog.String("peer", peer.String())) // This is called when a block is received from a peer. Handle this as you wish. // note: the block message is a custom BlockMessage and not a wire.MsgBlock return nil diff --git a/examples/simple/main.go b/examples/simple/main.go index e44c64c..788a93e 100644 --- a/examples/simple/main.go +++ b/examples/simple/main.go @@ -1,16 +1,16 @@ package main import ( + "log/slog" "os" "os/signal" "github.com/libsv/go-p2p" "github.com/libsv/go-p2p/wire" - "github.com/ordishs/gocore" ) func main() { - logger := gocore.Log("simple-p2p-test") + logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: slog.LevelInfo})) // Make sure to use the correct network here. // For mainnet use wire.MainNet @@ -26,11 +26,11 @@ func main() { peer, err := p2p.NewPeer(logger, "localhost:58333", peerHandler, network) if err != nil { - logger.Fatalf("failed to create peer: %s", err) + logger.Error("failed to create peer", slog.String("err", err.Error())) } if err = peerManager.AddPeer(peer); err != nil { - logger.Fatalf("failed to add peer: %s", err) + logger.Error("failed to add peer", slog.String("err", err.Error())) } // setup signal catching diff --git a/go.mod b/go.mod index 2e8fb04..7d55d5d 100644 --- a/go.mod +++ b/go.mod @@ -1,21 +1,15 @@ module github.com/libsv/go-p2p -go 1.19 +go 1.21.3 require ( github.com/cbeuw/connutil v0.0.0-20200411215123-966bfaa51ee3 github.com/davecgh/go-spew v1.1.1 github.com/ordishs/go-utils v1.0.24 - github.com/ordishs/gocore v1.0.33 github.com/stretchr/testify v1.8.1 ) require ( - github.com/mattn/go-colorable v0.1.13 // indirect - github.com/mattn/go-isatty v0.0.16 // indirect - github.com/mgutz/ansi v0.0.0-20170206155736-9520e82c474b // indirect github.com/pmezard/go-difflib v1.0.0 // indirect - golang.org/x/sys v0.3.0 // indirect - golang.org/x/text v0.6.0 // indirect gopkg.in/yaml.v3 v3.0.1 // indirect ) diff --git a/go.sum b/go.sum index 91063db..9d01b36 100644 --- a/go.sum +++ b/go.sum @@ -3,18 +3,8 @@ github.com/cbeuw/connutil v0.0.0-20200411215123-966bfaa51ee3/go.mod h1:6jR2SzckG github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= -github.com/mattn/go-colorable v0.1.2/go.mod h1:U0ppj6V5qS13XJ6of8GYAs25YV2eR4EVcfRqFIhoBtE= -github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA= -github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg= -github.com/mattn/go-isatty v0.0.8/go.mod h1:Iq45c/XA43vh69/j3iqttzPXn0bhXyGjM0Hdxcsrc5s= -github.com/mattn/go-isatty v0.0.16 h1:bq3VjFmv/sOjHtdEhmkEV4x1AJtvUvOJ2PFAZ5+peKQ= -github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM= -github.com/mgutz/ansi v0.0.0-20170206155736-9520e82c474b h1:j7+1HpAFS1zy5+Q4qx1fWh90gTKwiN4QCGoY9TWyyO4= -github.com/mgutz/ansi v0.0.0-20170206155736-9520e82c474b/go.mod h1:01TrycV0kFyexm33Z7vhZRXopbI8J3TDReVlkTgMUxE= github.com/ordishs/go-utils v1.0.24 h1:QIVYaaN4LE5SnCRbLii7OOrkC2Qqvg4FVKe9zzA3Yd8= github.com/ordishs/go-utils v1.0.24/go.mod h1:k9G7Bbv2GwoOn9fwZx70yM5jwwIymkv+90FUKLudtyc= -github.com/ordishs/gocore v1.0.33 h1:pJbrmi9OMNu73RtUpuzJK/4uvwgYmvuPlb6WxwYPW1g= -github.com/ordishs/gocore v1.0.33/go.mod h1:Nm48yxIUBuKvVXwLC8bB8aQDNUsBpaoVRTtcmjKlhrQ= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= @@ -24,35 +14,6 @@ github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/ github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU= github.com/stretchr/testify v1.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk= github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4= -github.com/yuin/goldmark v1.4.13/go.mod h1:6yULJ656Px+3vBD8DxQVa3kxgyrAnzto9xy5taEt/CY= -golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= -golang.org/x/crypto v0.0.0-20210921155107-089bfa567519/go.mod h1:GvvjBRRGRdwPK5ydBHafDWAxML/pGHZbMvKqRZ5+Abc= -golang.org/x/mod v0.6.0-dev.0.20220419223038-86c51ed26bb4/go.mod h1:jJ57K6gSWd91VN4djpZkiMVwK6gcyfeH4XE8wZrZaV4= -golang.org/x/net v0.0.0-20190620200207-3b0461eec859/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s= -golang.org/x/net v0.0.0-20210226172049-e18ecbb05110/go.mod h1:m0MpNAwzfU5UDzcl9v0D8zg8gWTRqZa9RBIspLL5mdg= -golang.org/x/net v0.0.0-20220722155237-a158d28d115b/go.mod h1:XRhObCWvk6IyKnWLug+ECip1KBveYUHfp+8e9klMJ9c= -golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= -golang.org/x/sync v0.0.0-20220722155255-886fb9371eb4/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= -golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= -golang.org/x/sys v0.0.0-20190222072716-a9d3bda3a223/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= -golang.org/x/sys v0.0.0-20201119102817-f84b799fce68/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= -golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/sys v0.0.0-20220520151302-bc2c85ada10a/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/sys v0.0.0-20220722155257-8c9f86f7a55f/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/sys v0.3.0 h1:w8ZOecv6NaNa/zC8944JTU3vz4u6Lagfk4RPQxv92NQ= -golang.org/x/sys v0.3.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo= -golang.org/x/term v0.0.0-20210927222741-03fcf44c2211/go.mod h1:jbD1KX2456YbFQfuXm/mYQcufACuNUgVhRMnK/tPxf8= -golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= -golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= -golang.org/x/text v0.3.7/go.mod h1:u+2+/6zg+i71rQMx5EYifcz6MCKuco9NR6JIITiCfzQ= -golang.org/x/text v0.6.0 h1:3XmdazWV+ubf7QgHSTWeykHOci5oeekaGJBLkrkaw4k= -golang.org/x/text v0.6.0/go.mod h1:mrYo+phRRbMaCq/xk9113O4dZlRixOauAjOtrjsXDZ8= -golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ= -golang.org/x/tools v0.0.0-20191119224855-298f0cb1881e/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo= -golang.org/x/tools v0.1.12/go.mod h1:hNGJHUnrk76NpqgfD5Aqm5Crs+Hm0VOH/i9J2+nxYbc= -golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=