diff --git a/changelogs/unreleased/1654-carthewd b/changelogs/unreleased/1654-carthewd new file mode 100644 index 000000000..53fad6b38 --- /dev/null +++ b/changelogs/unreleased/1654-carthewd @@ -0,0 +1 @@ +enhancement: allow option to choose JSON log output diff --git a/pkg/cmd/cli/restic/server.go b/pkg/cmd/cli/restic/server.go index 76e206271..1c2d1fa1a 100644 --- a/pkg/cmd/cli/restic/server.go +++ b/pkg/cmd/cli/restic/server.go @@ -47,6 +47,7 @@ import ( func NewServerCommand(f client.Factory) *cobra.Command { logLevelFlag := logging.LogLevelFlag(logrus.InfoLevel) + formatFlag := logging.NewFormatFlag() command := &cobra.Command{ Use: "server", @@ -57,7 +58,7 @@ func NewServerCommand(f client.Factory) *cobra.Command { logLevel := logLevelFlag.Parse() logrus.Infof("Setting log-level to %s", strings.ToUpper(logLevel.String())) - logger := logging.DefaultLogger(logLevel) + logger := logging.DefaultLogger(logLevel, formatFlag.Parse()) logger.Infof("Starting Velero restic server %s (%s)", buildinfo.Version, buildinfo.FormattedGitSHA()) s, err := newResticServer(logger, fmt.Sprintf("%s-%s", c.Parent().Name(), c.Name())) @@ -68,6 +69,7 @@ func NewServerCommand(f client.Factory) *cobra.Command { } command.Flags().Var(logLevelFlag, "log-level", fmt.Sprintf("the level at which to log. Valid values are %s.", strings.Join(logLevelFlag.AllowedValues(), ", "))) + command.Flags().Var(formatFlag, "log-format", fmt.Sprintf("the format for log output. Valid values are %s.", strings.Join(formatFlag.AllowedValues(), ", "))) return command } diff --git a/pkg/cmd/server/server.go b/pkg/cmd/server/server.go index b9466e3a0..2c064a793 100644 --- a/pkg/cmd/server/server.go +++ b/pkg/cmd/server/server.go @@ -119,6 +119,7 @@ type serverConfig struct { clientQPS float32 clientBurst int profilerAddress string + formatFlag *logging.FormatFlag } type controllerRunInfo struct { @@ -143,6 +144,7 @@ func NewCommand() *cobra.Command { clientBurst: defaultClientBurst, profilerAddress: defaultProfilerAddress, resourceTerminatingTimeout: defaultResourceTerminatingTimeout, + formatFlag: logging.NewFormatFlag(), } ) @@ -157,12 +159,16 @@ func NewCommand() *cobra.Command { log.SetOutput(os.Stdout) logLevel := logLevelFlag.Parse() + format := config.formatFlag.Parse() + // Make sure we log to stdout so cloud log dashboards don't show this as an error. logrus.SetOutput(os.Stdout) - logrus.Infof("setting log-level to %s", strings.ToUpper(logLevel.String())) // Velero's DefaultLogger logs to stdout, so all is good there. - logger := logging.DefaultLogger(logLevel) + logger := logging.DefaultLogger(logLevel, format) + + logger.Infof("setting log-level to %s", strings.ToUpper(logLevel.String())) + logger.Infof("Starting Velero server %s (%s)", buildinfo.Version, buildinfo.FormattedGitSHA()) // NOTE: the namespace flag is bound to velero's persistent flags when the root velero command @@ -191,6 +197,7 @@ func NewCommand() *cobra.Command { } command.Flags().Var(logLevelFlag, "log-level", fmt.Sprintf("the level at which to log. Valid values are %s.", strings.Join(logLevelFlag.AllowedValues(), ", "))) + command.Flags().Var(config.formatFlag, "log-format", fmt.Sprintf("the format for log output. Valid values are %s.", strings.Join(config.formatFlag.AllowedValues(), ", "))) command.Flags().StringVar(&config.pluginDir, "plugin-dir", config.pluginDir, "directory containing Velero plugins") command.Flags().StringVar(&config.metricsAddress, "metrics-address", config.metricsAddress, "the address to expose prometheus metrics") command.Flags().DurationVar(&config.backupSyncPeriod, "backup-sync-period", config.backupSyncPeriod, "how often to ensure all Velero backups in object storage exist as Backup API objects in the cluster") @@ -602,6 +609,7 @@ func (s *server) runControllers(defaultVolumeSnapshotLocations map[string]string s.sharedInformerFactory.Velero().V1().VolumeSnapshotLocations(), defaultVolumeSnapshotLocations, s.metrics, + s.config.formatFlag.Parse(), ) return controllerRunInfo{ @@ -692,6 +700,7 @@ func (s *server) runControllers(defaultVolumeSnapshotLocations map[string]string newPluginManager, s.config.defaultBackupLocation, s.metrics, + s.config.formatFlag.Parse(), ) return controllerRunInfo{ diff --git a/pkg/controller/backup_controller.go b/pkg/controller/backup_controller.go index 91247e59d..9e79a82f9 100644 --- a/pkg/controller/backup_controller.go +++ b/pkg/controller/backup_controller.go @@ -70,6 +70,7 @@ type backupController struct { defaultSnapshotLocations map[string]string metrics *metrics.ServerMetrics newBackupStore func(*velerov1api.BackupStorageLocation, persistence.ObjectStoreGetter, logrus.FieldLogger) (persistence.BackupStore, error) + formatFlag logging.Format } func NewBackupController( @@ -86,6 +87,7 @@ func NewBackupController( volumeSnapshotLocationInformer informers.VolumeSnapshotLocationInformer, defaultSnapshotLocations map[string]string, metrics *metrics.ServerMetrics, + formatFlag logging.Format, ) Interface { c := &backupController{ genericController: newGenericController("backup", logger), @@ -102,6 +104,7 @@ func NewBackupController( snapshotLocationLister: volumeSnapshotLocationInformer.Lister(), defaultSnapshotLocations: defaultSnapshotLocations, metrics: metrics, + formatFlag: formatFlag, newBackupStore: persistence.NewObjectBackupStore, } @@ -448,7 +451,7 @@ func (c *backupController) runBackup(backup *pkgbackup.Request) error { // Log the backup to both a backup log file and to stdout. This will help see what happened if the upload of the // backup log failed for whatever reason. - logger := logging.DefaultLogger(c.backupLogLevel) + logger := logging.DefaultLogger(c.backupLogLevel, c.formatFlag) logger.Out = io.MultiWriter(os.Stdout, gzippedLogFile) logCounter := logging.NewLogCounterHook() diff --git a/pkg/controller/backup_controller_test.go b/pkg/controller/backup_controller_test.go index 4494e2370..ab65aac53 100644 --- a/pkg/controller/backup_controller_test.go +++ b/pkg/controller/backup_controller_test.go @@ -98,14 +98,16 @@ func TestProcessBackupNonProcessedItems(t *testing.T) { for _, test := range tests { t.Run(test.name, func(t *testing.T) { + formatFlag := logging.FormatText var ( sharedInformers = informers.NewSharedInformerFactory(fake.NewSimpleClientset(), 0) - logger = logging.DefaultLogger(logrus.DebugLevel) + logger = logging.DefaultLogger(logrus.DebugLevel, formatFlag) ) c := &backupController{ genericController: newGenericController("backup-test", logger), lister: sharedInformers.Velero().V1().Backups().Lister(), + formatFlag: formatFlag, } if test.backup != nil { @@ -159,10 +161,11 @@ func TestProcessBackupValidationFailures(t *testing.T) { for _, test := range tests { t.Run(test.name, func(t *testing.T) { + formatFlag := logging.FormatText var ( clientset = fake.NewSimpleClientset(test.backup) sharedInformers = informers.NewSharedInformerFactory(clientset, 0) - logger = logging.DefaultLogger(logrus.DebugLevel) + logger = logging.DefaultLogger(logrus.DebugLevel, formatFlag) ) c := &backupController{ @@ -173,6 +176,7 @@ func TestProcessBackupValidationFailures(t *testing.T) { snapshotLocationLister: sharedInformers.Velero().V1().VolumeSnapshotLocations().Lister(), defaultBackupLocation: defaultBackupLocation.Name, clock: &clock.RealClock{}, + formatFlag: formatFlag, } require.NotNil(t, test.backup) @@ -225,10 +229,12 @@ func TestBackupLocationLabel(t *testing.T) { for _, test := range tests { t.Run(test.name, func(t *testing.T) { + formatFlag := logging.FormatText + var ( clientset = fake.NewSimpleClientset(test.backup) sharedInformers = informers.NewSharedInformerFactory(clientset, 0) - logger = logging.DefaultLogger(logrus.DebugLevel) + logger = logging.DefaultLogger(logrus.DebugLevel, formatFlag) ) c := &backupController{ @@ -239,6 +245,7 @@ func TestBackupLocationLabel(t *testing.T) { snapshotLocationLister: sharedInformers.Velero().V1().VolumeSnapshotLocations().Lister(), defaultBackupLocation: test.backupLocation.Name, clock: &clock.RealClock{}, + formatFlag: formatFlag, } res := c.prepareBackupRequest(test.backup) @@ -279,9 +286,10 @@ func TestDefaultBackupTTL(t *testing.T) { } for _, test := range tests { + formatFlag := logging.FormatText var ( clientset = fake.NewSimpleClientset(test.backup) - logger = logging.DefaultLogger(logrus.DebugLevel) + logger = logging.DefaultLogger(logrus.DebugLevel, formatFlag) sharedInformers = informers.NewSharedInformerFactory(clientset, 0) ) @@ -292,6 +300,7 @@ func TestDefaultBackupTTL(t *testing.T) { snapshotLocationLister: sharedInformers.Velero().V1().VolumeSnapshotLocations().Lister(), defaultBackupTTL: defaultBackupTTL.Duration, clock: clock.NewFakeClock(now), + formatFlag: formatFlag, } res := c.prepareBackupRequest(test.backup) @@ -528,10 +537,11 @@ func TestProcessBackupCompletions(t *testing.T) { for _, test := range tests { t.Run(test.name, func(t *testing.T) { + formatFlag := logging.FormatText var ( clientset = fake.NewSimpleClientset(test.backup) sharedInformers = informers.NewSharedInformerFactory(clientset, 0) - logger = logging.DefaultLogger(logrus.DebugLevel) + logger = logging.DefaultLogger(logrus.DebugLevel, formatFlag) pluginManager = new(pluginmocks.Manager) backupStore = new(persistencemocks.BackupStore) backupper = new(fakeBackupper) @@ -551,7 +561,8 @@ func TestProcessBackupCompletions(t *testing.T) { newBackupStore: func(*velerov1api.BackupStorageLocation, persistence.ObjectStoreGetter, logrus.FieldLogger) (persistence.BackupStore, error) { return backupStore, nil }, - backupper: backupper, + backupper: backupper, + formatFlag: formatFlag, } pluginManager.On("GetBackupItemActions").Return(nil, nil) diff --git a/pkg/controller/restore_controller.go b/pkg/controller/restore_controller.go index 610ceab27..b71444ddf 100644 --- a/pkg/controller/restore_controller.go +++ b/pkg/controller/restore_controller.go @@ -84,6 +84,7 @@ type restoreController struct { restoreLogLevel logrus.Level defaultBackupLocation string metrics *metrics.ServerMetrics + logFormat logging.Format newPluginManager func(logger logrus.FieldLogger) clientmgmt.Manager newBackupStore func(*api.BackupStorageLocation, persistence.ObjectStoreGetter, logrus.FieldLogger) (persistence.BackupStore, error) @@ -103,6 +104,7 @@ func NewRestoreController( newPluginManager func(logrus.FieldLogger) clientmgmt.Manager, defaultBackupLocation string, metrics *metrics.ServerMetrics, + logFormat logging.Format, ) Interface { c := &restoreController{ genericController: newGenericController("restore", logger), @@ -117,6 +119,7 @@ func NewRestoreController( restoreLogLevel: restoreLogLevel, defaultBackupLocation: defaultBackupLocation, metrics: metrics, + logFormat: logFormat, // use variables to refer to these functions so they can be // replaced with fakes for testing. @@ -412,7 +415,7 @@ func (c *restoreController) fetchBackupInfo(backupName string, pluginManager cli func (c *restoreController) runValidatedRestore(restore *api.Restore, info backupInfo) error { // instantiate the per-restore logger that will output both to a temp file // (for upload to object storage) and to stdout. - restoreLog, err := newRestoreLogger(restore, c.logger, c.restoreLogLevel) + restoreLog, err := newRestoreLogger(restore, c.logger, c.restoreLogLevel, c.logFormat) if err != nil { return err } @@ -555,14 +558,14 @@ type restoreLogger struct { w *gzip.Writer } -func newRestoreLogger(restore *api.Restore, baseLogger logrus.FieldLogger, logLevel logrus.Level) (*restoreLogger, error) { +func newRestoreLogger(restore *api.Restore, baseLogger logrus.FieldLogger, logLevel logrus.Level, logFormat logging.Format) (*restoreLogger, error) { file, err := ioutil.TempFile("", "") if err != nil { return nil, errors.Wrap(err, "error creating temp file") } w := gzip.NewWriter(file) - logger := logging.DefaultLogger(logLevel) + logger := logging.DefaultLogger(logLevel, logFormat) logger.Out = io.MultiWriter(os.Stdout, w) return &restoreLogger{ diff --git a/pkg/controller/restore_controller_test.go b/pkg/controller/restore_controller_test.go index 73cccb92b..743a8204c 100644 --- a/pkg/controller/restore_controller_test.go +++ b/pkg/controller/restore_controller_test.go @@ -47,6 +47,7 @@ import ( pluginmocks "github.com/heptio/velero/pkg/plugin/mocks" "github.com/heptio/velero/pkg/plugin/velero" pkgrestore "github.com/heptio/velero/pkg/restore" + "github.com/heptio/velero/pkg/util/logging" velerotest "github.com/heptio/velero/pkg/util/test" "github.com/heptio/velero/pkg/volume" ) @@ -85,6 +86,8 @@ func TestFetchBackupInfo(t *testing.T) { }, } + formatFlag := logging.FormatText + for _, test := range tests { t.Run(test.name, func(t *testing.T) { var ( @@ -113,6 +116,7 @@ func TestFetchBackupInfo(t *testing.T) { func(logrus.FieldLogger) clientmgmt.Manager { return pluginManager }, "default", metrics.NewServerMetrics(), + formatFlag, ).(*restoreController) c.newBackupStore = func(*api.BackupStorageLocation, persistence.ObjectStoreGetter, logrus.FieldLogger) (persistence.BackupStore, error) { @@ -183,6 +187,8 @@ func TestProcessQueueItemSkips(t *testing.T) { }, } + formatFlag := logging.FormatText + for _, test := range tests { t.Run(test.name, func(t *testing.T) { var ( @@ -206,6 +212,7 @@ func TestProcessQueueItemSkips(t *testing.T) { nil, "default", metrics.NewServerMetrics(), + formatFlag, ).(*restoreController) if test.restore != nil { @@ -378,6 +385,8 @@ func TestProcessQueueItem(t *testing.T) { }, } + formatFlag := logging.FormatText + for _, test := range tests { t.Run(test.name, func(t *testing.T) { var ( @@ -406,6 +415,7 @@ func TestProcessQueueItem(t *testing.T) { func(logrus.FieldLogger) clientmgmt.Manager { return pluginManager }, "default", metrics.NewServerMetrics(), + formatFlag, ).(*restoreController) c.newBackupStore = func(*api.BackupStorageLocation, persistence.ObjectStoreGetter, logrus.FieldLogger) (persistence.BackupStore, error) { @@ -607,6 +617,8 @@ func TestProcessQueueItem(t *testing.T) { } func TestvalidateAndCompleteWhenScheduleNameSpecified(t *testing.T) { + formatFlag := logging.FormatText + var ( client = fake.NewSimpleClientset() sharedInformers = informers.NewSharedInformerFactory(client, 0) @@ -628,6 +640,7 @@ func TestvalidateAndCompleteWhenScheduleNameSpecified(t *testing.T) { nil, "default", nil, + formatFlag, ).(*restoreController) restore := &api.Restore{ @@ -705,7 +718,6 @@ func TestBackupXorScheduleProvided(t *testing.T) { r.Spec.BackupName = "" r.Spec.ScheduleName = "schedule-1" assert.True(t, backupXorScheduleProvided(r)) - } func TestMostRecentCompletedBackup(t *testing.T) { diff --git a/pkg/discovery/helper_test.go b/pkg/discovery/helper_test.go index 554370716..bc9e184e1 100644 --- a/pkg/discovery/helper_test.go +++ b/pkg/discovery/helper_test.go @@ -180,10 +180,12 @@ func TestRefreshServerPreferredResources(t *testing.T) { }, } + formatFlag := logging.FormatText + for _, test := range tests { fakeServer := velerotest.NewFakeServerResourcesInterface(test.resourceList, test.failedGroups, test.returnError) t.Run(test.name, func(t *testing.T) { - resources, err := refreshServerPreferredResources(fakeServer, logging.DefaultLogger(logrus.DebugLevel)) + resources, err := refreshServerPreferredResources(fakeServer, logging.DefaultLogger(logrus.DebugLevel, formatFlag)) if test.returnError != nil { assert.NotNil(t, err) } else { diff --git a/pkg/util/logging/default_logger.go b/pkg/util/logging/default_logger.go index 0b98666b9..5586ebac5 100644 --- a/pkg/util/logging/default_logger.go +++ b/pkg/util/logging/default_logger.go @@ -1,5 +1,5 @@ /* -Copyright 2018 the Velero contributors. +Copyright 2019 the Velero contributors. Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with the License. @@ -32,10 +32,14 @@ func DefaultHooks() []logrus.Hook { } // DefaultLogger returns a Logger with the default properties -// and hooks. -func DefaultLogger(level logrus.Level) *logrus.Logger { +// and hooks. The desired output format is passed as a LogFormat Enum. +func DefaultLogger(level logrus.Level, format Format) *logrus.Logger { logger := logrus.New() + if format == FormatJSON { + logger.Formatter = new(logrus.JSONFormatter) + } + // Make sure the output is set to stdout so log messages don't show up as errors in cloud log dashboards. logger.Out = os.Stdout diff --git a/pkg/util/logging/default_logger_test.go b/pkg/util/logging/default_logger_test.go index 2c5f4fa1c..7aab50496 100644 --- a/pkg/util/logging/default_logger_test.go +++ b/pkg/util/logging/default_logger_test.go @@ -25,11 +25,16 @@ import ( ) func TestDefaultLogger(t *testing.T) { - logger := DefaultLogger(logrus.InfoLevel) - assert.Equal(t, logrus.InfoLevel, logger.Level) - assert.Equal(t, os.Stdout, logger.Out) + formatFlag := NewFormatFlag() - for _, level := range logrus.AllLevels { - assert.Equal(t, DefaultHooks(), logger.Hooks[level]) + for _, testFormat := range formatFlag.AllowedValues() { + formatFlag.Set(testFormat) + logger := DefaultLogger(logrus.InfoLevel, formatFlag.Parse()) + assert.Equal(t, logrus.InfoLevel, logger.Level) + assert.Equal(t, os.Stdout, logger.Out) + + for _, level := range logrus.AllLevels { + assert.Equal(t, DefaultHooks(), logger.Hooks[level]) + } } } diff --git a/pkg/util/logging/format_flag.go b/pkg/util/logging/format_flag.go new file mode 100644 index 000000000..82915e19e --- /dev/null +++ b/pkg/util/logging/format_flag.go @@ -0,0 +1,51 @@ +/* +Copyright 2018 the Velero contributors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ +package logging + +import "github.com/heptio/velero/pkg/cmd/util/flag" + +// Format is a string representation of the desired output format for logs +type Format string + +const ( + FormatText Format = "text" + FormatJSON Format = "json" + defaultValue Format = FormatText +) + +// FormatFlag is a command-line flag for setting the logrus +// log format. +type FormatFlag struct { + *flag.Enum + defaultValue Format +} + +// NewFormatFlag constructs a new log level flag. +func NewFormatFlag() *FormatFlag { + return &FormatFlag{ + Enum: flag.NewEnum( + string(defaultValue), + string(FormatText), + string(FormatJSON), + ), + defaultValue: defaultValue, + } +} + +// Parse returns the flag's value as a Format. +func (f *FormatFlag) Parse() Format { + return Format(f.String()) +}