Skip to content

Cleanup logs #3814

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
wants to merge 6 commits into
base: master
Choose a base branch
from
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
19 changes: 10 additions & 9 deletions .github/workflows/ci.yml
Original file line number Diff line number Diff line change
Expand Up @@ -110,15 +110,16 @@ jobs:
- name: Build AvalancheGo Binary
shell: bash
run: ./scripts/build.sh
- name: Run e2e tests
uses: ./.github/actions/run-monitored-tmpnet-cmd
with:
run: ./scripts/tests.upgrade.sh
artifact_prefix: upgrade
prometheus_username: ${{ secrets.PROMETHEUS_ID || '' }}
prometheus_password: ${{ secrets.PROMETHEUS_PASSWORD || '' }}
loki_username: ${{ secrets.LOKI_ID || '' }}
loki_password: ${{ secrets.LOKI_PASSWORD || '' }}
# TODO: Reactivate test once v1.13.0 is published
# - name: Run e2e tests
# uses: ./.github/actions/run-monitored-tmpnet-cmd
# with:
# run: ./scripts/tests.upgrade.sh
# artifact_prefix: upgrade
# prometheus_username: ${{ secrets.PROMETHEUS_ID || '' }}
# prometheus_password: ${{ secrets.PROMETHEUS_PASSWORD || '' }}
# loki_username: ${{ secrets.LOKI_ID || '' }}
# loki_password: ${{ secrets.LOKI_PASSWORD || '' }}
Lint:
runs-on: ubuntu-latest
steps:
Expand Down
23 changes: 19 additions & 4 deletions RELEASES.md
Original file line number Diff line number Diff line change
@@ -1,13 +1,28 @@
# Release Notes

## [v1.12.3] (pending)
## [v1.13.0](https://github.com/ava-labs/avalanchego/releases/tag/v1.13.0)

- Extended the network health check by also alerting if a primary network validator has no nodes connected to it. Runs a configurable time after startup or 10 minutes by default.
This upgrade consists of the following Avalanche Community Proposal (ACP):
- [ACP-176](https://github.com/avalanche-foundation/ACPs/blob/main/ACPs/176-dynamic-evm-gas-limit-and-price-discovery-updates/README.md) Dynamic EVM Gas Limits and Price Discovery Updates

The ACP in this upgrade goes into effect at 11 AM ET (3 PM UTC) on Tuesday, April 8th, 2025 on Mainnet.

**All Fortuna supporting Mainnet nodes should upgrade before 11 AM ET, April 8th 2025.**

The plugin version is unchanged at `39` and is compatible with version `v1.12.2`.

### APIs

- Added ProposerVM block timestamp metrics: `avalanche_proposervm_last_accepted_timestamp`
- Added network health check to alert if a primary network validator has no ingress connections. Runs a configurable time after startup or 10 minutes by default.

### Configs
- How long after startup the aforementioned health check runs can be configured via:
`--network-no-ingress-connections-grace-period`

- Added:
- `--proposervm-min-block-duration`
- `--network-no-ingress-connections-grace-period` to configure how long after startup it is expected for a Mainnet validator to have received an ingress connection.

**Full Changelog**: https://github.com/ava-labs/avalanchego/compare/v1.12.2...v1.13.0

## [v1.12.2](https://github.com/ava-labs/avalanchego/releases/tag/v1.12.2)

Expand Down
2 changes: 1 addition & 1 deletion api/server/server.go
Original file line number Diff line number Diff line change
Expand Up @@ -179,7 +179,7 @@ func (s *server) RegisterChain(chainName string, ctx *snow.ConsensusContext, vm
return
}

s.log.Verbo("about to add API endpoints",
s.log.Info("adding API endpoints",
zap.Stringer("chainID", ctx.ChainID),
)
// all subroutes to a chain begin with "bc/<the chain's ID>"
Expand Down
4 changes: 3 additions & 1 deletion app/app.go
Original file line number Diff line number Diff line change
Expand Up @@ -74,7 +74,9 @@ func New(config nodeconfig.Config) (App, error) {

n, err := node.New(&config, logFactory, log)
if err != nil {
log.Fatal("failed to initialize node", zap.Error(err))
log.Fatal("failed to initialize node",
zap.Error(err),
)
log.Stop()
logFactory.Close()
return nil, fmt.Errorf("failed to initialize node: %w", err)
Expand Down
4 changes: 2 additions & 2 deletions chains/manager.go
Original file line number Diff line number Diff line change
Expand Up @@ -348,7 +348,7 @@ func New(config *ManagerConfig) (Manager, error) {
// Invariant: Tracked Subnet must be checked before calling this function
func (m *manager) QueueChainCreation(chainParams ChainParameters) {
if sb, _ := m.Subnets.GetOrCreate(chainParams.SubnetID); !sb.AddChain(chainParams.ID) {
m.Log.Debug("skipping chain creation",
m.Log.Warn("skipping chain creation",
zap.String("reason", "chain already staged"),
zap.Stringer("subnetID", chainParams.SubnetID),
zap.Stringer("chainID", chainParams.ID),
Expand All @@ -358,7 +358,7 @@ func (m *manager) QueueChainCreation(chainParams ChainParameters) {
}

if ok := m.chainsQueue.PushRight(chainParams); !ok {
m.Log.Warn("skipping chain creation",
m.Log.Error("skipping chain creation",
zap.String("reason", "couldn't enqueue chain"),
zap.Stringer("subnetID", chainParams.SubnetID),
zap.Stringer("chainID", chainParams.ID),
Expand Down
3 changes: 1 addition & 2 deletions database/pebbledb/db.go
Original file line number Diff line number Diff line change
Expand Up @@ -87,8 +87,7 @@ func New(file string, configBytes []byte, log logging.Logger, _ prometheus.Regis
}
opts.Experimental.ReadSamplingMultiplier = -1 // Disable seek compaction

log.Info(
"opening pebble",
log.Info("opening pebble",
zap.Reflect("config", cfg),
)

Expand Down
2 changes: 1 addition & 1 deletion nat/nat.go
Original file line number Diff line number Diff line change
Expand Up @@ -190,5 +190,5 @@ func (m *Mapper) updateIP(ip *utils.Atomic[netip.AddrPort]) {
func (m *Mapper) UnmapAllPorts() {
close(m.closer)
m.wg.Wait()
m.log.Info("Unmapped all ports")
m.log.Info("unmapped all ports")
}
3 changes: 1 addition & 2 deletions network/dialer/dialer.go
Original file line number Diff line number Diff line change
Expand Up @@ -49,8 +49,7 @@ func NewDialer(network string, dialerConfig Config, log logging.Logger) Dialer {
} else {
throttler = throttling.NewDialThrottler(int(dialerConfig.ThrottleRps))
}
log.Debug(
"creating dialer",
log.Info("creating dialer",
zap.Uint32("throttleRPS", dialerConfig.ThrottleRps),
zap.Duration("dialTimeout", dialerConfig.ConnectionTimeout),
)
Expand Down
18 changes: 6 additions & 12 deletions network/example_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -36,24 +36,21 @@ type testExternalHandler struct {
// called by messages explicitly sent by the peer. If timeouts are required,
// that must be handled by the user of this utility.
func (t *testExternalHandler) HandleInbound(_ context.Context, message message.InboundMessage) {
t.log.Info(
"receiving message",
t.log.Info("receiving message",
zap.Stringer("op", message.Op()),
)
}

func (t *testExternalHandler) Connected(nodeID ids.NodeID, version *version.Application, subnetID ids.ID) {
t.log.Info(
"connected",
t.log.Info("connected",
zap.Stringer("nodeID", nodeID),
zap.Stringer("version", version),
zap.Stringer("subnetID", subnetID),
)
}

func (t *testExternalHandler) Disconnected(nodeID ids.NodeID) {
t.log.Info(
"disconnected",
t.log.Info("disconnected",
zap.Stringer("nodeID", nodeID),
)
}
Expand Down Expand Up @@ -98,8 +95,7 @@ func ExampleNewTestNetwork() {
trackedSubnets,
)
if err != nil {
log.Fatal(
"failed to create test network config",
log.Fatal("failed to create test network config",
zap.Error(err),
)
return
Expand All @@ -111,8 +107,7 @@ func ExampleNewTestNetwork() {
handler,
)
if err != nil {
log.Fatal(
"failed to create test network",
log.Fatal("failed to create test network",
zap.Error(err),
)
return
Expand All @@ -138,8 +133,7 @@ func ExampleNewTestNetwork() {
// Calling network.Dispatch() will block until a fatal error occurs or
// network.StartClose() is called.
err = network.Dispatch()
log.Info(
"network exited",
log.Info("network exited",
zap.Error(err),
)
}
32 changes: 13 additions & 19 deletions network/network.go
Original file line number Diff line number Diff line change
Expand Up @@ -457,8 +457,7 @@ func (n *network) Connected(nodeID ids.NodeID) {
n.peersLock.Lock()
peer, ok := n.connectingPeers.GetByID(nodeID)
if !ok {
n.peerConfig.Log.Error(
"unexpectedly connected to peer when not marked as attempting to connect",
n.peerConfig.Log.Error("unexpectedly connected to peer when not marked as attempting to connect",
zap.Stringer("nodeID", nodeID),
)
n.peersLock.Unlock()
Expand Down Expand Up @@ -609,7 +608,9 @@ func (n *network) Dispatch() error {

conn, err := n.listener.Accept() // Returns error when n.Close() is called
if err != nil {
n.peerConfig.Log.Debug("error during server accept", zap.Error(err))
n.peerConfig.Log.Debug("error during server accept",
zap.Error(err),
)
// Sleep for a small amount of time to try to wait for the
// error to go away.
time.Sleep(time.Millisecond)
Expand Down Expand Up @@ -947,8 +948,7 @@ func (n *network) dial(nodeID ids.NodeID, ip *trackedIP) {
// "connection reset by peer" errors from interfering with the
// later duplicated connection check.
if connecting || connected {
n.peerConfig.Log.Verbo(
"exiting attempt to dial peer",
n.peerConfig.Log.Verbo("exiting attempt to dial peer",
zap.String("reason", "already connected"),
zap.Stringer("nodeID", nodeID),
)
Expand Down Expand Up @@ -983,8 +983,7 @@ func (n *network) dial(nodeID ids.NodeID, ip *trackedIP) {

conn, err := n.dialer.Dial(n.onCloseCtx, ip.ip)
if err != nil {
n.peerConfig.Log.Verbo(
"failed to reach peer, attempting again",
n.peerConfig.Log.Verbo("failed to reach peer, attempting again",
zap.Stringer("nodeID", nodeID),
zap.Stringer("peerIP", ip.ip),
zap.Duration("delay", ip.delay),
Expand All @@ -1000,8 +999,7 @@ func (n *network) dial(nodeID ids.NodeID, ip *trackedIP) {

err = n.upgrade(conn, n.clientUpgrader, false)
if err != nil {
n.peerConfig.Log.Verbo(
"failed to upgrade, attempting again",
n.peerConfig.Log.Verbo("failed to upgrade, attempting again",
zap.Stringer("nodeID", nodeID),
zap.Stringer("peerIP", ip.ip),
zap.Duration("delay", ip.delay),
Expand Down Expand Up @@ -1053,14 +1051,13 @@ func (n *network) upgrade(conn net.Conn, upgrader peer.Upgrader, isIngress bool)

if nodeID == n.config.MyNodeID {
_ = tlsConn.Close()
n.peerConfig.Log.Verbo("dropping connection to myself")
n.peerConfig.Log.Trace("dropping connection to myself")
return nil
}

if !n.AllowConnection(nodeID) {
_ = tlsConn.Close()
n.peerConfig.Log.Verbo(
"dropping undesired connection",
n.peerConfig.Log.Verbo("dropping undesired connection",
zap.Stringer("nodeID", nodeID),
)
return nil
Expand All @@ -1071,8 +1068,7 @@ func (n *network) upgrade(conn net.Conn, upgrader peer.Upgrader, isIngress bool)
n.peersLock.Unlock()

_ = tlsConn.Close()
n.peerConfig.Log.Verbo(
"dropping connection",
n.peerConfig.Log.Verbo("dropping connection",
zap.String("reason", "shutting down the p2p network"),
zap.Stringer("nodeID", nodeID),
)
Expand All @@ -1083,8 +1079,7 @@ func (n *network) upgrade(conn net.Conn, upgrader peer.Upgrader, isIngress bool)
n.peersLock.Unlock()

_ = tlsConn.Close()
n.peerConfig.Log.Verbo(
"dropping connection",
n.peerConfig.Log.Verbo("dropping connection",
zap.String("reason", "already connecting to peer"),
zap.Stringer("nodeID", nodeID),
)
Expand All @@ -1095,9 +1090,8 @@ func (n *network) upgrade(conn net.Conn, upgrader peer.Upgrader, isIngress bool)
n.peersLock.Unlock()

_ = tlsConn.Close()
n.peerConfig.Log.Verbo(
"dropping connection",
zap.String("reason", "already connecting to peer"),
n.peerConfig.Log.Verbo("dropping connection",
zap.String("reason", "already connected to peer"),
zap.Stringer("nodeID", nodeID),
)
return nil
Expand Down
6 changes: 2 additions & 4 deletions network/p2p/acp118/aggregator.go
Original file line number Diff line number Diff line change
Expand Up @@ -151,8 +151,7 @@ func (s *SignatureAggregator) AggregateSignatures(
return msg, aggregatedStakeWeight, totalStakeWeight, nil
case result := <-results:
if result.Err != nil {
s.log.Debug(
"dropping response",
s.log.Debug("dropping response",
zap.Stringer("nodeID", result.NodeID),
zap.Error(err),
)
Expand All @@ -161,8 +160,7 @@ func (s *SignatureAggregator) AggregateSignatures(

// Validators may share public keys so drop any duplicate signatures
if signerBitSet.Contains(result.Validator.Index) {
s.log.Debug(
"dropping duplicate signature",
s.log.Debug("dropping duplicate signature",
zap.Stringer("nodeID", result.NodeID),
zap.Error(err),
)
Expand Down
20 changes: 10 additions & 10 deletions network/p2p/gossip/gossip.go
Original file line number Diff line number Diff line change
Expand Up @@ -230,8 +230,7 @@ func (p *PullGossiper[_]) handleResponse(
err error,
) {
if err != nil {
p.log.Debug(
"failed gossip request",
p.log.Debug("failed gossip request",
zap.Stringer("nodeID", nodeID),
zap.Error(err),
)
Expand All @@ -240,7 +239,9 @@ func (p *PullGossiper[_]) handleResponse(

gossip, err := ParseAppResponse(responseBytes)
if err != nil {
p.log.Debug("failed to unmarshal gossip response", zap.Error(err))
p.log.Trace("failed to unmarshal gossip response",
zap.Error(err),
)
return
}

Expand All @@ -250,23 +251,20 @@ func (p *PullGossiper[_]) handleResponse(

gossipable, err := p.marshaller.UnmarshalGossip(bytes)
if err != nil {
p.log.Debug(
"failed to unmarshal gossip",
p.log.Trace("failed to unmarshal gossip",
zap.Stringer("nodeID", nodeID),
zap.Error(err),
)
continue
}

gossipID := gossipable.GossipID()
p.log.Debug(
"received gossip",
p.log.Debug("received gossip",
zap.Stringer("nodeID", nodeID),
zap.Stringer("id", gossipID),
)
if err := p.set.Add(gossipable); err != nil {
p.log.Debug(
"failed to add gossip to the known set",
p.log.Debug("failed to add gossip to the known set",
zap.Stringer("nodeID", nodeID),
zap.Stringer("id", gossipID),
zap.Error(err),
Expand Down Expand Up @@ -577,7 +575,9 @@ func Every(ctx context.Context, log logging.Logger, gossiper Gossiper, frequency
select {
case <-ticker.C:
if err := gossiper.Gossip(ctx); err != nil {
log.Warn("failed to gossip", zap.Error(err))
log.Warn("failed to gossip",
zap.Error(err),
)
}
case <-ctx.Done():
log.Debug("shutting down gossip")
Expand Down
9 changes: 5 additions & 4 deletions network/p2p/gossip/handler.go
Original file line number Diff line number Diff line change
Expand Up @@ -92,7 +92,9 @@ func (h Handler[T]) AppRequest(_ context.Context, _ ids.NodeID, _ time.Time, req
func (h Handler[_]) AppGossip(_ context.Context, nodeID ids.NodeID, gossipBytes []byte) {
gossip, err := ParseAppGossip(gossipBytes)
if err != nil {
h.log.Debug("failed to unmarshal gossip", zap.Error(err))
h.log.Trace("failed to unmarshal gossip",
zap.Error(err),
)
return
}

Expand All @@ -101,16 +103,15 @@ func (h Handler[_]) AppGossip(_ context.Context, nodeID ids.NodeID, gossipBytes
receivedBytes += len(bytes)
gossipable, err := h.marshaller.UnmarshalGossip(bytes)
if err != nil {
h.log.Debug("failed to unmarshal gossip",
h.log.Trace("failed to unmarshal gossip",
zap.Stringer("nodeID", nodeID),
zap.Error(err),
)
continue
}

if err := h.set.Add(gossipable); err != nil {
h.log.Debug(
"failed to add gossip to the known set",
h.log.Debug("failed to add gossip to the known set",
zap.Stringer("nodeID", nodeID),
zap.Stringer("id", gossipable.GossipID()),
zap.Error(err),
Expand Down
Loading
Loading