luxfi/netrunner
1
0
Fork 0
mirror of https://github.com/luxfi/netrunner.git synced 2026-07-27 00:04:23 +00:00
Code Issues Packages Projects Releases Wiki Activity

Merge branch 'upgrade-avago-logging' into 225-logging

Browse Source
This commit is contained in:
Fabio Barone
2022-08-16 10:37:09 -05:00
parent 5122187ece c355ae3d0e
commit d130314be1
13 changed files with 185 additions and 163 deletions
Download Patch File Download Diff File Expand all files Collapse all files
client/client.go
+13 -12
View File
@@ -15,6 +15,7 @@ import (
"github.com/ava-labs/avalanche-network-runner/local"
"github.com/ava-labs/avalanche-network-runner/rpcpb"
"github.com/ava-labs/avalanchego/utils/logging"
"go.uber.org/zap"
"google.golang.org/grpc"
"google.golang.org/grpc/codes"
"google.golang.org/grpc/credentials/insecure"
@@ -62,7 +63,7 @@ type client struct {
}
func New(cfg Config, log logging.Logger) (Client, error) {
log.Debug("dialing server at endpoint %s", cfg.Endpoint)
log.Debug("dialing server at ", zap.String("endpoint", cfg.Endpoint))
ctx, cancel := context.WithTimeout(context.Background(), cfg.DialTimeout)
conn, err := grpc.DialContext(
@@ -179,7 +180,7 @@ func (c *client) StreamStatus(ctx context.Context, pushInterval time.Duration) (
ch := make(chan *rpcpb.ClusterInfo, 1)
go func() {
defer func() {
c.log.Debug("closing stream send %s", stream.CloseSend())
c.log.Debug("closing stream send ", zap.Error(stream.CloseSend()))
close(ch)
}()
c.log.Info("start receive routine")
@@ -205,9 +206,9 @@ func (c *client) StreamStatus(ctx context.Context, pushInterval time.Duration) (
return
}
if isClientCanceled(stream.Context().Err(), err) {
c.log.Warn("failed to receive status request from gRPC stream due to client cancellation: %s", err)
c.log.Warn("failed to receive status request from gRPC stream due to client cancellation: ", zap.Error(err))
} else {
c.log.Warn("failed to receive status request from gRPC stream: %s", err)
c.log.Warn("failed to receive status request from gRPC stream:", zap.Error(err))
}
return
}
@@ -231,12 +232,12 @@ func (c *client) AddNode(ctx context.Context, name string, execPath string, opts
ChainConfigs: ret.chainConfigs,
}
c.log.Info("add node %q", name)
c.log.Info("add node", zap.String("name", name))
return c.controlc.AddNode(ctx, req)
}
func (c *client) RemoveNode(ctx context.Context, name string) (*rpcpb.RemoveNodeResponse, error) {
c.log.Info("remove node %q", name)
c.log.Info("remove node", zap.String("name", name))
return c.controlc.RemoveNode(ctx, &rpcpb.RemoveNodeRequest{Name: name})
}
@@ -253,17 +254,17 @@ func (c *client) RestartNode(ctx context.Context, name string, opts ...OpOption)
}
req.ChainConfigs = ret.chainConfigs
c.log.Info("restart node %q", name)
c.log.Info("restart node", zap.String("name", name))
return c.controlc.RestartNode(ctx, req)
}
func (c *client) AttachPeer(ctx context.Context, nodeName string) (*rpcpb.AttachPeerResponse, error) {
c.log.Info("attaching peer %q", nodeName)
c.log.Info("attaching peer", zap.String("name", nodeName))
return c.controlc.AttachPeer(ctx, &rpcpb.AttachPeerRequest{NodeName: nodeName})
}
func (c *client) SendOutboundMessage(ctx context.Context, nodeName string, peerID string, op uint32, msgBody []byte) (*rpcpb.SendOutboundMessageResponse, error) {
c.log.Info("sending outbound message: node-name %s, peer-id %s", nodeName, peerID)
c.log.Info("sending outbound message", zap.String("name", nodeName), zap.String("peer-ID", peerID))
return c.controlc.SendOutboundMessage(ctx, &rpcpb.SendOutboundMessageRequest{
NodeName: nodeName,
PeerId: peerID,
@@ -273,12 +274,12 @@ func (c *client) SendOutboundMessage(ctx context.Context, nodeName string, peerI
}
func (c *client) SaveSnapshot(ctx context.Context, snapshotName string) (*rpcpb.SaveSnapshotResponse, error) {
c.log.Info("save snapshot with name %s", snapshotName)
c.log.Info("save snapshot", zap.String("snapshot-name", snapshotName))
return c.controlc.SaveSnapshot(ctx, &rpcpb.SaveSnapshotRequest{SnapshotName: snapshotName})
}
func (c *client) LoadSnapshot(ctx context.Context, snapshotName string, opts ...OpOption) (*rpcpb.LoadSnapshotResponse, error) {
c.log.Info("load snapshot with name %s", snapshotName)
c.log.Info("load snapshot", zap.String("snapshot-name", snapshotName))
ret := &Op{}
ret.applyOpts(opts)
req := rpcpb.LoadSnapshotRequest{
@@ -301,7 +302,7 @@ func (c *client) LoadSnapshot(ctx context.Context, snapshotName string, opts ...
}
func (c *client) RemoveSnapshot(ctx context.Context, snapshotName string) (*rpcpb.RemoveSnapshotResponse, error) {
c.log.Info("remove snapshot with name %s", snapshotName)
c.log.Info("remove snapshot", zap.String("snapshot-name", snapshotName))
return c.controlc.RemoveSnapshot(ctx, &rpcpb.RemoveSnapshotRequest{SnapshotName: snapshotName})
}
cmd/control/control.go
+22 -22
View File
@@ -20,6 +20,7 @@ import (
"github.com/ava-labs/avalanche-network-runner/ux"
"github.com/ava-labs/avalanchego/utils/logging"
"github.com/spf13/cobra"
"go.uber.org/zap"
)
func init() {
@@ -183,8 +184,7 @@ func startFunc(cmd *cobra.Command, args []string) error {
}
if globalNodeConfig != "" {
ux.Print(log, logging.Yellow.Wrap("global node config provided, will be applied to all nodes: %+v"), globalNodeConfig)
ux.Print(log, logging.Yellow.Wrap("global node config provided, will be applied to all nodes"), zap.String("global-node-config", globalNodeConfig))
// validate it's valid JSON
var js json.RawMessage
if err := json.Unmarshal([]byte(globalNodeConfig), &js); err != nil {
@@ -228,7 +228,7 @@ func startFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("start response: %+v"), info)
ux.Print(log, logging.Green.Wrap("start"), zap.Any("response", info))
return nil
}
@@ -266,7 +266,7 @@ func createBlockchainsFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("deploy-blockchains response: %+v"), info)
ux.Print(log, logging.Green.Wrap("deploy-blockchains"), zap.Any("response", info))
return nil
}
@@ -307,7 +307,7 @@ func createSubnetsFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("add-subnets response: %+v"), info)
ux.Print(log, logging.Green.Wrap("add-subnets"), zap.Any("response", info))
return nil
}
@@ -335,7 +335,7 @@ func healthFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("health response: %+v"), resp)
ux.Print(log, logging.Green.Wrap("health"), zap.Any("response", resp))
return nil
}
@@ -363,7 +363,7 @@ func urisFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("URIs: %q"), uris)
ux.Print(log, logging.Green.Wrap("URIs"), zap.Any("uris", uris))
return nil
}
@@ -391,7 +391,7 @@ func statusFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("status response: %+v"), resp)
ux.Print(log, logging.Green.Wrap("status"), zap.Any("response", resp))
return nil
}
@@ -429,7 +429,7 @@ func streamStatusFunc(cmd *cobra.Command, args []string) error {
go func() {
select {
case sig := <-sigc:
log.Warn("received signal: %s", sig.String())
log.Warn("received signal", zap.String("signal", sig.String()))
case <-ctx.Done():
}
cancel()
@@ -441,7 +441,7 @@ func streamStatusFunc(cmd *cobra.Command, args []string) error {
return err
}
for info := range ch {
ux.Print(log, logging.Cyan.Wrap("cluster info: %+v"), info)
ux.Print(log, logging.Cyan.Wrap("cluster"), zap.Any("info", info))
}
cancel() // receiver channel is closed, so cancel goroutine
<-donec
@@ -474,7 +474,7 @@ func removeNodeFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("remove node response: %+v"), info)
ux.Print(log, logging.Green.Wrap("remove node"), zap.Any("response", info))
return nil
}
@@ -518,7 +518,7 @@ func addNodeFunc(cmd *cobra.Command, args []string) error {
opts := []client.OpOption{}
if addNodeConfig != "" {
ux.Print(log, logging.Yellow.Wrap("WARNING: overriding node configs with custom provided config: %+v"), addNodeConfig)
ux.Print(log, logging.Yellow.Wrap("WARNING: overriding node configs with custom provided config"), zap.String("add-node-config", addNodeConfig))
// validate it's valid JSON
var js json.RawMessage
if err := json.Unmarshal([]byte(addNodeConfig), &js); err != nil {
@@ -547,7 +547,7 @@ func addNodeFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("add node response: %+v"), info)
ux.Print(log, logging.Green.Wrap("add node"), zap.Any("response", info))
return nil
}
@@ -612,7 +612,7 @@ func restartNodeFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("restart node response: %+v"), info)
ux.Print(log, logging.Green.Wrap("restart node"), zap.Any("response", info))
return nil
}
@@ -642,7 +642,7 @@ func attachPeerFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("attach peer response: %+v"), resp)
ux.Print(log, logging.Green.Wrap("attach peer"), zap.Any("response", resp))
return nil
}
@@ -711,7 +711,7 @@ func sendOutboundMessageFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("send outbound message response: %+v"), resp)
ux.Print(log, logging.Green.Wrap("send outbound message"), zap.Any("response", resp))
return nil
}
@@ -739,7 +739,7 @@ func stopFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("stop response: %+v"), info)
ux.Print(log, logging.Green.Wrap("stop"), zap.Any("response", info))
return nil
}
@@ -767,7 +767,7 @@ func saveSnapshotFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("save-snapshot response: %+v"), resp)
ux.Print(log, logging.Green.Wrap("save-snapshot"), zap.Any("response", resp))
return nil
}
@@ -833,7 +833,7 @@ func loadSnapshotFunc(cmd *cobra.Command, args []string) error {
}
if globalNodeConfig != "" {
ux.Print(log, logging.Yellow.Wrap("global node config provided, will be applied to all nodes: %+v"), globalNodeConfig)
ux.Print(log, logging.Yellow.Wrap("global node config provided, will be applied to all nodes"), zap.String("global-node-config", globalNodeConfig))
// validate it's valid JSON
var js json.RawMessage
@@ -850,7 +850,7 @@ func loadSnapshotFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("load-snapshot response: %+v"), resp)
ux.Print(log, logging.Green.Wrap("load-snapshot"), zap.Any("response", resp))
return nil
}
@@ -878,7 +878,7 @@ func removeSnapshotFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("remove-snapshot response: %+v"), resp)
ux.Print(log, logging.Green.Wrap("remove-snapshot"), zap.Any("response", resp))
return nil
}
@@ -905,7 +905,7 @@ func getSnapshotNamesFunc(cmd *cobra.Command, args []string) error {
return err
}
ux.Print(log, logging.Green.Wrap("Snapshots: %+v"), snapshotNames)
ux.Print(log, logging.Green.Wrap("Snapshots"), zap.Strings("snapshot-names", snapshotNames))
return nil
}
cmd/ping/ping.go
+3 -2
View File
@@ -12,6 +12,7 @@ import (
"github.com/ava-labs/avalanche-network-runner/ux"
"github.com/ava-labs/avalanchego/utils/logging"
"github.com/spf13/cobra"
"go.uber.org/zap"
)
var (
@@ -67,7 +68,7 @@ func pingFunc(cmd *cobra.Command, args []string) error {
return err
}
logString := "ping response " + logging.Green.Wrap("%+v")
ux.Print(log, logString, resp)
logString := logging.Green.Wrap("ping")
ux.Print(log, logString, zap.Any("response", resp))
return nil
}
cmd/server/server.go
+4 -3
View File
@@ -15,6 +15,7 @@ import (
"github.com/ava-labs/avalanche-network-runner/utils/constants"
"github.com/ava-labs/avalanchego/utils/logging"
"github.com/spf13/cobra"
"go.uber.org/zap"
)
func init() {
@@ -97,15 +98,15 @@ func serverFunc(cmd *cobra.Command, args []string) (err error) {
signal.Notify(sigc, syscall.SIGINT, syscall.SIGTERM)
select {
case sig := <-sigc:
log.Warn("signal received; closing server: %s", sig.String())
log.Warn("signal received; closing server: %s", zap.String("signal", sig.String()))
rootCancel()
// wait for server stop
waitForServerStop := <-errc
log.Warn("closed server: %v", waitForServerStop)
log.Warn("closed server", zap.Error(waitForServerStop))
case serverClosed := <-errc:
// server already stopped here
_ = rootCancel
log.Warn("server closed: %s", serverClosed)
log.Warn("server closed", zap.Error(serverClosed))
}
return err
}
go.mod
+9 -1
View File
@@ -2,6 +2,10 @@ module github.com/ava-labs/avalanche-network-runner
go 1.18
replace github.com/ava-labs/avalanchego => ../avalanchego-internal
replace github.com/ava-labs/avalanche-ledger-go => ../avalanche-ledger-go
require (
github.com/ava-labs/avalanchego v1.7.17
github.com/ava-labs/coreth v0.8.15-rc.2
@@ -14,6 +18,7 @@ require (
github.com/shirou/gopsutil v3.21.11+incompatible
github.com/spf13/cobra v1.3.0
github.com/stretchr/testify v1.7.2
go.uber.org/zap v1.21.0
golang.org/x/sync v0.0.0-20210220032951-036812b2e83c
google.golang.org/genproto v0.0.0-20220712132514-bdd2acd4974d
google.golang.org/grpc v1.47.0
@@ -21,10 +26,12 @@ require (
)
require (
github.com/FactomProject/btcutilecc v0.0.0-20130527213604-d3a63a5752ec // indirect
github.com/Microsoft/go-winio v0.5.2 // indirect
github.com/NYTimes/gziphandler v1.1.1 // indirect
github.com/VictoriaMetrics/fastcache v1.10.0 // indirect
github.com/aead/siphash v1.0.1 // indirect
github.com/ava-labs/avalanche-ledger-go v0.0.0-00010101000000-000000000000 // indirect
github.com/benbjohnson/clock v1.3.0 // indirect
github.com/beorn7/perks v1.0.1 // indirect
github.com/btcsuite/btcd v0.23.1 // indirect
@@ -112,9 +119,10 @@ require (
github.com/tklauser/numcpus v0.2.2 // indirect
github.com/tyler-smith/go-bip39 v1.0.2 // indirect
github.com/yusufpapurcu/wmi v1.2.2 // indirect
github.com/zondax/hid v0.9.0 // indirect
github.com/zondax/ledger-go v0.12.2 // indirect
go.uber.org/atomic v1.9.0 // indirect
go.uber.org/multierr v1.8.0 // indirect
go.uber.org/zap v1.21.0 // indirect
golang.org/x/crypto v0.0.0-20220622213112-05595931fe9d // indirect
golang.org/x/net v0.0.0-20220708220712-1185a9018129 // indirect
golang.org/x/sys v0.0.0-20220722155257-8c9f86f7a55f // indirect
go.sum
+6 -2
View File
@@ -53,6 +53,8 @@ github.com/BurntSushi/toml v0.3.1 h1:WXkYYl6Yr3qBf1K79EBnL4mak0OimBfB0XUf9Vl28OQ
github.com/BurntSushi/toml v0.3.1/go.mod h1:xHWCNGjB5oqiDr8zfno3MHue2Ht5sIBksp03qcyfWMU=
github.com/BurntSushi/xgb v0.0.0-20160522181843-27f122750802/go.mod h1:IVnqGOEym/WlBOVXweHU+Q+/VP0lqqI8lqeDx9IjBqo=
github.com/DataDog/datadog-go v3.2.0+incompatible/go.mod h1:LButxg5PwREeZtORoXG3tL4fMGNddJ+vMq1mwgfaqoQ=
github.com/FactomProject/btcutilecc v0.0.0-20130527213604-d3a63a5752ec h1:1Qb69mGp/UtRPn422BH4/Y4Q3SLUrD9KHuDkm8iodFc=
github.com/FactomProject/btcutilecc v0.0.0-20130527213604-d3a63a5752ec/go.mod h1:CD8UlnlLDiqb36L110uqiP2iSflVjx9g/3U9hCI4q2U=
github.com/Microsoft/go-winio v0.5.2 h1:a9IhgEQBCUEk6QCdml9CiJGhAws+YwffDHEMp1VMrpA=
github.com/Microsoft/go-winio v0.5.2/go.mod h1:WpS1mjBmmwHBEWmogvA2mj8546UReBk4v8QkMxJ6pZY=
github.com/NYTimes/gziphandler v1.1.1 h1:ZUDjpQae29j0ryrS0u/B8HZfJBtBQHjqw2rQ2cqUQ3I=
@@ -75,8 +77,6 @@ github.com/armon/go-metrics v0.0.0-20180917152333-f0300d1749da/go.mod h1:Q73ZrmV
github.com/armon/go-metrics v0.3.10/go.mod h1:4O98XIr/9W0sxpJ8UaYkvjk10Iff7SnFrb4QAOwNTFc=
github.com/armon/go-radix v0.0.0-20180808171621-7fddfc383310/go.mod h1:ufUuZ+zHj4x4TnLV4JWEpy2hxWSpsRywHrMgIH9cCH8=
github.com/armon/go-radix v1.0.0/go.mod h1:ufUuZ+zHj4x4TnLV4JWEpy2hxWSpsRywHrMgIH9cCH8=
github.com/ava-labs/avalanchego v1.7.17 h1:+Kafk8GaveL/J97yiw+DDtt8TaLWDsyrB61p/QTiEuU=
github.com/ava-labs/avalanchego v1.7.17/go.mod h1:PDJudeWWz4IXxexK95XRMuziAv6XPpMPbCHGwwlzNfw=
github.com/ava-labs/coreth v0.8.15-rc.2 h1:JYnxD1FWaTwwsWa92S4eoO9HRa0OD1YAvYThdblbCWQ=
github.com/ava-labs/coreth v0.8.15-rc.2/go.mod h1:Kobp6Sl243ZwHk3Td6nxbV+naCNsJxFZj7wc1k227cA=
github.com/benbjohnson/clock v1.1.0/go.mod h1:J11/hYXuz8f4ySSvYwY0FKfm+ezbsZBKZxNJlLklBHA=
@@ -593,6 +593,10 @@ github.com/yuin/goldmark v1.2.1/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9dec
github.com/yuin/goldmark v1.3.5/go.mod h1:mwnBkeHKe2W/ZEtQ+71ViKU8L12m81fl3OWwC1Zlc8k=
github.com/yusufpapurcu/wmi v1.2.2 h1:KBNDSne4vP5mbSWnJbO+51IMOXJB67QiYCSBrubbPRg=
github.com/yusufpapurcu/wmi v1.2.2/go.mod h1:SBZ9tNy3G9/m5Oi98Zks0QjeHVDvuK0qfxQmPyzfmi0=
github.com/zondax/hid v0.9.0 h1:eiT3P6vNxAEVxXMw66eZUAAnU2zD33JBkfG/EnfAKl8=
github.com/zondax/hid v0.9.0/go.mod h1:l5wttcP0jwtdLjqjMMWFVEE7d1zO0jvSPA9OPZxWpEM=
github.com/zondax/ledger-go v0.12.2 h1:HnuUEKylJ6GqNrLMwghCTHRRAsnr8NlriawMVaFZ7w0=
github.com/zondax/ledger-go v0.12.2/go.mod h1:KatxXrVDzgWwbssUWsF5+cOJHXPvzQ09YSlzGNuhOEo=
go.etcd.io/etcd/api/v3 v3.5.1/go.mod h1:cbVKeC6lCfl7j/8jBhAK6aIYO9XOjdptoxU/nLQcPvs=
go.etcd.io/etcd/client/pkg/v3 v3.5.1/go.mod h1:IJHfcCEKxYu1Os13ZdwCwIUTUVGYTSAM3YSwc9/Ac1g=
go.etcd.io/etcd/client/v2 v2.305.1/go.mod h1:pMEacxZW7o8pg4CrFE7pquyCJJzZvkvdD2RibOCCCGs=
local/blockchain.go
+38 -37
View File
@@ -28,6 +28,7 @@ import (
"github.com/ava-labs/avalanchego/vms/secp256k1fx"
"github.com/ava-labs/avalanchego/wallet/subnet/primary"
"github.com/ava-labs/avalanchego/wallet/subnet/primary/common"
"go.uber.org/zap"
)
const (
@@ -223,7 +224,7 @@ func (ln *localNetwork) installCustomChains(
if err != nil {
return nil, err
}
ln.log.Info("base wallet AVAX balance %d for address %s ", balances[avaxAssetID], testKeyAddr.String())
ln.log.Info("base wallet AVAX balance", zap.Uint64("balance", balances[avaxAssetID]), zap.String("address", testKeyAddr.String()))
return chainInfos, nil
}
@@ -276,7 +277,7 @@ func (ln *localNetwork) setupWalletAndInstallSubnets(
if err != nil {
return nil, err
}
ln.log.Info("base wallet AVAX balance %d for address %s", balances[avaxAssetID], testKeyAddr.String())
ln.log.Info("base wallet AVAX balance", zap.Uint64("balance", balances[avaxAssetID]), zap.String("address", testKeyAddr.String()))
return subnetIDs, nil
}
@@ -311,7 +312,7 @@ func (ln *localNetwork) installSubnets(
if err != nil {
return nil, nil, err
}
ln.log.Info("set up base wallet at endpoint %s with pre-funded test key address %s", clientURI, testKeyAddr.String())
ln.log.Info("set up base wallet with pre-funded test key address", zap.String("endpoint", clientURI), zap.String("address", testKeyAddr.String()))
}
return baseWallet, subnetIDs, nil
}
@@ -341,27 +342,27 @@ func (ln *localNetwork) waitForCustomChainsReady(
}
for nodeName, node := range ln.nodes {
ln.log.Info("inspecting node log directory %s for custom chain logs for node-name %s", node.GetLogsDir(), nodeName)
ln.log.Info("inspecting node log directory for custom chain logs", zap.String("log-dir", node.GetLogsDir()), zap.String("node-name", nodeName))
for _, chainInfo := range chainInfos {
p := filepath.Join(node.GetLogsDir(), chainInfo.blockchainID.String()+".log")
ln.log.Info("checking log, vm-id: %s, subnet-id: %s, blockchain-id: %s, log-path: %s",
chainInfo.vmID.String(),
chainInfo.subnetID.String(),
chainInfo.blockchainID.String(),
p,
ln.log.Info("checking log",
zap.String("vm-ID", chainInfo.vmID.String()),
zap.String("subnet-ID", chainInfo.subnetID.String()),
zap.String("blockchain-ID", chainInfo.blockchainID.String()),
zap.String("path", p),
)
for {
_, err := os.Stat(p)
if err == nil {
ln.log.Info("found the log at path %s", p)
ln.log.Info("found the log", zap.String("path", p))
break
}
ln.log.Info("log not found yet, retrying... vm-id: %s, subnet-id: %s, blockchain-id: %s, log-path: %s, err: %s",
chainInfo.vmID.String(),
chainInfo.subnetID.String(),
chainInfo.blockchainID.String(),
err,
ln.log.Info("log not found yet, retrying...",
zap.String("vm-ID", chainInfo.vmID.String()),
zap.String("subnet-ID", chainInfo.subnetID.String()),
zap.String("blockchain-ID", chainInfo.blockchainID.String()),
zap.Error(err),
)
select {
case <-ln.onStopCh:
@@ -404,7 +405,7 @@ func (ln *localNetwork) restartNodesWithWhitelistedSubnets(
subnetIDs []ids.ID,
) (err error) {
println()
ln.log.Info(logging.Green.Wrap("restarting each node with %s"), config.WhitelistedSubnetsKey)
ln.log.Info(logging.Green.Wrap("restarting each node"), zap.String("whitelisted-subnets", config.WhitelistedSubnetsKey))
whitelistedSubnetIDsMap := map[string]struct{}{}
currentSubnets, err := ln.getCurrentSubnets(ctx)
if err != nil {
@@ -423,7 +424,7 @@ func (ln *localNetwork) restartNodesWithWhitelistedSubnets(
sort.Strings(whitelistedSubnetIDs)
whitelistedSubnets := strings.Join(whitelistedSubnetIDs, ",")
ln.log.Info("restarting all nodes to whitelist subnets: %s", whitelistedSubnetIDs)
ln.log.Info("restarting all nodes to whitelist subnets", zap.Strings("whitelisted-subnet-IDs", whitelistedSubnetIDs))
// change default setting
ln.flags[config.WhitelistedSubnetsKey] = whitelistedSubnets
@@ -434,7 +435,7 @@ func (ln *localNetwork) restartNodesWithWhitelistedSubnets(
// delete node specific flag so as to use default one
delete(nodeConfig.Flags, config.WhitelistedSubnetsKey)
ln.log.Info("removing and adding back the node %q for whitelisted subnets", nodeName)
ln.log.Info("removing and adding back the node for whitelisted subnets", zap.String("node-name", nodeName))
if err := ln.removeNode(ctx, nodeName); err != nil {
return err
}
@@ -443,7 +444,7 @@ func (ln *localNetwork) restartNodesWithWhitelistedSubnets(
return err
}
ln.log.Info("waiting for local cluster readiness after restarting node %q", nodeName)
ln.log.Info("waiting for local cluster readiness after restarting node", zap.String("node-name", nodeName))
if err := ln.healthy(ctx); err != nil {
return err
}
@@ -469,7 +470,7 @@ func setupWallet(
if err != nil {
return nil, ids.Empty, ids.ShortEmpty, err
}
log.Info("set up base wallet at endpoint %s with pre-funded test key address %s", clientURI, testKeyAddr.String())
log.Info("set up base wallet with pre-funded test key address", zap.String("endpoint", clientURI), zap.String("address", testKeyAddr.String()))
println()
log.Info(logging.Green.Wrap("check if the seed test key has enough balance to create validators and subnets"))
@@ -482,7 +483,7 @@ func setupWallet(
if bal <= 1*units.Avax || !ok {
return nil, ids.Empty, ids.ShortEmpty, fmt.Errorf("not enough AVAX balance %v in the address %q", bal, testKeyAddr)
}
log.Info("fetched base wallet at api %s with AVAX balance %d at address %s", clientURI, bal, testKeyAddr.String())
log.Info("fetched base wallet", zap.String("api", clientURI), zap.Uint64("balance", bal), zap.String("address", testKeyAddr.String()))
return baseWallet, avaxAssetID, testKeyAddr, nil
}
@@ -536,7 +537,7 @@ func (ln *localNetwork) addPrimaryValidators(
if err != nil {
return err
}
ln.log.Info("added the node %q with node-id as primary subnet validator, tx-id: %s", nodeName, nodeID.String(), txID.String())
ln.log.Info("added node as primary subnet validator", zap.String("node-name", nodeName), zap.String("node-ID", nodeID.String()), zap.String("tx-ID", txID.String()))
}
return nil
}
@@ -549,7 +550,7 @@ func createSubnets(
log logging.Logger,
) ([]ids.ID, error) {
println()
log.Info(logging.Green.Wrap("creating %d subnets VM"), numSubnets)
log.Info(logging.Green.Wrap("creating subnets VM"), zap.Uint32("num-subnets", numSubnets))
subnetIDs := make([]ids.ID, numSubnets)
var i uint32
for i = 0; i < numSubnets; i++ {
@@ -567,7 +568,7 @@ func createSubnets(
if err != nil {
return nil, err
}
log.Info("created subnet tx, subnet-id: %s", subnetID.String())
log.Info("created subnet tx", zap.String("subnet-ID", subnetID.String()))
subnetIDs[i] = subnetID
}
return subnetIDs, nil
@@ -629,11 +630,11 @@ func (ln *localNetwork) addSubnetValidators(
if err != nil {
return err
}
ln.log.Info("added the node %q with node-id %s as a subnet validator to subnet-id %s, tx-id: %s",
nodeName,
nodeID.String(),
subnetID.String(),
txID.String(),
ln.log.Info("added node as a subnet validator to subnet",
zap.String("node-name", nodeName),
zap.String("node-ID", nodeID.String()),
zap.String("subnet-ID", subnetID.String()),
zap.String("tx-ID", txID.String()),
)
}
}
@@ -719,10 +720,10 @@ func createBlockchains(
}
vmGenesisBytes := chainSpec.Genesis
log.Info("creating blockchain tx for vm-name %s, vm-id %s; length of genesis bytes: %d",
vmName,
vmID.String(),
len(vmGenesisBytes),
log.Info("creating blockchain tx",
zap.String("vm-name", vmName),
zap.String("vm-ID", vmID.String()),
zap.Int("bytes length of genesis", len(vmGenesisBytes)),
)
cctx, cancel := createDefaultCtx(ctx)
subnetID, err := ids.FromString(*chainSpec.SubnetId)
@@ -745,10 +746,10 @@ func createBlockchains(
blockchainIDs[i] = blockchainID
log.Info("created a new blockchain for vm-name %s with vm-id %s, blockchain-id: %s",
vmName,
vmID.String(),
blockchainID.String(),
log.Info("created a new blockchain",
zap.String("vm-name", vmName),
zap.String("vm-ID", vmID.String()),
zap.String("blockchain-ID", blockchainID.String()),
)
}
local/helpers.go
+5 -5
View File
@@ -134,9 +134,9 @@ func makeNodeDir(log logging.Logger, rootDir, nodeName string) (string, error) {
nodeRootDir := filepath.Join(rootDir, nodeName)
if err := os.Mkdir(nodeRootDir, 0o755); err != nil {
if os.IsExist(err) {
log.Warn("node root directory already exists", zap.String("dir", nodeRootDir))
log.Warn("node root directory already exists", zap.String("root-dir", nodeRootDir))
} else {
return "", fmt.Errorf("error creating temp dir: %w", err)
return "", fmt.Errorf("error creating temp dir %s", err)
}
}
return nodeRootDir, nil
@@ -172,9 +172,9 @@ func addNetworkFlags(log logging.Logger, networkFlags map[string]interface{}, no
} else {
log.Debug(
"not overwriting node config flag with network config flag",
zap.String("flagName", flagName),
zap.Any("val", val),
zap.Any("networkConfigVal", flagVal),
zap.String("flag-name", flagName),
zap.Any("value", val),
zap.Any("network config value", flagVal),
)
}
}
local/network.go
+10 -9
View File
@@ -26,6 +26,7 @@ import (
"github.com/ava-labs/avalanchego/utils/ips"
"github.com/ava-labs/avalanchego/utils/logging"
"github.com/ava-labs/avalanchego/utils/wrappers"
"go.uber.org/zap"
"golang.org/x/sync/errgroup"
)
@@ -377,7 +378,7 @@ func (ln *localNetwork) loadConfig(ctx context.Context, networkConfig network.Co
if err := networkConfig.Validate(); err != nil {
return fmt.Errorf("config failed validation: %w", err)
}
ln.log.Info("creating network", zap.Int("nodes", len(networkConfig.NodeConfigs)))
ln.log.Info("creating network", zap.Int("node-num", len(networkConfig.NodeConfigs)))
ln.genesis = []byte(networkConfig.Genesis)
@@ -501,12 +502,12 @@ func (ln *localNetwork) addNode(nodeConfig node.Config) (node.Node, error) {
ln.log.Info(
"adding node",
zap.String("name", nodeConfig.Name),
zap.String("tmpDir", nodeDir),
zap.String("logDir", nodeData.logsDir),
zap.String("dbDir", nodeData.dbDir),
zap.Uint16("p2pPort", nodeData.p2pPort),
zap.Uint16("apiPort", nodeData.apiPort),
zap.String("node-name", nodeConfig.Name),
zap.String("node-dir", nodeDir),
zap.String("log-dir", nodeData.logsDir),
zap.String("db-dir", nodeData.dbDir),
zap.Uint16("p2p-port", nodeData.p2pPort),
zap.Uint16("api-port", nodeData.apiPort),
)
ln.log.Debug(
@@ -554,7 +555,7 @@ func (ln *localNetwork) Healthy(ctx context.Context) error {
}
func (ln *localNetwork) healthy(ctx context.Context) error {
ln.log.Info("checking local network healthiness, nodes: %d", len(ln.nodes))
ln.log.Info("checking local network healthiness", zap.Int("num-of-nodes", len(ln.nodes)))
// Return unhealthy if the network is stopped
if ln.stopCalled() {
@@ -875,7 +876,7 @@ func (ln *localNetwork) buildFlags(
// Note these will overwrite existing flags if the same flag is given twice.
for flagName, flagVal := range nodeConfig.Flags {
if _, ok := warnFlags[flagName]; ok {
ln.log.Warn("A provided flag can create conflicts with the runner. The suggestion is to remove this flag", zap.String("flagName", flagName))
ln.log.Warn("A provided flag can create conflicts with the runner. The suggestion is to remove this flag", zap.String("flag-name", flagName))
}
flags = append(flags, fmt.Sprintf("--%s=%v", flagName, flagVal))
}
server/network.go
+4 -3
View File
@@ -20,6 +20,7 @@ import (
"github.com/ava-labs/avalanchego/ids"
avago_constants "github.com/ava-labs/avalanchego/utils/constants"
"github.com/ava-labs/avalanchego/utils/logging"
"go.uber.org/zap"
)
type localNetwork struct {
@@ -432,7 +433,7 @@ func (lc *localNetwork) updateSubnetInfo(ctx context.Context) error {
for _, nodeName := range lc.nodeNames {
nodeInfo := lc.nodeInfos[nodeName]
for chainID, chainInfo := range lc.customChainIDToInfo {
ux.Print(lc.log, logging.Blue.Wrap(logging.Bold.Wrap("[blockchain RPC for %q] \"%s/ext/bc/%s\"")), chainInfo.info.VmId, nodeInfo.GetUri(), chainID)
ux.Print(lc.log, logging.Blue.Wrap(logging.Bold.Wrap("blockchain RPC")), zap.String("vm-id", chainInfo.info.VmId), zap.String("RPC endpoint", fmt.Sprintf("\"%s/ext/bc/%s\"", nodeInfo.GetUri(), chainID)))
}
}
return nil
@@ -447,7 +448,7 @@ func (lc *localNetwork) waitForLocalClusterReady(ctx context.Context) error {
for _, name := range lc.nodeNames {
nodeInfo := lc.nodeInfos[name]
ux.Print(lc.log, logging.Cyan.Wrap("%s: node ID %q, URI %q"), name, nodeInfo.Id, nodeInfo.Uri)
ux.Print(lc.log, logging.Cyan.Wrap("node-info"), zap.String("node-name", name), zap.String("node-ID", nodeInfo.Id), zap.String("URI", nodeInfo.Uri))
}
return nil
}
@@ -513,6 +514,6 @@ func (lc *localNetwork) stop(ctx context.Context) {
}
serr := lc.nw.Stop(ctx)
<-lc.startDoneCh
ux.Print(lc.log, logging.Red.Wrap(logging.Bold.Wrap("terminated network (error %s)")), serr)
ux.Print(lc.log, logging.Red.Wrap(logging.Bold.Wrap("terminated network")), zap.Error(serr))
})
}
server/server.go
+50 -48
View File
@@ -27,6 +27,7 @@ import (
"github.com/ava-labs/avalanchego/snow/networking/router"
"github.com/ava-labs/avalanchego/utils/logging"
"github.com/grpc-ecosystem/grpc-gateway/v2/runtime"
"go.uber.org/zap"
"google.golang.org/grpc"
"google.golang.org/grpc/codes"
"google.golang.org/grpc/credentials/insecure"
@@ -143,7 +144,7 @@ func (s *server) Run(rootCtx context.Context) (err error) {
gRPCErrc := make(chan error)
go func() {
s.log.Info("serving gRPC server at port %s", s.cfg.Port)
s.log.Info("serving gRPC server", zap.String("port", s.cfg.Port))
gRPCErrc <- s.gRPCServer.Serve(s.ln)
}()
@@ -152,7 +153,7 @@ func (s *server) Run(rootCtx context.Context) (err error) {
s.log.Info("gRPC gateway server is disabled")
} else {
go func() {
s.log.Info("dialing gRPC server for gRPC gateway at port %s", s.cfg.Port)
s.log.Info("dialing gRPC server for gRPC gateway", zap.String("port", s.cfg.Port))
ctx, cancel := context.WithTimeout(rootCtx, s.cfg.DialTimeout)
gwConn, err := grpc.DialContext(
ctx,
@@ -176,7 +177,7 @@ func (s *server) Run(rootCtx context.Context) (err error) {
return
}
s.log.Info("serving gRPC gateway at port %s", s.cfg.GwPort)
s.log.Info("serving gRPC gateway", zap.String("port", s.cfg.GwPort))
gwErrc <- s.gwServer.ListenAndServe()
}()
}
@@ -186,7 +187,7 @@ func (s *server) Run(rootCtx context.Context) (err error) {
s.log.Warn("root context is done")
if !s.cfg.GwDisabled {
s.log.Warn("closed gRPC gateway server: %v", s.gwServer.Close())
s.log.Warn("closed gRPC gateway server", zap.Error(s.gwServer.Close()))
<-gwErrc
}
@@ -196,14 +197,15 @@ func (s *server) Run(rootCtx context.Context) (err error) {
s.log.Warn("gRPC terminated")
case err = <-gRPCErrc:
s.log.Warn("gRPC server failed: %s", err)
s.log.Warn("gRPC server failed", zap.Error(err))
if !s.cfg.GwDisabled {
s.log.Warn("closed gRPC gateway server: %v", s.gwServer.Close())
s.log.Warn("closed gRPC gateway server", zap.Error(s.gwServer.Close()))
<-gwErrc
}
case err = <-gwErrc: // if disabled, this will never be selected
s.log.Warn("gRPC gateway server failed: %s", err)
s.log.Warn("gRPC gateway server failed", zap.Error(err))
s.gRPCServer.Stop()
s.log.Warn("closed gRPC server")
<-gRPCErrc
@@ -235,9 +237,9 @@ func (s *server) Start(ctx context.Context, req *rpcpb.StartRequest) (*rpcpb.Sta
var cancel context.CancelFunc
ctx, cancel = context.WithTimeout(context.Background(), defaultStartTimeout)
_ = cancel // don't call since "start" is async, "curl" may not specify timeout
s.log.Info("received start request with default timeout: %s", defaultStartTimeout.String())
s.log.Info("received start request with default timeout", zap.String("timeout", defaultStartTimeout.String()))
} else {
s.log.Info("received start request with existing timeout: %s", deadline.String())
s.log.Info("received start request with existing timeout", zap.String("timeout", deadline.String()))
}
if req.NumNodes == nil {
@@ -259,7 +261,7 @@ func (s *server) Start(ctx context.Context, req *rpcpb.StartRequest) (*rpcpb.Sta
}
chainSpecs := []network.BlockchainSpec{}
if len(req.GetBlockchainSpecs()) > 0 {
s.log.Info("plugin dir: %s", pluginDir)
s.log.Info("plugin-dir:", zap.String("plugin-dir", pluginDir))
for i := range req.GetBlockchainSpecs() {
spec := req.GetBlockchainSpecs()[i]
if spec.SubnetId != nil {
@@ -267,10 +269,10 @@ func (s *server) Start(ctx context.Context, req *rpcpb.StartRequest) (*rpcpb.Sta
}
vmName := spec.VmName
vmGenesisFilePath := spec.Genesis
s.log.Info("checking custom chain's VM ID before installation, id is %s", vmName)
s.log.Info("checking custom chain's VM ID before installation", zap.String("id", vmName))
vmID, err := utils.VMID(vmName)
if err != nil {
s.log.Warn("failed to convert VM name %s to VM ID: %s", vmName, err)
s.log.Warn("failed to convert VM name to VM ID", zap.String("vm-name", vmName), zap.Error(err))
return nil, ErrInvalidVMName
}
if err := utils.CheckPluginPaths(
@@ -324,15 +326,15 @@ func (s *server) Start(ctx context.Context, req *rpcpb.StartRequest) (*rpcpb.Sta
Healthy: false,
}
s.log.Info("starting with execPath %s, numNodes %d, whitelistedSubnets %s, pid %d, rootDataDir %s, pluginDir %s, chainConfigs %s, globalNodeConfig %s",
execPath,
numNodes,
whitelistedSubnets,
pid,
rootDataDir,
pluginDir,
req.ChainConfigs,
globalNodeConfig,
s.log.Info("starting",
zap.String("exec-path", execPath),
zap.Uint32("num-nodes", numNodes),
zap.String("whitelisted-subnets", whitelistedSubnets),
zap.Int32("pid", pid),
zap.String("root-data-dir", rootDataDir),
zap.String("plugin-dir", pluginDir),
zap.Any("chain-configs", req.ChainConfigs),
zap.String("global-node-config", globalNodeConfig),
)
if s.network != nil {
@@ -340,7 +342,7 @@ func (s *server) Start(ctx context.Context, req *rpcpb.StartRequest) (*rpcpb.Sta
}
if len(customNodeConfigs) > 0 {
s.log.Warn("custom node configs have been provided; ignoring the 'number-of-nodes' parameter and setting it to: %d", len(customNodeConfigs))
s.log.Warn("custom node configs have been provided; ignoring the 'number-of-nodes' parameter and setting it to:", zap.Int("number-of-nodes", len(customNodeConfigs)))
numNodes = uint32(len(customNodeConfigs))
}
@@ -407,7 +409,7 @@ func (s *server) waitChAndUpdateClusterInfo(waitMsg string, readyCh chan struct{
// TODO: decide what to do here, general failure cause network stop()?
// maybe try decide if operation was partial (undesired network, fail)
// or was not stated (preconditions check, continue)
s.log.Warn("async call %s failed to complete :%s", waitMsg, serr)
s.log.Warn("async call failed to complete", zap.String("async-call", waitMsg), zap.Error(serr))
panic(serr)
case <-readyCh:
s.mu.Lock()
@@ -432,9 +434,9 @@ func (s *server) CreateBlockchains(ctx context.Context, req *rpcpb.CreateBlockch
var cancel context.CancelFunc
ctx, cancel = context.WithTimeout(context.Background(), defaultStartTimeout)
_ = cancel // don't call since "start" is async, "curl" may not specify timeout
s.log.Info("received start request with default timeout: %s", defaultStartTimeout.String())
s.log.Info("received start request with default timeout", zap.String("timeout", defaultStartTimeout.String()))
} else {
s.log.Info("received start request with existing timeout: %s", deadline.String())
s.log.Info("received start request with existing timeout", zap.String("timeout", deadline.String()))
}
s.log.Debug("CreateBlockchains")
@@ -450,10 +452,10 @@ func (s *server) CreateBlockchains(ctx context.Context, req *rpcpb.CreateBlockch
for i := range req.GetBlockchainSpecs() {
vmName := req.GetBlockchainSpecs()[i].VmName
vmGenesisFilePath := req.GetBlockchainSpecs()[i].Genesis
s.log.Info("checking custom chain's VM ID before installation, vm-id: %s", vmName)
s.log.Info("checking custom chain's VM ID before installation", zap.String("vm-id", vmName))
vmID, err := utils.VMID(vmName)
if err != nil {
s.log.Warn("failed to convert VM name %s to VM ID: %s", vmName, err)
s.log.Warn("failed to convert VM name to VM ID", zap.String("vm-name", vmName), zap.Error(err))
return nil, ErrInvalidVMName
}
if err := utils.CheckPluginPaths(
@@ -521,12 +523,12 @@ func (s *server) CreateSubnets(ctx context.Context, req *rpcpb.CreateSubnetsRequ
var cancel context.CancelFunc
ctx, cancel = context.WithTimeout(context.Background(), defaultStartTimeout)
_ = cancel // don't call since "start" is async, "curl" may not specify timeout
s.log.Info("received start request with default timeout: %s", defaultStartTimeout.String())
s.log.Info("received start request with default timeout", zap.String("timeout", defaultStartTimeout.String()))
} else {
s.log.Info("received start request with existing timeout: %s", deadline.String())
s.log.Info("received start request with existing timeout", zap.String("timeout", deadline.String()))
}
s.log.Debug("CreateSubnets with num-subnets: %d ", req.GetNumSubnets())
s.log.Debug("CreateSubnets", zap.Uint32("num-subnets", req.GetNumSubnets()))
if info := s.getClusterInfo(); info == nil {
return nil, ErrNotBootstrapped
@@ -617,7 +619,7 @@ func (s *server) StreamStatus(req *rpcpb.StreamStatusRequest, stream rpcpb.Contr
interval := time.Duration(req.PushInterval)
// returns this method, then server closes the stream
s.log.Info("pushing status updates to the stream with interval: %s", interval.String())
s.log.Info("pushing status updates to the stream", zap.String("interval", interval.String()))
wg := sync.WaitGroup{}
wg.Add(1)
go func() {
@@ -630,9 +632,9 @@ func (s *server) StreamStatus(req *rpcpb.StreamStatusRequest, stream rpcpb.Contr
rerr := s.recvLoop(stream)
if rerr != nil {
if isClientCanceled(stream.Context().Err(), rerr) {
s.log.Warn("failed to receive status request from gRPC stream due to client cancellation: %s", rerr)
s.log.Warn("failed to receive status request from gRPC stream due to client cancellation", zap.Error(rerr))
} else {
s.log.Warn("failed to receive status request from gRPC stream: %s", rerr)
s.log.Warn("failed to receive status request from gRPC stream", zap.Error(rerr))
}
}
errc <- rerr
@@ -673,10 +675,10 @@ func (s *server) sendLoop(stream rpcpb.ControlService_StreamStatusServer, interv
s.log.Debug("sending cluster info")
if err := stream.Send(&rpcpb.StreamStatusResponse{ClusterInfo: s.getClusterInfo()}); err != nil {
if isClientCanceled(stream.Context().Err(), err) {
s.log.Debug("client stream canceled: %s", err)
s.log.Debug("client stream canceled", zap.Error(err))
return
}
s.log.Warn("failed to send an event: %s", err)
s.log.Warn("failed to send an event", zap.Error(err))
return
}
}
@@ -708,7 +710,7 @@ func (s *server) recvLoop(stream rpcpb.ControlService_StreamStatusServer) error
}
func (s *server) AddNode(ctx context.Context, req *rpcpb.AddNodeRequest) (*rpcpb.AddNodeResponse, error) {
s.log.Debug("received add node request with name: %s", req.Name)
s.log.Debug("received add node request", zap.String("name", req.Name))
if info := s.getClusterInfo(); info == nil {
return nil, ErrNotBootstrapped
@@ -748,7 +750,7 @@ func (s *server) AddNode(ctx context.Context, req *rpcpb.AddNodeRequest) (*rpcpb
}
func (s *server) RemoveNode(ctx context.Context, req *rpcpb.RemoveNodeRequest) (*rpcpb.RemoveNodeResponse, error) {
s.log.Debug("received remove node request for name: %s", req.Name)
s.log.Debug("received remove node request", zap.String("name", req.Name))
if info := s.getClusterInfo(); info == nil {
return nil, ErrNotBootstrapped
}
@@ -771,7 +773,7 @@ func (s *server) RemoveNode(ctx context.Context, req *rpcpb.RemoveNodeRequest) (
}
func (s *server) RestartNode(ctx context.Context, req *rpcpb.RestartNodeRequest) (*rpcpb.RestartNodeResponse, error) {
s.log.Debug("received remove node request for name: %s", req.Name)
s.log.Debug("received remove node request", zap.String("name", req.Name))
if info := s.getClusterInfo(); info == nil {
return nil, ErrNotBootstrapped
}
@@ -830,7 +832,7 @@ type loggingInboundHandler struct {
}
func (lh *loggingInboundHandler) HandleInbound(m message.InboundMessage) {
lh.log.Debug("inbound handler received a message %s for node-name: %s", m.Op().String(), lh.nodeName)
lh.log.Debug("inbound handler received a message", zap.String("message", m.Op().String()), zap.String("node-name", lh.nodeName))
}
func (s *server) AttachPeer(ctx context.Context, req *rpcpb.AttachPeerRequest) (*rpcpb.AttachPeerResponse, error) {
@@ -856,7 +858,7 @@ func (s *server) AttachPeer(ctx context.Context, req *rpcpb.AttachPeerRequest) (
newPeerID := newPeer.ID().String()
s.log.Debug("new peer with peer-id %s is attached to node-name: %s", newPeerID, node.GetName())
s.log.Debug("new peer is attached to", zap.String("peer-ID", newPeerID), zap.String("node-name", node.GetName()))
if s.clusterInfo.AttachedPeerInfos == nil {
s.clusterInfo.AttachedPeerInfos = make(map[string]*rpcpb.ListOfAttachedPeerInfo)
@@ -895,9 +897,9 @@ func (s *server) LoadSnapshot(ctx context.Context, req *rpcpb.LoadSnapshotReques
var cancel context.CancelFunc
ctx, cancel = context.WithTimeout(context.Background(), defaultStartTimeout)
_ = cancel // don't call since "start" is async, "curl" may not specify timeout
s.log.Info("received start request with default timeout: %s", defaultStartTimeout.String())
s.log.Info("received start request with default timeout", zap.String("timeout", defaultStartTimeout.String()))
} else {
s.log.Info("received start request with existing timeout: %s", deadline.String())
s.log.Info("received start request with existing timeout", zap.String("timeout", deadline.String()))
}
s.mu.Lock()
@@ -929,7 +931,7 @@ func (s *server) LoadSnapshot(ctx context.Context, req *rpcpb.LoadSnapshotReques
Healthy: false,
}
s.log.Info("starting with pid %d and rootDataDir %s", pid, rootDataDir)
s.log.Info("starting", zap.Int32("pid", pid), zap.String("root-data-dir", rootDataDir))
if s.network != nil {
return nil, ErrAlreadyBootstrapped
@@ -957,7 +959,7 @@ func (s *server) LoadSnapshot(ctx context.Context, req *rpcpb.LoadSnapshotReques
// blocking load snapshot to soon get not found snapshot errors
if err := s.network.loadSnapshot(ctx, req.SnapshotName); err != nil {
s.log.Warn("snapshot load failed to complete: %s", err)
s.log.Warn("snapshot load failed to complete", zap.Error(err))
s.network = nil
s.clusterInfo = nil
return nil, err
@@ -979,7 +981,7 @@ func (s *server) LoadSnapshot(ctx context.Context, req *rpcpb.LoadSnapshotReques
}
func (s *server) SaveSnapshot(ctx context.Context, req *rpcpb.SaveSnapshotRequest) (*rpcpb.SaveSnapshotResponse, error) {
s.log.Info("received save snapshot request for snapshot-name: %s", req.SnapshotName)
s.log.Info("received save snapshot request", zap.String("snapshot-name", req.SnapshotName))
info := s.getClusterInfo()
if info == nil {
return nil, ErrNotBootstrapped
@@ -990,7 +992,7 @@ func (s *server) SaveSnapshot(ctx context.Context, req *rpcpb.SaveSnapshotReques
snapshotPath, err := s.network.nw.SaveSnapshot(ctx, req.SnapshotName)
if err != nil {
s.log.Warn("snapshot save failed to complete: %s", err)
s.log.Warn("snapshot save failed to complete", zap.Error(err))
return nil, err
}
s.network = nil
@@ -1000,14 +1002,14 @@ func (s *server) SaveSnapshot(ctx context.Context, req *rpcpb.SaveSnapshotReques
}
func (s *server) RemoveSnapshot(ctx context.Context, req *rpcpb.RemoveSnapshotRequest) (*rpcpb.RemoveSnapshotResponse, error) {
s.log.Info("received remove snapshot request for snapshot-name: %s", req.SnapshotName)
s.log.Info("received remove snapshot request", zap.String("snapshot-name", req.SnapshotName))
info := s.getClusterInfo()
if info == nil {
return nil, ErrNotBootstrapped
}
if err := s.network.nw.RemoveSnapshot(req.SnapshotName); err != nil {
s.log.Warn("snapshot remove failed to complete: %s", err)
s.log.Warn("snapshot remove failed to complete", zap.Error(err))
return nil, err
}
return &rpcpb.RemoveSnapshotResponse{}, nil
tests/e2e/e2e_test.go
+17 -16
View File
@@ -29,6 +29,7 @@ import (
ginkgo "github.com/onsi/ginkgo/v2"
"github.com/onsi/gomega"
"github.com/prometheus/client_golang/prometheus"
"go.uber.org/zap"
)
func TestE2e(t *testing.T) {
@@ -149,7 +150,7 @@ var _ = ginkgo.Describe("[Start/Remove/Restart/Add/Stop]", func() {
ginkgo.It("can create blockhains", func() {
existingSubnetID := ""
ginkgo.By("start with blockchain specs", func() {
ux.Print(log, logging.Green.Wrap("sending 'start' with the valid binary path"), execPath2)
ux.Print(log, logging.Green.Wrap("sending 'start' with the valid binary path"), zap.String("execPath2", execPath2))
ctx, cancel := context.WithTimeout(context.Background(), 15*time.Second)
resp, err := cli.Start(ctx, execPath2,
client.WithBlockchainSpecs([]*rpcpb.BlockchainSpec{
@@ -161,7 +162,7 @@ var _ = ginkgo.Describe("[Start/Remove/Restart/Add/Stop]", func() {
)
cancel()
gomega.Ω(err).Should(gomega.BeNil())
ux.Print(log, logging.Green.Wrap("successfully started: %q"), resp.ClusterInfo.NodeNames)
ux.Print(log, logging.Green.Wrap("successfully started"), zap.Strings("node-names", resp.ClusterInfo.NodeNames))
})
ginkgo.By("wait for custom chains healthy", func() {
@@ -338,12 +339,12 @@ var _ = ginkgo.Describe("[Start/Remove/Restart/Add/Stop]", func() {
})
ginkgo.By("calling start API with the valid binary path", func() {
ux.Print(log, logging.Green.Wrap("sending 'start' with the valid binary path: %q"), execPath1)
ux.Print(log, logging.Green.Wrap("sending 'start' with the valid binary path"), zap.String("execPath1", execPath1))
ctx, cancel := context.WithTimeout(context.Background(), 15*time.Second)
resp, err := cli.Start(ctx, execPath1)
cancel()
gomega.Ω(err).Should(gomega.BeNil())
ux.Print(log, logging.Green.Wrap("successfully started: %q"), resp.ClusterInfo.NodeNames)
ux.Print(log, logging.Green.Wrap("successfully started"), zap.Strings("node-names", resp.ClusterInfo.NodeNames))
})
})
@@ -359,7 +360,7 @@ var _ = ginkgo.Describe("[Start/Remove/Restart/Add/Stop]", func() {
uris, err := cli.URIs(ctx)
cancel()
gomega.Ω(err).Should(gomega.BeNil())
ux.Print(log, logging.Blue.Wrap("URIs: %q"), uris)
ux.Print(log, logging.Blue.Wrap("URIs"), zap.Strings("uris", uris))
})
ginkgo.It("can fetch status", func() {
@@ -375,7 +376,7 @@ var _ = ginkgo.Describe("[Start/Remove/Restart/Add/Stop]", func() {
ch, err := cli.StreamStatus(ctx, 5*time.Second)
gomega.Ω(err).Should(gomega.BeNil())
for info := range ch {
ux.Print(log, logging.Green.Wrap("fetched info: %q"), info.NodeNames)
ux.Print(log, logging.Green.Wrap("fetched info"), zap.Strings("node-names", info.NodeNames))
if info.Healthy {
break
}
@@ -389,7 +390,7 @@ var _ = ginkgo.Describe("[Start/Remove/Restart/Add/Stop]", func() {
resp, err := cli.RemoveNode(ctx, "node5")
cancel()
gomega.Ω(err).Should(gomega.BeNil())
ux.Print(log, logging.Green.Wrap("successfully removed: %q"), resp.ClusterInfo.NodeNames)
ux.Print(log, logging.Green.Wrap("successfully removed"), zap.Strings("node-names", resp.ClusterInfo.NodeNames))
})
})
@@ -400,7 +401,7 @@ var _ = ginkgo.Describe("[Start/Remove/Restart/Add/Stop]", func() {
resp, err := cli.RestartNode(ctx, "node4", client.WithExecPath(execPath2))
cancel()
gomega.Ω(err).Should(gomega.BeNil())
ux.Print(log, logging.Green.Wrap("successfully restarted: %q"), resp.ClusterInfo.NodeNames)
ux.Print(log, logging.Green.Wrap("successfully restarted"), zap.Strings("node-names", resp.ClusterInfo.NodeNames))
})
})
@@ -414,7 +415,7 @@ var _ = ginkgo.Describe("[Start/Remove/Restart/Add/Stop]", func() {
v, ok := resp.ClusterInfo.AttachedPeerInfos["node1"]
gomega.Ω(ok).Should(gomega.BeTrue())
ux.Print(log, logging.Green.Wrap("successfully attached peer: %+v"), v.Peers)
ux.Print(log, logging.Green.Wrap("successfully attached peer"), zap.Any("peers", v.Peers))
mc, err := message.NewCreator(
prometheus.NewRegistry(),
@@ -445,16 +446,16 @@ var _ = ginkgo.Describe("[Start/Remove/Restart/Add/Stop]", func() {
time.Sleep(10 * time.Second)
ginkgo.It("can add a node", func() {
ginkgo.By("calling AddNode", func() {
ux.Print(log, logging.Green.Wrap("calling 'add-node' with the valid binary path: %q"), execPath1)
ux.Print(log, logging.Green.Wrap("calling 'add-node' with the valid binary path"), zap.String("execPath1", execPath1))
ctx, cancel := context.WithTimeout(context.Background(), 15*time.Second)
resp, err := cli.AddNode(ctx, newNodeName, execPath1)
cancel()
gomega.Ω(err).Should(gomega.BeNil())
ux.Print(log, logging.Green.Wrap("successfully started: %q"), resp.ClusterInfo.NodeNames)
ux.Print(log, logging.Green.Wrap("successfully started"), zap.Strings("node-names", resp.ClusterInfo.NodeNames))
})
ginkgo.By("calling AddNode with existing node name, should fail", func() {
ux.Print(log, logging.Green.Wrap("calling 'add-node' with the valid binary path: %q"), execPath1)
ux.Print(log, logging.Green.Wrap("calling 'add-node' with the valid binary path"), zap.String("execPath1", execPath1))
ctx, cancel := context.WithTimeout(context.Background(), 15*time.Second)
resp, err := cli.AddNode(ctx, newNodeName, execPath1)
cancel()
@@ -476,7 +477,7 @@ var _ = ginkgo.Describe("[Start/Remove/Restart/Add/Stop]", func() {
gomega.Ω(err).Should(gomega.BeNil())
})
ginkgo.By("calling start API with custom config", func() {
ux.Print(log, logging.Green.Wrap("sending 'start' with the valid binary path: %q"), execPath1)
ux.Print(log, logging.Green.Wrap("sending 'start' with the valid binary path"), zap.String("execPath1", execPath1))
ctx, cancel := context.WithTimeout(context.Background(), 15*time.Second)
opts := []client.OpOption{
client.WithNumNodes(numNodes),
@@ -485,7 +486,7 @@ var _ = ginkgo.Describe("[Start/Remove/Restart/Add/Stop]", func() {
resp, err := cli.Start(ctx, execPath1, opts...)
cancel()
gomega.Ω(err).Should(gomega.BeNil())
ux.Print(log, logging.Green.Wrap("successfully started: %q"), resp.ClusterInfo.NodeNames)
ux.Print(log, logging.Green.Wrap("successfully started"), zap.Strings("node-names", resp.ClusterInfo.NodeNames))
})
ginkgo.By("can wait for health", func() {
// start is async, so wait some time for cluster health
@@ -497,13 +498,13 @@ var _ = ginkgo.Describe("[Start/Remove/Restart/Add/Stop]", func() {
gomega.Ω(err).Should(gomega.BeNil())
})
ginkgo.By("overrides num-nodes", func() {
ux.Print(log, logging.Green.Wrap("checking that given num-nodes %d have been overriden by custom configs with %d"), numNodes, len(customNodeConfigs))
ux.Print(log, logging.Green.Wrap("checking that given num-nodes have been overriden by custom configs"), zap.Uint32("num-nodes", numNodes), zap.Int("len(custom-node-configs)", len(customNodeConfigs)))
ctx, cancel := context.WithTimeout(context.Background(), 15*time.Second)
uris, err := cli.URIs(ctx)
cancel()
gomega.Ω(err).Should(gomega.BeNil())
gomega.Ω(uris).Should(gomega.HaveLen(len(customNodeConfigs)))
ux.Print(log, logging.Green.Wrap("expected number of nodes up: %q"), len(customNodeConfigs))
ux.Print(log, logging.Green.Wrap("expected number of nodes up"), zap.Int("num-nodes", len(customNodeConfigs)))
ux.Print(log, logging.Green.Wrap("checking correct admin APIs are enabled resp. disabled"))
// we have 7 nodes, 3 have the admin API enabled, the other 4 disabled
ux/output.go
+4 -3
View File
@@ -6,9 +6,10 @@ import (
"fmt"
"github.com/ava-labs/avalanchego/utils/logging"
"go.uber.org/zap"
)
func Print(log logging.Logger, msg string, args ...interface{}) {
fmt.Println(fmt.Sprintf(msg, args...))
log.Info(msg, args)
func Print(log logging.Logger, msg string, args ...zap.Field) {
fmt.Println(zap.Any("", args))
log.Info(msg, args...)
}