*: logging revamp

app/app.go

@@ -521,7 +521,7 @@ func wireCoreWorkflow(ctx context.Context, life *lifecycle.Manager, conf Config,
 
 		_, _, refresh, err := valCache.GetBySlot(ctx, slotToFetch)
 		if err != nil {
-			log.Error(ctx, "Cannot refresh validator cache", err)
+			log.Error(ctx, "Failed to refresh validator cache", err)
 			return err
 		}
 

app/eth2wrap/synthproposer.go

@@ -210,7 +210,7 @@ func fraction(transactions []bellatrix.Transaction) []bellatrix.Transaction {
 // SubmitBlindedProposal submits a blinded beacon block proposal or swallows it if marked as synthetic.
 func (h *synthWrapper) SubmitBlindedProposal(ctx context.Context, opts *eth2api.SubmitBlindedProposalOpts) error {
 	if IsSyntheticBlindedBlock(opts.Proposal) {
-		log.Debug(ctx, "Synthetic blinded beacon proposal swallowed")
+		log.Debug(ctx, "Ignoring synthetic blinded beacon proposal")
 		return nil
 	}
 
@@ -220,7 +220,7 @@ func (h *synthWrapper) SubmitBlindedProposal(ctx context.Context, opts *eth2api.
 // SubmitProposal submits a beacon block or swallows it if marked as synthetic.
 func (h *synthWrapper) SubmitProposal(ctx context.Context, opts *eth2api.SubmitProposalOpts) error {
 	if IsSyntheticProposal(opts.Proposal) {
-		log.Debug(ctx, "Synthetic beacon block swallowed")
+		log.Debug(ctx, "Ignoring synthetic beacon block proposal")
 		return nil
 	}
 

app/eth2wrap/version.go

@@ -84,16 +84,16 @@ func CheckBeaconNodeVersion(ctx context.Context, bnVersion string) {
 	//nolint:revive // enforce-switch-style: the list is exhaustive and there is no need for default
 	switch status {
 	case VersionFormatError:
-		log.Warn(ctx, "Failed to parse beacon node version string due to unexpected format",
+		log.Warn(ctx, "Failed to parse beacon node version string due to unexpected format. This may indicate an unsupported or custom beacon node build",
 			nil, z.Str("input", bnVersion))
 	case VersionUnknownClient:
-		log.Warn(ctx, "Unknown beacon node client not in supported client list",
+		log.Warn(ctx, "Unknown beacon node client detected. The client is not in the supported client list and may cause compatibility issues",
 			nil, z.Str("client", bnVersion))
 	case VersionTooOld:
-		log.Warn(ctx, "Beacon node client version is below the minimum supported version. Please upgrade your beacon node.",
+		log.Warn(ctx, "Beacon node client version is below the minimum supported version. Please upgrade your beacon node to ensure compatibility and security",
 			nil, z.Str("client_version", currentVersion), z.Str("minimum_required", minVersion))
 	case VersionIncompatible:
-		log.Warn(ctx, "Beacon node client version is known to be incompatible. Please upgrade or downgrade your beacon node.",
+		log.Warn(ctx, "Beacon node client version is known to be incompatible with Charon. Please upgrade or downgrade your beacon node to a compatible version",
 			nil, z.Str("client_version", currentVersion))
 	case VersionOK:
 		// Do nothing

app/monitoringapi.go

@@ -133,13 +133,13 @@ func startReadyChecker(ctx context.Context, p2pNode host.Host, eth2Cl eth2wrap.C
 	go func() {
 		genesisTime, err := eth2wrap.FetchGenesisTime(ctx, eth2Cl)
 		if err != nil {
-			log.Error(ctx, "Failed to fetch genesis time", err)
+			log.Error(ctx, "Failed to fetch genesis time from beacon node. Check beacon node connectivity and ensure it is synced", err)
 			return
 		}
 
 		slotDuration, slotsPerEpoch, err := eth2wrap.FetchSlotsConfig(ctx, eth2Cl)
 		if err != nil {
-			log.Error(ctx, "Failed to fetch slots config", err)
+			log.Error(ctx, "Failed to fetch slot configuration from beacon node. Check beacon node connectivity and ensure it is synced", err)
 			return
 		}
 
@@ -274,7 +274,7 @@ func beaconNodeVersionMetric(ctx context.Context, eth2Cl eth2wrap.Client, clock
 	setNodeVersion := func() {
 		eth2Resp, err := eth2Cl.NodeVersion(ctx, &eth2api.NodeVersionOpts{})
 		if err != nil {
-			log.Error(ctx, "Failed to get beacon node version", err)
+			log.Error(ctx, "Failed to fetch beacon node version. Check beacon node connectivity and API availability", err)
 			return
 		}
 

app/peerinfo/peerinfo.go

@@ -201,7 +201,7 @@ func (p *PeerInfo) sendOnce(ctx context.Context, now time.Time) {
 			if err != nil {
 				return // Logging handled by send func.
 			} else if resp.GetSentAt() == nil || resp.GetStartedAt() == nil {
-				log.Error(ctx, "Invalid peerinfo response", err, z.Str("peer", p2p.PeerName(peerID)))
+				log.Error(ctx, "Received invalid peerinfo response from peer (missing timestamps). This may indicate the peer is running incompatible software or experiencing network issues. Check peer connectivity and version compatibility", err, z.Str("peer", p2p.PeerName(peerID)))
 				return
 			}
 
@@ -231,7 +231,7 @@ func (p *PeerInfo) sendOnce(ctx context.Context, now time.Time) {
 				peerCompatibleGauge.WithLabelValues(name).Set(0) // Set to false
 
 				// Log as error since user action required
-				log.Error(ctx, "Invalid peer version", err,
+				log.Error(ctx, "Peer is running an incompatible Charon version. Please coordinate with the peer to upgrade or downgrade to a compatible version", err,
 					z.Str("peer", name),
 					z.Str("peer_version", resp.GetCharonVersion()),
 					z.Any("supported_versions", version.Supported()),

cmd/createcluster.go

@@ -828,7 +828,7 @@ func writeKeysToKeymanager(ctx context.Context, conf clusterConfig, numNodes int
 
 		err := clients[i].ImportKeystores(ctx, keystores, passwords)
 		if err != nil {
-			log.Error(ctx, "Failed to import keys", err, z.Str("addr", conf.KeymanagerAddrs[i]))
+			log.Error(ctx, "Failed to import validator keys to keymanager. Check keymanager API connectivity and authentication", err, z.Str("addr", conf.KeymanagerAddrs[i]))
 			return err
 		}
 

cmd/createcluster_internal_test.go

@@ -339,7 +339,7 @@ func testCreateCluster(t *testing.T, conf clusterConfig, def cluster.Definition,
 
 	err := runCreateCluster(context.Background(), &buf, conf)
 	if err != nil {
-		log.Error(context.Background(), "", err)
+		log.Error(context.Background(), "runCreateCluster error in test", err)
 	}
 
 	if expectedErr != "" {
@@ -822,7 +822,7 @@ func TestKeymanager(t *testing.T) {
 
 		err = runCreateCluster(context.Background(), &buf, conf)
 		if err != nil {
-			log.Error(context.Background(), "", err)
+			log.Error(context.Background(), "runCreateCluster error in TestKeymanager/all_successful", err)
 		}
 
 		require.NoError(t, err)
@@ -852,7 +852,7 @@ func TestKeymanager(t *testing.T) {
 
 		err = runCreateCluster(context.Background(), &buf, conf)
 		if err != nil {
-			log.Error(context.Background(), "", err)
+			log.Error(context.Background(), "runCreateCluster error in TestKeymanager/some_unsuccessful", err)
 		}
 
 		require.ErrorContains(t, err, "cannot ping address")
@@ -906,7 +906,7 @@ func TestPublish(t *testing.T) {
 
 		err := runCreateCluster(context.Background(), &buf, conf)
 		if err != nil {
-			log.Error(context.Background(), "", err)
+			log.Error(context.Background(), "runCreateCluster error in TestPublish/upload_successful", err)
 		}
 
 		require.NoError(t, err)

cmd/relay/relay.go

@@ -359,7 +359,7 @@ func wrapHandler(handler func(ctx context.Context) (response []byte, err error))
 
 		response, err := handler(ctx)
 		if err != nil {
-			log.Error(ctx, "Handler error", err, z.Str("path", r.URL.Path))
+			log.Error(ctx, "HTTP handler error", err, z.Str("path", r.URL.Path))
 			w.WriteHeader(http.StatusInternalServerError)
 
 			return

cmd/testbeacon.go

@@ -484,7 +484,6 @@ func beaconPingLoadTest(ctx context.Context, conf *testBeaconConfig, target stri
 	for pingCtx.Err() == nil {
 		select {
 		case <-ticker.C:
-
 			wg.Go(func() {
 				pingBeaconContinuously(pingCtx, target, testResCh)
 			})

cmd/testpeers.go

@@ -451,7 +451,6 @@ func peerPingLoadTest(ctx context.Context, conf *testPeersConfig, p2pNode host.H
 	for pingCtx.Err() == nil {
 		select {
 		case <-ticker.C:
-
 			wg.Go(func() {
 				pingPeerContinuously(pingCtx, p2pNode, peer, testResCh)
 			})
@@ -923,7 +922,7 @@ func setupP2P(ctx context.Context, privKey *k1.PrivateKey, conf p2p.Config, peer
 	return tcpNode, func() {
 		err := tcpNode.Close()
 		if err != nil && !errors.Is(err, context.Canceled) {
-			log.Error(ctx, "Close TCP node", err)
+			log.Error(ctx, "Failed to close TCP node", err)
 		}
 	}, nil
 }

cmd/testvalidator.go

@@ -245,7 +245,6 @@ func validatorPingLoadTest(ctx context.Context, conf *testValidatorConfig) testR
 	for pingCtx.Err() == nil {
 		select {
 		case <-ticker.C:
-
 			wg.Go(func() {
 				pingValidatorContinuously(pingCtx, conf.APIAddress, testResCh)
 			})

core/bcast/bcast.go

@@ -82,7 +82,7 @@ func (b Broadcaster) Broadcast(ctx context.Context, duty core.Duty, set core.Sig
 		// - another charon node at version v1.3.2, v1.4.2 or newer
 		// this (expensive) code block will not be triggered.
 		if checkValIdxs {
-			log.Warn(ctx, "There is a charon node in the cluster at one of the following versions: v1.3.0, v1.3.1, v1.4.0 or v1.4.1. Please update, as it causes performance degradation.", errors.New("peer version causes slowdown"))
+			log.Warn(ctx, "One or more cluster nodes are running outdated Charon versions (v1.3.0, v1.3.1, v1.4.0, or v1.4.1) which cause performance degradation. Please coordinate with operators to upgrade all nodes to v1.3.2, v1.4.2, or newer", errors.New("peer version causes slowdown"))
 
 			if len(atts) == 0 {
 				return errors.New("no attestations")

core/bcast/recast.go

@@ -127,7 +127,7 @@ func (r *Recaster) SlotTicked(ctx context.Context, slot core.Slot) error {
 	for pubkey, tuple := range r.tuples {
 		ethPk, err := pubkey.ToETH2()
 		if err != nil {
-			log.Error(ctx, "Can't convert pubkey to eth2 format", err)
+			log.Error(ctx, "Failed to convert pubkey to eth2 format", err)
 			continue
 		}
 
@@ -152,7 +152,7 @@ func (r *Recaster) SlotTicked(ctx context.Context, slot core.Slot) error {
 		for _, sub := range clonedSubs {
 			err := sub(dutyCtx, duty, set)
 			if err != nil {
-				log.Error(dutyCtx, "Rebroadcast duty error (will retry next epoch)", err)
+				log.Error(dutyCtx, "Failed to rebroadcast duty. Will retry in the next epoch", err)
 				incRegCounter(duty, recastErrors)
 			}
 

core/consensus/qbft/qbft.go

@@ -55,19 +55,19 @@ func newDefinition(nodes int, subs func() []subscriber, roundTimer timer.RoundTi
 		Decide: func(ctx context.Context, duty core.Duty, _ [32]byte, qcommit []qbft.Msg[core.Duty, [32]byte, proto.Message]) {
 			msg, ok := qcommit[0].(Msg)
 			if !ok {
-				log.Error(ctx, "Invalid message type", nil)
+				log.Error(ctx, "Internal error: Invalid message type in qcommit. This indicates a consensus protocol bug that should be reported", nil, z.Str("got_type", fmt.Sprintf("%T", qcommit[0])))
 				return
 			}
 
 			anyValue, ok := msg.Values()[msg.Value()]
 			if !ok {
-				log.Error(ctx, "Invalid value hash", nil)
+				log.Error(ctx, "Internal error: Consensus value hash not found in values map. This indicates state inconsistency in the QBFT protocol and should be reported", nil)
 				return
 			}
 
 			value, err := anyValue.UnmarshalNew()
 			if err != nil {
-				log.Error(ctx, "Invalid any value", err)
+				log.Error(ctx, "Internal error: Failed to unmarshal consensus value. This indicates a serialization issue in the QBFT protocol and should be reported", err)
 				return
 			}
 

core/parsigdb/memory.go

@@ -89,7 +89,7 @@ func (db *MemDB) StoreExternal(ctx context.Context, duty core.Duty, signedSet co
 		if err != nil {
 			return err
 		} else if !ok {
-			log.Debug(ctx, "Partial signed data ignored since duplicate")
+			log.Debug(ctx, "Ignoring duplicate partial signature")
 
 			continue
 		}

core/parsigex/parsigex.go

@@ -106,7 +106,7 @@ func (m *ParSigEx) handle(ctx context.Context, _ peer.ID, req proto.Message) (pr
 		// TODO(corver): Call this async
 		err := sub(ctx, duty, set)
 		if err != nil {
-			log.Error(ctx, "Subscribe error", err)
+			log.Error(ctx, "Partial signature exchange subscriber encountered an error while processing the partial signature set", err)
 		}
 	}
 

core/scheduler/scheduler.go

@@ -160,7 +160,7 @@ func (s *Scheduler) emitCoreSlot(ctx context.Context, slot core.Slot) {
 		go func(sub func(context.Context, core.Slot) error) {
 			err := sub(ctx, slot)
 			if err != nil {
-				log.Error(ctx, "Emit scheduled slot event", err, z.U64("slot", slot.Slot))
+				log.Error(ctx, "Failed to emit scheduled slot event", err, z.U64("slot", slot.Slot))
 			}
 		}(sub)
 	}
@@ -255,12 +255,12 @@ func (s *Scheduler) scheduleSlot(ctx context.Context, slot core.Slot) {
 			for _, sub := range s.dutySubs {
 				clone, err := defSet.Clone() // Clone for each subscriber.
 				if err != nil {
-					log.Error(dutyCtx, "Cloning duty definition set", err)
+					log.Error(dutyCtx, "Failed to clone duty definition set", err)
 					return
 				}
 
 				if err := sub(dutyCtx, duty, clone); err != nil {
-					log.Error(dutyCtx, "Trigger duty subscriber error", err, z.U64("slot", slot.Slot))
+					log.Error(dutyCtx, "Failed to trigger duty subscriber", err, z.U64("slot", slot.Slot))
 				}
 			}
 		}()
@@ -377,7 +377,7 @@ func (s *Scheduler) resolveAttDuties(ctx context.Context, slot core.Slot, vals v
 
 		pubkey, ok := vals.PubKeyFromIndex(attDuty.ValidatorIndex)
 		if !ok {
-			log.Warn(ctx, "Ignoring unexpected attester duty", nil, z.U64("vidx", uint64(attDuty.ValidatorIndex)), z.U64("slot", slot.Slot))
+			log.Warn(ctx, "Received attester duty for unknown validator. The validator may not be part of this cluster. Ignoring. If edit command was recently executed, Charon and/or VC might have not been restarted or not read the new keys properly", nil, z.U64("vidx", uint64(attDuty.ValidatorIndex)), z.U64("slot", slot.Slot))
 			continue
 		}
 
@@ -405,7 +405,7 @@ func (s *Scheduler) resolveAttDuties(ctx context.Context, slot core.Slot, vals v
 	}
 
 	if len(remaining) > 0 {
-		log.Warn(ctx, "Missing attester duties", nil,
+		log.Warn(ctx, "Missing attester duties from beacon node. Some validators did not receive duty assignments. Check beacon node sync status and validator activation", nil,
 			z.U64("slot", slot.Slot),
 			z.U64("epoch", slot.Epoch()),
 			z.Any("validator_indexes", remaining),
@@ -446,7 +446,7 @@ func (s *Scheduler) resolveProDuties(ctx context.Context, slot core.Slot, vals v
 
 		pubkey, ok := vals.PubKeyFromIndex(proDuty.ValidatorIndex)
 		if !ok {
-			log.Warn(ctx, "Ignoring unexpected proposer duty", nil, z.U64("vidx", uint64(proDuty.ValidatorIndex)), z.U64("slot", slot.Slot))
+			log.Warn(ctx, "Received proposer duty for unknown validator. The validator may not be part of this cluster. Ignoring", nil, z.U64("vidx", uint64(proDuty.ValidatorIndex)), z.U64("slot", slot.Slot))
 			continue
 		}
 
@@ -495,7 +495,7 @@ func (s *Scheduler) resolveSyncCommDuties(ctx context.Context, slot core.Slot, v
 
 		pubkey, ok := vals.PubKeyFromIndex(vIdx)
 		if !ok {
-			log.Warn(ctx, "Ignoring unexpected sync committee duty", nil, z.U64("vidx", uint64(vIdx)), z.U64("slot", slot.Slot))
+			log.Warn(ctx, "Received sync committee duty for unknown validator. The validator may not be part of this cluster. Ignoring", nil, z.U64("vidx", uint64(vIdx)), z.U64("slot", slot.Slot))
 			continue
 		}
 
@@ -731,7 +731,7 @@ func waitChainStart(ctx context.Context, eth2Cl eth2wrap.Client, clock clockwork
 	for i := 0; ctx.Err() == nil; i++ {
 		genesis, err := eth2Cl.Genesis(ctx, &eth2api.GenesisOpts{})
 		if err != nil {
-			log.Error(ctx, "Failure getting genesis", err)
+			log.Error(ctx, "Failed to fetch genesis information from beacon node. Check beacon node connectivity and API availability", err)
 			clock.Sleep(expbackoff.Backoff(expbackoff.FastConfig, i))
 
 			continue
@@ -757,7 +757,7 @@ func waitBeaconSync(ctx context.Context, eth2Cl eth2wrap.Client, clock clockwork
 	for i := 0; ctx.Err() == nil; i++ {
 		eth2Resp, err := eth2Cl.NodeSyncing(ctx, &eth2api.NodeSyncingOpts{})
 		if err != nil {
-			log.Error(ctx, "Failure getting sync state", err)
+			log.Error(ctx, "Failed to fetch sync state from beacon node. Check beacon node connectivity and ensure it is synced", err)
 			clock.Sleep(expbackoff.Backoff(expbackoff.FastConfig, i))
 
 			continue

core/sigagg/sigagg.go

@@ -65,7 +65,7 @@ func (a *Aggregator) Aggregate(ctx context.Context, duty core.Duty, set map[core
 		output[pubkey] = signed
 	}
 
-	log.Debug(ctx, "Threshold aggregated partial signatures")
+	log.Debug(ctx, "Successfully aggregated partial signatures to reach threshold")
 
 	// Call subscriptions.
 	for _, sub := range a.subs {

core/signeddata.go

@@ -780,7 +780,7 @@ func (a VersionedAttestation) Signature() Signature {
 	sig, err := a.VersionedAttestation.Signature()
 	// This should never happen as if data is signed it should have data and signature in the object
 	if err != nil {
-		log.Error(context.Background(), "get attestation signature", err)
+		log.Error(context.Background(), "Failed to get attestation signature", err)
 		return []byte{}
 	}
 

core/tracker/inclusion.go

@@ -254,7 +254,7 @@ func (i *inclusionCore) CheckBlock(ctx context.Context, slot uint64, found bool)
 
 			proposal, ok := sub.Data.(core.VersionedSignedProposal)
 			if !ok {
-				log.Error(ctx, "Submission data has wrong type", nil, z.Str("type", fmt.Sprintf("%T", sub.Data)))
+				log.Error(ctx, "Internal error: Submission data type mismatch. This indicates a bug in duty type handling", nil, z.Str("got_type", fmt.Sprintf("%T", sub.Data)), z.Str("expected_type", "core.VersionedSignedProposal"))
 				continue
 			}
 
@@ -321,7 +321,7 @@ func (i *inclusionCore) CheckBlockAndAtts(ctx context.Context, block block) {
 
 			proposal, ok := sub.Data.(core.VersionedSignedProposal)
 			if !ok {
-				log.Error(ctx, "Submission data has wrong type", nil, z.Str("type", fmt.Sprintf("%T", sub.Data)))
+				log.Error(ctx, "Internal error: Submission data type mismatch. This indicates a bug in duty type handling", nil, z.Str("got_type", fmt.Sprintf("%T", sub.Data)), z.Str("expected_type", "core.VersionedSignedProposal"))
 				continue
 			}
 
@@ -473,7 +473,7 @@ func reportMissed(ctx context.Context, sub submission) {
 	case core.DutyProposer:
 		proposal, ok := sub.Data.(core.VersionedSignedProposal)
 		if !ok {
-			log.Error(ctx, "Submission data has wrong type", nil, z.Str("type", fmt.Sprintf("%T", sub.Data)))
+			log.Error(ctx, "Internal error: Submission data type mismatch. This indicates a bug in duty type handling", nil, z.Str("got_type", fmt.Sprintf("%T", sub.Data)), z.Str("expected_type", "core.VersionedSignedProposal"))
 		} else {
 			msg := "Broadcasted block never included on-chain"
 			if proposal.Blinded {

core/tracker/tracker.go

@@ -523,7 +523,7 @@ func newUnsupportedIgnorer() func(ctx context.Context, duty core.Duty, failed bo
 
 		if !aggregationSupported && duty.Type == core.DutyAggregator && step == fetcher && reason == reasonZeroAggregatorSelections {
 			if !loggedNoAggregator {
-				log.Warn(ctx, "Ignoring attestation aggregation failures since VCs do not seem to support beacon committee selection aggregation", nil)
+				log.Warn(ctx, "Validator client does not support beacon committee selection aggregation. Attestation aggregation duties will be ignored. This is expected for some validator clients", nil)
 			}
 
 			loggedNoAggregator = true
@@ -533,7 +533,7 @@ func newUnsupportedIgnorer() func(ctx context.Context, duty core.Duty, failed bo
 
 		if !contributionSupported && duty.Type == core.DutySyncContribution && step == fetcher && reason == reasonSyncContributionZeroPrepares {
 			if !loggedNoContribution {
-				log.Warn(ctx, "Ignoring sync contribution failures since VCs do not seem to support sync committee selection aggregation", nil)
+				log.Warn(ctx, "Validator client does not support sync committee selection aggregation. Sync contribution duties will be ignored. This is expected for some validator clients", nil)
 			}
 
 			loggedNoContribution = true

core/tracking.go

@@ -65,7 +65,7 @@ func WithTracking(tracker Tracker, inclusion InclusionChecker) WireOption {
 		w.BroadcasterBroadcast = func(ctx context.Context, duty Duty, set SignedDataSet) error {
 			// Check inclusion even if we fail to broadcast, since peers may succeed.
 			if err := inclusion.Submitted(duty, set); err != nil {
-				log.Error(ctx, "Bug: failed to submit duty to inclusion checker", err)
+				log.Error(ctx, "Internal error: Failed to submit duty to inclusion checker. This indicates a tracking bug that should be reported", err)
 			}
 
 			err := clone.BroadcasterBroadcast(ctx, duty, set)