From 0d5e2cb9b3d7a1fd5f18b3f3a00d88a291b2cb1c Mon Sep 17 00:00:00 2001 From: Chris Gianelloni Date: Thu, 24 Oct 2024 19:55:25 -0400 Subject: [PATCH] refactor(logs): use slog attributes for protocol clients Signed-off-by: Chris Gianelloni --- protocol/blockfetch/client.go | 61 +++++++- protocol/chainsync/client.go | 148 ++++++++++++++++-- protocol/handshake/client.go | 20 ++- protocol/keepalive/client.go | 13 +- protocol/localstatequery/client.go | 217 +++++++++++++++++++++++---- protocol/localtxmonitor/client.go | 75 +++++++-- protocol/localtxsubmission/client.go | 33 +++- protocol/peersharing/client.go | 14 +- protocol/txsubmission/client.go | 21 ++- 9 files changed, 521 insertions(+), 81 deletions(-) diff --git a/protocol/blockfetch/client.go b/protocol/blockfetch/client.go index 33d08c64..c96b8d06 100644 --- a/protocol/blockfetch/client.go +++ b/protocol/blockfetch/client.go @@ -82,7 +82,11 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { func (c *Client) Start() { c.onceStart.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: starting client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("starting client protocol", + "component", "network", + "protocol", ProtocolName, + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.Protocol.Start() // Start goroutine to cleanup resources on protocol shutdown go func() { @@ -97,7 +101,11 @@ func (c *Client) Stop() error { var err error c.onceStop.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: stopping client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("stopping client protocol", + "component", "network", + "protocol", ProtocolName, + "connection_id", c.callbackContext.ConnectionId.String(), + ) msg := NewMsgClientDone() err = c.SendMessage(msg) }) @@ -107,7 +115,18 @@ func (c *Client) Stop() error { // GetBlockRange starts an async process to fetch all blocks in the specified range (inclusive) func (c *Client) GetBlockRange(start common.Point, end common.Point) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client called GetBlockRange(start: {Slot: %d, Hash: %x}, end: {Slot: %d, Hash: %x})", ProtocolName, start.Slot, start.Hash, end.Slot, end.Hash)) + Debug( + fmt.Sprintf("calling GetBlockRange(start: {Slot: %d, Hash: %x}, end: {Slot: %d, Hash: %x})", + start.Slot, + start.Hash, + end.Slot, + end.Hash, + ), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() c.blockUseCallback = true msg := NewMsgRequestRange(start, end) @@ -129,7 +148,13 @@ func (c *Client) GetBlockRange(start common.Point, end common.Point) error { // GetBlock requests and returns a single block specified by the provided point func (c *Client) GetBlock(point common.Point) (ledger.Block, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client called GetBlock(point: {Slot: %d, Hash: %x})", ProtocolName, point.Slot, point.Hash)) + Debug( + fmt.Sprintf("calling GetBlock(point: {Slot: %d, Hash: %x})", point.Slot, point.Hash), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() c.blockUseCallback = false msg := NewMsgRequestRange(point, point) @@ -175,14 +200,24 @@ func (c *Client) messageHandler(msg protocol.Message) error { func (c *Client) handleStartBatch() error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client start batch for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("starting batch", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.startBatchResultChan <- nil return nil } func (c *Client) handleNoBlocks() error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client no blocks found for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("no blocks returned", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) err := fmt.Errorf("block(s) not found") c.startBatchResultChan <- err return nil @@ -190,7 +225,12 @@ func (c *Client) handleNoBlocks() error { func (c *Client) handleBlock(msgGeneric protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client block found for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("block returned", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) msg := msgGeneric.(*MsgBlock) // Decode only enough to get the block type value var wrappedBlock WrappedBlock @@ -217,7 +257,12 @@ func (c *Client) handleBlock(msgGeneric protocol.Message) error { func (c *Client) handleBatchDone() error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client batch done for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("batch done", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Unlock() return nil } diff --git a/protocol/chainsync/client.go b/protocol/chainsync/client.go index 5029546a..0ceb1d77 100644 --- a/protocol/chainsync/client.go +++ b/protocol/chainsync/client.go @@ -117,7 +117,11 @@ func NewClient( func (c *Client) Start() { c.onceStart.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: starting client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("starting client protocol", + "component", "network", + "protocol", ProtocolName, + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.Protocol.Start() // Start goroutine to cleanup resources on protocol shutdown go func() { @@ -132,7 +136,11 @@ func (c *Client) Stop() error { var err error c.onceStop.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: stopping client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("stopping client protocol", + "component", "network", + "protocol", ProtocolName, + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() msg := NewMsgDone() @@ -146,7 +154,12 @@ func (c *Client) Stop() error { // GetCurrentTip returns the current chain tip func (c *Client) GetCurrentTip() (*Tip, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetCurrentTip()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetCurrentTip()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) done := atomic.Bool{} requestResultChan := make(chan Tip, 1) requestErrorChan := make(chan error, 1) @@ -186,13 +199,25 @@ func (c *Client) GetCurrentTip() (*Tip, error) { waitingForCurrentTipChan = nil case tip := <-waitingResultChan: c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: returning tip results {Slot: %d, Hash: %x, BlockNumber: %d} to %+v", ProtocolName, tip.Point.Slot, tip.Point.Hash, tip.BlockNumber, c.callbackContext.ConnectionId.RemoteAddr)) + Debug( + fmt.Sprintf("received tip results {Slot: %d, Hash: %x, BlockNumber: %d}", tip.Point.Slot, tip.Point.Hash, tip.BlockNumber), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) // The result from the other request is ready. done.Store(true) return &tip, nil case tip := <-requestResultChan: c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: returning tip results {Slot: %d, Hash: %x, BlockNumber: %d} to %+v", ProtocolName, tip.Point.Slot, tip.Point.Hash, tip.BlockNumber, c.callbackContext.ConnectionId.RemoteAddr)) + Debug( + fmt.Sprintf("received tip results {Slot: %d, Hash: %x, BlockNumber: %d}", tip.Point.Slot, tip.Point.Hash, tip.BlockNumber), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) // If waitingForCurrentTipChan is full, the for loop that empties it might finish the // loop before the select statement that writes to it is triggered. For that reason we // require requestResultChan here. @@ -215,16 +240,49 @@ func (c *Client) GetAvailableBlockRange( if len(intersectPoints) == 0 { intersectPoints = []common.Point{common.NewPointOrigin()} } + + // Debug logging switch len(intersectPoints) { case 1: c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetAvailableBlockRange(intersectPoints: []{Slot: %d, Hash: %x})", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, intersectPoints[0].Slot, intersectPoints[0].Hash)) + Debug( + fmt.Sprintf( + "calling GetAvailableBlockRange(intersectPoints: []{Slot: %d, Hash: %x})", + intersectPoints[0].Slot, + intersectPoints[0].Hash, + ), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) case 2: c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetAvailableBlockRange(intersectPoints: []{Slot: %d, Hash: %x},{Slot: %d, Hash: %x})", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, intersectPoints[0].Slot, intersectPoints[0].Hash, intersectPoints[1].Slot, intersectPoints[1].Hash)) + Debug( + fmt.Sprintf( + "calling GetAvailableBlockRange(intersectPoints: []{Slot: %d, Hash: %x},{Slot: %d, Hash: %x})", + intersectPoints[0].Slot, + intersectPoints[0].Hash, + intersectPoints[1].Slot, + intersectPoints[1].Hash, + ), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) default: c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetAvailableBlockRange(intersectPoints: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, intersectPoints)) + Debug( + fmt.Sprintf( + "calling GetAvailableBlockRange(intersectPoints: %+v)", + intersectPoints, + ), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) } // Find our chain intersection @@ -300,16 +358,49 @@ func (c *Client) Sync(intersectPoints []common.Point) error { if len(intersectPoints) == 0 { intersectPoints = []common.Point{common.NewPointOrigin()} } + + // Debug logging switch len(intersectPoints) { case 1: c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called Sync(intersectPoints: []{Slot: %d, Hash: %x})", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, intersectPoints[0].Slot, intersectPoints[0].Hash)) + Debug( + fmt.Sprintf( + "calling Sync(intersectPoints: []{Slot: %d, Hash: %x})", + intersectPoints[0].Slot, + intersectPoints[0].Hash, + ), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) case 2: c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called Sync(intersectPoints: []{Slot: %d, Hash: %x},{Slot: %d, Hash: %x})", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, intersectPoints[0].Slot, intersectPoints[0].Hash, intersectPoints[1].Slot, intersectPoints[1].Hash)) + Debug( + fmt.Sprintf( + "calling Sync(intersectPoints: []{Slot: %d, Hash: %x},{Slot: %d, Hash: %x})", + intersectPoints[0].Slot, + intersectPoints[0].Hash, + intersectPoints[1].Slot, + intersectPoints[1].Hash, + ), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) default: c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called Sync(intersectPoints: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, intersectPoints)) + Debug( + fmt.Sprintf( + "calling Sync(intersectPoints: %+v)", + intersectPoints, + ), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) } intersectResultChan, cancel := c.wantIntersectFound() @@ -478,13 +569,23 @@ func (c *Client) messageHandler(msg protocol.Message) error { func (c *Client) handleAwaitReply() error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client await reply for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("waiting for next reply", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) return nil } func (c *Client) handleRollForward(msgGeneric protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client roll forward for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("roll forward", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) firstBlockChan := func() chan<- clientPointResult { select { case ch := <-c.wantFirstBlockChan: @@ -594,7 +695,12 @@ func (c *Client) handleRollForward(msgGeneric protocol.Message) error { func (c *Client) handleRollBackward(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client roll backward for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("roll backward", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) msgRollBackward := msg.(*MsgRollBackward) c.sendCurrentTip(msgRollBackward.Tip) if len(c.wantFirstBlockChan) == 0 { @@ -621,7 +727,12 @@ func (c *Client) handleRollBackward(msg protocol.Message) error { func (c *Client) handleIntersectFound(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client intersect found for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("chain intersect found", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) msgIntersectFound := msg.(*MsgIntersectFound) c.sendCurrentTip(msgIntersectFound.Tip) @@ -635,7 +746,12 @@ func (c *Client) handleIntersectFound(msg protocol.Message) error { func (c *Client) handleIntersectNotFound(msgGeneric protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client intersect not found for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("chain intersect not found", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) msgIntersectNotFound := msgGeneric.(*MsgIntersectNotFound) c.sendCurrentTip(msgIntersectNotFound.Tip) diff --git a/protocol/handshake/client.go b/protocol/handshake/client.go index 10fb4c22..77c5487b 100644 --- a/protocol/handshake/client.go +++ b/protocol/handshake/client.go @@ -70,7 +70,11 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { func (c *Client) Start() { c.onceStart.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: starting client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("starting client protocol", + "component", "network", + "protocol", ProtocolName, + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.Protocol.Start() // Send our ProposeVersions message msg := NewMsgProposeVersions(c.config.ProtocolVersionMap) @@ -97,7 +101,12 @@ func (c *Client) messageHandler(msg protocol.Message) error { func (c *Client) handleAcceptVersion(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client accept version for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("accepted version negotiation", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) if c.config.FinishedFunc == nil { return fmt.Errorf( "received handshake AcceptVersion message but no callback function is defined", @@ -120,7 +129,12 @@ func (c *Client) handleAcceptVersion(msg protocol.Message) error { func (c *Client) handleRefuse(msgGeneric protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client refuse for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("refused handshake", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) msg := msgGeneric.(*MsgRefuse) var err error switch msg.Reason[0].(uint64) { diff --git a/protocol/keepalive/client.go b/protocol/keepalive/client.go index 1612f827..65898f86 100644 --- a/protocol/keepalive/client.go +++ b/protocol/keepalive/client.go @@ -70,7 +70,11 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { func (c *Client) Start() { c.onceStart.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: starting client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("starting client protocol", + "component", "network", + "protocol", ProtocolName, + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.Protocol.Start() // Start goroutine to cleanup resources on protocol shutdown go func() { @@ -123,7 +127,12 @@ func (c *Client) messageHandler(msg protocol.Message) error { func (c *Client) handleKeepAliveResponse(msgGeneric protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client keepalive response for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("keepalive response", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) msg := msgGeneric.(*MsgKeepAliveResponse) if msg.Cookie != c.config.Cookie { return fmt.Errorf( diff --git a/protocol/localstatequery/client.go b/protocol/localstatequery/client.go index ca81bcff..0ab65bf2 100644 --- a/protocol/localstatequery/client.go +++ b/protocol/localstatequery/client.go @@ -96,7 +96,11 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { func (c *Client) Start() { c.onceStart.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: starting client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("starting client protocol", + "component", "network", + "protocol", ProtocolName, + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.Protocol.Start() // Start goroutine to cleanup resources on protocol shutdown go func() { @@ -110,7 +114,13 @@ 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("%s: client %+v called Acquire(point: {Slot: %d, Hash: %x})", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, point.Slot, point.Hash)) + Debug( + fmt.Sprintf("calling Acquire(point: {Slot: %d, Hash: %x})", point.Slot, point.Hash), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() return c.acquire(point) @@ -119,7 +129,12 @@ 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("%s: client %+v called Release()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling Release()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() return c.release() @@ -128,7 +143,12 @@ func (c *Client) Release() error { // GetCurrentEra returns the current era ID func (c *Client) GetCurrentEra() (int, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetCurrentEra()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetCurrentEra()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() return c.getCurrentEra() @@ -137,7 +157,12 @@ func (c *Client) GetCurrentEra() (int, error) { // GetSystemStart returns the SystemStart value func (c *Client) GetSystemStart() (*SystemStartResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetSystemStart()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetSystemStart()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() query := buildQuery( @@ -153,7 +178,12 @@ func (c *Client) GetSystemStart() (*SystemStartResult, error) { // GetChainBlockNo returns the latest block number func (c *Client) GetChainBlockNo() (int64, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetChainBlockNo()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetChainBlockNo()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() query := buildQuery( @@ -169,7 +199,12 @@ 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("%s: client %+v called GetChainPoint()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetChainPoint()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() query := buildQuery( @@ -185,7 +220,12 @@ func (c *Client) GetChainPoint() (*common.Point, error) { // GetEraHistory returns the era history func (c *Client) GetEraHistory() ([]EraHistoryResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetEraHistory()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetEraHistory()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() query := buildHardForkQuery(QueryTypeHardForkEraHistory) @@ -199,7 +239,12 @@ func (c *Client) GetEraHistory() ([]EraHistoryResult, error) { // GetEpochNo returns the current epoch number func (c *Client) GetEpochNo() (int, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetEpochNo()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetEpochNo()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -223,7 +268,12 @@ 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("%s: client %+v called GetNonMyopicMemberRewards()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetNonMyopicMemberRewards()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -244,7 +294,12 @@ 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("%s: client %+v called GetCurrentProtocolParams()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetCurrentProtocolParams()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -300,7 +355,12 @@ 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("%s: client %+v called GetProposedProtocolParamsUpdates()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetProposedProtocolParamsUpdates()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -322,7 +382,12 @@ func (c *Client) GetProposedProtocolParamsUpdates() (*ProposedProtocolParamsUpda // GetStakeDistribution returns the stake distribution func (c *Client) GetStakeDistribution() (*StakeDistributionResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetStakeDistribution()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetStakeDistribution()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -345,7 +410,12 @@ func (c *Client) GetUTxOByAddress( addrs []ledger.Address, ) (*UTxOByAddressResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetUTxOByAddress(addrs: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, addrs)) + Debug(fmt.Sprintf("calling GetUTxOByAddress(addrs: %+v)", addrs), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -367,7 +437,12 @@ func (c *Client) GetUTxOByAddress( // GetUTxOWhole returns the current UTxO set func (c *Client) GetUTxOWhole() (*UTxOWholeResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetUTxOWhole()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetUTxOWhole()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -388,7 +463,12 @@ func (c *Client) GetUTxOWhole() (*UTxOWholeResult, error) { // TODO func (c *Client) DebugEpochState() (*DebugEpochStateResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called DebugEpochState()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling DebugEpochState()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -414,7 +494,12 @@ func (c *Client) GetFilteredDelegationsAndRewardAccounts( creds []interface{}, ) (*FilteredDelegationsAndRewardAccountsResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetFilteredDelegationsAndRewardAccounts(creds: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, creds)) + Debug(fmt.Sprintf("calling GetFilteredDelegationsAndRewardAccounts(creds: %+v)", creds), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -435,7 +520,12 @@ func (c *Client) GetFilteredDelegationsAndRewardAccounts( func (c *Client) GetGenesisConfig() (*GenesisConfigResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetGenesisConfig()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetGenesisConfig()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -456,7 +546,12 @@ func (c *Client) GetGenesisConfig() (*GenesisConfigResult, error) { // TODO func (c *Client) DebugNewEpochState() (*DebugNewEpochStateResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called DebugNewEpochState()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling DebugNewEpochState()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -477,7 +572,12 @@ func (c *Client) DebugNewEpochState() (*DebugNewEpochStateResult, error) { // TODO func (c *Client) DebugChainDepState() (*DebugChainDepStateResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called DebugChainDepState()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling DebugChainDepState()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -497,7 +597,12 @@ func (c *Client) DebugChainDepState() (*DebugChainDepStateResult, error) { func (c *Client) GetRewardProvenance() (*RewardProvenanceResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetRewardProvenance()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetRewardProvenance()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -519,7 +624,12 @@ func (c *Client) GetUTxOByTxIn( txIns []ledger.TransactionInput, ) (*UTxOByTxInResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetUTxOByTxIn(txIns: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, txIns)) + Debug(fmt.Sprintf("calling GetUTxOByTxIn(txIns: %+v)", txIns), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -540,7 +650,12 @@ func (c *Client) GetUTxOByTxIn( func (c *Client) GetStakePools() (*StakePoolsResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetStakePools()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetStakePools()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -562,7 +677,12 @@ func (c *Client) GetStakePoolParams( poolIds []ledger.PoolId, ) (*StakePoolParamsResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetStakePoolParams(poolIds: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, poolIds)) + Debug(fmt.Sprintf("calling GetStakePoolParams(poolIds: %+v)", poolIds), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -587,7 +707,12 @@ func (c *Client) GetStakePoolParams( // TODO func (c *Client) GetRewardInfoPools() (*RewardInfoPoolsResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetRewardInfoPools()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetRewardInfoPools()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -608,7 +733,12 @@ func (c *Client) GetRewardInfoPools() (*RewardInfoPoolsResult, error) { // TODO func (c *Client) GetPoolState(poolIds []interface{}) (*PoolStateResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetPoolState(poolIds: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, poolIds)) + Debug(fmt.Sprintf("calling GetPoolState(poolIds: %+v)", poolIds), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -631,7 +761,12 @@ func (c *Client) GetStakeSnapshots( poolId interface{}, ) (*StakeSnapshotsResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetStakeSnapshots(poolId: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, poolId)) + Debug(fmt.Sprintf("calling GetStakeSnapshots(poolId: %+v)", poolId), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -652,7 +787,12 @@ func (c *Client) GetStakeSnapshots( // TODO func (c *Client) GetPoolDistr(poolIds []interface{}) (*PoolDistrResult, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetPoolDistr(poolIds: %+v)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, poolIds)) + Debug(fmt.Sprintf("calling GetPoolDistr(poolIds: %+v)", poolIds), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() currentEra, err := c.getCurrentEra() @@ -691,7 +831,12 @@ func (c *Client) messageHandler(msg protocol.Message) error { func (c *Client) handleAcquired() error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client acquired for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("acquired", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.acquired = true c.acquireResultChan <- nil c.currentEra = -1 @@ -700,7 +845,12 @@ func (c *Client) handleAcquired() error { func (c *Client) handleFailure(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client failure for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("failed", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) msgFailure := msg.(*MsgFailure) switch msgFailure.Failure { case AcquireFailurePointTooOld: @@ -715,7 +865,12 @@ func (c *Client) handleFailure(msg protocol.Message) error { func (c *Client) handleResult(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client result for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("results", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) msgResult := msg.(*MsgResult) c.queryResultChan <- msgResult.Result return nil diff --git a/protocol/localtxmonitor/client.go b/protocol/localtxmonitor/client.go index fd370680..abfa5b90 100644 --- a/protocol/localtxmonitor/client.go +++ b/protocol/localtxmonitor/client.go @@ -85,7 +85,11 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { func (c *Client) Start() { c.onceStart.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: starting client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("starting client protocol", + "component", "network", + "protocol", ProtocolName, + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.Protocol.Start() // Start goroutine to cleanup resources on protocol shutdown go func() { @@ -103,7 +107,11 @@ func (c *Client) Stop() error { var err error c.onceStop.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: stopping client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("stopping client protocol", + "component", "network", + "protocol", ProtocolName, + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() msg := NewMsgDone() @@ -117,7 +125,12 @@ 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("%s: client %+v called Acquire()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling Acquire()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() return c.acquire() @@ -126,7 +139,12 @@ func (c *Client) Acquire() error { // Release releases the previously acquired mempool snapshot func (c *Client) Release() error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called Release()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling Release()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() return c.release() @@ -135,7 +153,12 @@ 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("%s: client %+v called HasTx(txId: %x)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, txId)) + Debug(fmt.Sprintf("calling HasTx(txId: %x)", txId), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() if !c.acquired { @@ -157,7 +180,12 @@ 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("%s: client %+v called NextTx()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling NextTx()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() if !c.acquired { @@ -179,7 +207,12 @@ 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("%s: client %+v called GetSizes()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling GetSizes()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() if !c.acquired { @@ -221,7 +254,12 @@ func (c *Client) messageHandler(msg protocol.Message) error { func (c *Client) handleAcquired(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client acquired for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("acquired", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) msgAcquired := msg.(*MsgAcquired) c.acquired = true c.acquiredSlot = msgAcquired.SlotNo @@ -231,7 +269,12 @@ func (c *Client) handleAcquired(msg protocol.Message) error { func (c *Client) handleReplyHasTx(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client reply has tx for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("reply has tx", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) msgReplyHasTx := msg.(*MsgReplyHasTx) c.hasTxResultChan <- msgReplyHasTx.Result return nil @@ -239,7 +282,12 @@ func (c *Client) handleReplyHasTx(msg protocol.Message) error { func (c *Client) handleReplyNextTx(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client reply next tx for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("reply next tx", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) msgReplyNextTx := msg.(*MsgReplyNextTx) c.nextTxResultChan <- msgReplyNextTx.Transaction.Tx return nil @@ -247,7 +295,12 @@ func (c *Client) handleReplyNextTx(msg protocol.Message) error { func (c *Client) handleReplyGetSizes(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client reply get sizes for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("reply get sizes", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) msgReplyGetSizes := msg.(*MsgReplyGetSizes) c.getSizesResultChan <- msgReplyGetSizes.Result return nil diff --git a/protocol/localtxsubmission/client.go b/protocol/localtxsubmission/client.go index b0b8828c..37b1b11e 100644 --- a/protocol/localtxsubmission/client.go +++ b/protocol/localtxsubmission/client.go @@ -74,7 +74,11 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { func (c *Client) Start() { c.onceStart.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: starting client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("starting client protocol", + "component", "network", + "protocol", ProtocolName, + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.Protocol.Start() // Start goroutine to cleanup resources on protocol shutdown go func() { @@ -89,7 +93,11 @@ func (c *Client) Stop() error { var err error c.onceStop.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: stopping client protocol for connection %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("stopping client protocol", + "component", "network", + "protocol", ProtocolName, + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() msg := NewMsgDone() @@ -103,7 +111,12 @@ 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)) + Debug(fmt.Sprintf("calling SubmitTx(eraId: %d, tx: %x)", eraId, tx), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.busyMutex.Lock() defer c.busyMutex.Unlock() msg := NewMsgSubmitTx(eraId, tx) @@ -136,14 +149,24 @@ func (c *Client) messageHandler(msg protocol.Message) error { func (c *Client) handleAcceptTx() error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client accept tx for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("accept tx", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) c.submitResultChan <- nil return nil } func (c *Client) handleRejectTx(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client reject tx for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("reject tx", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) msgRejectTx := msg.(*MsgRejectTx) rejectErr, err := ledger.NewTxSubmitErrorFromCbor(msgRejectTx.Reason) if err != nil { diff --git a/protocol/peersharing/client.go b/protocol/peersharing/client.go index 79bc72a9..eb867361 100644 --- a/protocol/peersharing/client.go +++ b/protocol/peersharing/client.go @@ -68,7 +68,12 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { func (c *Client) GetPeers(amount uint8) ([]PeerAddress, error) { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called GetPeers(amount: %d)", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr, amount)) + Debug(fmt.Sprintf("calling GetPeers(amount: %d)", amount), + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) msg := NewMsgShareRequest(amount) if err := c.SendMessage(msg); err != nil { return nil, err @@ -97,7 +102,12 @@ func (c *Client) messageHandler(msg protocol.Message) error { func (c *Client) handleSharePeers(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client share peers for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("share peers", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) msgSharePeers := msg.(*MsgSharePeers) c.sharePeersChan <- msgSharePeers.PeerAddresses return nil diff --git a/protocol/txsubmission/client.go b/protocol/txsubmission/client.go index 5ff68a5f..1fb8f083 100644 --- a/protocol/txsubmission/client.go +++ b/protocol/txsubmission/client.go @@ -70,7 +70,12 @@ func NewClient(protoOptions protocol.ProtocolOptions, cfg *Config) *Client { func (c *Client) Init() { c.onceInit.Do(func() { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client %+v called Init()", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("calling Init()", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) // Send our Init message msg := NewMsgInit() _ = c.SendMessage(msg) @@ -98,7 +103,12 @@ func (c *Client) messageHandler(msg protocol.Message) error { func (c *Client) handleRequestTxIds(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client request tx ids for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("requesting tx ids", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) if c.config.RequestTxIdsFunc == nil { return fmt.Errorf( "received tx-submission RequestTxIds message but no callback function is defined", @@ -124,7 +134,12 @@ func (c *Client) handleRequestTxIds(msg protocol.Message) error { func (c *Client) handleRequestTxs(msg protocol.Message) error { c.Protocol.Logger(). - Debug(fmt.Sprintf("%s: client request txs for %+v", ProtocolName, c.callbackContext.ConnectionId.RemoteAddr)) + Debug("requesting txs", + "component", "network", + "protocol", ProtocolName, + "role", "client", + "connection_id", c.callbackContext.ConnectionId.String(), + ) if c.config.RequestTxsFunc == nil { return fmt.Errorf( "received tx-submission RequestTxs message but no callback function is defined",