m/p/supervisor: implement sub-loggers
This permits logging from a runnable into a logtree sub-DN that is not
backed by an actualy child runnable. For example, 'root.foo' can request
a SubLogger with name 'bar' to emit logs into 'root.foo.bar'.
This is in preparation for logging RPC calls within supervised
runnables, but can also come in handy in other situations where we'd
like to log to separete 'topics' within a single runnable.
This breaks 1:1 correspondence between logtree DNs and supervisor DNs.
An alternative would be to introduce extra 'tags'/'topics' eg
root.foo:bar, but that would require encoding extra logic to the
logtree. However, that would perhaps allow us to introduce higher
cardinality child loggers, with a logger per RPC. We'll have to consider
this at some later point.
Let's see where this takes us, there's a chance we'll roll this
back if it's too confusing from an UX point of view.
Change-Id: Ibdee5c2b400bb8fce76b0a4f781914748793db0e
Reviewed-on: https://review.monogon.dev/c/monogon/+/536
Reviewed-by: Leopold Schabel <leo@nexantic.com>
diff --git a/metropolis/pkg/supervisor/BUILD.bazel b/metropolis/pkg/supervisor/BUILD.bazel
index 2062522..fdac70f 100644
--- a/metropolis/pkg/supervisor/BUILD.bazel
+++ b/metropolis/pkg/supervisor/BUILD.bazel
@@ -22,4 +22,5 @@
name = "go_default_test",
srcs = ["supervisor_test.go"],
embed = [":go_default_library"],
+ deps = ["//metropolis/pkg/logtree:go_default_library"],
)
diff --git a/metropolis/pkg/supervisor/supervisor.go b/metropolis/pkg/supervisor/supervisor.go
index 77c2d02..ef7b909 100644
--- a/metropolis/pkg/supervisor/supervisor.go
+++ b/metropolis/pkg/supervisor/supervisor.go
@@ -23,6 +23,7 @@
import (
"context"
+ "fmt"
"io"
"sync"
@@ -160,3 +161,29 @@
defer unlock()
return node.sup.logtree.MustRawFor(logtree.DN(node.dn()))
}
+
+// SubLogger returns a LeveledLogger for a given name. The name is used to
+// placed that logger within the logtree hierarchy. For example, if the
+// runnable `root.foo` requests a SubLogger for name `bar`, the returned logger
+// will log to `root.foo.bar` in the logging tree.
+//
+// An error is returned if the given name is invalid or conflicts with a child
+// runnable of the current runnable. In addition, whenever a node uses a
+// sub-logger with a given name, that name also becomes unavailable for use as
+// a child runnable (no runnable and sub-logger may ever log into the same
+// logtree DN).
+func SubLogger(ctx context.Context, name string) (logtree.LeveledLogger, error) {
+ node, unlock := fromContext(ctx)
+ defer unlock()
+
+ if _, ok := node.children[name]; ok {
+ return nil, fmt.Errorf("name %q already in use by child runnable", name)
+ }
+ if !reNodeName.MatchString(name) {
+ return nil, fmt.Errorf("sub-logger name %q is invalid", name)
+ }
+ node.reserved[name] = true
+
+ dn := fmt.Sprintf("%s.%s", node.dn(), name)
+ return node.sup.logtree.LeveledFor(logtree.DN(dn))
+}
diff --git a/metropolis/pkg/supervisor/supervisor_node.go b/metropolis/pkg/supervisor/supervisor_node.go
index a3bf5e4..4fb2ddb 100644
--- a/metropolis/pkg/supervisor/supervisor_node.go
+++ b/metropolis/pkg/supervisor/supervisor_node.go
@@ -43,6 +43,10 @@
// Children of this tree. This is represented by a map keyed from child
// node names, for easy access.
children map[string]*node
+ // Reserved nodes that may not be used as child names. This is currently
+ // used by sub-loggers (see SubLogger function), preventing a sub-logger
+ // name from colliding with a node name.
+ reserved map[string]bool
// Supervision groups. Each group is a set of names of children. Sets, and
// as such groups, don't overlap between each other. A supervision group
// indicates that if any child within that group fails, all others should
@@ -199,6 +203,7 @@
// Clear children and state
n.state = nodeStateNew
n.children = make(map[string]*node)
+ n.reserved = make(map[string]bool)
n.groups = nil
// The node is now ready to be scheduled.
@@ -244,6 +249,9 @@
if _, ok := n.children[name]; ok {
return fmt.Errorf("runnable %q already exists", name)
}
+ if _, ok := n.reserved[name]; ok {
+ return fmt.Errorf("runnable %q would shadow reserved name (eg. sub-logger)", name)
+ }
}
// Create child nodes.
diff --git a/metropolis/pkg/supervisor/supervisor_test.go b/metropolis/pkg/supervisor/supervisor_test.go
index 7f2ffa4..a735de4 100644
--- a/metropolis/pkg/supervisor/supervisor_test.go
+++ b/metropolis/pkg/supervisor/supervisor_test.go
@@ -21,6 +21,8 @@
"fmt"
"testing"
"time"
+
+ "source.monogon.dev/metropolis/pkg/logtree"
)
// waitSettle waits until the supervisor reaches a 'settled' state - ie., one
@@ -533,6 +535,87 @@
oneTest()
}
+// TestSubLoggers exercises the reserved/sub-logger functionality of runnable
+// nodes. It ensures a sub-logger and runnable cannot have colliding names, and
+// that logging actually works.
+func TestSubLoggers(t *testing.T) {
+ ctx, ctxC := context.WithCancel(context.Background())
+ defer ctxC()
+
+ errCA := make(chan error)
+ errCB := make(chan error)
+ lt := logtree.New()
+ New(ctx, func(ctx context.Context) error {
+ err := RunGroup(ctx, map[string]Runnable{
+ // foo will first create a sublogger, then attempt to create a
+ // colliding runnable.
+ "foo": func(ctx context.Context) error {
+ sl, err := SubLogger(ctx, "dut")
+ if err != nil {
+ errCA <- fmt.Errorf("creating sub-logger: %w", err)
+ return nil
+ }
+ sl.Infof("hello from foo.dut")
+ err = Run(ctx, "dut", runnableBecomesHealthy(nil, nil))
+ if err == nil {
+ errCA <- fmt.Errorf("creating colliding runnable should have failed")
+ return nil
+ }
+ Signal(ctx, SignalHealthy)
+ Signal(ctx, SignalDone)
+ errCA <- nil
+ return nil
+ },
+ })
+ if err != nil {
+ return err
+ }
+ _, err = SubLogger(ctx, "foo")
+ if err == nil {
+ errCB <- fmt.Errorf("creating collising sub-logger should have failed")
+ return nil
+ }
+ Signal(ctx, SignalHealthy)
+ Signal(ctx, SignalDone)
+ errCB <- nil
+ return nil
+ }, WithPropagatePanic, WithExistingLogtree(lt))
+
+ err := <-errCA
+ if err != nil {
+ t.Fatalf("from root.foo: %v", err)
+ }
+ err = <-errCB
+ if err != nil {
+ t.Fatalf("from root: %v", err)
+ }
+
+ // Now enure that the expected message appears in the logtree.
+ dn := logtree.DN("root.foo.dut")
+ r, err := lt.Read(dn, logtree.WithBacklog(logtree.BacklogAllAvailable))
+ if err != nil {
+ t.Fatalf("logtree read failed: %v", err)
+ }
+ defer r.Close()
+ found := false
+ for _, e := range r.Backlog {
+ if e.DN != dn {
+ continue
+ }
+ if e.Leveled == nil {
+ continue
+ }
+ if e.Leveled.MessagesJoined() != "hello from foo.dut" {
+ continue
+ }
+ found = true
+ break
+ }
+ if !found {
+ t.Fatalf("did not find expected logline in %s", dn)
+ }
+}
+
func ExampleNew() {
// Minimal runnable that is immediately done.
childC := make(chan struct{})