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/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{})