From 893972afffa5ea6672faa6e11743ae46322ec58c Mon Sep 17 00:00:00 2001 From: Lucas Roesler Date: Sat, 10 Aug 2019 21:02:36 +0200 Subject: [PATCH] Add flags to control the log output format **What** - Add new flags to toggle the name, instance, and timestamp fields. Additionally, the new `time-format` also allows controlling the actual timestamp format. - Also provide the log format flag to allow printing the output as JSON, key-values, or the plain format. This should make it easy to integrate with other tools, like JQ etc. Signed-off-by: Lucas Roesler --- commands/logs.go | 26 ++++++--- commands/logs_format.go | 89 ++++++++++++++++++++++++++++++ commands/logs_format_test.go | 104 +++++++++++++++++++++++++++++++++++ flags/log_format.go | 37 +++++++++++++ flags/log_format_test.go | 33 +++++++++++ flags/time_format.go | 64 +++++++++++++++++++++ flags/time_format_test.go | 32 +++++++++++ 7 files changed, 377 insertions(+), 8 deletions(-) create mode 100644 commands/logs_format.go create mode 100644 commands/logs_format_test.go create mode 100644 flags/log_format.go create mode 100644 flags/log_format_test.go create mode 100644 flags/time_format.go create mode 100644 flags/time_format_test.go diff --git a/commands/logs.go b/commands/logs.go index 1af8267d..1a8b34cd 100644 --- a/commands/logs.go +++ b/commands/logs.go @@ -6,7 +6,6 @@ package commands import ( "fmt" "os" - "strings" "time" "github.com/openfaas/faas-cli/flags" @@ -22,12 +21,16 @@ var ( ) type logFlags struct { - instance string - since time.Duration - sinceTime flags.TimestampFlag - follow bool - tail int - token string + instance string + since time.Duration + sinceTime flags.TimestampFlag + follow bool + tail int + token string + logFormat flags.LogFormat + includeName bool + includeInstance bool + timeFormat flags.TimeFormat } func init() { @@ -71,6 +74,12 @@ func initLogCmdFlags(cmd *cobra.Command) { cmd.Flags().IntVar(&logFlagValues.tail, "tail", -1, "number of recent log lines file to display. Defaults to -1, unlimited if <=0") cmd.Flags().BoolVar(&logFlagValues.follow, "follow", true, "continue printing new logs until the end of the request, up to 30s") cmd.Flags().StringVarP(&logFlagValues.token, "token", "k", "", "Pass a JWT token to use instead of basic auth") + + logFlagValues.timeFormat = flags.TimeFormat(time.RFC3339) + cmd.Flags().Var(&logFlagValues.logFormat, "format", "output format. Note that JSON format will always include all log message keys (plain|key-value|json)") + cmd.Flags().Var(&logFlagValues.timeFormat, "time-format", "string format for the timestamp, any value go time format string is allowed, empty will not print the timestamp") + cmd.Flags().BoolVar(&logFlagValues.includeName, "name", true, "print the function name") + cmd.Flags().BoolVar(&logFlagValues.includeInstance, "instance", true, "print the function instance name/id") } func runLogs(cmd *cobra.Command, args []string) error { @@ -86,8 +95,9 @@ func runLogs(cmd *cobra.Command, args []string) error { return err } + formatter := GetLogFormatter(string(logFlagValues.logFormat)) for logMsg := range logEvents { - fmt.Fprintln(os.Stdout, strings.TrimRight(logMsg.String(), "\n")) + fmt.Fprintln(os.Stdout, formatter(logMsg, logFlagValues.timeFormat.String(), logFlagValues.includeName, logFlagValues.includeInstance)) } return nil diff --git a/commands/logs_format.go b/commands/logs_format.go new file mode 100644 index 00000000..534002b6 --- /dev/null +++ b/commands/logs_format.go @@ -0,0 +1,89 @@ +package commands + +import ( + "encoding/json" + "strings" + + "github.com/openfaas/faas-cli/flags" + "github.com/openfaas/faas-provider/logs" +) + +// LogFormatter is a function that converts a log message to a string based on the supplied options +type LogFormatter func(msg logs.Message, timeFormat string, includeName, includeInstance bool) string + +// GetLogFormatter maps a formatter name to a LogFormatter method +func GetLogFormatter(name string) LogFormatter { + switch name { + case string(flags.JSONLogFormat): + return JSONFormatMessage + case string(flags.KeyValueLogFormat): + return KeyValueFormatMessage + default: + return PlainFormatMessage + } +} + +// JSONFormatMessage is a JSON formatting for log messages, the options are ignored and the entire log +// message json serialized +func JSONFormatMessage(msg logs.Message, timeFormat string, includeName, includeInstance bool) string { + // error really can't happen here because of how simple the msg object is + b, _ := json.Marshal(msg) + return string(b) +} + +// KeyValueFormatMessage returns the message in the format "timestamp=<> name=<> instance=<> message=<>" +func KeyValueFormatMessage(msg logs.Message, timeFormat string, includeName, includeInstance bool) string { + var b strings.Builder + + // note that WriteString's error is always nil and safe to ignore here + if timeFormat != "" { + b.WriteString("timestamp=\"") + b.WriteString(msg.Timestamp.Format(timeFormat)) + b.WriteString("\" ") + } + + if includeName { + b.WriteString("name=\"") + b.WriteString(msg.Name) + b.WriteString("\" ") + } + + if includeInstance { + b.WriteString("instance=\"") + b.WriteString(msg.Instance) + b.WriteString("\" ") + } + + b.WriteString("text=\"") + b.WriteString(strings.TrimRight(msg.Text, "\n")) + b.WriteString("\" ") + + return b.String() +} + +// PlainFormatMessage formats a log message as " () " +func PlainFormatMessage(msg logs.Message, timeFormat string, includeName, includeInstance bool) string { + var b strings.Builder + + // note that WriteString's error is always nil and safe to ignore here + if timeFormat != "" { + b.WriteString(msg.Timestamp.Format(timeFormat)) + b.WriteString(" ") + } + + if includeName { + b.WriteString(msg.Name) + b.WriteString(" ") + } + + if includeInstance { + b.WriteString("(") + b.WriteString(msg.Instance) + b.WriteString(")") + b.WriteString(" ") + } + + b.WriteString(msg.Text) + + return strings.TrimRight(b.String(), "\n") +} diff --git a/commands/logs_format_test.go b/commands/logs_format_test.go new file mode 100644 index 00000000..56871021 --- /dev/null +++ b/commands/logs_format_test.go @@ -0,0 +1,104 @@ +package commands + +import ( + "encoding/json" + "strings" + "testing" + "time" + + "github.com/openfaas/faas-provider/logs" +) + +func Test_JSONLogFormatter(t *testing.T) { + now := time.Now() + msg := logs.Message{ + Timestamp: now, + Name: "test-func", + Instance: "123test", + Text: "test message\n", + } + msgJSON, _ := json.Marshal(msg) + + cases := []struct { + name string + timeFormat string + includeName bool + includeInstance bool + expected string + }{ + {"default behavior", "rfc3339", true, true, string(msgJSON)}, + {"default behavior with all empty options", "", false, false, string(msgJSON)}, + } + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + formatted := JSONFormatMessage(msg, tc.timeFormat, tc.includeName, tc.includeInstance) + if formatted != tc.expected { + t.Fatalf("incorrect message format:\n got %s\n expected %s\n", formatted, tc.expected) + } + }) + } +} + +func Test_PlainLogFormatter(t *testing.T) { + ts := time.Date(2009, time.November, 10, 23, 0, 0, 0, time.UTC) + msg := logs.Message{ + Timestamp: ts, + Name: "test-func", + Instance: "123test", + Text: "test message\n", + } + + cases := []struct { + name string + timeFormat string + includeName bool + includeInstance bool + expected string + }{ + {"default settings", time.RFC3339, true, true, "2009-11-10T23:00:00Z test-func (123test) test message"}, + {"default can modify timestamp", "2006-01-02 15:04:05.999999999 -0700 MST", true, true, msg.String()}, + {"can hide name", time.RFC3339, false, true, "2009-11-10T23:00:00Z (123test) test message"}, + {"can hide instance", time.RFC3339, true, false, "2009-11-10T23:00:00Z test-func test message"}, + {"can hide all metadata", "", false, false, "test message"}, + } + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + formatted := PlainFormatMessage(msg, tc.timeFormat, tc.includeName, tc.includeInstance) + if strings.TrimSpace(formatted) != strings.TrimSpace(tc.expected) { + t.Fatalf("incorrect message format:\n got %s\n expected %s\n", formatted, tc.expected) + } + }) + } +} + +func Test_KeyValueLogFormatter(t *testing.T) { + ts := time.Date(2009, time.November, 10, 23, 0, 0, 0, time.UTC) + msg := logs.Message{ + Timestamp: ts, + Name: "test-func", + Instance: "123test", + Text: "test message\n", + } + + cases := []struct { + name string + timeFormat string + includeName bool + includeInstance bool + expected string + }{ + {"default settings", time.RFC3339, true, true, "timestamp=\"2009-11-10T23:00:00Z\" name=\"test-func\" instance=\"123test\" text=\"test message\""}, + {"default settings", "2006-01-02 15:04:05.999999999 -0700 MST", true, true, "timestamp=\"2009-11-10 23:00:00 +0000 UTC\" name=\"test-func\" instance=\"123test\" text=\"test message\""}, + {"can hide name", time.RFC3339, false, true, "timestamp=\"2009-11-10T23:00:00Z\" instance=\"123test\" text=\"test message\""}, + {"can hide instance", time.RFC3339, true, false, "timestamp=\"2009-11-10T23:00:00Z\" name=\"test-func\" text=\"test message\""}, + {"can hide all metadata", "", false, false, "text=\"test message\""}, + } + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + formatted := KeyValueFormatMessage(msg, tc.timeFormat, tc.includeName, tc.includeInstance) + if strings.TrimSpace(formatted) != strings.TrimSpace(tc.expected) { + t.Fatalf("incorrect message format:\n got %s\n expected %s\n", formatted, tc.expected) + } + }) + } +} diff --git a/flags/log_format.go b/flags/log_format.go new file mode 100644 index 00000000..57b910ed --- /dev/null +++ b/flags/log_format.go @@ -0,0 +1,37 @@ +package flags + +import ( + "fmt" + "strings" +) + +// LogFormat determines the output format of the log stream +type LogFormat string + +const PlainLogFormat LogFormat = "plain" +const KeyValueLogFormat LogFormat = "keyvalue" +const JSONLogFormat LogFormat = "json" + +// Type implements pflag.Value +func (l *LogFormat) Type() string { + return "logformat" +} + +// String implements Stringer +func (l *LogFormat) String() string { + if l == nil { + return "" + } + return string(*l) +} + +// Set implements pflag.Value +func (l *LogFormat) Set(value string) error { + switch strings.ToLower(value) { + case "plain", "keyvalue", "json": + *l = LogFormat(value) + default: + return fmt.Errorf("unknown log format: '%s'", value) + } + return nil +} diff --git a/flags/log_format_test.go b/flags/log_format_test.go new file mode 100644 index 00000000..112b82e3 --- /dev/null +++ b/flags/log_format_test.go @@ -0,0 +1,33 @@ +package flags + +import ( + "errors" + "testing" +) + +func TestLogFormat(t *testing.T) { + cases := []struct { + name string + value string + err error + }{ + {"can accept plain", "plain", nil}, + {"can accept keyvalue", "keyvalue", nil}, + {"can accept json", "json", nil}, + {"unknown strings cause error string", "nonsense", errors.New("unknown log format: 'nonsense'")}, + } + + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + var f LogFormat + err := f.Set(tc.value) + if tc.err != nil && tc.err.Error() != err.Error() { + t.Fatalf("expected error %s, got %s", tc.err, err) + } + if tc.err == nil && f.String() != tc.value { + t.Errorf("expected format %s, got %s", tc.value, f.String()) + } + }) + } + +} diff --git a/flags/time_format.go b/flags/time_format.go new file mode 100644 index 00000000..7488da36 --- /dev/null +++ b/flags/time_format.go @@ -0,0 +1,64 @@ +package flags + +import ( + "strings" + "time" +) + +// TimeFormat is a timestamp format string that also accepts the following RFC names as shortcuts +// +// ANSIC = "Mon Jan _2 15:04:05 2006" +// UnixDate = "Mon Jan _2 15:04:05 MST 2006" +// RubyDate = "Mon Jan 02 15:04:05 -0700 2006" +// RFC822 = "02 Jan 06 15:04 MST" +// RFC822Z = "02 Jan 06 15:04 -0700" // RFC822 with numeric zone +// RFC850 = "Monday, 02-Jan-06 15:04:05 MST" +// RFC1123 = "Mon, 02 Jan 2006 15:04:05 MST" +// RFC1123Z = "Mon, 02 Jan 2006 15:04:05 -0700" // RFC1123 with numeric zone +// RFC3339 = "2006-01-02T15:04:05Z07:00" +// RFC3339Nano = "2006-01-02T15:04:05.999999999Z07:00" +// +// Any string is accepted +type TimeFormat string + +// Type implements pflag.Value +func (l *TimeFormat) Type() string { + return "timeformat" +} + +// String implements Stringer +func (l *TimeFormat) String() string { + if l == nil { + return "" + } + return string(*l) +} + +// Set implements pflag.Value +func (l *TimeFormat) Set(value string) error { + switch strings.ToLower(value) { + case "ansic": + *l = TimeFormat(time.ANSIC) + case "unixdate": + *l = TimeFormat(time.UnixDate) + case "rubydate": + *l = TimeFormat(time.RubyDate) + case "rfc822": + *l = TimeFormat(time.RFC822) + case "rfc822z": + *l = TimeFormat(time.RFC822Z) + case "rfc850": + *l = TimeFormat(time.RFC850) + case "rfc1123": + *l = TimeFormat(time.RFC1123) + case "rfc1123z": + *l = TimeFormat(time.RFC1123Z) + case "rfc3339": + *l = TimeFormat(time.RFC3339) + case "rfc3339nano": + *l = TimeFormat(time.RFC3339Nano) + default: + *l = TimeFormat(value) + } + return nil +} diff --git a/flags/time_format_test.go b/flags/time_format_test.go new file mode 100644 index 00000000..5387436b --- /dev/null +++ b/flags/time_format_test.go @@ -0,0 +1,32 @@ +package flags + +import ( + "testing" +) + +func TestTimeFormat(t *testing.T) { + + cases := []struct { + name string + value string + expected string + }{ + {"can parse short name rfc850", "rfc850", "Monday, 02-Jan-06 15:04:05 MST"}, + {"can accept an arbitrary format string", "2006-01-02 15:04:05.999999999 -0700 MST", "2006-01-02 15:04:05.999999999 -0700 MST"}, + {"can accept arbitrary string", "nonsense", "nonsense"}, + } + + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + var f TimeFormat + err := f.Set(tc.value) + if err != nil { + t.Fatalf("should not be able to error") + } + if f.String() != tc.expected { + t.Errorf("expected time %s, got %s", tc.expected, f.String()) + } + }) + } + +}