add a logger that can be used within plugins to emit logs into Ark server

Signed-off-by: Steve Kriss <steve@heptio.com>

pkg/cmd/server/plugin/plugin.go

@@ -17,8 +17,6 @@ limitations under the License.
 package plugin
 
 import (
-	"log"
-
 	plugin "github.com/hashicorp/go-plugin"
 	"github.com/spf13/cobra"
 
@@ -30,6 +28,8 @@ import (
 )
 
 func NewCommand() *cobra.Command {
+	logger := arkplugin.NewPluginLogger()
+
 	objectStores := map[string]cloudprovider.ObjectStore{
 		"aws":   aws.NewObjectStore(),
 		"gcp":   gcp.NewObjectStore(),
@@ -48,24 +48,24 @@ func NewCommand() *cobra.Command {
 		Short:  "INTERNAL COMMAND ONLY - not intended to be run directly by users",
 		Run: func(c *cobra.Command, args []string) {
 			if len(args) != 2 {
-				log.Fatalf("You must specify exactly two arguments, the plugin kind and the plugin name")
+				logger.Fatal("You must specify exactly two arguments, the plugin kind and the plugin name")
 			}
 
 			kind := args[0]
 			name := args[1]
 
-			log.Printf("Running plugin command for kind=%s, name=%s", kind, name)
+			logger.Debugf("Running plugin command for kind=%s, name=%s", kind, name)
 
 			switch kind {
 			case "cloudprovider":
 				objectStore, found := objectStores[name]
 				if !found {
-					log.Fatalf("Unrecognized plugin name %q", name)
+					logger.Fatalf("Unrecognized plugin name %q", name)
 				}
 
 				blockStore, found := blockStores[name]
 				if !found {
-					log.Fatalf("Unrecognized plugin name %q", name)
+					logger.Fatalf("Unrecognized plugin name %q", name)
 				}
 
 				plugin.Serve(&plugin.ServeConfig{
@@ -77,7 +77,7 @@ func NewCommand() *cobra.Command {
 					GRPCServer: plugin.DefaultGRPCServer,
 				})
 			default:
-				log.Fatalf("Unsupported plugin kind %q", kind)
+				logger.Fatalf("Unsupported plugin kind %q", kind)
 			}
 		},
 	}

pkg/plugin/logger.go

@@ -0,0 +1,52 @@
+/*
+Copyright 2017 the Heptio Ark 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 plugin
+
+import (
+	"github.com/sirupsen/logrus"
+
+	"github.com/heptio/ark/pkg/util/logging"
+)
+
+// NewPluginLogger returns a logger that is suitable for use within an
+// Ark plugin.
+func NewPluginLogger() logrus.FieldLogger {
+	logger := logrus.New()
+
+	// we use the JSON formatter because go-plugin will parse incoming
+	// JSON on stderr and use it to create structured log entries.
+	logger.Formatter = &logrus.JSONFormatter{
+		FieldMap: logrus.FieldMap{
+			// this is the hclog-compatible message field
+			logrus.FieldKeyMsg: "@message",
+		},
+		// Ark server already adds timestamps when emitting logs, so
+		// don't do it within the plugin.
+		DisableTimestamp: true,
+	}
+
+	// set a logger name for the location hook which will signal to the Ark
+	// server logger that the location has been set within a hook.
+	logger.Hooks.Add((&logging.LogLocationHook{}).WithLoggerName("plugin"))
+
+	// this hook adjusts the string representation of WarnLevel to "warn"
+	// rather than "warning" to make it parseable by go-plugin within the
+	// Ark server code
+	logger.Hooks.Add(&logging.HcLogLevelHook{})
+
+	return logger
+}

pkg/util/logging/hclog_level_hook.go

@@ -0,0 +1,45 @@
+/*
+Copyright 2017 Heptio Inc.
+
+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/sirupsen/logrus"
+)
+
+// HcLogLevelHook adds an hclog-compatible field ("@level") containing
+// the log level. Note that if you use this, you SHOULD NOT use
+// logrus.JSONFormatter's FieldMap to set the level key to "@level" because
+// that will result in the hclog-compatible info written here being
+// overwritten.
+type HcLogLevelHook struct{}
+
+func (h *HcLogLevelHook) Levels() []logrus.Level {
+	return logrus.AllLevels
+}
+
+func (h *HcLogLevelHook) Fire(entry *logrus.Entry) error {
+	switch entry.Level {
+	// logrus uses "warning" to represent WarnLevel,
+	// which is not compatible with hclog's "warn".
+	case logrus.WarnLevel:
+		entry.Data["@level"] = "warn"
+	default:
+		entry.Data["@level"] = entry.Level.String()
+	}
+
+	return nil
+}

pkg/util/logging/log_location_hook.go

@@ -24,11 +24,28 @@ import (
 	"github.com/sirupsen/logrus"
 )
 
-const logLocationField = "logSource"
+const (
+	logSourceField          = "logSource"
+	logSourceSetMarkerField = "@logSourceSetBy"
+)
 
 // LogLocationHook is a logrus hook that attaches location information
 // to log entries, i.e. the file and line number of the logrus log call.
+// This hook is designed for use in both the Ark server and Ark plugin
+// implementations. When triggered within a plugin, a marker field will
+// be set on the log entry indicating that the location came from a plugin.
+// The Ark server instance will not overwrite location information if
+// it sees this marker.
 type LogLocationHook struct {
+	loggerName string
+}
+
+// WithLoggerName gives the hook a name to use when setting the marker field
+// on a log entry indicating the location has been recorded by a plugin. This
+// should only be used when setting up a hook for a logger used in a plugin.
+func (h *LogLocationHook) WithLoggerName(name string) *LogLocationHook {
+	h.loggerName = name
+	return h
 }
 
 func (h *LogLocationHook) Levels() []logrus.Level {
@@ -60,9 +77,40 @@ func (h *LogLocationHook) Fire(entry *logrus.Entry) error {
 			continue
 		}
 
-		entry.Data[logLocationField] = fmt.Sprintf("%s:%d", frame.File, frame.Line)
+		// set the marker field if we're within a plugin indicating that
+		// the location comes from the plugin.
+		if h.loggerName != "" {
+			entry.Data[logSourceSetMarkerField] = h.loggerName
+		}
+
+		// record the log statement location if we're within a plugin OR if
+		// we're in Ark server and not logging something that has the marker
+		// set (which would indicate the log statement is coming from a plugin).
+		if h.loggerName != "" || getLogSourceSetMarker(entry) == "" {
+			entry.Data[logSourceField] = fmt.Sprintf("%s:%d", frame.File, frame.Line)
+		}
+
+		// if we're in the Ark server, remove the marker field since we don't
+		// want to record it in the actual log.
+		if h.loggerName == "" {
+			delete(entry.Data, logSourceSetMarkerField)
+		}
+
 		break
 	}
 
 	return nil
 }
+
+func getLogSourceSetMarker(entry *logrus.Entry) string {
+	nameVal, found := entry.Data[logSourceSetMarkerField]
+	if !found {
+		return ""
+	}
+
+	if name, ok := nameVal.(string); ok {
+		return name
+	}
+
+	return fmt.Sprintf("%s", nameVal)
+}