Merge pull request #39 from pior/logs

Refactor logging

logger.go

@@ -5,16 +5,25 @@ import (
 	"os"
 )
 
-var log Logger = stdlog.New(os.Stdout, "[RUNNABLE] ", stdlog.Ldate|stdlog.Ltime)
+var log Logger
+
+func init() {
+	SetLogger(nil)
+}
 
 // SetLogger replaces the default logger with a runnable.Logger.
 func SetLogger(l Logger) {
 	if l == nil {
-		panic("Runnable: logger cannot be nil")
+		l = stdlog.New(os.Stdout, "[RUNNABLE] ", stdlog.Ldate|stdlog.Ltime)
 	}
 	log = l
 }
 
 type Logger interface {
-	Printf(format string, args ...interface{})
+	Printf(format string, args ...any)
+}
+
+// Log logs a formatted message, prefixed by the runnable chain.
+func Log(self any, format string, args ...any) {
+	log.Printf(findName(self)+": "+format, args...)
 }

manager.go

@@ -80,15 +80,15 @@ func (m *manager) Run(ctx context.Context) error {
 	// run the runnables in Go routines.
 	for _, c := range m.containers {
 		c.launch(completedChan, dying)
-		log.Printf("manager: %s started", c.name())
+		Log(m, "%s started", c.name())
 	}
 
 	// block until group is cancelled, or a runnable dies.
 	select {
 	case <-ctx.Done():
-		log.Printf("manager: starting shutdown (context cancelled)")
+		Log(m, "starting shutdown (context cancelled)")
 	case c := <-dying:
-		log.Printf("manager: starting shutdown (%s died)", c.name())
+		Log(m, "starting shutdown (%s died)", c.name())
 	}
 
 	// starting shutdown
@@ -117,7 +117,7 @@ func (m *manager) Run(ctx context.Context) error {
 			}
 
 			if !cancelled.contains(c) {
-				log.Printf("manager: %s cancelled", c.name())
+				Log(m, "%s cancelled", c.name())
 				c.shutdown()
 				cancelled.insert(c)
 			}
@@ -129,9 +129,9 @@ func (m *manager) Run(ctx context.Context) error {
 			completed.insert(c)
 
 			if c.err == nil || errors.Is(c.err, context.Canceled) {
-				log.Printf("manager: %s stopped", c.name())
+				Log(m, "%s stopped", c.name())
 			} else {
-				log.Printf("manager: %s stopped with error: %+v", c.name(), c.err)
+				Log(m, "%s stopped with error: %+v", c.name(), c.err)
 			}
 
 			if len(completed) == len(m.containers) {
@@ -146,15 +146,15 @@ func (m *manager) Run(ctx context.Context) error {
 	errs := []string{}
 	for _, c := range m.containers {
 		if !completed.contains(c) {
-			log.Printf("manager: %s is still running", c.name())
+			Log(m, "%s is still running", c.name())
 			errs = append(errs, fmt.Sprintf("%s is still running", c.name()))
 		}
 		if c.err != nil && !errors.Is(c.err, context.Canceled) {
 			errs = append(errs, fmt.Sprintf("%s crashed with %+v", c.name(), c.err))
 		}
 	}
 
-	log.Printf("manager: shutdown complete")
+	Log(m, "shutdown complete")
 
 	if len(errs) != 0 {
 		return fmt.Errorf("manager: %s", strings.Join(errs, ", "))

restart.go

@@ -29,9 +29,9 @@ func RestartCrashLimit(times int) RestartOption {
 }
 
 // RestartDelay sets the time waited before restarting the runnable after a successful execution.
-func RestartDelay(times time.Duration) RestartOption {
+func RestartDelay(delay time.Duration) RestartOption {
 	return func(cfg *restartConfig) {
-		cfg.restartDelay = times
+		cfg.restartDelay = delay
 	}
 }
 
@@ -65,6 +65,7 @@ func (r *restart) Run(ctx context.Context) error {
 	crashCount := 0
 
 	for {
+		Log(r, "starting (restart=%d crash=%d)", restartCount, crashCount)
 		err := r.runnable.Run(ctx)
 		isCrash := err != nil
 
@@ -73,12 +74,12 @@ func (r *restart) Run(ctx context.Context) error {
 		}
 
 		if r.cfg.restartLimit > 0 && restartCount >= r.cfg.restartLimit {
-			log.Printf("restart: not restarting (hit the restart limit: %d)", r.cfg.restartLimit)
+			Log(r, "not restarting (hit the restart limit: %d)", r.cfg.restartLimit)
 			return err
 		}
 
 		if r.cfg.crashLimit > 0 && crashCount >= r.cfg.crashLimit {
-			log.Printf("restart: not restarting (hit the crash limit: %d)", r.cfg.crashLimit)
+			Log(r, "not restarting (hit the crash limit: %d)", r.cfg.crashLimit)
 			return err
 		}
 

restart_test.go

@@ -8,6 +8,22 @@ import (
 	"github.com/stretchr/testify/require"
 )
 
+func ExampleRestart() {
+	ctx, cancel := initializeForExample()
+	defer cancel()
+
+	runnable := newDyingRunnable()
+
+	r := Restart(runnable, RestartCrashLimit(3))
+	_ = r.Run(ctx)
+
+	// Output:
+	// restart/dyingRunnable: starting (restart=0 crash=0)
+	// restart/dyingRunnable: starting (restart=1 crash=1)
+	// restart/dyingRunnable: starting (restart=2 crash=2)
+	// restart/dyingRunnable: not restarting (hit the crash limit: 3)
+}
+
 func TestRestart_Cancellation(t *testing.T) {
 	r := Restart(newDummyRunnable())
 	AssertRunnableRespectCancellation(t, r, time.Millisecond*100)

server.go

@@ -22,7 +22,7 @@ func (r *httpServer) Run(ctx context.Context) error {
 	errChan := make(chan error)
 
 	go func() {
-		log.Printf("http_server: listening on %s", r.server.Addr)
+		Log(r, "listening on %s", r.server.Addr)
 		errChan <- r.server.ListenAndServe()
 	}()
 
@@ -31,11 +31,11 @@ func (r *httpServer) Run(ctx context.Context) error {
 
 	select {
 	case <-ctx.Done():
-		log.Printf("http_server: shutdown")
+		Log(r, "shutdown")
 		shutdownErr = r.shutdown()
 		err = <-errChan
 	case err = <-errChan:
-		log.Printf("http_server: shutdown (err: %s)", err)
+		Log(r, "shutdown (err: %s)", err)
 		shutdownErr = r.shutdown()
 	}
 

server_test.go

@@ -1,53 +1,41 @@
-package runnable_test
+package runnable
 
 import (
-	"context"
-	stdlog "log"
 	"net/http"
-	"os"
-	"time"
-
-	"github.com/pior/runnable"
 )
 
 func ExampleHTTPServer() {
-	runnable.SetLogger(stdlog.New(os.Stdout, "", 0))
+	ctx, cancel := initializeForExample()
+	defer cancel()
 
 	server := &http.Server{
 		Addr:    "127.0.0.1:8080",
 		Handler: http.NotFoundHandler(),
 	}
 
-	r := runnable.HTTPServer(server)
-
-	ctx := context.Background()
-	ctx, cancel := context.WithTimeout(ctx, time.Millisecond*100)
-	defer cancel()
+	r := HTTPServer(server)
 
 	_ = r.Run(ctx)
 
 	// Output:
-	// http_server: listening on 127.0.0.1:8080
-	// http_server: shutdown
+	// httpserver: listening on 127.0.0.1:8080
+	// httpserver: shutdown
 }
 
 func ExampleHTTPServer_error() {
-	runnable.SetLogger(stdlog.New(os.Stdout, "", 0))
+	ctx, cancel := initializeForExample()
+	defer cancel()
 
 	server := &http.Server{
 		Addr:    "INVALID",
 		Handler: http.NotFoundHandler(),
 	}
 
-	r := runnable.HTTPServer(server)
-
-	ctx := context.Background()
-	ctx, cancel := context.WithTimeout(ctx, time.Millisecond*1000)
-	defer cancel()
+	r := HTTPServer(server)
 
 	_ = r.Run(ctx)
 
 	// Output:
-	// http_server: listening on INVALID
-	// http_server: shutdown (err: listen tcp: address INVALID: missing port in address)
+	// httpserver: listening on INVALID
+	// httpserver: shutdown (err: listen tcp: address INVALID: missing port in address)
 }

signals.go

@@ -3,7 +3,7 @@ package runnable
 import (
 	"context"
 	"os"
-	"os/signal"
+	ossignal "os/signal"
 	"syscall"
 )
 
@@ -14,25 +14,25 @@ func Signal(runnable Runnable, signals ...os.Signal) Runnable {
 		signals = append(signals, syscall.SIGTERM)
 	}
 
-	return &signalRunnable{runnable, signals}
+	return &signal{runnable, signals}
 }
 
-type signalRunnable struct {
+type signal struct {
 	runnable Runnable
 	signals  []os.Signal
 }
 
-func (s *signalRunnable) Run(ctx context.Context) error {
+func (s *signal) Run(ctx context.Context) error {
 	ctx, cancelFunc := context.WithCancel(ctx)
 
 	sigChan := make(chan os.Signal, 1)
-	signal.Notify(sigChan, s.signals...)
+	ossignal.Notify(sigChan, s.signals...)
 
 	go func() {
-		defer signal.Reset(s.signals...)
+		defer ossignal.Reset(s.signals...)
 
 		sig := <-sigChan
-		log.Printf("signal: received signal %s", sig)
+		Log(s, "received signal %s", sig)
 		cancelFunc()
 	}()
 

testing_test.go

@@ -3,6 +3,8 @@ package runnable
 import (
 	"context"
 	"errors"
+	stdlog "log"
+	"os"
 	"testing"
 	"time"
 
@@ -17,8 +19,10 @@ func newDummyRunnable() *dummyRunnable {
 
 type dummyRunnable struct{}
 
-func (*dummyRunnable) Run(ctx context.Context) error {
+func (r *dummyRunnable) Run(ctx context.Context) error {
+	Log(r, "started")
 	<-ctx.Done()
+	Log(r, "stopped")
 	return ctx.Err()
 }
 
@@ -136,3 +140,12 @@ func cancelledContext() context.Context {
 	cancelFunc()
 	return ctx
 }
+
+func initializeForExample() (context.Context, func()) {
+	ctx := context.Background()
+	ctx, cancel := context.WithTimeout(ctx, 200*time.Millisecond)
+
+	SetLogger(stdlog.New(os.Stdout, "", 0))
+
+	return ctx, cancel
+}