From 4e361c59b539cfc3bd186014ed8a8d0c2e1a93c1 Mon Sep 17 00:00:00 2001 From: Chris Gianelloni Date: Sat, 5 Oct 2024 18:06:51 -0400 Subject: [PATCH] fix: standardize mini-protocol debug logging (#741) Signed-off-by: Chris Gianelloni --- protocol/blockfetch/client.go | 4 +- protocol/blockfetch/server.go | 14 +++--- protocol/chainsync/client.go | 4 +- protocol/chainsync/server.go | 16 +++---- protocol/handshake/client.go | 2 +- protocol/handshake/server.go | 4 +- protocol/keepalive/client.go | 2 +- protocol/keepalive/server.go | 5 +++ protocol/localstatequery/client.go | 64 ++++++++++++++-------------- protocol/localstatequery/server.go | 12 +++--- protocol/localtxmonitor/client.go | 24 +++++------ protocol/localtxmonitor/server.go | 14 +++--- protocol/localtxsubmission/client.go | 12 +++--- protocol/localtxsubmission/server.go | 6 +-- protocol/peersharing/client.go | 6 +-- protocol/peersharing/server.go | 5 +++ protocol/txsubmission/client.go | 2 + protocol/txsubmission/server.go | 15 +++++++ 18 files changed, 110 insertions(+), 101 deletions(-) diff --git a/protocol/blockfetch/client.go b/protocol/blockfetch/client.go index 3b124401..33d08c64 100644 --- a/protocol/blockfetch/client.go +++ b/protocol/blockfetch/client.go @@ -82,7 +82,7 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { func (c *Client) Start() { c.onceStart.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: starting protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug(fmt.Sprintf("%s: starting client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.Protocol.Start() // Start goroutine to cleanup resources on protocol shutdown go func() { @@ -97,7 +97,7 @@ func (c *Client) Stop() error { var err error c.onceStop.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: stopping protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug(fmt.Sprintf("%s: stopping client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) msg := NewMsgClientDone() err = c.SendMessage(msg) }) diff --git a/protocol/blockfetch/server.go b/protocol/blockfetch/server.go index b00f7770..b3d563b8 100644 --- a/protocol/blockfetch/server.go +++ b/protocol/blockfetch/server.go @@ -61,21 +61,21 @@ func (s *Server) initProtocol() { func (s *Server) NoBlocks() error { s.Protocol.Logger(). - Debug(fmt.Sprintf("server called %s NoBlocks()", ProtocolName)) + Debug(fmt.Sprintf("%s: server %+v called NoBlocks()", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) msg := NewMsgNoBlocks() return s.SendMessage(msg) } func (s *Server) StartBatch() error { s.Protocol.Logger(). - Debug(fmt.Sprintf("server called %s StartBatch()", ProtocolName)) + Debug(fmt.Sprintf("%s: server %+v called StartBatch()", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) msg := NewMsgStartBatch() return s.SendMessage(msg) } func (s *Server) Block(blockType uint, blockData []byte) error { s.Protocol.Logger(). - Debug(fmt.Sprintf("server called %s Block(blockType: %+v, blockData: %x)", ProtocolName, blockType, blockData)) + Debug(fmt.Sprintf("%s: server %+v called Block(blockType: %+v, blockData: %x)", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr, blockType, blockData)) wrappedBlock := WrappedBlock{ Type: blockType, RawBlock: blockData, @@ -90,14 +90,12 @@ func (s *Server) Block(blockType uint, blockData []byte) error { func (s *Server) BatchDone() error { s.Protocol.Logger(). - Debug(fmt.Sprintf("server called %s BatchDone()", ProtocolName)) + Debug(fmt.Sprintf("%s: server %+v called BatchDone()", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) msg := NewMsgBatchDone() return s.SendMessage(msg) } func (s *Server) messageHandler(msg protocol.Message) error { - s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server message for %s", ProtocolName)) var err error switch msg.Type() { case MessageTypeRequestRange: @@ -116,7 +114,7 @@ func (s *Server) messageHandler(msg protocol.Message) error { func (s *Server) handleRequestRange(msg protocol.Message) error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server request range for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server request range for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) if s.config == nil || s.config.RequestRangeFunc == nil { return fmt.Errorf( "received block-fetch RequestRange message but no callback function is defined", @@ -132,7 +130,7 @@ func (s *Server) handleRequestRange(msg protocol.Message) error { func (s *Server) handleClientDone() error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server client done for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server client done for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) // Restart protocol s.Protocol.Stop() s.initProtocol() diff --git a/protocol/chainsync/client.go b/protocol/chainsync/client.go index 0546400c..5029546a 100644 --- a/protocol/chainsync/client.go +++ b/protocol/chainsync/client.go @@ -117,7 +117,7 @@ func NewClient( func (c *Client) Start() { c.onceStart.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: starting protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug(fmt.Sprintf("%s: starting client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.Protocol.Start() // Start goroutine to cleanup resources on protocol shutdown go func() { @@ -132,7 +132,7 @@ func (c *Client) Stop() error { var err error c.onceStop.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: stopping protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug(fmt.Sprintf("%s: stopping client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() msg := NewMsgDone() diff --git a/protocol/chainsync/server.go b/protocol/chainsync/server.go index b9e81ebe..974f8973 100644 --- a/protocol/chainsync/server.go +++ b/protocol/chainsync/server.go @@ -79,21 +79,21 @@ func (s *Server) initProtocol() { func (s *Server) RollBackward(point common.Point, tip Tip) error { s.Protocol.Logger(). - Debug(fmt.Sprintf("server called %s RollBackward(point: %+v, tip: %+v)", ProtocolName, point, tip)) + Debug(fmt.Sprintf("%s: server %+v called RollBackward(point: {Slot: %d, Hash: %x}, tip: {Point: %+v, BlockNumber: %d})", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr, point.Slot, point.Hash, tip.Point, tip.BlockNumber)) msg := NewMsgRollBackward(point, tip) return s.SendMessage(msg) } func (s *Server) AwaitReply() error { s.Protocol.Logger(). - Debug(fmt.Sprintf("server called %s AwaitReply()", ProtocolName)) + Debug(fmt.Sprintf("%s: server %+v called AwaitReply()", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) msg := NewMsgAwaitReply() return s.SendMessage(msg) } func (s *Server) RollForward(blockType uint, blockData []byte, tip Tip) error { s.Protocol.Logger(). - Debug(fmt.Sprintf("server called %s Rollforward(blockType: %+v, blockData: %x, tip: %+v)", ProtocolName, blockType, blockData, tip)) + Debug(fmt.Sprintf("%s: server %+v called RollForward(blockType: %+v, blockData: %x, tip: {Point: {Slot: %d, Hash: %x}, BlockNumber: %d})", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr, blockType, blockData, tip.Point.Slot, tip.Point.Hash, tip.BlockNumber)) if s.Mode() == protocol.ProtocolModeNodeToNode { eraId := ledger.BlockToBlockHeaderTypeMap[blockType] msg := NewMsgRollForwardNtN( @@ -114,8 +114,6 @@ func (s *Server) RollForward(blockType uint, blockData []byte, tip Tip) error { } func (s *Server) messageHandler(msg protocol.Message) error { - s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server message for %s", ProtocolName)) var err error switch msg.Type() { case MessageTypeRequestNext: @@ -137,8 +135,8 @@ func (s *Server) messageHandler(msg protocol.Message) error { func (s *Server) handleRequestNext() error { // TODO: figure out why this one log message causes a panic (and only this one) // during tests - // s.Protocol.Logger(). - // Debug(fmt.Sprintf("handling server request next for %s", ProtocolName)) + //s.Protocol.Logger(). + // Debug(fmt.Sprintf("%s: server request next for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) if s.config == nil || s.config.RequestNextFunc == nil { return fmt.Errorf( "received chain-sync RequestNext message but no callback function is defined", @@ -149,7 +147,7 @@ func (s *Server) handleRequestNext() error { func (s *Server) handleFindIntersect(msg protocol.Message) error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server find intersect for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server find intersect for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) if s.config == nil || s.config.FindIntersectFunc == nil { return fmt.Errorf( "received chain-sync FindIntersect message but no callback function is defined", @@ -179,7 +177,7 @@ func (s *Server) handleFindIntersect(msg protocol.Message) error { func (s *Server) handleDone() error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server done for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server done for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) // Restart protocol s.Protocol.Stop() s.initProtocol() diff --git a/protocol/handshake/client.go b/protocol/handshake/client.go index 31b6b5a1..10fb4c22 100644 --- a/protocol/handshake/client.go +++ b/protocol/handshake/client.go @@ -70,7 +70,7 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { func (c *Client) Start() { c.onceStart.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: starting protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug(fmt.Sprintf("%s: starting client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.Protocol.Start() // Send our ProposeVersions message msg := NewMsgProposeVersions(c.config.ProtocolVersionMap) diff --git a/protocol/handshake/server.go b/protocol/handshake/server.go index cc26fcab..e5a6edbc 100644 --- a/protocol/handshake/server.go +++ b/protocol/handshake/server.go @@ -61,8 +61,6 @@ func NewServer(protoOptions protocol.ProtocolOptions, cfg *Config) *Server { } func (s *Server) handleMessage(msg protocol.Message) error { - s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server message for %s", ProtocolName)) var err error switch msg.Type() { case MessageTypeProposeVersions: @@ -79,7 +77,7 @@ func (s *Server) handleMessage(msg protocol.Message) error { func (s *Server) handleProposeVersions(msg protocol.Message) error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server propose versions for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server propose versions for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) if s.config.FinishedFunc == nil { return fmt.Errorf( "received handshake ProposeVersions message but no callback function is defined", diff --git a/protocol/keepalive/client.go b/protocol/keepalive/client.go index 5e65861b..1612f827 100644 --- a/protocol/keepalive/client.go +++ b/protocol/keepalive/client.go @@ -70,7 +70,7 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { func (c *Client) Start() { c.onceStart.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: starting protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug(fmt.Sprintf("%s: starting client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.Protocol.Start() // Start goroutine to cleanup resources on protocol shutdown go func() { diff --git a/protocol/keepalive/server.go b/protocol/keepalive/server.go index ed46786e..8d353c68 100644 --- a/protocol/keepalive/server.go +++ b/protocol/keepalive/server.go @@ -38,6 +38,7 @@ func NewServer(protoOptions protocol.ProtocolOptions, cfg *Config) *Server { Name: ProtocolName, ProtocolId: ProtocolId, Muxer: protoOptions.Muxer, + Logger: protoOptions.Logger, ErrorChan: protoOptions.ErrorChan, Mode: protoOptions.Mode, Role: protocol.ProtocolRoleServer, @@ -68,6 +69,8 @@ func (s *Server) messageHandler(msg protocol.Message) error { } func (s *Server) handleKeepAlive(msgGeneric protocol.Message) error { + s.Protocol.Logger(). + Debug(fmt.Sprintf("%s: server keep alive for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) msg := msgGeneric.(*MsgKeepAlive) if s.config != nil && s.config.KeepAliveFunc != nil { // Call the user callback function @@ -80,6 +83,8 @@ func (s *Server) handleKeepAlive(msgGeneric protocol.Message) error { } func (s *Server) handleDone() error { + s.Protocol.Logger(). + Debug(fmt.Sprintf("%s: server done for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) if s.config != nil && s.config.DoneFunc != nil { // Call the user callback function return s.config.DoneFunc(s.callbackContext) diff --git a/protocol/localstatequery/client.go b/protocol/localstatequery/client.go index 076da965..ca81bcff 100644 --- a/protocol/localstatequery/client.go +++ b/protocol/localstatequery/client.go @@ -96,7 +96,7 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { func (c *Client) Start() { c.onceStart.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("starting protocol: %s", ProtocolName)) + Debug(fmt.Sprintf("%s: starting client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.Protocol.Start() // Start goroutine to cleanup resources on protocol shutdown go func() { @@ -110,7 +110,7 @@ func (c *Client) Start() { // Acquire starts the acquire process for the specified chain point func (c *Client) Acquire(point *common.Point) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s Acquire(point: %+v)", ProtocolName, point)) + Debug(fmt.Sprintf("%s: client %+v called Acquire(point: {Slot: %d, Hash: %x})", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, point.Slot, point.Hash)) c.busyMutex.Lock() defer c.busyMutex.Unlock() return c.acquire(point) @@ -119,7 +119,7 @@ func (c *Client) Acquire(point *common.Point) error { // Release releases the previously acquired chain point func (c *Client) Release() error { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s Release()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called Release()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() return c.release() @@ -128,7 +128,7 @@ func (c *Client) Release() error { // GetCurrentEra returns the current era ID func (c *Client) GetCurrentEra() (int, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetCurrentEra()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetCurrentEra()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() return c.getCurrentEra() @@ -137,7 +137,7 @@ func (c *Client) GetCurrentEra() (int, error) { // GetSystemStart returns the SystemStart value func (c *Client) GetSystemStart() (*SystemStartResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetSystemStart()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetSystemStart()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() query := buildQuery( @@ -153,7 +153,7 @@ func (c *Client) GetSystemStart() (*SystemStartResult, error) { // GetChainBlockNo returns the latest block number func (c *Client) GetChainBlockNo() (int64, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetChainBlockNo()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetChainBlockNo()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() query := buildQuery( @@ -169,7 +169,7 @@ func (c *Client) GetChainBlockNo() (int64, error) { // GetChainPoint returns the current chain tip func (c *Client) GetChainPoint() (*common.Point, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetChainPoint()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetChainPoint()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() query := buildQuery( @@ -185,7 +185,7 @@ func (c *Client) GetChainPoint() (*common.Point, error) { // GetEraHistory returns the era history func (c *Client) GetEraHistory() ([]EraHistoryResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetEraHistory()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetEraHistory()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() query := buildHardForkQuery(QueryTypeHardForkEraHistory) @@ -199,7 +199,7 @@ func (c *Client) GetEraHistory() ([]EraHistoryResult, error) { // GetEpochNo returns the current epoch number func (c *Client) GetEpochNo() (int, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetEpochNo()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetEpochNo()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -223,7 +223,7 @@ query [2 #6.258([*[0 int]]) int is the stake the user intends to delegate, the a */ func (c *Client) GetNonMyopicMemberRewards() (*NonMyopicMemberRewardsResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetNonMyopicMemberRewards()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetNonMyopicMemberRewards()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -244,7 +244,7 @@ func (c *Client) GetNonMyopicMemberRewards() (*NonMyopicMemberRewardsResult, err // GetCurrentProtocolParams returns the set of protocol params that are currently in effect func (c *Client) GetCurrentProtocolParams() (CurrentProtocolParamsResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetCurrentProtocolParams()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetCurrentProtocolParams()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -300,7 +300,7 @@ func (c *Client) GetCurrentProtocolParams() (CurrentProtocolParamsResult, error) // GetProposedProtocolParamsUpdates returns the set of proposed protocol params updates func (c *Client) GetProposedProtocolParamsUpdates() (*ProposedProtocolParamsUpdatesResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetProposedProtocolParamsUpdates()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetProposedProtocolParamsUpdates()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -322,7 +322,7 @@ func (c *Client) GetProposedProtocolParamsUpdates() (*ProposedProtocolParamsUpda // GetStakeDistribution returns the stake distribution func (c *Client) GetStakeDistribution() (*StakeDistributionResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetStakeDistribution()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetStakeDistribution()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -345,7 +345,7 @@ func (c *Client) GetUTxOByAddress( addrs []ledger.Address, ) (*UTxOByAddressResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetUTxOByAddress(addrs: %+v)", ProtocolName, addrs)) + Debug(fmt.Sprintf("%s: client %+v called GetUTxOByAddress(addrs: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, addrs)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -367,7 +367,7 @@ func (c *Client) GetUTxOByAddress( // GetUTxOWhole returns the current UTxO set func (c *Client) GetUTxOWhole() (*UTxOWholeResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetUTxOWhole()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetUTxOWhole()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -388,7 +388,7 @@ func (c *Client) GetUTxOWhole() (*UTxOWholeResult, error) { // TODO func (c *Client) DebugEpochState() (*DebugEpochStateResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s DebugEpochState()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called DebugEpochState()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -414,7 +414,7 @@ func (c *Client) GetFilteredDelegationsAndRewardAccounts( creds []interface{}, ) (*FilteredDelegationsAndRewardAccountsResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetFilteredDelegationsAndRewardAccounts(creds: %+v)", ProtocolName, creds)) + Debug(fmt.Sprintf("%s: client %+v called GetFilteredDelegationsAndRewardAccounts(creds: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, creds)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -435,7 +435,7 @@ func (c *Client) GetFilteredDelegationsAndRewardAccounts( func (c *Client) GetGenesisConfig() (*GenesisConfigResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetGenesisConfig()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetGenesisConfig()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -456,7 +456,7 @@ func (c *Client) GetGenesisConfig() (*GenesisConfigResult, error) { // TODO func (c *Client) DebugNewEpochState() (*DebugNewEpochStateResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s DebugNewEpochState()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called DebugNewEpochState()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -477,7 +477,7 @@ func (c *Client) DebugNewEpochState() (*DebugNewEpochStateResult, error) { // TODO func (c *Client) DebugChainDepState() (*DebugChainDepStateResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s DebugChainDepState()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called DebugChainDepState()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -497,7 +497,7 @@ func (c *Client) DebugChainDepState() (*DebugChainDepStateResult, error) { func (c *Client) GetRewardProvenance() (*RewardProvenanceResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetRewardProvenance()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetRewardProvenance()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -519,7 +519,7 @@ func (c *Client) GetUTxOByTxIn( txIns []ledger.TransactionInput, ) (*UTxOByTxInResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetUTxOByTxIn(txIns: %+v)", ProtocolName, txIns)) + Debug(fmt.Sprintf("%s: client %+v called GetUTxOByTxIn(txIns: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, txIns)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -540,7 +540,7 @@ func (c *Client) GetUTxOByTxIn( func (c *Client) GetStakePools() (*StakePoolsResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetStakePools()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetStakePools()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -562,7 +562,7 @@ func (c *Client) GetStakePoolParams( poolIds []ledger.PoolId, ) (*StakePoolParamsResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetStakePoolParams(poolIds: %+v)", ProtocolName, poolIds)) + Debug(fmt.Sprintf("%s: client %+v called GetStakePoolParams(poolIds: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, poolIds)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -587,7 +587,7 @@ func (c *Client) GetStakePoolParams( // TODO func (c *Client) GetRewardInfoPools() (*RewardInfoPoolsResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetRewardInfoPools()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetRewardInfoPools()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -608,7 +608,7 @@ func (c *Client) GetRewardInfoPools() (*RewardInfoPoolsResult, error) { // TODO func (c *Client) GetPoolState(poolIds []interface{}) (*PoolStateResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetPoolState(poolIds: %+v)", ProtocolName, poolIds)) + Debug(fmt.Sprintf("%s: client %+v called GetPoolState(poolIds: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, poolIds)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -631,7 +631,7 @@ func (c *Client) GetStakeSnapshots( poolId interface{}, ) (*StakeSnapshotsResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetStakeSnapshots(poolId: %+v)", ProtocolName, poolId)) + Debug(fmt.Sprintf("%s: client %+v called GetStakeSnapshots(poolId: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, poolId)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -652,7 +652,7 @@ func (c *Client) GetStakeSnapshots( // TODO func (c *Client) GetPoolDistr(poolIds []interface{}) (*PoolDistrResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetPoolDistr(poolIds: %+v)", ProtocolName, poolIds)) + Debug(fmt.Sprintf("%s: client %+v called GetPoolDistr(poolIds: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, poolIds)) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -671,8 +671,6 @@ func (c *Client) GetPoolDistr(poolIds []interface{}) (*PoolDistrResult, error) { } func (c *Client) messageHandler(msg protocol.Message) error { - c.Protocol.Logger(). - Debug(fmt.Sprintf("handling client message for %s", ProtocolName)) var err error switch msg.Type() { case MessageTypeAcquired: @@ -693,7 +691,7 @@ func (c *Client) messageHandler(msg protocol.Message) error { func (c *Client) handleAcquired() error { c.Protocol.Logger(). - Debug(fmt.Sprintf("handling client acquired for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: client acquired for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.acquired = true c.acquireResultChan <- nil c.currentEra = -1 @@ -702,7 +700,7 @@ func (c *Client) handleAcquired() error { func (c *Client) handleFailure(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("handling client failure for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: client failure for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) msgFailure := msg.(*MsgFailure) switch msgFailure.Failure { case AcquireFailurePointTooOld: @@ -717,7 +715,7 @@ func (c *Client) handleFailure(msg protocol.Message) error { func (c *Client) handleResult(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("handling client result for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: client result for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) msgResult := msg.(*MsgResult) c.queryResultChan <- msgResult.Result return nil diff --git a/protocol/localstatequery/server.go b/protocol/localstatequery/server.go index 27d92635..c42f920f 100644 --- a/protocol/localstatequery/server.go +++ b/protocol/localstatequery/server.go @@ -65,8 +65,6 @@ func NewServer(protoOptions protocol.ProtocolOptions, cfg *Config) *Server { } func (s *Server) messageHandler(msg protocol.Message) error { - s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server message for %s", ProtocolName)) var err error switch msg.Type() { case MessageTypeAcquire: @@ -95,7 +93,7 @@ func (s *Server) messageHandler(msg protocol.Message) error { func (s *Server) handleAcquire(msg protocol.Message) error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server acquire for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server acquire for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) if s.config.AcquireFunc == nil { return fmt.Errorf( "received local-state-query Acquire message but no callback function is defined", @@ -114,7 +112,7 @@ func (s *Server) handleAcquire(msg protocol.Message) error { func (s *Server) handleQuery(msg protocol.Message) error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server query for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server query for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) if s.config.QueryFunc == nil { return fmt.Errorf( "received local-state-query Query message but no callback function is defined", @@ -127,7 +125,7 @@ func (s *Server) handleQuery(msg protocol.Message) error { func (s *Server) handleRelease() error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server release for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server release for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) if s.config.ReleaseFunc == nil { return fmt.Errorf( "received local-state-query Release message but no callback function is defined", @@ -139,7 +137,7 @@ func (s *Server) handleRelease() error { func (s *Server) handleReAcquire(msg protocol.Message) error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server reacquire for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server reacquire for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) if s.config.ReAcquireFunc == nil { return fmt.Errorf( "received local-state-query ReAcquire message but no callback function is defined", @@ -158,7 +156,7 @@ func (s *Server) handleReAcquire(msg protocol.Message) error { func (s *Server) handleDone() error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server done for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server done for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) if s.config.DoneFunc == nil { return fmt.Errorf( "received local-state-query Done message but no callback function is defined", diff --git a/protocol/localtxmonitor/client.go b/protocol/localtxmonitor/client.go index c46b8918..fd370680 100644 --- a/protocol/localtxmonitor/client.go +++ b/protocol/localtxmonitor/client.go @@ -85,7 +85,7 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { func (c *Client) Start() { c.onceStart.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("starting protocol: %s", ProtocolName)) + Debug(fmt.Sprintf("%s: starting client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.Protocol.Start() // Start goroutine to cleanup resources on protocol shutdown go func() { @@ -103,7 +103,7 @@ func (c *Client) Stop() error { var err error c.onceStop.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("stopping protocol: %s", ProtocolName)) + Debug(fmt.Sprintf("%s: stopping client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() msg := NewMsgDone() @@ -117,7 +117,7 @@ func (c *Client) Stop() error { // Acquire starts the acquire process for a current mempool snapshot func (c *Client) Acquire() error { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s Acquire()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called Acquire()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() return c.acquire() @@ -126,7 +126,7 @@ func (c *Client) Acquire() error { // Release releases the previously acquired mempool snapshot func (c *Client) Release() error { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s Release()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called Release()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() return c.release() @@ -135,7 +135,7 @@ func (c *Client) Release() error { // HasTx returns whether or not the specified transaction ID exists in the mempool snapshot func (c *Client) HasTx(txId []byte) (bool, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s HasTx(txId: %x)", ProtocolName, txId)) + Debug(fmt.Sprintf("%s: client %+v called HasTx(txId: %x)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, txId)) c.busyMutex.Lock() defer c.busyMutex.Unlock() if !c.acquired { @@ -157,7 +157,7 @@ func (c *Client) HasTx(txId []byte) (bool, error) { // NextTx returns the next transaction in the mempool snapshot func (c *Client) NextTx() ([]byte, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s NextTx()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called NextTx()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() if !c.acquired { @@ -179,7 +179,7 @@ func (c *Client) NextTx() ([]byte, error) { // GetSizes returns the capacity (in bytes), size (in bytes), and number of transactions in the mempool snapshot func (c *Client) GetSizes() (uint32, uint32, uint32, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("client called %s GetSizes()", ProtocolName)) + Debug(fmt.Sprintf("%s: client %+v called GetSizes()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() if !c.acquired { @@ -199,8 +199,6 @@ func (c *Client) GetSizes() (uint32, uint32, uint32, error) { } func (c *Client) messageHandler(msg protocol.Message) error { - c.Protocol.Logger(). - Debug(fmt.Sprintf("handling client message for %s", ProtocolName)) var err error switch msg.Type() { case MessageTypeAcquired: @@ -223,7 +221,7 @@ func (c *Client) messageHandler(msg protocol.Message) error { func (c *Client) handleAcquired(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("handling client acquired for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: client acquired for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) msgAcquired := msg.(*MsgAcquired) c.acquired = true c.acquiredSlot = msgAcquired.SlotNo @@ -233,7 +231,7 @@ func (c *Client) handleAcquired(msg protocol.Message) error { func (c *Client) handleReplyHasTx(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("handling client reply has tx for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: client reply has tx for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) msgReplyHasTx := msg.(*MsgReplyHasTx) c.hasTxResultChan <- msgReplyHasTx.Result return nil @@ -241,7 +239,7 @@ func (c *Client) handleReplyHasTx(msg protocol.Message) error { func (c *Client) handleReplyNextTx(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("handling client reply next tx for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: client reply next tx for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) msgReplyNextTx := msg.(*MsgReplyNextTx) c.nextTxResultChan <- msgReplyNextTx.Transaction.Tx return nil @@ -249,7 +247,7 @@ func (c *Client) handleReplyNextTx(msg protocol.Message) error { func (c *Client) handleReplyGetSizes(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("handling client reply get sizes for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: client reply get sizes for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) msgReplyGetSizes := msg.(*MsgReplyGetSizes) c.getSizesResultChan <- msgReplyGetSizes.Result return nil diff --git a/protocol/localtxmonitor/server.go b/protocol/localtxmonitor/server.go index 9b7b58d8..29e82463 100644 --- a/protocol/localtxmonitor/server.go +++ b/protocol/localtxmonitor/server.go @@ -59,8 +59,6 @@ func NewServer(protoOptions protocol.ProtocolOptions, cfg *Config) *Server { } func (s *Server) messageHandler(msg protocol.Message) error { - s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server message for %s", ProtocolName)) var err error switch msg.Type() { case MessageTypeAcquire: @@ -87,7 +85,7 @@ func (s *Server) messageHandler(msg protocol.Message) error { func (s *Server) handleAcquire() error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server acquire for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server acquire for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) if s.config.GetMempoolFunc == nil { return fmt.Errorf( "received local-tx-monitor Acquire message but no GetMempool callback function is defined", @@ -128,13 +126,13 @@ func (s *Server) handleAcquire() error { func (s *Server) handleDone() error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server done for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server done for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) return nil } func (s *Server) handleRelease() error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server release for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server release for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) s.mempoolCapacity = 0 s.mempoolTxs = nil return nil @@ -142,7 +140,7 @@ func (s *Server) handleRelease() error { func (s *Server) handleHasTx(msg protocol.Message) error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server has tx for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server has tx for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) msgHasTx := msg.(*MsgHasTx) txId := hex.EncodeToString(msgHasTx.TxId) hasTx := false @@ -161,7 +159,7 @@ func (s *Server) handleHasTx(msg protocol.Message) error { func (s *Server) handleNextTx() error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server next tx for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server next tx for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) if s.mempoolNextTxIdx > len(s.mempoolTxs) { newMsg := NewMsgReplyNextTx(0, nil) if err := s.SendMessage(newMsg); err != nil { @@ -180,7 +178,7 @@ func (s *Server) handleNextTx() error { func (s *Server) handleGetSizes() error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server get sizes for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server get sizes for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) totalTxSize := 0 for _, tx := range s.mempoolTxs { totalTxSize += len(tx.Tx) diff --git a/protocol/localtxsubmission/client.go b/protocol/localtxsubmission/client.go index b747bae8..b0b8828c 100644 --- a/protocol/localtxsubmission/client.go +++ b/protocol/localtxsubmission/client.go @@ -74,7 +74,7 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { func (c *Client) Start() { c.onceStart.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("starting protocol: %s", ProtocolName)) + Debug(fmt.Sprintf("%s: starting client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.Protocol.Start() // Start goroutine to cleanup resources on protocol shutdown go func() { @@ -89,7 +89,7 @@ func (c *Client) Stop() error { var err error c.onceStop.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("stopping protocol: %s", ProtocolName)) + Debug(fmt.Sprintf("%s: stopping client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.busyMutex.Lock() defer c.busyMutex.Unlock() msg := NewMsgDone() @@ -102,6 +102,8 @@ func (c *Client) Stop() error { // SubmitTx submits a transaction using the specified transaction era ID and TX payload func (c *Client) SubmitTx(eraId uint16, tx []byte) error { + c.Protocol.Logger(). + Debug(fmt.Sprintf("%s: client %+v called SubmitTx(eraId: %d, tx: %x)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, eraId, tx)) c.busyMutex.Lock() defer c.busyMutex.Unlock() msg := NewMsgSubmitTx(eraId, tx) @@ -116,8 +118,6 @@ func (c *Client) SubmitTx(eraId uint16, tx []byte) error { } func (c *Client) messageHandler(msg protocol.Message) error { - c.Protocol.Logger(). - Debug(fmt.Sprintf("handling client message for %s", ProtocolName)) var err error switch msg.Type() { case MessageTypeAcceptTx: @@ -136,14 +136,14 @@ func (c *Client) messageHandler(msg protocol.Message) error { func (c *Client) handleAcceptTx() error { c.Protocol.Logger(). - Debug(fmt.Sprintf("handling client accept tx for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: client accept tx for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) c.submitResultChan <- nil return nil } func (c *Client) handleRejectTx(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("handling client reject tx for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: client reject tx for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) msgRejectTx := msg.(*MsgRejectTx) rejectErr, err := ledger.NewTxSubmitErrorFromCbor(msgRejectTx.Reason) if err != nil { diff --git a/protocol/localtxsubmission/server.go b/protocol/localtxsubmission/server.go index 40357ea2..e79d3427 100644 --- a/protocol/localtxsubmission/server.go +++ b/protocol/localtxsubmission/server.go @@ -55,8 +55,6 @@ func NewServer(protoOptions protocol.ProtocolOptions, cfg *Config) *Server { } func (s *Server) messageHandler(msg protocol.Message) error { - s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server message for %s", ProtocolName)) var err error switch msg.Type() { case MessageTypeSubmitTx: @@ -75,7 +73,7 @@ func (s *Server) messageHandler(msg protocol.Message) error { func (s *Server) handleSubmitTx(msg protocol.Message) error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server submit tx for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server submit tx for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) if s.config.SubmitTxFunc == nil { return fmt.Errorf( "received local-tx-submission SubmitTx message but no callback function is defined", @@ -104,6 +102,6 @@ func (s *Server) handleSubmitTx(msg protocol.Message) error { func (s *Server) handleDone() error { s.Protocol.Logger(). - Debug(fmt.Sprintf("handling server done for %s", ProtocolName)) + Debug(fmt.Sprintf("%s: server done for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) return nil } diff --git a/protocol/peersharing/client.go b/protocol/peersharing/client.go index 9ca18c6b..79bc72a9 100644 --- a/protocol/peersharing/client.go +++ b/protocol/peersharing/client.go @@ -57,7 +57,7 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { ErrorChan: protoOptions.ErrorChan, Mode: protoOptions.Mode, Role: protocol.ProtocolRoleClient, - MessageHandlerFunc: c.handleMessage, + MessageHandlerFunc: c.messageHandler, MessageFromCborFunc: NewMsgFromCbor, StateMap: stateMap, InitialState: stateIdle, @@ -80,9 +80,7 @@ func (c *Client) GetPeers(amount uint8) ([]PeerAddress, error) { return peers, nil } -func (c *Client) handleMessage(msg protocol.Message) error { - c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client message for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) +func (c *Client) messageHandler(msg protocol.Message) error { var err error switch msg.Type() { case MessageTypeSharePeers: diff --git a/protocol/peersharing/server.go b/protocol/peersharing/server.go index 32dc1973..109de046 100644 --- a/protocol/peersharing/server.go +++ b/protocol/peersharing/server.go @@ -48,6 +48,7 @@ func (s *Server) initProtocol() { Name: ProtocolName, ProtocolId: ProtocolId, Muxer: s.protoOptions.Muxer, + Logger: s.protoOptions.Logger, ErrorChan: s.protoOptions.ErrorChan, Mode: s.protoOptions.Mode, Role: protocol.ProtocolRoleServer, @@ -77,6 +78,8 @@ func (s *Server) handleMessage(msg protocol.Message) error { } func (s *Server) handleShareRequest(msg protocol.Message) error { + s.Protocol.Logger(). + Debug(fmt.Sprintf("%s: server share request for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) if s.config == nil || s.config.ShareRequestFunc == nil { return fmt.Errorf( "received peer-sharing ShareRequest message but no callback function is defined", @@ -98,6 +101,8 @@ func (s *Server) handleShareRequest(msg protocol.Message) error { } func (s *Server) handleDone(msg protocol.Message) error { + s.Protocol.Logger(). + Debug(fmt.Sprintf("%s: server done for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) // Restart protocol s.Protocol.Stop() s.initProtocol() diff --git a/protocol/txsubmission/client.go b/protocol/txsubmission/client.go index 553b7bcd..5ff68a5f 100644 --- a/protocol/txsubmission/client.go +++ b/protocol/txsubmission/client.go @@ -69,6 +69,8 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { // Init tells the server to begin asking us for transactions func (c *Client) Init() { c.onceInit.Do(func() { + c.Protocol.Logger(). + Debug(fmt.Sprintf("%s: client %+v called Init()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) // Send our Init message msg := NewMsgInit() _ = c.SendMessage(msg) diff --git a/protocol/txsubmission/server.go b/protocol/txsubmission/server.go index 3fa6a8e6..be207182 100644 --- a/protocol/txsubmission/server.go +++ b/protocol/txsubmission/server.go @@ -55,6 +55,7 @@ func (s *Server) initProtocol() { Name: ProtocolName, ProtocolId: ProtocolId, Muxer: s.protoOptions.Muxer, + Logger: s.protoOptions.Logger, ErrorChan: s.protoOptions.ErrorChan, Mode: s.protoOptions.Mode, Role: protocol.ProtocolRoleServer, @@ -68,6 +69,8 @@ func (s *Server) initProtocol() { func (s *Server) Start() { s.onceStart.Do(func() { + s.Protocol.Logger(). + Debug(fmt.Sprintf("%s: starting server protocol for connection %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) s.Protocol.Start() // Start goroutine to cleanup resources on protocol shutdown go func() { @@ -104,6 +107,8 @@ func (s *Server) RequestTxIds( blocking bool, reqCount int, ) ([]TxIdAndSize, error) { + s.Protocol.Logger(). + Debug(fmt.Sprintf("%s: server %+v called RequestTxIds(blocking: %+v, reqCount: %d)", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr, blocking, reqCount)) msg := NewMsgRequestTxIds(blocking, uint16(s.ackCount), uint16(reqCount)) if err := s.SendMessage(msg); err != nil { return nil, err @@ -120,6 +125,8 @@ func (s *Server) RequestTxIds( // RequestTxs requests the content of the requested TX identifiers from the remote node's mempool func (s *Server) RequestTxs(txIds []TxId) ([]TxBody, error) { + s.Protocol.Logger(). + Debug(fmt.Sprintf("%s: server %+v called RequestTxs(txIds: %+v)", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr, txIds)) msg := NewMsgRequestTxs(txIds) if err := s.SendMessage(msg); err != nil { return nil, err @@ -133,18 +140,24 @@ func (s *Server) RequestTxs(txIds []TxId) ([]TxBody, error) { } func (s *Server) handleReplyTxIds(msg protocol.Message) error { + s.Protocol.Logger(). + Debug(fmt.Sprintf("%s: server reply tx ids for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) msgReplyTxIds := msg.(*MsgReplyTxIds) s.requestTxIdsResultChan <- msgReplyTxIds.TxIds return nil } func (s *Server) handleReplyTxs(msg protocol.Message) error { + s.Protocol.Logger(). + Debug(fmt.Sprintf("%s: server reply txs for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) msgReplyTxs := msg.(*MsgReplyTxs) s.requestTxsResultChan <- msgReplyTxs.Txs return nil } func (s *Server) handleDone() error { + s.Protocol.Logger(). + Debug(fmt.Sprintf("%s: server done for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) // Restart protocol s.Protocol.Stop() s.initProtocol() @@ -155,6 +168,8 @@ func (s *Server) handleDone() error { } func (s *Server) handleInit() error { + s.Protocol.Logger(). + Debug(fmt.Sprintf("%s: server init for %+v", ProtocolName, s.callbackContext.ConnectionId.RemoteAddr)) if s.config == nil || s.config.InitFunc == nil { return fmt.Errorf( "received tx-submission Init message but no callback function is defined",