Clean up logging (#986)

Signed-off-by: Arne Rutjes <[email protected]>

Author: arner

pkg/node/node.go

@@ -66,42 +66,42 @@ func (n *Node) ID() string {
 func (n *Node) Start() (err error) {
 	defer func() {
 		if r := recover(); r != nil {
-			log.Printf("Start triggered panic: %s\n%s\n", r, debug.Stack())
-			err = errors.Errorf("Start triggered panic: %s", r)
+			log.Printf("start triggered panic: %s\n%s\n", r, debug.Stack())
+			err = errors.Errorf("start triggered panic: %s", r)
 			n.Stop()
 		}
 	}()
 
 	n.running = true
 	// Install
-	logger.Infof("Installing sdks...")
+	logger.Infof("installing sdks...")
 	for _, p := range n.sdks {
 		if err := p.Install(); err != nil {
-			logger.Errorf("Failed installing platform [%s]", err)
+			logger.Errorf("failed installing platform [%s]", err.Error())
 			return err
 		}
 	}
-	logger.Infof("Installing sdks...done")
+	logger.Infof("installing sdks...done")
 
 	n.context, n.cancel = context.WithCancel(context.Background())
 
 	// Start
-	logger.Info("Starting sdks...")
+	logger.Info("starting sdks...")
 	for _, p := range n.sdks {
 		if err := p.Start(n.context); err != nil {
-			logger.Errorf("Failed starting platform [%s]", err)
+			logger.Errorf("failed starting platform [%s]", err.Error())
 			return err
 		}
 	}
-	logger.Infof("Starting sdks...done")
+	logger.Infof("starting sdks...done")
 
 	// PostStart
-	logger.Info("Post-starting sdks...")
+	logger.Info("post-starting sdks...")
 	for _, p := range n.sdks {
 		ps, ok := p.(PostStart)
 		if ok {
 			if err := ps.PostStart(n.context); err != nil {
-				logger.Errorf("Failed post-starting platform [%s]", err)
+				logger.Errorf("failed post-starting platform [%s]", err.Error())
 				return err
 			}
 		}

platform/common/core/generic/committer/finality.go

@@ -107,15 +107,15 @@ func (c *FinalityManager[V]) runStatusListener(ctx context.Context) {
 			}
 
 			newCtx, span := c.tracer.Start(context.Background(), "committer_status_listener")
-			c.logger.Debugf("check vault status for [%d] transactions", len(txIDs))
+			c.logger.DebugfContext(ctx, "check vault status for [%d] transactions", len(txIDs))
 			statuses, err := c.vault.Statuses(newCtx, txIDs...)
 			if err != nil {
-				c.logger.Errorf("error fetching statuses: %w", err)
+				c.logger.Errorf("error fetching statuses: %s", err.Error())
 				span.RecordError(err)
 				span.End()
 				continue
 			}
-			c.logger.Debugf("got vault status for [%d] transactions, post event...", len(txIDs))
+			c.logger.DebugfContext(ctx, "got vault status for [%d] transactions, post event...", len(txIDs))
 			span.AddEvent("post_events")
 			for _, status := range statuses {
 				// check txID status, if it is valid or invalid, post an event

platform/fabric/core/config.go

@@ -52,7 +52,6 @@ func NewConfig(configProvider ConfigProvider) (*Config, error) {
 			if fsnConfig.Default {
 				if len(defaultName) != 0 {
 					logger.Warnf("only one network should be set as default, ignoring [%s], default is set to [%s]", name, fsnConfig.Default)
-					// return nil, errors.Errorf("only one network can be set as default")
 					continue
 				}
 				defaultName = name

platform/fabric/core/generic/config/service.go

@@ -129,7 +129,7 @@ func createPeerMap(peers []*grpc.ConnectionConfig, tlsEnabled bool) map[driver.P
 		if funcType, ok := funcTypeMap[strings.ToLower(peerCC.Usage)]; ok {
 			peerMapping[funcType] = append(peerMapping[funcType], peerCC)
 		} else {
-			logger.Warn("connection usage [%s] not recognized [%v]", peerCC.Usage, peerCC)
+			logger.Warnf("connection usage [%s] not recognized [%v]", peerCC.Usage, peerCC)
 		}
 	}
 	return peerMapping

platform/fabric/core/generic/delivery/delivery.go

@@ -158,7 +158,7 @@ func (d *Delivery) readBlocks(ch <-chan blockResponse) {
 	for {
 		select {
 		case b := <-ch:
-			logger.Debugf("Invoking callback for block [%d]", b.block.Header)
+			logger.Debugf("Invoking callback for block [%d]", b.block.Header.Number)
 			stop, err := d.callback(b.ctx, b.block)
 			if err != nil {
 				logger.Errorf("callback errored for block [%d], stop delivery: [%v]", b.block.Header.Number, err)

platform/fabric/core/generic/events/listenermanager.go

@@ -85,7 +85,7 @@ func NewListenerManager[T EventInfo](
 ) (*ListenerManager[T], error) {
 	var events cache.Map[EventID, T]
 	if config.LRUSize > 0 && config.LRUBuffer > 0 {
-		events = cache.NewLRUCache[EventID, T](config.LRUSize, config.LRUBuffer, func(evicted map[EventID]T) {
+		events = cache.NewLRUCache(config.LRUSize, config.LRUBuffer, func(evicted map[EventID]T) {
 			logger.Debugf("evicted keys [%s]. If they are looked up, they will be fetched directly from the ledger from now on...", logging.Keys(evicted))
 		})
 	} else {
@@ -103,7 +103,7 @@ func NewListenerManager[T EventInfo](
 	}
 	var listeners cache.Map[EventID, []ListenerEntry[T]]
 	if config.ListenerTimeout > 0 {
-		listeners = cache.NewTimeoutCache[EventID, []ListenerEntry[T]](config.ListenerTimeout, func(evicted map[EventID][]ListenerEntry[T]) {
+		listeners = cache.NewTimeoutCache(config.ListenerTimeout, func(evicted map[EventID][]ListenerEntry[T]) {
 			if len(evicted) == 0 {
 				return
 			}
@@ -113,7 +113,7 @@ func NewListenerManager[T EventInfo](
 				logging.Keys(evicted),
 				lastBlockNum,
 			)
-			fetchTxs(logger, context.TODO(), lastBlockNum, evicted, queryService)
+			fetchTxs(context.TODO(), logger, lastBlockNum, evicted, queryService)
 		})
 	} else {
 		listeners = cache.NewMapCache[EventID, []ListenerEntry[T]]()
@@ -260,19 +260,19 @@ func (m *ListenerManager[T]) RemoveEventListener(id EventID, e ListenerEntry[T])
 	return errors.Errorf("could not find listener [%v] in eventID [%s]", e, id)
 }
 
-func fetchTxs[T EventInfo](logger logging.Logger, ctx context.Context, lastBlock driver.BlockNum, evicted map[EventID][]ListenerEntry[T], queryService QueryByIDService[T]) {
+func fetchTxs[T EventInfo](ctx context.Context, logger logging.Logger, lastBlock driver.BlockNum, evicted map[EventID][]ListenerEntry[T], queryService QueryByIDService[T]) {
 	go func() {
 		ch, err := queryService.QueryByID(ctx, lastBlock, evicted)
 		if err != nil {
-			logger.Errorf("failed scanning: %v", err)
+			logger.Errorf("failed scanning: %s", err.Error())
 			return
 		}
 		for events := range ch {
-			logger.Debugf("received [%d] events", len(events))
+			logger.DebugfContext(ctx, "received [%d] events", len(events))
 			for _, event := range events {
-				logger.Debugf("evicted event [%s], notify [%d] listeners", event.ID(), len(evicted[event.ID()]))
+				logger.DebugfContext(ctx, "evicted event [%s], notify [%d] listeners", event.ID(), len(evicted[event.ID()]))
 				for i, listener := range evicted[event.ID()] {
-					logger.Debugf("calling listener [%d], event [%s]", i, event.ID())
+					logger.DebugfContext(ctx, "calling listener [%d], event [%s]", i, event.ID())
 					go listener.OnStatus(context.TODO(), event)
 				}
 			}

platform/fabric/core/generic/msp/idemix/cache.go

@@ -112,7 +112,7 @@ func (c *IdentityCache) provisionIdentities() {
 	for {
 		id, audit, err := c.backed(c.opts)
 		if err != nil {
-			logger.Errorf("failed to provision identity [%s]", err)
+			logger.Errorf("failed to provision identity [%s]", err.Error())
 			continue
 		}
 		logger.Debugf("generated new idemix identity [%d]", count)

platform/fabric/core/generic/msp/idemix/id.go

@@ -74,7 +74,7 @@ func (id *MSPIdentity) GetOrganizationalUnits() []*msp.OUIdentifier {
 	// we use the (serialized) public key of this MSP as the CertifiersIdentifier
 	certifiersIdentifier, err := id.Idemix.IssuerPublicKey.Bytes()
 	if err != nil {
-		logger.Errorf("Failed to marshal ipk in GetOrganizationalUnits: %s", err)
+		logger.Errorf("Failed to marshal ipk in GetOrganizationalUnits: %s", err.Error())
 		return nil
 	}
 

platform/fabric/core/generic/ordering/bft.go

@@ -8,6 +8,7 @@ package ordering
 
 import (
 	"context"
+	"fmt"
 	"math"
 	"sync"
 	"time"
@@ -44,9 +45,9 @@ func NewBFTBroadcaster(configService driver.ConfigService, cf Services, metrics
 	}
 }
 
-func (o *BFTBroadcaster) Broadcast(context context.Context, env *common2.Envelope) error {
-	logger.DebugfContext(context, "Start BFT Broadcast")
-	defer logger.DebugfContext(context, "End BFT Broadcast")
+func (o *BFTBroadcaster) Broadcast(ctx context.Context, env *common2.Envelope) error {
+	logger.DebugfContext(ctx, "Start BFT Broadcast")
+	defer logger.DebugfContext(ctx, "End BFT Broadcast")
 	// send the envelope for ordering
 	retries := o.ConfigService.BroadcastNumRetries()
 	retryInterval := o.ConfigService.BroadcastRetryInterval()
@@ -59,9 +60,9 @@ func (o *BFTBroadcaster) Broadcast(context context.Context, env *common2.Envelop
 	f := (int(n) - 1) / 3
 	threshold := int(math.Ceil((float64(n) + float64(f) + 1) / 2.0))
 
-	for i := 0; i < retries; i++ {
+	for i := range retries {
 		if i > 0 {
-			logger.Debugf("broadcast, retry [%d]...", i)
+			logger.DebugfContext(ctx, "broadcast, retry [%d]...", i)
 			// wait a bit
 			time.Sleep(retryInterval)
 		}
@@ -79,31 +80,31 @@ func (o *BFTBroadcaster) Broadcast(context context.Context, env *common2.Envelop
 			go func(orderer *grpc.ConnectionConfig) {
 				defer wg.Done()
 
-				logger.Debugf("get connection to [%s]", orderer.Address)
-				connection, err := o.getConnection(context, orderer)
+				logger.DebugfContext(ctx, "get connection to [%s]", orderer.Address)
+				connection, err := o.getConnection(ctx, orderer)
 
 				lock.Lock()
 				if err != nil {
 					errs = append(errs, errors.Wrapf(err, "failed connecting to [%v]", orderer.Address))
-					logger.Warnf("failed to get connection to orderer [%s]", orderer.Address, err)
+					logger.WarnfContext(ctx, "failed to get connection to orderer [%s]", orderer.Address, err)
 					lock.Unlock()
 					return
 				}
 
 				lock.Unlock()
 
-				logger.Debugf("broadcast to [%s]", orderer.Address)
+				logger.DebugfContext(ctx, "broadcast to [%s]", orderer.Address)
 				err = connection.Send(env)
 				if err != nil {
-					logger.Errorf("failed to broadcast to [%s]: %s", orderer.Address, err)
+					logger.ErrorfContext(ctx, "failed to broadcast to [%s]: %s", orderer.Address, err.Error())
 					lock.Lock()
 					defer lock.Unlock()
 					usedConnections = append(usedConnections, connection)
 					return
 				}
 				status, err := connection.Recv()
 				if err != nil {
-					logger.Errorf("failed to get status after broadcast to [%s]: %s", orderer.Address, err)
+					logger.ErrorfContext(ctx, "failed to get status after broadcast to [%s]: %s", orderer.Address, err.Error())
 					lock.Lock()
 					defer lock.Unlock()
 					usedConnections = append(usedConnections, connection)
@@ -119,8 +120,8 @@ func (o *BFTBroadcaster) Broadcast(context context.Context, env *common2.Envelop
 					counter++
 				default:
 					usedConnections = append(usedConnections, connection)
-					logger.Errorf("failed to get status after broadcast to [%s]: %s", orderer.Address, common2.Status_name[int32(status.GetStatus())])
-					errs = append(errs, errors.Errorf("failed to get status after broadcast to [%s]: %s", orderer.Address, common2.Status_name[int32(status.GetStatus())]))
+					logger.ErrorfContext(ctx, "failed to get status after broadcast to [%s]: %s", orderer.Address, common2.Status_name[int32(status.GetStatus())])
+					errs = append(errs, fmt.Errorf("failed to get status after broadcast to [%s]: %s", orderer.Address, common2.Status_name[int32(status.GetStatus())]))
 					return
 				}
 			}(orderer)
@@ -137,7 +138,7 @@ func (o *BFTBroadcaster) Broadcast(context context.Context, env *common2.Envelop
 		}
 
 		// fail
-		logger.Warnf("failed to broadcast, got [%d of %d] success and errs [%v], retry after a delay", counter, threshold, errs)
+		logger.WarnfContext(ctx, "failed to broadcast, got [%d of %d] success and errs [%v], retry after a delay", counter, threshold, errs)
 		// cleanup connections
 		for _, connection := range usedConnections {
 			o.discardConnection(connection)

platform/fabric/fns.go

@@ -140,8 +140,8 @@ func (nsp *NetworkServiceProvider) FabricNetworkService(id string) (*NetworkServ
 
 	internalFns, err := nsp.fnsProvider.FabricNetworkService(id)
 	if err != nil {
-		logger.Errorf("Failed to get Fabric Network Service for id [%s]: [%s]", id, err)
-		return nil, errors.WithMessagef(err, "Failed to get Fabric Network Service for id [%s]", id)
+		logger.Errorf("failed to get Fabric Network Service for id [%s]: [%s]", id, err.Error())
+		return nil, errors.WithMessagef(err, "failed to get Fabric Network Service for id [%s]", id)
 	}
 	ns, ok = nsp.networkServices[internalFns.Name()]
 	if ok {