Added option for JSON-formatted logging. (#159)

Closes: #286

CHANGELOG.md

@@ -21,6 +21,7 @@
 - Added HTTP proxy support for NetApp Cloud Volumes Service in AWS driver. (Issue [#246](https://github.com/NetApp/trident/issues/246))
 - Added snapshotDir option to NetApp Cloud Volumes Service in AWS driver.
 - Added driver for NetApp Cloud Volumes Service in Google Cloud Platform.
+- Added option for JSON-formatted logging. (Issue [#286](https://github.com/NetApp/trident/issues/286))
 
 **Deprecations:**
 - Changed minimum supported ONTAP version to 9.1.

cli/cmd/install.go

@@ -65,6 +65,7 @@ var (
 	pvcName         string
 	tridentImage    string
 	etcdImage       string
+	logFormat       string
 	k8sTimeout      time.Duration
 	migratorTimeout time.Duration
 
@@ -115,6 +116,7 @@ func init() {
 	installCmd.Flags().StringVar(&pvName, "pv", DefaultPVName, "The name of the legacy PV used by Trident, will be migrated to CRDs.")
 	installCmd.Flags().StringVar(&tridentImage, "trident-image", "", "The Trident image to install.")
 	installCmd.Flags().StringVar(&etcdImage, "etcd-image", "", "The etcd image to install.")
+	installCmd.Flags().StringVar(&logFormat, "log-format", "text", "The Trident logging format (text, json).")
 
 	installCmd.Flags().DurationVar(&k8sTimeout, "k8s-timeout", 180*time.Second, "The timeout for all Kubernetes operations.")
 	installCmd.Flags().DurationVar(&migratorTimeout, "migrator-timeout", 300*time.Minute, "The timeout for etcd-to-CRD migration.")
@@ -329,6 +331,13 @@ func validateInstallationArguments() error {
 		return fmt.Errorf("'%s' is not a valid PV name; %s", pvName, subdomainFormat)
 	}
 
+	switch logFormat {
+	case "text", "json":
+		break
+	default:
+		return fmt.Errorf("'%s' is not a valid log format", logFormat)
+	}
+
 	return nil
 }
 
@@ -400,7 +409,7 @@ func prepareYAMLFiles() error {
 		return fmt.Errorf("could not write custom resource definition YAML file; %v", err)
 	}
 
-	deploymentYAML := k8sclient.GetDeploymentYAML(tridentImage, appLabelValue, Debug)
+	deploymentYAML := k8sclient.GetDeploymentYAML(tridentImage, appLabelValue, logFormat, Debug)
 	if err = writeFile(deploymentPath, deploymentYAML); err != nil {
 		return fmt.Errorf("could not write deployment YAML file; %v", err)
 	}
@@ -444,12 +453,14 @@ func prepareCSIYAMLFiles() error {
 		return fmt.Errorf("could not write service YAML file; %v", err)
 	}
 
-	deploymentYAML := k8sclient.GetCSIDeploymentYAML(tridentImage, appLabelValue, Debug, client.ServerVersion())
+	deploymentYAML := k8sclient.GetCSIDeploymentYAML(
+		tridentImage, appLabelValue, logFormat, Debug, client.ServerVersion())
 	if err = writeFile(deploymentPath, deploymentYAML); err != nil {
 		return fmt.Errorf("could not write deployment YAML file; %v", err)
 	}
 
-	daemonSetYAML := k8sclient.GetCSIDaemonSetYAML(tridentImage, TridentNodeLabelValue, Debug, client.ServerVersion())
+	daemonSetYAML := k8sclient.GetCSIDaemonSetYAML(
+		tridentImage, TridentNodeLabelValue, logFormat, Debug, client.ServerVersion())
 	if err = writeFile(csiDaemonSetPath, daemonSetYAML); err != nil {
 		return fmt.Errorf("could not write daemonset YAML file; %v", err)
 	}
@@ -628,7 +639,8 @@ func installTrident() (returnError error) {
 			returnError = client.CreateObjectByFile(deploymentPath)
 			logFields = log.Fields{"path": deploymentPath}
 		} else {
-			returnError = client.CreateObjectByYAML(k8sclient.GetDeploymentYAML(tridentImage, appLabelValue, Debug))
+			returnError = client.CreateObjectByYAML(k8sclient.GetDeploymentYAML(
+				tridentImage, appLabelValue, logFormat, Debug))
 			logFields = log.Fields{}
 		}
 		if returnError != nil {
@@ -727,7 +739,7 @@ func installTrident() (returnError error) {
 			logFields = log.Fields{"path": deploymentPath}
 		} else {
 			returnError = client.CreateObjectByYAML(
-				k8sclient.GetCSIDeploymentYAML(tridentImage, appLabelValue, Debug, client.ServerVersion()))
+				k8sclient.GetCSIDeploymentYAML(tridentImage, appLabelValue, logFormat, Debug, client.ServerVersion()))
 			logFields = log.Fields{}
 		}
 		if returnError != nil {
@@ -747,7 +759,8 @@ func installTrident() (returnError error) {
 			logFields = log.Fields{"path": csiDaemonSetPath}
 		} else {
 			returnError = client.CreateObjectByYAML(
-				k8sclient.GetCSIDaemonSetYAML(tridentImage, TridentNodeLabelValue, Debug, client.ServerVersion()))
+				k8sclient.GetCSIDaemonSetYAML(
+					tridentImage, TridentNodeLabelValue, logFormat, Debug, client.ServerVersion()))
 			logFields = log.Fields{}
 		}
 		if returnError != nil {
@@ -1594,6 +1607,10 @@ func installTridentInCluster() (returnError error) {
 		commandArgs = append(commandArgs, "--etcd-image")
 		commandArgs = append(commandArgs, etcdImage)
 	}
+	if logFormat != "" {
+		commandArgs = append(commandArgs, "--log-format")
+		commandArgs = append(commandArgs, logFormat)
+	}
 	commandArgs = append(commandArgs, "--in-cluster=false")
 
 	// Create the install pod

cli/k8s_client/yaml_factory.go

@@ -198,7 +198,7 @@ roleRef:
   apiGroup: rbac.authorization.k8s.io
 `
 
-func GetDeploymentYAML(tridentImage, label string, debug bool) string {
+func GetDeploymentYAML(tridentImage, label, logFormat string, debug bool) string {
 
 	var debugLine string
 	if debug {
@@ -210,6 +210,7 @@ func GetDeploymentYAML(tridentImage, label string, debug bool) string {
 	deploymentYAML := strings.Replace(deploymentYAMLTemplate, "{TRIDENT_IMAGE}", tridentImage, 1)
 	deploymentYAML = strings.Replace(deploymentYAML, "{DEBUG}", debugLine, 1)
 	deploymentYAML = strings.Replace(deploymentYAML, "{LABEL}", label, -1)
+	deploymentYAML = strings.Replace(deploymentYAML, "{LOG_FORMAT}", logFormat, -1)
 	return deploymentYAML
 }
 
@@ -241,6 +242,7 @@ spec:
         args:
         - "--crd_persistence"
         - "--k8s_pod"
+        - "--log_format={LOG_FORMAT}"
         {DEBUG}
         livenessProbe:
           exec:
@@ -280,7 +282,7 @@ spec:
       targetPort: 8443
 `
 
-func GetCSIDeploymentYAML(tridentImage, label string, debug bool, version *utils.Version) string {
+func GetCSIDeploymentYAML(tridentImage, label, logFormat string, debug bool, version *utils.Version) string {
 
 	var debugLine string
 	var logLevel string
@@ -311,6 +313,7 @@ func GetCSIDeploymentYAML(tridentImage, label string, debug bool, version *utils
 	deploymentYAML = strings.Replace(deploymentYAML, "{DEBUG}", debugLine, 1)
 	deploymentYAML = strings.Replace(deploymentYAML, "{LABEL}", label, -1)
 	deploymentYAML = strings.Replace(deploymentYAML, "{LOG_LEVEL}", logLevel, -1)
+	deploymentYAML = strings.Replace(deploymentYAML, "{LOG_FORMAT}", logFormat, -1)
 	return deploymentYAML
 }
 
@@ -349,6 +352,7 @@ spec:
         - "--csi_node_name=$(KUBE_NODE_NAME)"
         - "--csi_endpoint=$(CSI_ENDPOINT)"
         - "--csi_role=controller"
+        - "--log_format={LOG_FORMAT}"
         {DEBUG}
         livenessProbe:
           exec:
@@ -470,6 +474,7 @@ spec:
         - "--csi_node_name=$(KUBE_NODE_NAME)"
         - "--csi_endpoint=$(CSI_ENDPOINT)"
         - "--csi_role=controller"
+        - "--log_format={LOG_FORMAT}"
         {DEBUG}
         livenessProbe:
           exec:
@@ -579,6 +584,7 @@ spec:
         - "--csi_node_name=$(KUBE_NODE_NAME)"
         - "--csi_endpoint=$(CSI_ENDPOINT)"
         - "--csi_role=controller"
+        - "--log_format={LOG_FORMAT}"
         {DEBUG}
         livenessProbe:
           exec:
@@ -653,7 +659,7 @@ spec:
           secretName: trident-csi
 `
 
-func GetCSIDaemonSetYAML(tridentImage, label string, debug bool, version *utils.Version) string {
+func GetCSIDaemonSetYAML(tridentImage, label, logFormat string, debug bool, version *utils.Version) string {
 
 	var debugLine string
 	var logLevel string
@@ -677,6 +683,7 @@ func GetCSIDaemonSetYAML(tridentImage, label string, debug bool, version *utils.
 	daemonSetYAML = strings.Replace(daemonSetYAML, "{LABEL}", label, -1)
 	daemonSetYAML = strings.Replace(daemonSetYAML, "{DEBUG}", debugLine, 1)
 	daemonSetYAML = strings.Replace(daemonSetYAML, "{LOG_LEVEL}", logLevel, -1)
+	daemonSetYAML = strings.Replace(daemonSetYAML, "{LOG_FORMAT}", logFormat, -1)
 	return daemonSetYAML
 }
 
@@ -716,6 +723,7 @@ spec:
         - "--csi_node_name=$(KUBE_NODE_NAME)"
         - "--csi_endpoint=$(CSI_ENDPOINT)"
         - "--csi_role=node"
+        - "--log_format={LOG_FORMAT}"
         {DEBUG}
         env:
         - name: KUBE_NODE_NAME
@@ -844,6 +852,7 @@ spec:
         - "--csi_node_name=$(KUBE_NODE_NAME)"
         - "--csi_endpoint=$(CSI_ENDPOINT)"
         - "--csi_role=node"
+        - "--log_format={LOG_FORMAT}"
         {DEBUG}
         env:
         - name: KUBE_NODE_NAME

logging/logging.go

@@ -4,6 +4,7 @@ package logging
 
 import (
 	"bytes"
+	"encoding/json"
 	"fmt"
 	"io"
 	"io/ioutil"
@@ -23,22 +24,32 @@ import (
 	"github.com/netapp/trident/utils"
 )
 
-// InitLogging configures logging for nDVP.  Logs are written both to a log file as well as stdout/stderr.
+const (
+	TextFormat             = "text"
+	JSONFormat             = "json"
+	defaultTimestampFormat = time.RFC3339
+)
+
+// InitLoggingForDocker configures logging for nDVP.  Logs are written both to a log file as well as stdout/stderr.
 // Since logrus doesn't support multiple writers, each log stream is implemented as a hook.
-func InitLogging(logName string) error {
+func InitLoggingForDocker(logName, logFormat string) error {
 
 	// No output except for the hooks
 	log.SetOutput(ioutil.Discard)
 
 	// Write to the log file
-	logFileHook, err := NewFileHook(logName)
+	logFileHook, err := NewFileHook(logName, logFormat)
 	if err != nil {
-		return fmt.Errorf("could not initialize logging to file %s: %v", logFileHook.GetLocation(), err)
+		return fmt.Errorf("could not initialize logging to file: %v", err)
 	}
 	log.AddHook(logFileHook)
 
 	// Write to stdout/stderr
-	log.AddHook(NewConsoleHook())
+	logConsoleHook, err := NewConsoleHook(logFormat)
+	if err != nil {
+		return fmt.Errorf("could not initialize logging to console: %v", err)
+	}
+	log.AddHook(logConsoleHook)
 
 	// Remind users where the log file lives
 	log.WithFields(log.Fields{
@@ -73,16 +84,39 @@ func InitLogLevel(debug bool, logLevel string) error {
 	return nil
 }
 
+// InitLogFormat configures the log format, allowing a choice of text or JSON.
+func InitLogFormat(logFormat string) error {
+	switch logFormat {
+	case TextFormat:
+		log.SetFormatter(&log.TextFormatter{})
+	case JSONFormat:
+		log.SetFormatter(&JSONFormatter{})
+	default:
+		return fmt.Errorf("unknown log format: %s", logFormat)
+	}
+	return nil
+}
+
 // ConsoleHook sends log entries to stdout.
 type ConsoleHook struct {
 	formatter log.Formatter
 }
 
 // NewConsoleHook creates a new log hook for writing to stdout/stderr.
-func NewConsoleHook() *ConsoleHook {
+func NewConsoleHook(logFormat string) (*ConsoleHook, error) {
+
+	var formatter log.Formatter
+
+	switch logFormat {
+	case TextFormat:
+		formatter = &log.TextFormatter{FullTimestamp: true}
+	case JSONFormat:
+		formatter = &JSONFormatter{}
+	default:
+		return nil, fmt.Errorf("unknown log format: %s", logFormat)
+	}
 
-	formatter := &log.TextFormatter{FullTimestamp: true}
-	return &ConsoleHook{formatter}
+	return &ConsoleHook{formatter}, nil
 }
 
 func (hook *ConsoleHook) Levels() []log.Level {
@@ -107,10 +141,15 @@ func (hook *ConsoleHook) Fire(entry *log.Entry) error {
 		logWriter = os.Stdout
 	case log.ErrorLevel, log.FatalLevel, log.PanicLevel:
 		logWriter = os.Stderr
+	default:
+		return fmt.Errorf("unknown log level: %v", entry.Level)
 	}
 
 	// Write log entry to output stream
-	hook.formatter.(*log.TextFormatter).ForceColors = hook.checkIfTerminal(logWriter)
+	if textFormatter, ok := hook.formatter.(*log.TextFormatter); ok {
+		textFormatter.ForceColors = hook.checkIfTerminal(logWriter)
+	}
+
 	lineBytes, err := hook.formatter.Format(entry)
 	if err != nil {
 		fmt.Fprintf(os.Stderr, "Unable to read entry, %v", err)
@@ -134,9 +173,18 @@ type FileHook struct {
 }
 
 // NewFileHook creates a new log hook for writing to a file.
-func NewFileHook(logName string) (*FileHook, error) {
+func NewFileHook(logName, logFormat string) (*FileHook, error) {
 
-	formatter := &PlainTextFormatter{}
+	var formatter log.Formatter
+
+	switch logFormat {
+	case TextFormat:
+		formatter = &PlainTextFormatter{}
+	case JSONFormat:
+		formatter = &JSONFormatter{}
+	default:
+		return nil, fmt.Errorf("unknown log format: %s", logFormat)
+	}
 
 	// If config.LogRoot doesn't exist, make it
 	dir, err := os.Lstat(LogRoot)
@@ -359,3 +407,55 @@ func (f *PlainTextFormatter) appendValue(b *bytes.Buffer, value interface{}) {
 		fmt.Fprint(b, value)
 	}
 }
+
+type JSONFormatter struct {
+	// TimestampFormat sets the format used for marshaling timestamps.
+	TimestampFormat string
+	// DisableTimestamp allows disabling automatic timestamps in output
+	DisableTimestamp bool
+	// PrettyPrint will indent all json logs
+	PrettyPrint bool
+}
+
+func (f *JSONFormatter) Format(entry *log.Entry) ([]byte, error) {
+
+	data := make(map[string]string, len(entry.Data)+4)
+	for k, v := range entry.Data {
+		switch v := v.(type) {
+		case error:
+			// Otherwise errors are ignored by `encoding/json`
+			// https://github.com/sirupsen/logrus/issues/137
+			data[k] = v.Error()
+		default:
+			data[k] = fmt.Sprintf("%+v", v)
+		}
+	}
+
+	timestampFormat := f.TimestampFormat
+	if timestampFormat == "" {
+		timestampFormat = defaultTimestampFormat
+	}
+
+	if !f.DisableTimestamp {
+		data["time"] = entry.Time.Format(timestampFormat)
+	}
+	data["msg"] = entry.Message
+	data["level"] = entry.Level.String()
+
+	var b *bytes.Buffer
+	if entry.Buffer != nil {
+		b = entry.Buffer
+	} else {
+		b = &bytes.Buffer{}
+	}
+
+	encoder := json.NewEncoder(b)
+	if f.PrettyPrint {
+		encoder.SetIndent("", "  ")
+	}
+	if err := encoder.Encode(data); err != nil {
+		return nil, fmt.Errorf("failed to marshal fields to JSON, %v", err)
+	}
+
+	return b.Bytes(), nil
+}