metropolis/resolver: use logging.Leveled
This moves the resover client library to use logging.Leveled instead of
an ad-hoc logger interface.
By now having multiple level of logs, and by defaulting metroctl to show
errors and warnings, this should fix #302.
Change-Id: I7cae1cf1be377ec824ad46ea1da1b23b46e01903
Reviewed-on: https://review.monogon.dev/c/monogon/+/3432
Reviewed-by: Lorenz Brun <lorenz@monogon.tech>
Tested-by: Jenkins CI
diff --git a/metropolis/cli/metroctl/BUILD.bazel b/metropolis/cli/metroctl/BUILD.bazel
index 2b53acf..6e75400 100644
--- a/metropolis/cli/metroctl/BUILD.bazel
+++ b/metropolis/cli/metroctl/BUILD.bazel
@@ -36,6 +36,7 @@
visibility = ["//visibility:private"],
deps = [
"//go/clitable",
+ "//go/logging",
"//metropolis/cli/flagdefs",
"//metropolis/cli/metroctl/core",
"//metropolis/node",
diff --git a/metropolis/cli/metroctl/core/BUILD.bazel b/metropolis/cli/metroctl/core/BUILD.bazel
index e65a8a7..3a599a7 100644
--- a/metropolis/cli/metroctl/core/BUILD.bazel
+++ b/metropolis/cli/metroctl/core/BUILD.bazel
@@ -12,6 +12,7 @@
importpath = "source.monogon.dev/metropolis/cli/metroctl/core",
visibility = ["//visibility:public"],
deps = [
+ "//go/logging",
"//metropolis/node",
"//metropolis/node/core/curator/proto/api",
"//metropolis/node/core/rpc",
diff --git a/metropolis/cli/metroctl/core/config.go b/metropolis/cli/metroctl/core/config.go
index d119883..d22dd9a 100644
--- a/metropolis/cli/metroctl/core/config.go
+++ b/metropolis/cli/metroctl/core/config.go
@@ -20,6 +20,7 @@
"k8s.io/client-go/tools/clientcmd"
clientapi "k8s.io/client-go/tools/clientcmd/api"
+ "source.monogon.dev/go/logging"
"source.monogon.dev/metropolis/node"
)
@@ -339,7 +340,7 @@
Endpoints []string
// ResolverLogger can be set to enable verbose logging of the Metropolis RPC
// resolver layer.
- ResolverLogger ResolverLogger
+ ResolverLogger logging.Leveled
// TOFU overrides the trust-on-first-use behaviour for CA certificates for the
// connection. If not set, TerminalTOFU is used which will interactively ask the
// user to accept a CA certificate using os.Stdin/Stdout.
diff --git a/metropolis/cli/metroctl/core/rpc.go b/metropolis/cli/metroctl/core/rpc.go
index a5aac60..91d5175 100644
--- a/metropolis/cli/metroctl/core/rpc.go
+++ b/metropolis/cli/metroctl/core/rpc.go
@@ -18,8 +18,6 @@
"source.monogon.dev/metropolis/proto/api"
)
-type ResolverLogger func(format string, args ...interface{})
-
func DialOpts(ctx context.Context, c *ConnectOptions) ([]grpc.DialOption, error) {
var opts []grpc.DialOption
if c.ProxyServer != "" {
diff --git a/metropolis/cli/metroctl/main.go b/metropolis/cli/metroctl/main.go
index cdc4947..fcdbccd 100644
--- a/metropolis/cli/metroctl/main.go
+++ b/metropolis/cli/metroctl/main.go
@@ -3,12 +3,13 @@
import (
"context"
"crypto/x509"
- "log"
+ "os"
"path/filepath"
"github.com/adrg/xdg"
"github.com/spf13/cobra"
+ "source.monogon.dev/go/logging"
"source.monogon.dev/metropolis/cli/metroctl/core"
)
@@ -61,14 +62,6 @@
rootCmd.PersistentFlags().BoolVar(&flags.acceptAnyCA, "insecure-accept-and-persist-first-encountered-ca", false, "Accept the first encountered CA while connecting as the trusted CA for future metroctl connections with this config path. This is very insecure and should only be used for testing.")
}
-// rpcLogger passes through the cluster resolver logs, if "--verbose" flag was
-// used.
-func rpcLogger(f string, args ...interface{}) {
- if flags.verbose {
- log.Printf("resolver: "+f, args...)
- }
-}
-
func main() {
cobra.CheckErr(rootCmd.Execute())
}
@@ -86,11 +79,15 @@
if flags.acceptAnyCA {
tofu = &acceptall{}
}
+ logger := logging.NewWriterBackend(os.Stderr)
+ if !flags.verbose {
+ logger.MinimumSeverity = logging.WARNING
+ }
return &core.ConnectOptions{
ConfigPath: flags.configPath,
ProxyServer: flags.proxyAddr,
Endpoints: flags.clusterEndpoints,
- ResolverLogger: rpcLogger,
+ ResolverLogger: logger,
TOFU: tofu,
}
}
diff --git a/metropolis/node/core/cluster/cluster_join.go b/metropolis/node/core/cluster/cluster_join.go
index 18cfa4e..112b463 100644
--- a/metropolis/node/core/cluster/cluster_join.go
+++ b/metropolis/node/core/cluster/cluster_join.go
@@ -42,9 +42,7 @@
// long-term resolver.
rctx, rctxC := context.WithCancel(ctx)
defer rctxC()
- r := resolver.New(rctx, resolver.WithoutCuratorUpdater(), resolver.WithLogger(func(f string, args ...interface{}) {
- supervisor.Logger(ctx).WithAddedStackDepth(1).Infof(f, args...)
- }))
+ r := resolver.New(rctx, resolver.WithoutCuratorUpdater(), resolver.WithLogger(supervisor.Logger(ctx)))
addedNodes := 0
for _, node := range cd.Nodes {
if len(node.Addresses) == 0 {
diff --git a/metropolis/node/core/cluster/cluster_register.go b/metropolis/node/core/cluster/cluster_register.go
index 2175f04..5df7448 100644
--- a/metropolis/node/core/cluster/cluster_register.go
+++ b/metropolis/node/core/cluster/cluster_register.go
@@ -69,9 +69,7 @@
// long-term resolver.
rctx, rctxC := context.WithCancel(ctx)
defer rctxC()
- r := resolver.New(rctx, resolver.WithoutCuratorUpdater(), resolver.WithLogger(func(f string, args ...interface{}) {
- supervisor.Logger(ctx).WithAddedStackDepth(1).Infof(f, args...)
- }))
+ r := resolver.New(rctx, resolver.WithoutCuratorUpdater(), resolver.WithLogger(supervisor.Logger(ctx)))
addedNodes := 0
for _, node := range register.ClusterDirectory.Nodes {
if len(node.Addresses) == 0 {
diff --git a/metropolis/node/core/main.go b/metropolis/node/core/main.go
index e675f87..f737bd6 100644
--- a/metropolis/node/core/main.go
+++ b/metropolis/node/core/main.go
@@ -141,9 +141,7 @@
ctxS, ctxC := context.WithCancel(context.Background())
// Make node-wide cluster resolver.
- res := resolver.New(ctxS, resolver.WithLogger(func(f string, args ...interface{}) {
- lt.MustLeveledFor("resolver").WithAddedStackDepth(1).Infof(f, args...)
- }))
+ res := resolver.New(ctxS, resolver.WithLogger(lt.MustLeveledFor("resolver")))
// Function which performs core, one-way initialization of the node. This means
// waiting for the network, starting the cluster manager, and then starting all
diff --git a/metropolis/node/core/rpc/resolver/BUILD.bazel b/metropolis/node/core/rpc/resolver/BUILD.bazel
index 4ba9c9f..6438c62 100644
--- a/metropolis/node/core/rpc/resolver/BUILD.bazel
+++ b/metropolis/node/core/rpc/resolver/BUILD.bazel
@@ -10,6 +10,7 @@
importpath = "source.monogon.dev/metropolis/node/core/rpc/resolver",
visibility = ["//visibility:public"],
deps = [
+ "//go/logging",
"//metropolis/node",
"//metropolis/node/core/curator/proto/api",
"//metropolis/node/core/curator/watcher",
@@ -26,6 +27,7 @@
srcs = ["resolver_test.go"],
embed = [":resolver"],
deps = [
+ "//go/logging",
"//metropolis/node/core/curator/proto/api",
"//metropolis/node/core/rpc",
"//metropolis/proto/api",
diff --git a/metropolis/node/core/rpc/resolver/resolver.go b/metropolis/node/core/rpc/resolver/resolver.go
index 88d95d7..316c319 100644
--- a/metropolis/node/core/rpc/resolver/resolver.go
+++ b/metropolis/node/core/rpc/resolver/resolver.go
@@ -13,9 +13,11 @@
"google.golang.org/grpc"
"google.golang.org/grpc/keepalive"
+ "source.monogon.dev/go/logging"
common "source.monogon.dev/metropolis/node"
- apb "source.monogon.dev/metropolis/node/core/curator/proto/api"
"source.monogon.dev/metropolis/node/core/curator/watcher"
+
+ apb "source.monogon.dev/metropolis/node/core/curator/proto/api"
cpb "source.monogon.dev/metropolis/proto/common"
)
@@ -82,7 +84,7 @@
// logger, if set, will be called with fmt.Sprintf-like arguments containing
// debug logs from the running ClusterResolver, subordinate watchers and
// updaters.
- logger func(f string, args ...interface{})
+ logger logging.Leveled
// noCuratorUpdater makes the resolver not run a curator updater. This is used
// in one-shot resolvers which are given an ahead-of-time list of curators to
@@ -97,7 +99,7 @@
r := &Resolver{
reqC: make(chan *request),
ctx: ctx,
- logger: func(string, ...interface{}) {},
+ logger: logging.NewFunctionBackend(func(severity logging.Severity, msg string) {}),
}
for _, opt := range opts {
opt(r)
@@ -109,9 +111,9 @@
// ResolverOption are passed to a Resolver being created.
type ResolverOption func(r *Resolver)
-// WithLogger configures a given function as the logger of the resolver. The
-// function should take a printf-style format string and arguments.
-func WithLogger(logger func(f string, args ...interface{})) ResolverOption {
+// WithLogger sets the logger that the resolver will use. If not configured, the
+// resolver will silently block on errors!
+func WithLogger(logger logging.Leveled) ResolverOption {
return func(r *Resolver) {
r.logger = logger
}
@@ -288,8 +290,8 @@
msg = append(msg, fmt.Sprintf("leader: %s/%s", dbg.leader.nodeID, dbg.leader.endpoint.endpoint))
}
- r.logger("CURUPDATE: error in loop: %v, retrying in %s...", err, t.String())
- r.logger("CURUPDATE: processor state: %s", strings.Join(msg, ", "))
+ r.logger.Errorf("CURUPDATE: error in loop: %v, retrying in %s...", err, t.String())
+ r.logger.Infof("CURUPDATE: processor state: %s", strings.Join(msg, ", "))
})
}
@@ -304,7 +306,7 @@
err := backoff.RetryNotify(func() error {
curMap := r.curatorMap()
for _, endpoint := range curMap.candidates() {
- r.logger("FINDLEADER: trying via %s...", endpoint)
+ r.logger.Infof("FINDLEADER: trying via %s...", endpoint)
ok := r.watchLeaderVia(ctx, endpoint, opts)
if ok {
bo.Reset()
@@ -312,9 +314,9 @@
}
return fmt.Errorf("out of endpoints")
}, backoff.WithContext(bo, ctx), func(err error, t time.Duration) {
- r.logger("FINDLEADER: error in loop: %v, retrying in %s...", err, t.String())
+ r.logger.Errorf("FINDLEADER: error in loop: %v, retrying in %s...", err, t.String())
})
- r.logger("FINDLEADER: exiting: %v", err)
+ r.logger.Infof("FINDLEADER: exiting: %v", err)
return err
}
@@ -339,7 +341,7 @@
}))
cl, err := grpc.Dial(via, opts...)
if err != nil {
- r.logger("WATCHLEADER: dialing %s failed: %v", via, err)
+ r.logger.Infof("WATCHLEADER: dialing %s failed: %v", via, err)
return false
}
defer cl.Close()
@@ -347,22 +349,22 @@
cur, err := cpl.GetCurrentLeader(ctx, &apb.GetCurrentLeaderRequest{})
if err != nil {
- r.logger("WATCHLEADER: failed to retrieve current leader from %s: %v", via, err)
+ r.logger.Warningf("WATCHLEADER: failed to retrieve current leader from %s: %v", via, err)
return false
}
ok := false
for {
- r.logger("WATCHLEADER: receiving...")
+ r.logger.Infof("WATCHLEADER: receiving...")
leaderInfo, err := cur.Recv()
if err == io.EOF {
- r.logger("WATCHLEADER: connection with %s closed", via)
+ r.logger.Infof("WATCHLEADER: connection with %s closed", via)
return ok
}
if err != nil {
- r.logger("WATCHLEADER: connection with %s failed: %v", via, err)
+ r.logger.Infof("WATCHLEADER: connection with %s failed: %v", via, err)
return ok
}
- r.logger("WATCHLEADER: received: %+v", leaderInfo)
+ r.logger.Infof("WATCHLEADER: received: %+v", leaderInfo)
curMap := r.curatorMap()
@@ -373,7 +375,7 @@
}
if leaderInfo.LeaderNodeId == "" {
- r.logger("WATCHLEADER: %s does not know the leader, trying next", viaID)
+ r.logger.Warningf("WATCHLEADER: %s does not know the leader, trying next", viaID)
return false
}
endpoint := ""
@@ -385,13 +387,13 @@
}
} else {
if leaderInfo.LeaderPort == 0 {
- r.logger("WATCHLEADER: %s knows the leader's host (%s), but not its' port", viaID, leaderInfo.LeaderHost)
+ r.logger.Warningf("WATCHLEADER: %s knows the leader's host (%s), but not its' port", viaID, leaderInfo.LeaderHost)
return false
}
endpoint = net.JoinHostPort(leaderInfo.LeaderHost, fmt.Sprintf("%d", leaderInfo.LeaderPort))
}
- r.logger("WATCHLEADER: got new leader: %s (%s) via %s", leaderInfo.LeaderNodeId, endpoint, viaID)
+ r.logger.Infof("WATCHLEADER: got new leader: %s (%s) via %s", leaderInfo.LeaderNodeId, endpoint, viaID)
select {
case <-ctx.Done():
diff --git a/metropolis/node/core/rpc/resolver/resolver_test.go b/metropolis/node/core/rpc/resolver/resolver_test.go
index e0f67ef..075fd09 100644
--- a/metropolis/node/core/rpc/resolver/resolver_test.go
+++ b/metropolis/node/core/rpc/resolver/resolver_test.go
@@ -6,6 +6,7 @@
"fmt"
"log"
"net"
+ "os"
"strconv"
"sync"
"testing"
@@ -15,11 +16,13 @@
"google.golang.org/grpc"
"google.golang.org/grpc/credentials"
- ipb "source.monogon.dev/metropolis/node/core/curator/proto/api"
+ "source.monogon.dev/go/logging"
"source.monogon.dev/metropolis/node/core/rpc"
+ "source.monogon.dev/metropolis/test/util"
+
+ ipb "source.monogon.dev/metropolis/node/core/curator/proto/api"
apb "source.monogon.dev/metropolis/proto/api"
cpb "source.monogon.dev/metropolis/proto/common"
- "source.monogon.dev/metropolis/test/util"
)
// fakeCuratorClusterAware is a fake curator implementation that has a vague
@@ -164,9 +167,7 @@
// Create our DUT resolver.
r := New(ctx)
- r.logger = func(f string, args ...interface{}) {
- log.Printf(f, args...)
- }
+ r.logger = logging.NewWriterBackend(os.Stdout)
creds := credentials.NewTLS(&tls.Config{
Certificates: []tls.Certificate{eph.Manager},
diff --git a/metropolis/test/launch/BUILD.bazel b/metropolis/test/launch/BUILD.bazel
index c217b35..7c6c6d0 100644
--- a/metropolis/test/launch/BUILD.bazel
+++ b/metropolis/test/launch/BUILD.bazel
@@ -39,6 +39,7 @@
"xNodeImagePath": "$(rlocationpath //metropolis/node:image )",
},
deps = [
+ "//go/logging",
"//go/qcow2",
"//metropolis/cli/metroctl/core",
"//metropolis/node",
diff --git a/metropolis/test/launch/cluster.go b/metropolis/test/launch/cluster.go
index e0a0473..8be6736 100644
--- a/metropolis/test/launch/cluster.go
+++ b/metropolis/test/launch/cluster.go
@@ -41,6 +41,7 @@
apb "source.monogon.dev/metropolis/proto/api"
cpb "source.monogon.dev/metropolis/proto/common"
+ "source.monogon.dev/go/logging"
"source.monogon.dev/go/qcow2"
metroctl "source.monogon.dev/metropolis/cli/metroctl/core"
"source.monogon.dev/metropolis/node"
@@ -199,9 +200,9 @@
func (c *Cluster) CuratorClient() (*grpc.ClientConn, error) {
if c.authClient == nil {
authCreds := rpc.NewAuthenticatedCredentials(c.Owner, rpc.WantInsecure())
- r := resolver.New(c.ctxT, resolver.WithLogger(func(f string, args ...interface{}) {
- launch.Log("Cluster: client resolver: %s", fmt.Sprintf(f, args...))
- }))
+ r := resolver.New(c.ctxT, resolver.WithLogger(logging.NewFunctionBackend(func(severity logging.Severity, msg string) {
+ launch.Log("Cluster: client resolver: %s: %s", severity, msg)
+ })))
for _, n := range c.NodeIDs {
ep, err := resolver.NodeWithDefaultPort(n)
if err != nil {