insert restoreEnd event into deferred func

Separates the log level and log format.  This will allows
sdk consumers using `SeedLogger` to utilize JSON
format logs without sacrificing log level controls.

src/cmd/factory/factory.go

@@ -34,7 +34,7 @@ var oneDriveCmd = &cobra.Command{
 // ------------------------------------------------------------------------------------------
 
 func main() {
-	ctx, _ := logger.SeedLevel(context.Background(), logger.Development)
+	ctx, _ := logger.SeedLevel(context.Background(), logger.LLDebug, logger.LFText)
 	ctx = SetRootCmd(ctx, factoryCmd)
 
 	defer logger.Flush(ctx)

src/cmd/getM365/main.go

@@ -17,7 +17,7 @@ var rootCmd = &cobra.Command{
 }
 
 func main() {
-	ctx, _ := logger.SeedLevel(context.Background(), logger.Development)
+	ctx, _ := logger.SeedLevel(context.Background(), logger.LLDebug, logger.LFText)
 
 	ctx = SetRootCmd(ctx, rootCmd)
 	defer logger.Flush(ctx)

src/cmd/purge/purge.go

@@ -49,7 +49,7 @@ var ErrPurging = clues.New("not all items were successfully purged")
 // ------------------------------------------------------------------------------------------
 
 func main() {
-	ctx, _ := logger.SeedLevel(context.Background(), logger.Development)
+	ctx, _ := logger.SeedLevel(context.Background(), logger.LLDebug, logger.LFText)
 	ctx = SetRootCmd(ctx, purgeCmd)
 
 	defer logger.Flush(ctx)

src/internal/kopia/wrapper_test.go

@@ -1007,7 +1007,7 @@ func (suite *KopiaSimpleRepoIntegrationSuite) SetupTest() {
 	expectedDirs := 6
 	expectedFiles := len(suite.filesByPath)
 	//nolint:forbidigo
-	suite.ctx, _ = logger.SeedLevel(context.Background(), logger.Development)
+	suite.ctx, _ = logger.SeedLevel(context.Background(), logger.LLDebug, logger.LFText)
 
 	c, err := openKopiaRepo(t, suite.ctx)
 	require.NoError(t, err, clues.ToCore(err))

src/internal/operations/backup.go

@@ -170,6 +170,22 @@ func (op *BackupOperation) Run(ctx context.Context) (err error) {
 			events.BackupID:  op.Results.BackupID,
 		})
 
+	defer func() {
+		op.bus.Event(
+			ctx,
+			events.BackupEnd,
+			map[string]any{
+				events.BackupID:   op.Results.BackupID,
+				events.DataStored: op.Results.BytesUploaded,
+				events.Duration:   op.Results.CompletedAt.Sub(op.Results.StartedAt),
+				events.EndTime:    dttm.Format(op.Results.CompletedAt),
+				events.Resources:  op.Results.ResourceOwners,
+				events.Service:    op.Selectors.PathService().String(),
+				events.StartTime:  dttm.Format(op.Results.StartedAt),
+				events.Status:     op.Status.String(),
+			})
+	}()
+
 	// -----
 	// Execution
 	// -----
@@ -871,19 +887,5 @@ func (op *BackupOperation) createBackupModels(
 		return clues.Wrap(err, "creating backup model").WithClues(ctx)
 	}
 
-	op.bus.Event(
-		ctx,
-		events.BackupEnd,
-		map[string]any{
-			events.BackupID:   b.ID,
-			events.DataStored: op.Results.BytesUploaded,
-			events.Duration:   op.Results.CompletedAt.Sub(op.Results.StartedAt),
-			events.EndTime:    dttm.Format(op.Results.CompletedAt),
-			events.Resources:  op.Results.ResourceOwners,
-			events.Service:    op.Selectors.PathService().String(),
-			events.StartTime:  dttm.Format(op.Results.StartedAt),
-			events.Status:     op.Status.String(),
-		})
-
 	return nil
 }

src/internal/operations/restore.go

@@ -140,6 +140,25 @@ func (op *RestoreOperation) Run(ctx context.Context) (restoreDetails *details.De
 		"service", op.Selectors.Service,
 		"destination_container", clues.Hide(op.Destination.ContainerName))
 
+	defer func() {
+		op.bus.Event(
+			ctx,
+			events.RestoreEnd,
+			map[string]any{
+				events.BackupID:      op.BackupID,
+				events.DataRetrieved: op.Results.BytesRead,
+				events.Duration:      op.Results.CompletedAt.Sub(op.Results.StartedAt),
+				events.EndTime:       dttm.Format(op.Results.CompletedAt),
+				events.ItemsRead:     op.Results.ItemsRead,
+				events.ItemsWritten:  op.Results.ItemsWritten,
+				events.Resources:     op.Results.ResourceOwners,
+				events.RestoreID:     opStats.restoreID,
+				events.Service:       op.Selectors.Service.String(),
+				events.StartTime:     dttm.Format(op.Results.StartedAt),
+				events.Status:        op.Status.String(),
+			})
+	}()
+
 	// -----
 	// Execution
 	// -----
@@ -283,24 +302,6 @@ func (op *RestoreOperation) persistResults(
 
 	op.Results.ItemsWritten = opStats.gc.Successes
 
-	op.bus.Event(
-		ctx,
-		events.RestoreEnd,
-		map[string]any{
-			events.BackupID:      op.BackupID,
-			events.DataRetrieved: op.Results.BytesRead,
-			events.Duration:      op.Results.CompletedAt.Sub(op.Results.StartedAt),
-			events.EndTime:       dttm.Format(op.Results.CompletedAt),
-			events.ItemsRead:     op.Results.ItemsRead,
-			events.ItemsWritten:  op.Results.ItemsWritten,
-			events.Resources:     op.Results.ResourceOwners,
-			events.RestoreID:     opStats.restoreID,
-			events.Service:       op.Selectors.Service.String(),
-			events.StartTime:     dttm.Format(op.Results.StartedAt),
-			events.Status:        op.Status.String(),
-		},
-	)
-
 	return op.Errors.Failure()
 }
 

src/internal/tester/cli.go

@@ -34,21 +34,22 @@ func StubRootCmd(args ...string) *cobra.Command {
 }
 
 func NewContext() (context.Context, func()) {
-	level := logger.Info
+	level := logger.LLInfo
+	format := logger.LFText
 
 	for _, a := range os.Args {
 		if a == "-test.v=true" {
-			level = logger.Development
+			level = logger.LLDebug
 		}
 	}
 
 	//nolint:forbidigo
-	ctx, _ := logger.SeedLevel(context.Background(), level)
+	ctx, _ := logger.SeedLevel(context.Background(), level, format)
 
 	return ctx, func() { logger.Flush(ctx) }
 }
 
 func WithContext(ctx context.Context) (context.Context, func()) {
-	ctx, _ = logger.SeedLevel(ctx, logger.Development)
+	ctx, _ = logger.SeedLevel(ctx, logger.LLDebug, logger.LFText)
 	return ctx, func() { logger.Flush(ctx) }
 }

src/pkg/logger/logger.go

@@ -22,20 +22,40 @@ var (
 	loggerton *zap.SugaredLogger
 )
 
-type logLevel int
+// type logLevel int
+
+// const (
+// 	Debug logLevel = iota
+// 	Info
+// 	Warn
+// 	Error
+// 	Disabled
+// )
+
+type logLevel string
 
 const (
-	Development logLevel = iota
-	Info
-	Warn
-	Production
-	Disabled
+	LLDebug    logLevel = "debug"
+	LLInfo     logLevel = "info"
+	LLWarn     logLevel = "warn"
+	LLError    logLevel = "error"
+	LLDisabled logLevel = "disabled"
+)
+
+type logFormat string
+
+const (
+	// use for cli/terminal
+	LFText logFormat = "text"
+	// use for cloud logging
+	LFJSON logFormat = "json"
 )
 
 // flag names
 const (
 	DebugAPIFN          = "debug-api-calls"
 	LogFileFN           = "log-file"
+	LogFormatFN         = "log-format"
 	LogLevelFN          = "log-level"
 	ReadableLogsFN      = "readable-logs"
 	MaskSensitiveDataFN = "mask-sensitive-data"
@@ -45,7 +65,8 @@ const (
 var (
 	DebugAPIFV          bool
 	logFileFV           = ""
-	LogLevelFV          = "info"
+	LogFormatFV         = string(LFText)
+	LogLevelFV          = string(LLInfo)
 	ReadableLogsFV      bool
 	MaskSensitiveDataFV bool
 
@@ -59,12 +80,6 @@ const (
 	PIIHash      = "hash"
 	PIIMask      = "mask"
 	PIIPlainText = "plaintext"
-
-	LLDebug    = "debug"
-	LLInfo     = "info"
-	LLWarn     = "warn"
-	LLError    = "error"
-	LLDisabled = "disabled"
 )
 
 // Returns the default location for writing logs
@@ -90,9 +105,15 @@ func addFlags(fs *pflag.FlagSet, defaultFile string) {
 	fs.StringVar(
 		&LogLevelFV,
 		LogLevelFN,
-		LLInfo,
+		string(LLInfo),
 		fmt.Sprintf("set the log level to %s|%s|%s|%s", LLDebug, LLInfo, LLWarn, LLError))
 
+	fs.StringVar(
+		&LogFormatFV,
+		LogFormatFN,
+		string(LFText),
+		fmt.Sprintf("set the log format to %s|%s", LFText, LFJSON))
+
 	// The default provided here is only for help info
 	fs.StringVar(&logFileFV, LogFileFN, defaultFile, "location for writing logs, use '-' for stdout")
 	fs.BoolVar(&DebugAPIFV, DebugAPIFN, false, "add non-2xx request/response errors to logging")
@@ -112,9 +133,10 @@ func addFlags(fs *pflag.FlagSet, defaultFile string) {
 
 // Settings records the user's preferred logging settings.
 type Settings struct {
-	File        string // what file to log to (alt: stderr, stdout)
-	Level       string // what level to log at
-	PIIHandling string // how to obscure pii
+	File        string    // what file to log to (alt: stderr, stdout)
+	Format      logFormat // whether to format as text (console) or json (cloud)
+	Level       logLevel  // what level to log at
+	PIIHandling string    // how to obscure pii
 }
 
 // Due to races between the lazy evaluation of flags in cobra and the
@@ -132,7 +154,8 @@ func PreloadLoggingFlags(args []string) Settings {
 
 	ls := Settings{
 		File:        "",
-		Level:       LogLevelFV,
+		Format:      logFormat(LogFormatFV),
+		Level:       logLevel(LogLevelFV),
 		PIIHandling: PIIPlainText,
 	}
 
@@ -152,7 +175,16 @@ func PreloadLoggingFlags(args []string) Settings {
 		return ls
 	}
 
-	ls.Level = levelString
+	ls.Level = logLevel(levelString)
+
+	// retrieve the user's preferred log format
+	// automatically defaults to "text"
+	formatString, err := fs.GetString(LogFormatFN)
+	if err != nil {
+		return ls
+	}
+
+	ls.Format = logFormat(formatString)
 
 	// retrieve the user's preferred log file location
 	// automatically defaults to default log location
@@ -207,53 +239,50 @@ func GetLogFile(logFileFlagVal string) string {
 	return r
 }
 
-func genLogger(level logLevel, logfile string) (*zapcore.Core, *zap.SugaredLogger) {
+func genLogger(level logLevel, format logFormat, logfile string) (*zapcore.Core, *zap.SugaredLogger) {
 	// when testing, ensure debug logging matches the test.v setting
 	for _, arg := range os.Args {
 		if arg == `--test.v=true` {
-			level = Development
+			level = LLDebug
 		}
 	}
 
-	// set up a logger core to use as a fallback
-	levelFilter := zap.LevelEnablerFunc(func(lvl zapcore.Level) bool {
-		switch level {
-		case Info:
-			return lvl >= zapcore.InfoLevel
-		case Warn:
-			return lvl >= zapcore.WarnLevel
-		case Production:
-			return lvl >= zapcore.ErrorLevel
-		case Disabled:
-			return false
-		default:
-			return true
-		}
-	})
-	out := zapcore.Lock(os.Stderr)
-	consoleEncoder := zapcore.NewConsoleEncoder(zap.NewDevelopmentEncoderConfig())
-	core := zapcore.NewTee(
-		zapcore.NewCore(consoleEncoder, out, levelFilter),
-	)
-
-	// then try to set up a logger directly
 	var (
 		lgr  *zap.Logger
 		err  error
 		opts = []zap.Option{zap.AddStacktrace(zapcore.PanicLevel)}
+
+		// set up a logger core to use as a fallback
+		levelFilter = zap.LevelEnablerFunc(func(lvl zapcore.Level) bool {
+			switch level {
+			case LLInfo:
+				return lvl >= zapcore.InfoLevel
+			case LLWarn:
+				return lvl >= zapcore.WarnLevel
+			case LLError:
+				return lvl >= zapcore.ErrorLevel
+			case LLDisabled:
+				return false
+			default:
+				return true
+			}
+		})
+
+		out            = zapcore.Lock(os.Stderr)
+		consoleEncoder = zapcore.NewConsoleEncoder(zap.NewDevelopmentEncoderConfig())
+		core           = zapcore.NewTee(
+			zapcore.NewCore(consoleEncoder, out, levelFilter),
+		)
+
+		cfg zap.Config
 	)
 
-	if level != Production {
-		cfg := zap.NewDevelopmentConfig()
-
-		switch level {
-		case Info:
-			cfg.Level = zap.NewAtomicLevelAt(zapcore.InfoLevel)
-		case Warn:
-			cfg.Level = zap.NewAtomicLevelAt(zapcore.WarnLevel)
-		case Disabled:
-			cfg.Level = zap.NewAtomicLevelAt(zapcore.FatalLevel)
-		}
+	switch format {
+	case LFJSON:
+		cfg = setLevel(zap.NewProductionConfig(), level)
+		cfg.OutputPaths = []string{logfile}
+	default:
+		cfg = setLevel(zap.NewDevelopmentConfig(), level)
 
 		if ReadableLogsFV {
 			opts = append(opts, zap.WithCaller(false))
@@ -265,14 +294,10 @@ func genLogger(level logLevel, logfile string) (*zapcore.Core, *zap.SugaredLogge
 		}
 
 		cfg.OutputPaths = []string{logfile}
-		lgr, err = cfg.Build(opts...)
-	} else {
-		cfg := zap.NewProductionConfig()
-		cfg.OutputPaths = []string{logfile}
-		lgr, err = cfg.Build(opts...)
 	}
 
 	// fall back to the core config if the default creation fails
+	lgr, err = cfg.Build(opts...)
 	if err != nil {
 		lgr = zap.New(core)
 	}
@@ -280,7 +305,22 @@ func genLogger(level logLevel, logfile string) (*zapcore.Core, *zap.SugaredLogge
 	return &core, lgr.Sugar()
 }
 
-func singleton(level logLevel, logfile string) *zap.SugaredLogger {
+func setLevel(cfg zap.Config, level logLevel) zap.Config {
+	switch level {
+	case LLInfo:
+		cfg.Level = zap.NewAtomicLevelAt(zapcore.InfoLevel)
+	case LLWarn:
+		cfg.Level = zap.NewAtomicLevelAt(zapcore.WarnLevel)
+	case LLError:
+		cfg.Level = zap.NewAtomicLevelAt(zapcore.ErrorLevel)
+	case LLDisabled:
+		cfg.Level = zap.NewAtomicLevelAt(zapcore.FatalLevel)
+	}
+
+	return cfg
+}
+
+func singleton(level logLevel, format logFormat, logfile string) *zap.SugaredLogger {
 	if loggerton != nil {
 		return loggerton
 	}
@@ -292,7 +332,7 @@ func singleton(level logLevel, logfile string) *zap.SugaredLogger {
 		return loggerton
 	}
 
-	logCore, loggerton = genLogger(level, logfile)
+	logCore, loggerton = genLogger(level, format, logfile)
 
 	return loggerton
 }
@@ -314,9 +354,13 @@ func Seed(ctx context.Context, set Settings) (context.Context, *zap.SugaredLogge
 		set.Level = LLInfo
 	}
 
+	if len(set.Format) == 0 {
+		set.Format = LFText
+	}
+
 	setCluesSecretsHash(set.PIIHandling)
 
-	zsl := singleton(levelOf(set.Level), set.File)
+	zsl := singleton(set.Level, set.Format, set.File)
 
 	return Set(ctx, zsl), zsl
 }
@@ -334,8 +378,8 @@ func setCluesSecretsHash(alg string) {
 	}
 }
 
-// SeedLevel generates a logger within the context with the given log-level.
-func SeedLevel(ctx context.Context, level logLevel) (context.Context, *zap.SugaredLogger) {
+// SeedLevel generates a logger within the context with the given log-level and -format.
+func SeedLevel(ctx context.Context, level logLevel, format logFormat) (context.Context, *zap.SugaredLogger) {
 	l := ctx.Value(ctxKey)
 	if l == nil {
 		logfile := os.Getenv("CORSO_LOG_FILE")
@@ -344,7 +388,7 @@ func SeedLevel(ctx context.Context, level logLevel) (context.Context, *zap.Sugar
 			logfile = defaultLogLocation()
 		}
 
-		zsl := singleton(level, logfile)
+		zsl := singleton(level, format, logfile)
 
 		return Set(ctx, zsl), zsl
 	}
@@ -365,7 +409,10 @@ func Set(ctx context.Context, logger *zap.SugaredLogger) context.Context {
 func Ctx(ctx context.Context) *zap.SugaredLogger {
 	l := ctx.Value(ctxKey)
 	if l == nil {
-		return singleton(levelOf(LogLevelFV), defaultLogLocation())
+		return singleton(
+			logLevel(LogLevelFV),
+			logFormat(LogFormatFV),
+			defaultLogLocation())
 	}
 
 	return l.(*zap.SugaredLogger).With(clues.In(ctx).Slice()...)
@@ -381,22 +428,6 @@ func CtxErr(ctx context.Context, err error) *zap.SugaredLogger {
 		With(clues.InErr(err).Slice()...)
 }
 
-// transforms the llevel flag value to a logLevel enum
-func levelOf(lvl string) logLevel {
-	switch lvl {
-	case LLDebug:
-		return Development
-	case LLWarn:
-		return Warn
-	case LLError:
-		return Production
-	case LLDisabled:
-		return Disabled
-	}
-
-	return Info
-}
-
 // Flush writes out all buffered logs.
 func Flush(ctx context.Context) {
 	_ = Ctx(ctx).Sync()

src/pkg/logger/logger_test.go

@@ -32,7 +32,8 @@ func (suite *LoggerUnitSuite) TestAddLoggingFlags() {
 		Run: func(cmd *cobra.Command, args []string) {
 			assert.True(t, logger.DebugAPIFV, logger.DebugAPIFN)
 			assert.True(t, logger.ReadableLogsFV, logger.ReadableLogsFN)
-			assert.Equal(t, logger.LLError, logger.LogLevelFV, logger.LogLevelFN)
+			assert.Equal(t, string(logger.LLError), logger.LogLevelFV, logger.LogLevelFN)
+			assert.Equal(t, string(logger.LFText), logger.LogFormatFV, logger.LogFormatFN)
 			assert.True(t, logger.MaskSensitiveDataFV, logger.MaskSensitiveDataFN)
 			// empty assertion here, instead of matching "log-file", because the LogFile
 			// var isn't updated by running the command (this is expected and correct),
@@ -48,7 +49,8 @@ func (suite *LoggerUnitSuite) TestAddLoggingFlags() {
 		"test",
 		"--" + logger.DebugAPIFN,
 		"--" + logger.LogFileFN, "log-file",
-		"--" + logger.LogLevelFN, logger.LLError,
+		"--" + logger.LogLevelFN, string(logger.LLError),
+		"--" + logger.LogFormatFN, string(logger.LFText),
 		"--" + logger.ReadableLogsFN,
 		"--" + logger.MaskSensitiveDataFN,
 	})
@@ -66,7 +68,8 @@ func (suite *LoggerUnitSuite) TestPreloadLoggingFlags() {
 	args := []string{
 		"--" + logger.DebugAPIFN,
 		"--" + logger.LogFileFN, "log-file",
-		"--" + logger.LogLevelFN, logger.LLError,
+		"--" + logger.LogLevelFN, string(logger.LLError),
+		"--" + logger.LogFormatFN, string(logger.LFText),
 		"--" + logger.ReadableLogsFN,
 		"--" + logger.MaskSensitiveDataFN,
 	}
@@ -77,5 +80,6 @@ func (suite *LoggerUnitSuite) TestPreloadLoggingFlags() {
 	assert.True(t, logger.ReadableLogsFV, logger.ReadableLogsFN)
 	assert.Equal(t, "log-file", settings.File, "settings.File")
 	assert.Equal(t, logger.LLError, settings.Level, "settings.Level")
+	assert.Equal(t, logger.LFText, settings.Format, "settings.Format")
 	assert.Equal(t, logger.PIIHash, settings.PIIHandling, "settings.PIIHandling")
 }