pass --log-level to plugins (#1278)

Plumb the log level through to plugin processes


Signed-off-by: Steve Kriss <krisss@vmware.com>

changelogs/unreleased/1278-skriss

@@ -0,0 +1 @@
+Pass --log-level flag to internal/external plugins, matching Velero server's log level

docs/plugins.md

@@ -22,8 +22,9 @@ Velero currently supports the following kinds of plugins:
 ## Plugin Logging
 
 Velero provides a [logger][2] that can be used by plugins to log structured information to the main Velero server log or 
-per-backup/restore logs. See the [sample repository][1] for an example of how to instantiate and use the logger 
-within your plugin.
+per-backup/restore logs. It also passes a `--log-level` flag to each plugin binary, whose value is the value of the same 
+flag from the main Velero process. This means that if you turn on debug logging for the Velero server via `--log-level=debug`, 
+plugins will also emit debug-level logs. See the [sample repository][1] for an example of how to use the logger within your plugin.
 
 
 

pkg/cmd/server/plugin/plugin.go

@@ -1,5 +1,5 @@
 /*
-Copyright 2017 the Heptio Ark contributors.
+Copyright 2017, 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.
@@ -31,16 +31,13 @@ import (
 )
 
 func NewCommand(f client.Factory) *cobra.Command {
-	logger := veleroplugin.NewLogger()
-
+	pluginServer := veleroplugin.NewServer()
 	c := &cobra.Command{
 		Use:    "run-plugins",
 		Hidden: true,
 		Short:  "INTERNAL COMMAND ONLY - not intended to be run directly by users",
 		Run: func(c *cobra.Command, args []string) {
-			logger.Debug("Executing run-plugins command")
-
-			veleroplugin.NewServer(logger).
+			pluginServer.
 				RegisterObjectStore("aws", newAwsObjectStore).
 				RegisterObjectStore("azure", newAzureObjectStore).
 				RegisterObjectStore("gcp", newGcpObjectStore).
@@ -59,6 +56,8 @@ func NewCommand(f client.Factory) *cobra.Command {
 		},
 	}
 
+	pluginServer.BindFlags(c.Flags())
+
 	return c
 }
 

pkg/plugin/client_builder.go

@@ -1,5 +1,5 @@
 /*
-Copyright 2018 the Heptio Ark contributors.
+Copyright 2018, 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.
@@ -44,6 +44,9 @@ func newClientBuilder(command string, logger logrus.FieldLogger, logLevel logrus
 		// For plugins compiled into the velero executable, we need to run "velero run-plugins"
 		b.commandArgs = []string{"run-plugins"}
 	}
+
+	b.commandArgs = append(b.commandArgs, "--log-level", logLevel.String())
+
 	return b
 }
 

pkg/plugin/client_builder_test.go

@@ -1,5 +1,5 @@
 /*
-Copyright 2018 the Heptio Ark contributors.
+Copyright 2018, 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,12 +32,12 @@ func TestNewClientBuilder(t *testing.T) {
 	logLevel := logrus.InfoLevel
 	cb := newClientBuilder("velero", logger, logLevel)
 	assert.Equal(t, cb.commandName, "velero")
-	assert.Empty(t, cb.commandArgs)
+	assert.Equal(t, []string{"--log-level", "info"}, cb.commandArgs)
 	assert.Equal(t, newLogrusAdapter(logger, logLevel), cb.pluginLogger)
 
 	cb = newClientBuilder(os.Args[0], logger, logLevel)
 	assert.Equal(t, cb.commandName, os.Args[0])
-	assert.Equal(t, []string{"run-plugins"}, cb.commandArgs)
+	assert.Equal(t, []string{"run-plugins", "--log-level", "info"}, cb.commandArgs)
 	assert.Equal(t, newLogrusAdapter(logger, logLevel), cb.pluginLogger)
 }
 

pkg/plugin/logger.go

@@ -1,5 +1,5 @@
 /*
-Copyright 2017 the Heptio Ark contributors.
+Copyright 2017, 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.
@@ -22,9 +22,9 @@ import (
 	"github.com/heptio/velero/pkg/util/logging"
 )
 
-// NewLogger returns a logger that is suitable for use within an
+// newLogger returns a logger that is suitable for use within an
 // Velero plugin.
-func NewLogger() logrus.FieldLogger {
+func newLogger() *logrus.Logger {
 	logger := logrus.New()
 	/*
 		!!!DO NOT SET THE OUTPUT TO STDOUT!!!

pkg/plugin/logger_test.go

@@ -1,5 +1,5 @@
 /*
-Copyright 2018 the Heptio Ark contributors.
+Copyright 2018, 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.
@@ -25,7 +25,7 @@ import (
 )
 
 func TestNewLogger(t *testing.T) {
-	l := NewLogger().(*logrus.Logger)
+	l := newLogger()
 
 	expectedFormatter := &logrus.JSONFormatter{
 		FieldMap: logrus.FieldMap{

pkg/plugin/server.go

@@ -1,5 +1,5 @@
 /*
-Copyright 2017 the Heptio Ark contributors.
+Copyright 2017, 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.
@@ -17,10 +17,15 @@ limitations under the License.
 package plugin
 
 import (
+	"fmt"
 	"os"
+	"strings"
 
 	plugin "github.com/hashicorp/go-plugin"
 	"github.com/sirupsen/logrus"
+	"github.com/spf13/pflag"
+
+	"github.com/heptio/velero/pkg/util/logging"
 )
 
 // Handshake is configuration information that allows go-plugin clients and servers to perform a handshake.
@@ -35,6 +40,14 @@ var Handshake = plugin.HandshakeConfig{
 
 // Server serves registered plugin implementations.
 type Server interface {
+	// BindFlags defines the plugin server's command-line flags
+	// on the provided FlagSet. If you're not sure what flag set
+	// to use, pflag.CommandLine is the default set of command-line
+	// flags.
+	//
+	// This method must be called prior to calling .Serve().
+	BindFlags(flags *pflag.FlagSet) Server
+
 	// RegisterBackupItemAction registers a backup item action.
 	RegisterBackupItemAction(name string, initializer HandlerInitializer) Server
 
@@ -65,6 +78,9 @@ type Server interface {
 
 // server implements Server.
 type server struct {
+	log               *logrus.Logger
+	logLevelFlag      *logging.LevelFlag
+	flagSet           *pflag.FlagSet
 	backupItemAction  *BackupItemActionPlugin
 	blockStore        *BlockStorePlugin
 	objectStore       *ObjectStorePlugin
@@ -72,8 +88,12 @@ type server struct {
 }
 
 // NewServer returns a new Server
-func NewServer(log logrus.FieldLogger) Server {
+func NewServer() Server {
+	log := newLogger()
+
 	return &server{
+		log:               log,
+		logLevelFlag:      logging.LogLevelFlag(log.Level),
 		backupItemAction:  NewBackupItemActionPlugin(serverLogger(log)),
 		blockStore:        NewBlockStorePlugin(serverLogger(log)),
 		objectStore:       NewObjectStorePlugin(serverLogger(log)),
@@ -81,6 +101,13 @@ func NewServer(log logrus.FieldLogger) Server {
 	}
 }
 
+func (s *server) BindFlags(flags *pflag.FlagSet) Server {
+	flags.Var(s.logLevelFlag, "log-level", fmt.Sprintf("the level at which to log. Valid values are %s.", strings.Join(s.logLevelFlag.AllowedValues(), ", ")))
+	s.flagSet = flags
+
+	return s
+}
+
 func (s *server) RegisterBackupItemAction(name string, initializer HandlerInitializer) Server {
 	s.backupItemAction.register(name, initializer)
 	return s
@@ -142,6 +169,14 @@ func getNames(command string, kind PluginKind, plugin Interface) []PluginIdentif
 }
 
 func (s *server) Serve() {
+	if s.flagSet != nil && !s.flagSet.Parsed() {
+		s.log.Infof("Parsing flags")
+		s.flagSet.Parse(os.Args[1:])
+	}
+
+	s.log.Level = s.logLevelFlag.Parse()
+	s.log.Infof("Setting log level to %s", strings.ToUpper(s.log.Level.String()))
+
 	command := os.Args[0]
 
 	var pluginIdentifiers []PluginIdentifier