diff --git a/README.md b/README.md index ae69b28..78be6c8 100644 --- a/README.md +++ b/README.md @@ -29,4 +29,5 @@ Deprecations ------------ - `csrf/` - just use SameSite cookies -- `crypto/pkencryptedstream/` - provides confidentiality, but is malleable (ciphertext is not authenticated). Use Age instead. +- [crypto/pkencryptedstream/](crypto/pkencryptedstream/) - provides confidentiality, but is malleable (ciphertext is not authenticated). Use Age instead. +- [log/logex/](log/logex/) - use [log/slog](https://go.dev/blog/slog) i.e. the offial solution to pain which our package addressed. diff --git a/app/cli/DEPRECATED.go b/app/cli/DEPRECATED.go new file mode 100644 index 0000000..db085e4 --- /dev/null +++ b/app/cli/DEPRECATED.go @@ -0,0 +1,33 @@ +package cli + +import ( + "context" + "log" + + "github.com/function61/gokit/log/logex" + "github.com/function61/gokit/os/osutil" + "github.com/spf13/cobra" +) + +// below intended to be deprecated soon + +func RunnerNoArgs(run func(ctx context.Context, logger *log.Logger) error) func(*cobra.Command, []string) { + return func(_ *cobra.Command, _ []string) { + logger := logex.StandardLogger() + + osutil.ExitIfError(run( + osutil.CancelOnInterruptOrTerminate(logger), + logger)) + } +} + +func Runner(run func(ctx context.Context, args []string, logger *log.Logger) error) func(*cobra.Command, []string) { + return func(_ *cobra.Command, args []string) { + logger := logex.StandardLogger() + + osutil.ExitIfError(run( + osutil.CancelOnInterruptOrTerminate(logger), + args, + logger)) + } +} diff --git a/app/cli/cobrawrappers.go b/app/cli/cobrawrappers.go index 3fe6f9f..bccee6d 100644 --- a/app/cli/cobrawrappers.go +++ b/app/cli/cobrawrappers.go @@ -1,32 +1,56 @@ -// Cobra wrappers to wrap awkward API (no exit codes and no built-in "ctrl-c => cancel" support) +// Making CLI commands have some quality without too much boilerplate. package cli import ( "context" - "log" + "os" - "github.com/function61/gokit/log/logex" + "github.com/function61/gokit/app/dynversion" "github.com/function61/gokit/os/osutil" "github.com/spf13/cobra" + "github.com/spf13/pflag" ) -func RunnerNoArgs(run func(ctx context.Context, logger *log.Logger) error) func(*cobra.Command, []string) { - return func(_ *cobra.Command, _ []string) { - logger := logex.StandardLogger() +// wraps the `Execute()` call of the command to inject boilerplate details like `Use`, `Version` and +// handling of error to `Command.Execute()` (such as flag validation, missing command etc.) +func Execute(app *cobra.Command) { + // dirty to mutate after-the-fact - osutil.ExitIfError(run( - osutil.CancelOnInterruptOrTerminate(logger), - logger)) - } + app.Use = os.Args[0] + app.Version = dynversion.Version + // hide the default "completion" subcommand from polluting UX (it can still be used). https://github.com/spf13/cobra/issues/1507 + app.CompletionOptions = cobra.CompletionOptions{HiddenDefaultCmd: true} + + AddLogLevelControls(app.Flags()) + + osutil.ExitIfError(app.Execute()) } -func Runner(run func(ctx context.Context, args []string, logger *log.Logger) error) func(*cobra.Command, []string) { +// fixes problems of cobra commands' bare run callbacks with regards to application quality: +// 1. logging not configured +// 2. no interrupt handling +// 3. no error handling +func WrapRun(run func(ctx context.Context, args []string) error) func(*cobra.Command, []string) { return func(_ *cobra.Command, args []string) { - logger := logex.StandardLogger() + // handle logging + configureLogging() + + // handle interrupts + ctx := notifyContextInterruptOrTerminate() - osutil.ExitIfError(run( - osutil.CancelOnInterruptOrTerminate(logger), - args, - logger)) + // run the actual code (jump from CLI context to higher-level application context) + // this can be kinda read as: + // output = logic(input) + err := run(ctx, args) + + // handle errors + osutil.ExitIfError(err) } } + +// adds CLI flags that control the logging level +func AddLogLevelControls(flags *pflag.FlagSet) { + flags.BoolVarP(&logLevelVerbose, "verbose", "v", logLevelVerbose, "Include debug-level logs") + + // TODO: maybe add a "quiet" level as well +} diff --git a/app/cli/logging.go b/app/cli/logging.go new file mode 100644 index 0000000..a4a90ee --- /dev/null +++ b/app/cli/logging.go @@ -0,0 +1,82 @@ +package cli + +import ( + "log/slog" + "os" + "time" + + "github.com/lmittmann/tint" + "github.com/mattn/go-isatty" +) + +var ( + logLevelVerbose = false + discardAttr = slog.Attr{} // zero `Attr` means discard +) + +func configureLogging() { + logLevel := func() slog.Level { + if logLevelVerbose { + return slog.LevelDebug + } else { + return slog.LevelInfo + } + }() + + addSource := func() bool { + if logLevelVerbose { + return true + } else { + return false + } + }() + + errorStream := os.Stderr + errorStreamIsUserTerminal := isatty.IsTerminal(errorStream.Fd()) + + logHandler := func() slog.Handler { + if errorStreamIsUserTerminal { // output format optimized to looking at from terminal + return tint.NewHandler(errorStream, &tint.Options{ + Level: logLevel, + AddSource: addSource, + TimeFormat: time.TimeOnly, // not using freedom time (`time.Kitchen`) + // intentionally not giving `ReplaceAttr` because for terminal we can always include times + }) + } else { // "production" log output + logAttrReplacer := timeRemoverAttrReplacer + if !logsShouldOmitTime() { + logAttrReplacer = nil + } + + return slog.NewTextHandler(errorStream, &slog.HandlerOptions{ + Level: logLevel, + AddSource: addSource, + ReplaceAttr: logAttrReplacer, + }) + } + }() + + // expecting the apps to just use the global logger + slog.SetDefault(slog.New(logHandler)) +} + +// if our logs are redirected to journald or similar which already add timestamps don't add double timestamps +func logsShouldOmitTime() bool { + // "This permits invoked processes to safely detect whether their standard output or standard + // error output are connected to the journal." + // https://www.freedesktop.org/software/systemd/man/systemd.exec.html#%24JOURNAL_STREAM + systemdJournal := os.Getenv("JOURNAL_STREAM") != "" + + // explicitly asked, e.g. set by orchestrator when running in Docker with log redirection taken care of + explicitSuppress := os.Getenv("LOGGER_SUPPRESS_TIMESTAMPS") == "1" + + return systemdJournal || explicitSuppress +} + +func timeRemoverAttrReplacer(groups []string, a slog.Attr) slog.Attr { + if a.Key == slog.TimeKey { + return discardAttr + } else { + return a + } +} diff --git a/app/cli/signalnotifycontext.go b/app/cli/signalnotifycontext.go new file mode 100644 index 0000000..969757d --- /dev/null +++ b/app/cli/signalnotifycontext.go @@ -0,0 +1,38 @@ +package cli + +import ( + "context" + "log/slog" + "os" + "os/signal" + "syscall" +) + +// same as `signal.NotifyContext()` but logs output when got signal to give useful feedback to user +// that we have begun teardown. this feedback becomes extremely important if the teardown process +// takes time or gets stuck. +func notifyContextInterruptOrTerminate() context.Context { + ctx, cancel := context.WithCancel(context.Background()) + + // need a buffered channel because the sending side is non-blocking + ch := make(chan os.Signal, 1) + + // "The SIGINT signal is sent to a process by its controlling terminal when a user wishes to interrupt the process" + // "The SIGTERM signal is sent to a process to request its termination" + // "SIGINT is nearly identical to SIGTERM" + // https://en.wikipedia.org/wiki/Signal_(IPC) + signal.Notify(ch, syscall.SIGINT, syscall.SIGTERM) + + go func() { + slog.Info("STOPPING. (If stuck, send sig again to force exit.)", "signal", <-ch) + + // stop accepting signals on the channel. this undoes the effect of this func, + // and thus makes the process terminate on the next received signal (so you can stop + // your program if the cleanup code gets stuck) + signal.Stop(ch) + + cancel() + }() + + return ctx +} diff --git a/go.mod b/go.mod index ecd007d..712135c 100644 --- a/go.mod +++ b/go.mod @@ -24,6 +24,7 @@ require ( github.com/golang/protobuf v1.3.2 // indirect github.com/inconshreveable/mousetrap v1.0.1 // indirect github.com/jmespath/go-jmespath v0.0.0-20180206201540-c2b33e8439af // indirect + github.com/lmittmann/tint v1.0.5 // indirect github.com/matttproud/golang_protobuf_extensions v1.0.1 // indirect github.com/pkg/errors v0.8.1 // indirect github.com/prometheus/client_model v0.2.0 // indirect diff --git a/go.sum b/go.sum index b8f772e..fa8455f 100644 --- a/go.sum +++ b/go.sum @@ -45,6 +45,8 @@ github.com/json-iterator/go v1.1.7/go.mod h1:KdQUCv79m/52Kvf8AW2vK1V8akMuk1QjK/u github.com/julienschmidt/httprouter v1.2.0/go.mod h1:SYymIcj16QtmaHHD7aYtjjsJG7VTCxuUUipMqKk8s4w= github.com/konsorten/go-windows-terminal-sequences v1.0.1/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ= github.com/kr/logfmt v0.0.0-20140226030751-b84e30acd515/go.mod h1:+0opPa2QZZtGFBFZlji/RkVcI2GknAs/DXo4wKdlNEc= +github.com/lmittmann/tint v1.0.5 h1:NQclAutOfYsqs2F1Lenue6OoWCajs5wJcP3DfWVpePw= +github.com/lmittmann/tint v1.0.5/go.mod h1:HIS3gSy7qNwGCj+5oRjAutErFBl4BzdQP6cJZ0NfMwE= github.com/mattn/go-isatty v0.0.20 h1:xfD0iDuEKnDkl03q4limB+vH+GxLEtL/jb4xVJSWWEY= github.com/mattn/go-isatty v0.0.20/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y= github.com/matttproud/golang_protobuf_extensions v1.0.1 h1:4hp9jkHxhMHkqkrB3Ix0jegS5sx/RkqARlsWZ6pIwiU=