[Telemetry] Apply shared logging module (#420)

## Description

This:

- Replaces all the `log` calls with the logging module
- Initializes a new instance of the logging module object in all of the
modules and submodules that relied on logging calls
- Updates the reflex configuration to output cleaner logs
- BugFixes in the logging module to make it work properly

## Issue

Fixes #288 

## Type of change

Please mark the relevant option(s):

- [x] New feature, functionality or library
- [x] Bug fix
- [x] Code health or cleanup
- [x] Major breaking change
- [ ] Documentation
- [ ] Other <!-- add details here if it a different type of change -->

## List of changes

<!-- REMOVE this comment block after following the instructions
 List out all the changes made
-->

- Replaces all the `log` calls with the logging module
- Initializes a new instance of the logging module object in all of the
modules and submodules that relied on logging calls
- Updates the reflex configuration to output cleaner logs
- BugFixes in the logging module to make it work properly

## Testing

- [x] `make develop_test`
- [x]
[LocalNet](https://github.com/pokt-network/pocket/blob/main/docs/development/README.md)
w/ all of the steps outlined in the `README`

## Required Checklist

- [x] I have performed a self-review of my own code
- [x] I have commented my code, particularly in hard-to-understand areas
- [x] I have tested my changes using the available tooling
- [ ] I have updated the corresponding CHANGELOG

### If Applicable Checklist
- [ ] I have updated the corresponding README(s); local and/or global
- [ ] I have added tests that prove my fix is effective or that my
feature works
- [ ] I have added, or updated,
[mermaid.js](https://mermaid-js.github.io) diagrams in the corresponding
README(s)
- [ ] I have added, or updated, documentation and
[mermaid.js](https://mermaid-js.github.io) diagrams in `shared/docs/*`
if I updated `shared/*`README(s)

---------

Co-authored-by: Daniel Olshansky <[email protected]>
Co-authored-by: Dmitry Knyazev <[email protected]>
Co-authored-by: Dmitry K <[email protected]>
Co-authored-by: Daniel Olshansky <[email protected]>

app/client/cli/debug.go

@@ -1,10 +1,10 @@
 package cli
 
 import (
-	"log"
 	"os"
 
 	"github.com/manifoldco/promptui"
+	"github.com/pokt-network/pocket/logger"
 	"github.com/pokt-network/pocket/p2p"
 	debugABP "github.com/pokt-network/pocket/p2p/providers/addrbook_provider/debug"
 	debugCHP "github.com/pokt-network/pocket/p2p/providers/current_height_provider/debug"
@@ -77,7 +77,7 @@ func NewDebugCommand() *cobra.Command {
 			// TODO(#429): refactor injecting the dependencies into the bus so that they can be consumed in an updated `P2PModule.Create()` implementation
 			p2pM, err := p2p.CreateWithProviders(runtimeMgr.GetBus(), debugAddressBookProvider, debugCurrentHeightProvider)
 			if err != nil {
-				log.Fatalf("[ERROR] Failed to create p2p module: %v", err.Error())
+				logger.Global.Fatal().Err(err).Msg("Failed to create p2p module")
 			}
 			p2pMod = p2pM.(modules.P2PModule)
 
@@ -111,7 +111,7 @@ func promptGetInput() (string, error) {
 	}
 
 	if err != nil {
-		log.Printf("Prompt failed %v\n", err)
+		logger.Global.Error().Err(err).Msg("Prompt failed")
 		return "", err
 	}
 
@@ -151,15 +151,15 @@ func handleSelect(selection string) {
 		}
 		sendDebugMessage(m)
 	default:
-		log.Println("Selection not yet implemented...", selection)
+		logger.Global.Error().Msg("Selection not yet implemented...")
 	}
 }
 
 // Broadcast to the entire validator set
 func broadcastDebugMessage(debugMsg *messaging.DebugMessage) {
 	anyProto, err := anypb.New(debugMsg)
 	if err != nil {
-		log.Fatalf("[ERROR] Failed to create Any proto: %v", err)
+		logger.Global.Fatal().Err(err).Msg("Failed to create Any proto")
 	}
 
 	// TODO(olshansky): Once we implement the cleanup layer in RainTree, we'll be able to use
@@ -170,7 +170,7 @@ func broadcastDebugMessage(debugMsg *messaging.DebugMessage) {
 	for _, valAddr := range validators {
 		addr, err := pocketCrypto.NewAddress(valAddr.GetAddress())
 		if err != nil {
-			log.Fatalf("[ERROR] Failed to convert validator address into pocketCrypto.Address: %v", err)
+			logger.Global.Fatal().Err(err).Msg("Failed to convert validator address into pocketCrypto.Address")
 		}
 		p2pMod.Send(addr, anyProto)
 	}
@@ -180,18 +180,18 @@ func broadcastDebugMessage(debugMsg *messaging.DebugMessage) {
 func sendDebugMessage(debugMsg *messaging.DebugMessage) {
 	anyProto, err := anypb.New(debugMsg)
 	if err != nil {
-		log.Fatalf("[ERROR] Failed to create Any proto: %v", err)
+		logger.Global.Error().Err(err).Msg("Failed to create Any proto")
 	}
 
 	var validatorAddress []byte
 	if len(validators) == 0 {
-		log.Fatalf("[ERROR] No validators found")
+		logger.Global.Fatal().Msg("No validators found")
 	}
 
 	// if the message needs to be broadcast, it'll be handled by the business logic of the message handler
 	validatorAddress, err = pocketCrypto.NewAddress(validators[0].GetAddress())
 	if err != nil {
-		log.Fatalf("[ERROR] Failed to convert validator address into pocketCrypto.Address: %v", err)
+		logger.Global.Fatal().Err(err).Msg("Failed to convert validator address into pocketCrypto.Address")
 	}
 
 	p2pMod.Send(validatorAddress, anyProto)

app/client/cli/docgen/main.go

@@ -1,9 +1,8 @@
 package main
 
 import (
-	"log"
-
 	"github.com/pokt-network/pocket/app/client/cli"
+	"github.com/pokt-network/pocket/logger"
 
 	"github.com/spf13/cobra/doc"
 )
@@ -12,6 +11,6 @@ func main() {
 	cmd := cli.GetRootCmd()
 	err := doc.GenMarkdownTree(cmd, "../doc/commands")
 	if err != nil {
-		log.Fatal(err)
+		logger.Global.Fatal().Err(err).Msg("failed to generate markdown tree")
 	}
 }

app/client/cli/utils.go

@@ -7,13 +7,13 @@ import (
 	"encoding/hex"
 	"fmt"
 	"io"
-	"log"
 	"math/big"
 	"math/rand"
 	"os"
 	"strings"
 	"time"
 
+	"github.com/pokt-network/pocket/logger"
 	"github.com/pokt-network/pocket/rpc"
 	"github.com/pokt-network/pocket/shared/codec"
 	"github.com/pokt-network/pocket/shared/converters"
@@ -61,7 +61,7 @@ func credentials(pwd string) string {
 	}
 	bytePassword, err := terminal.ReadPassword(int(os.Stdin.Fd()))
 	if err != nil {
-		log.Fatalf(err.Error())
+		logger.Global.Fatal().Err(err).Msg("failed to read password")
 	}
 	return strings.TrimSpace(string(bytePassword))
 }

app/client/doc/CHANGELOG.md

@@ -7,9 +7,13 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ## [Unreleased]
 
+## [0.0.0.7] - 2023-02-04
+
+- Changed log lines to utilize new logger module.
+
 ## [0.0.0.6] - 2023-02-02
 
-## Added
+### Added
 
 - Fix broken link to `shared/crypto/README.md` in keybase documentation
 

app/client/main.go

@@ -2,24 +2,24 @@ package main
 
 import (
 	"context"
-	"log"
 	"os"
 	"os/signal"
 	"syscall"
 
 	"github.com/pokt-network/pocket/app/client/cli"
+	"github.com/pokt-network/pocket/logger"
 )
 
 func main() {
 	ctx := newCLIContext()
 	err := cli.ExecuteContext(ctx)
 	if ctx.Err() == context.Canceled || err == context.Canceled {
-		log.Fatalf("aborted\n")
+		logger.Global.Fatal().Msg("aborted")
 		return
 	}
 
 	if err != nil {
-		log.Fatalf("err: %v\n", err)
+		logger.Global.Fatal().Err(err).Msg("failed to execute command")
 	}
 }
 

app/pocket/doc/CHANGELOG.md

@@ -7,6 +7,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ## [Unreleased]
 
+## [0.0.0.2] - 2023-02-04
+
+- Changed log lines to utilize new logger module.
+
 ## [0.0.0.1] - 2023-01-10
 
 - Updated module constructor to accept a `bus` and not a `runtimeMgr` anymore

app/pocket/main.go

@@ -2,9 +2,9 @@ package main
 
 import (
 	"flag"
-	"log"
 
 	"github.com/pokt-network/pocket/app"
+	"github.com/pokt-network/pocket/logger"
 	"github.com/pokt-network/pocket/runtime"
 	"github.com/pokt-network/pocket/shared"
 )
@@ -17,22 +17,22 @@ func main() {
 	flag.Parse()
 
 	if *v {
-		log.Printf("Version flag currently unused %s\n", app.AppVersion)
+		logger.Global.Info().Str("version", app.AppVersion).Msg("Version flag currently unused")
 		return
 	}
 
 	runtimeMgr := runtime.NewManagerFromFiles(*configFilename, *genesisFilename)
 	bus, err := runtime.CreateBus(runtimeMgr)
 	if err != nil {
-		log.Fatalf("Failed to create bus: %s", err)
+		logger.Global.Fatal().Err(err).Msg("Failed to create bus")
 	}
 
 	pocketNode, err := shared.CreateNode(bus)
 	if err != nil {
-		log.Fatalf("Failed to create pocket node: %s", err)
+		logger.Global.Fatal().Err(err).Msg("Failed to create pocket node")
 	}
 
 	if err = pocketNode.Start(); err != nil {
-		log.Fatalf("Failed to start pocket node: %s", err)
+		logger.Global.Fatal().Err(err).Msg("Failed to start pocket node")
 	}
 }

build/docs/CHANGELOG.md

@@ -7,6 +7,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ## [Unreleased]
 
+## [0.0.0.7] - 2023-02-04
+
+- Added `--decoration="none"` flag to `reflex`
+
 ## [0.0.0.6] - 2023-01-23
 
 - Added pprof feature flag guideline in docker-compose.yml

build/scripts/watch.sh

@@ -21,4 +21,5 @@ fi
 reflex \
   --start-service \
   -r '\.go' \
+  --decoration="none" \
   -s -- sh -c "$command";

build/scripts/watch_build.sh

@@ -2,7 +2,7 @@
 
 if command -v reflex >/dev/null
 then
-  reflex -r '\.go$' -s -- sh -c "go build -v app/pocket/main.go"
+  reflex -r '\.go$' -s --decoration="none" -- sh -c "go build -v app/pocket/main.go"
 else
     echo "reflex not found. Install with `go install github.com/cespare/reflex@latest`"
 fi

consensus/block.go

@@ -2,7 +2,6 @@ package consensus
 
 import (
 	"fmt"
-	"log"
 	"unsafe"
 
 	typesCons "github.com/pokt-network/pocket/consensus/types"
@@ -14,11 +13,18 @@ func (m *consensusModule) commitBlock(block *coreTypes.Block) error {
 	if err := m.utilityContext.Commit(block.BlockHeader.QuorumCertificate); err != nil {
 		return err
 	}
-	m.nodeLog(typesCons.CommittingBlock(m.height, len(block.Transactions)))
+
+	m.logger.Info().
+		Fields(
+			map[string]any{
+				"height":       block.BlockHeader.Height,
+				"transactions": len(block.Transactions),
+			}).
+		Msg("🧱🧱🧱 Committing block 🧱🧱🧱")
 
 	// Release the context
 	if err := m.utilityContext.Release(); err != nil {
-		log.Println("[WARN] Error releasing utility context: ", err)
+		m.logger.Warn().Err(err).Msg("Error releasing utility context")
 	}
 
 	m.utilityContext = nil
@@ -36,7 +42,7 @@ func (m *consensusModule) isValidMessageBlock(msg *typesCons.HotstuffMessage) (b
 		if step != NewRound {
 			return false, fmt.Errorf("validateBlockBasic failed - block is nil during step %s", typesCons.StepToString[m.step])
 		}
-		m.nodeLog("[DEBUG] Nil (expected) block is present during NewRound step.")
+		m.logger.Debug().Msg("Nil (expected) block is present during NewRound step.")
 		return true, nil
 	}
 
@@ -58,7 +64,7 @@ func (m *consensusModule) isValidMessageBlock(msg *typesCons.HotstuffMessage) (b
 		// DISCUSS: The only difference between blocks from one step to another is the QC, so we need
 		//          to determine where/how to validate this
 		if protoHash(m.block) != protoHash(block) {
-			log.Println("[TECHDEBT] validateBlockBasic warning - block hash is the same but serialization is not")
+			m.logger.Warn().Bool("TECHDEBT", true).Msg("WalidateBlockBasic warning - block hash is the same but serialization is not")
 		}
 	}
 
@@ -70,17 +76,17 @@ func (m *consensusModule) refreshUtilityContext() error {
 	// Catch-all structure to release the previous utility context if it wasn't properly cleaned up.
 	// Ideally, this should not be called.
 	if m.utilityContext != nil {
-		m.nodeLog(typesCons.NilUtilityContextWarning)
+		m.logger.Warn().Msg(typesCons.NilUtilityContextWarning)
 		if err := m.utilityContext.Release(); err != nil {
-			log.Printf("[WARN] Error releasing utility context: %v\n", err)
+			m.logger.Warn().Err(err).Msg("Error releasing utility context")
 		}
 		m.utilityContext = nil
 	}
 
 	// Only one write context can exist at a time, and the utility context needs to instantiate
 	// a new one to modify the state.
 	if err := m.GetBus().GetPersistenceModule().ReleaseWriteContext(); err != nil {
-		log.Printf("[WARN] Error releasing persistence write context: %v\n", err)
+		m.logger.Warn().Err(err).Msg("Error releasing persistence write context")
 	}
 
 	utilityContext, err := m.GetBus().GetUtilityModule().NewContext(int64(m.height))

consensus/debugging.go

@@ -1,8 +1,6 @@
 package consensus
 
 import (
-	"log"
-
 	typesCons "github.com/pokt-network/pocket/consensus/types"
 	"github.com/pokt-network/pocket/shared/messaging"
 )
@@ -21,7 +19,7 @@ func (m *consensusModule) HandleDebugMessage(debugMessage *messaging.DebugMessag
 	case messaging.DebugMessageAction_DEBUG_CONSENSUS_TOGGLE_PACE_MAKER_MODE:
 		m.togglePacemakerManualMode(debugMessage)
 	default:
-		log.Printf("Debug message: %s \n", debugMessage.Message)
+		m.logger.Debug().Msgf("Debug message: %s", debugMessage.Message)
 	}
 	return nil
 }
@@ -43,7 +41,7 @@ func (m *consensusModule) GetNodeState() typesCons.ConsensusNodeState {
 }
 
 func (m *consensusModule) resetToGenesis(_ *messaging.DebugMessage) {
-	m.nodeLog(typesCons.DebugResetToGenesis)
+	m.logger.Debug().Msg(typesCons.DebugResetToGenesis)
 
 	m.height = 0
 	m.ResetForNewHeight()
@@ -58,11 +56,16 @@ func (m *consensusModule) resetToGenesis(_ *messaging.DebugMessage) {
 
 func (m *consensusModule) printNodeState(_ *messaging.DebugMessage) {
 	state := m.GetNodeState()
-	m.nodeLog(typesCons.DebugNodeState(state))
+	m.logger.Debug().
+		Fields(map[string]any{
+			"step":   state.Step,
+			"height": state.Height,
+			"round":  state.Round,
+		}).Msg("Node state")
 }
 
 func (m *consensusModule) triggerNextView(_ *messaging.DebugMessage) {
-	m.nodeLog(typesCons.DebugTriggerNextView)
+	m.logger.Debug().Msg(typesCons.DebugTriggerNextView)
 
 	currentHeight := m.height
 	currentStep := m.step
@@ -80,9 +83,9 @@ func (m *consensusModule) triggerNextView(_ *messaging.DebugMessage) {
 func (m *consensusModule) togglePacemakerManualMode(_ *messaging.DebugMessage) {
 	newMode := !m.paceMaker.IsManualMode()
 	if newMode {
-		m.nodeLog(typesCons.DebugTogglePacemakerManualMode("MANUAL"))
+		m.logger.Debug().Str("pacemaker_mode", "MANUAL").Msg("Toggle pacemaker to MANUAL mode")
 	} else {
-		m.nodeLog(typesCons.DebugTogglePacemakerManualMode("AUTOMATIC"))
+		m.logger.Debug().Str("pacemaker_mode", "AUTOMATIC").Msg("Toggle pacemaker to AUTOMATIC mode")
 	}
 	m.paceMaker.SetManualMode(newMode)
 }

consensus/doc/CHANGELOG.md

@@ -7,6 +7,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ## [Unreleased]
 
+## [0.0.0.25] - 2023-02-04
+
+- Changed log lines to utilize new logger module.
+
 ## [0.0.0.24] - 2023-02-03
 
 - Introduced `hotstuffFIFOMempool` that extends the logic provided by the genericized FIFO mempool in `shared`.