Security: Refactor log levels and events #98

Signed-off-by: Michael Mayer <michael@photoprism.app>

internal/commands/migrations.go

@@ -117,7 +117,7 @@ func migrationsStatusAction(ctx *cli.Context) error {
 	}
 
 	// Display report.
-	info, err := report.Render(rows, cols, report.CliFormat(ctx))
+	info, err := report.RenderFormat(rows, cols, report.CliFormat(ctx))
 
 	if err != nil {
 		return err

internal/commands/show_config.go

@@ -31,7 +31,7 @@ func showConfigAction(ctx *cli.Context) error {
 
 	rows, cols := conf.Report()
 
-	result, err := report.Render(rows, cols, report.CliFormat(ctx))
+	result, err := report.RenderFormat(rows, cols, report.CliFormat(ctx))
 
 	fmt.Println(result)
 

internal/commands/show_filters.go

@@ -31,7 +31,7 @@ func showFiltersAction(ctx *cli.Context) error {
 		}
 	})
 
-	result, err := report.Render(rows, cols, report.CliFormat(ctx))
+	result, err := report.RenderFormat(rows, cols, report.CliFormat(ctx))
 
 	fmt.Println(result)
 

internal/commands/show_formats.go

@@ -26,7 +26,7 @@ var ShowFormatsCommand = cli.Command{
 func showFormatsAction(ctx *cli.Context) error {
 	rows, cols := media.Report(fs.Extensions.Types(true), !ctx.Bool("short"), true, true)
 
-	result, err := report.Render(rows, cols, report.CliFormat(ctx))
+	result, err := report.RenderFormat(rows, cols, report.CliFormat(ctx))
 
 	fmt.Println(result)
 

internal/commands/show_options.go

@@ -33,7 +33,7 @@ func showOptionsAction(ctx *cli.Context) error {
 
 	// CSV Export?
 	if ctx.Bool("csv") || ctx.Bool("tsv") {
-		result, err := report.Render(rows, cols, report.CliFormat(ctx))
+		result, err := report.RenderFormat(rows, cols, report.CliFormat(ctx))
 
 		fmt.Println(result)
 
@@ -96,7 +96,7 @@ func showOptionsAction(ctx *cli.Context) error {
 			}
 		}
 
-		result, err := report.Render(secRows, cols, report.CliFormat(ctx))
+		result, err := report.RenderFormat(secRows, cols, report.CliFormat(ctx))
 
 		if err != nil {
 			return err

internal/commands/show_tags.go

@@ -37,7 +37,7 @@ func showTagsAction(ctx *cli.Context) error {
 
 	// Output overview of supported metadata tags.
 	format := report.CliFormat(ctx)
-	result, err := report.Render(rows, cols, format)
+	result, err := report.RenderFormat(rows, cols, format)
 
 	fmt.Println(result)
 
@@ -46,7 +46,7 @@ func showTagsAction(ctx *cli.Context) error {
 	}
 
 	// Documentation links for those who want to delve deeper.
-	result, err = report.Render(meta.Docs, []string{"Namespace", "Documentation"}, format)
+	result, err = report.RenderFormat(meta.Docs, []string{"Namespace", "Documentation"}, format)
 
 	fmt.Printf("## Metadata Tags by Namespace ##\n\n")
 	fmt.Println(result)

internal/commands/users_list.go

@@ -46,7 +46,7 @@ func usersListAction(ctx *cli.Context) error {
 			}
 		}
 
-		result, err := report.Render(rows, cols, report.CliFormat(ctx))
+		result, err := report.RenderFormat(rows, cols, report.CliFormat(ctx))
 
 		fmt.Printf("\n%s\n", result)
 

internal/commands/users_show.go

@@ -44,7 +44,7 @@ func usersShowAction(ctx *cli.Context) error {
 		report.Sort(rows)
 
 		// Show user information.
-		result, err := report.Render(rows, cols, report.CliFormat(ctx))
+		result, err := report.RenderFormat(rows, cols, report.CliFormat(ctx))
 
 		fmt.Printf("\n%s\n", result)
 

internal/entity/auth_session_signin.go

@@ -53,7 +53,7 @@ func (m *Session) SignIn(f form.Login, c *gin.Context) (err error) {
 			return i18n.Error(i18n.ErrInvalidCredentials)
 		} else {
 			event.AuditInfo([]string{m.IP(), "session %s", "login as %s", "succeeded"}, m.RefID, clean.LogQuote(name))
-			event.LoginSuccess(m.IP(), "api", name, m.UserAgent)
+			event.LoginInfo(m.IP(), "api", name, m.UserAgent)
 		}
 
 		m.SetUser(user)

internal/event/audit.go

@@ -10,16 +10,38 @@ import (
 // AuditLog optionally logs security events.
 var AuditLog Logger
 var AuditPrefix = "audit: "
+var AuditMessageSep = " › "
 
 // Format formats an audit log event.
 func Format(ev []string, args ...interface{}) string {
-	return fmt.Sprintf(strings.Join(ev, " › "), args...)
+	return fmt.Sprintf(strings.Join(ev, AuditMessageSep), args...)
 }
 
 // Audit optionally reports security-relevant events.
 func Audit(level logrus.Level, ev []string, args ...interface{}) {
-	if AuditLog != nil && len(ev) > 0 {
+	// Skip if empty.
-		AuditLog.Log(level, AuditPrefix+Format(ev, args...))
+	if len(ev) == 0 {
+		return
+	}
+
+	// Format log message.
+	message := Format(ev, args...)
+
+	// Show log message if AuditLog is specified.
+	if AuditLog != nil {
+		AuditLog.Log(level, AuditPrefix+message)
+	}
+
+	// Publish event if log level is info or higher.
+	if level <= logrus.InfoLevel {
+		Publish(
+			"audit."+level.String(),
+			Data{
+				"time":    TimeStamp(),
+				"level":   level.String(),
+				"message": message,
+			},
+		)
 	}
 }
 

internal/event/login.go

@@ -19,12 +19,12 @@ func LoginData(level logrus.Level, ip, realm, name, browser, message string) Dat
 	}
 }
 
-// LoginSuccess publishes a successful login event.
+// LoginInfo publishes a successful login event.
-func LoginSuccess(ip, realm, name, browser string) {
+func LoginInfo(ip, realm, name, browser string) {
-	Publish("audit.login", LoginData(logrus.InfoLevel, ip, realm, name, browser, ""))
+	Publish("login.info", LoginData(logrus.InfoLevel, ip, realm, name, browser, ""))
 }
 
 // LoginError publishes a login error event.
 func LoginError(ip, realm, name, browser, error string) {
-	Publish("audit.login", LoginData(logrus.ErrorLevel, ip, realm, name, browser, error))
+	Publish("login.error", LoginData(logrus.ErrorLevel, ip, realm, name, browser, error))
 }

internal/server/basicauth.go

@@ -92,7 +92,7 @@ func BasicAuth() gin.HandlerFunc {
 		} else {
 			// Successfully authenticated.
 			event.AuditInfo([]string{api.ClientIP(c), "webdav login as %s", "succeeded"}, clean.LogQuote(name))
-			event.LoginSuccess(api.ClientIP(c), "webdav", name, api.UserAgent(c))
+			event.LoginInfo(api.ClientIP(c), "webdav", name, api.UserAgent(c))
 
 			// Cache successful authentication.
 			basicAuthCache.SetDefault(key, user)

pkg/report/markdown.go

@@ -9,9 +9,9 @@ import (
 
 // MarkdownTable returns a text-formatted table with caption, optionally as valid Markdown,
 // so the output can be pasted into the docs.
-func MarkdownTable(rows [][]string, cols []string, caption string, valid bool) string {
+func MarkdownTable(rows [][]string, cols []string, opt Options) string {
 	// Escape Markdown.
-	if valid {
+	if opt.Valid {
 		for i := range rows {
 			for j := range rows[i] {
 				if strings.ContainsRune(rows[i][j], '|') {
@@ -27,19 +27,19 @@ func MarkdownTable(rows [][]string, cols []string, caption string, valid bool) s
 	borders := tablewriter.Border{
 		Left:   true,
 		Right:  true,
-		Top:    !valid,
+		Top:    !opt.Valid,
-		Bottom: !valid,
+		Bottom: !opt.Valid,
 	}
 
-	// Render.
+	// RenderFormat.
 	table := tablewriter.NewWriter(buf)
 
 	// Set Caption.
-	if caption != "" {
+	if opt.Caption != "" {
-		table.SetCaption(true, caption)
+		table.SetCaption(true, opt.Caption)
 	}
 
-	table.SetAutoWrapText(!valid)
+	table.SetAutoWrapText(!opt.Valid && !opt.NoWrap)
 	table.SetAutoFormatHeaders(false)
 	table.SetHeader(cols)
 	table.SetBorders(borders)

pkg/report/options.go

@@ -0,0 +1,9 @@
+package report
+
+// Options represents render options.
+type Options struct {
+	Format  Format
+	Caption string
+	Valid   bool
+	NoWrap  bool
+}

pkg/report/render.go

@@ -6,19 +6,38 @@ import (
 	"github.com/photoprism/photoprism/pkg/clean"
 )
 
+// RenderFormat returns a text-formatted table, optionally as valid Markdown,
+// so the output can be pasted into the docs.
+func RenderFormat(rows [][]string, cols []string, format Format) (string, error) {
+	switch format {
+	case CSV:
+		return Render(rows, cols, Options{Format: CSV})
+	case TSV:
+		return Render(rows, cols, Options{Format: TSV})
+	case Markdown:
+		return Render(rows, cols, Options{Format: Markdown, Valid: true})
+	case Default:
+		return Render(rows, cols, Options{Format: Default, Valid: false})
+	default:
+		return "", fmt.Errorf("invalid format %s", clean.Log(string(format)))
+	}
+}
+
 // Render returns a text-formatted table, optionally as valid Markdown,
 // so the output can be pasted into the docs.
-func Render(rows [][]string, cols []string, format Format) (string, error) {
+func Render(rows [][]string, cols []string, opt Options) (string, error) {
-	switch format {
+	switch opt.Format {
 	case CSV:
 		return CsvExport(rows, cols, ';')
 	case TSV:
 		return CsvExport(rows, cols, '\t')
 	case Markdown:
-		return MarkdownTable(rows, cols, "", true), nil
+		opt.Valid = true
+		return MarkdownTable(rows, cols, opt), nil
 	case Default:
-		return MarkdownTable(rows, cols, "", false), nil
+		opt.Valid = false
+		return MarkdownTable(rows, cols, opt), nil
 	default:
-		return "", fmt.Errorf("invalid format %s", clean.Log(string(format)))
+		return "", fmt.Errorf("invalid format %s", clean.Log(string(opt.Format)))
 	}
 }

pkg/report/render_test.go

@@ -14,14 +14,14 @@ func TestTable(t *testing.T) {
 		{"bar", "b & a | z"}}
 
 	t.Run("DefaultTable", func(t *testing.T) {
-		result, err := Render(rows, cols, Default)
+		result, err := RenderFormat(rows, cols, Default)
 		if err != nil {
 			t.Fatal(err)
 		}
 		assert.Contains(t, result, "| bar  | b & a | z                      |")
 	})
 	t.Run("MarkdownTable", func(t *testing.T) {
-		result, err := Render(rows, cols, Markdown)
+		result, err := RenderFormat(rows, cols, Markdown)
 		if err != nil {
 			t.Fatal(err)
 		}
@@ -29,7 +29,7 @@ func TestTable(t *testing.T) {
 		assert.Contains(t, result, "| bar  | b & a \\| z")
 	})
 	t.Run("CsvExport", func(t *testing.T) {
-		result, err := Render(rows, cols, CSV)
+		result, err := RenderFormat(rows, cols, CSV)
 		if err != nil {
 			t.Fatal(err)
 		}
@@ -42,7 +42,7 @@ func TestTable(t *testing.T) {
 		assert.Equal(t, expected, result)
 	})
 	t.Run("TsvExport", func(t *testing.T) {
-		result, err := Render(rows, cols, TSV)
+		result, err := RenderFormat(rows, cols, TSV)
 		if err != nil {
 			t.Fatal(err)
 		}
@@ -50,7 +50,7 @@ func TestTable(t *testing.T) {
 		assert.Contains(t, result, "Col1\tCol2\nfoo\tbar, abc, abc")
 	})
 	t.Run("Invalid", func(t *testing.T) {
-		_, err := Render(rows, cols, Format("invalid"))
+		_, err := RenderFormat(rows, cols, Format("invalid"))
 
 		if err == nil {
 			t.Fatal("error expected")

pkg/sev/levels.go

@@ -0,0 +1,79 @@
+package sev
+
+import (
+	"fmt"
+)
+
+const (
+	Emergency Level = iota
+	Alert
+	Critical
+	Error
+	Warning
+	Notice
+	Info
+	Debug
+)
+
+var Levels = []Level{
+	Emergency,
+	Alert,
+	Critical,
+	Error,
+	Warning,
+	Notice,
+	Info,
+	Debug,
+}
+
+// UnmarshalText implements encoding.TextUnmarshaler.
+func (level *Level) UnmarshalText(text []byte) error {
+	l, err := Parse(string(text))
+	if err != nil {
+		return err
+	}
+
+	*level = l
+
+	return nil
+}
+
+func (level Level) MarshalText() ([]byte, error) {
+	switch level {
+	case Debug:
+		return []byte("debug"), nil
+	case Info:
+		return []byte("info"), nil
+	case Notice:
+		return []byte("notice"), nil
+	case Warning:
+		return []byte("warning"), nil
+	case Error:
+		return []byte("error"), nil
+	case Critical:
+		return []byte("critical"), nil
+	case Alert:
+		return []byte("alert"), nil
+	case Emergency:
+		return []byte("emergency"), nil
+	}
+
+	return nil, fmt.Errorf("not a valid severity level %d", level)
+}
+
+func (level Level) Status() string {
+	switch level {
+	case Warning:
+		return "warning"
+	case Error:
+		return "error"
+	case Critical:
+		return "critical"
+	case Alert:
+		return "alert"
+	case Emergency:
+		return "emergency"
+	default:
+		return "OK"
+	}
+}

pkg/sev/logrus.go

@@ -0,0 +1,21 @@
+package sev
+
+import "github.com/sirupsen/logrus"
+
+// LogLevel takes a logrus log level and returns the severity.
+func LogLevel(lvl logrus.Level) Level {
+	switch lvl {
+	case logrus.PanicLevel:
+		return Alert
+	case logrus.FatalLevel:
+		return Critical
+	case logrus.ErrorLevel:
+		return Error
+	case logrus.WarnLevel:
+		return Warning
+	case logrus.InfoLevel:
+		return Info
+	default:
+		return Debug
+	}
+}

pkg/sev/parse.go

@@ -0,0 +1,31 @@
+package sev
+
+import (
+	"fmt"
+	"strings"
+)
+
+// Parse takes a string level and returns the severity constant.
+func Parse(lvl string) (Level, error) {
+	switch strings.ToLower(lvl) {
+	case "emergency", "emerg", "panic":
+		return Emergency, nil
+	case "fatal", "alert":
+		return Alert, nil
+	case "critical", "crit":
+		return Critical, nil
+	case "error", "err":
+		return Error, nil
+	case "warn", "warning":
+		return Warning, nil
+	case "notice", "note":
+		return Notice, nil
+	case "info", "informational", "ok":
+		return Info, nil
+	case "debug":
+		return Debug, nil
+	}
+
+	var l Level
+	return l, fmt.Errorf("not a valid Level: %q", lvl)
+}

pkg/sev/severity.go

@@ -0,0 +1,37 @@
+/*
+Package sev provides event importance levels and parsers.
+
+Copyright (c) 2018 - 2022 PhotoPrism UG. All rights reserved.
+
+	This program is free software: you can redistribute it and/or modify
+	it under Version 3 of the GNU Affero General Public License (the "AGPL"):
+	<https://docs.photoprism.app/license/agpl>
+
+	This program is distributed in the hope that it will be useful,
+	but WITHOUT ANY WARRANTY; without even the implied warranty of
+	MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+	GNU Affero General Public License for more details.
+
+	The AGPL is supplemented by our Trademark and Brand Guidelines,
+	which describe how our Brand Assets may be used:
+	<https://photoprism.app/trademark>
+
+Feel free to send an email to hello@photoprism.app if you have questions,
+want to support our work, or just want to say hello.
+
+Additional information can be found in our Developer Guide:
+<https://docs.photoprism.app/developer-guide/>
+*/
+package sev
+
+// Level represents the severity of an event.
+type Level uint8
+
+// String returns the severity level as a string, e.g. Alert becomes "alert".
+func (level Level) String() string {
+	if b, err := level.MarshalText(); err == nil {
+		return string(b)
+	} else {
+		return "unknown"
+	}
+}

pkg/sev/severity_test.go

@@ -0,0 +1,62 @@
+package sev
+
+import (
+	"bytes"
+	"encoding/json"
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+)
+
+func TestLevelJsonEncoding(t *testing.T) {
+	type X struct {
+		Level Level
+	}
+
+	var x X
+	x.Level = Warning
+	var buf bytes.Buffer
+	enc := json.NewEncoder(&buf)
+	assert.NoError(t, enc.Encode(x))
+	dec := json.NewDecoder(&buf)
+	var y X
+	assert.NoError(t, dec.Decode(&y))
+}
+
+func TestLevelUnmarshalText(t *testing.T) {
+	var u Level
+	for _, level := range Levels {
+		t.Run(level.String(), func(t *testing.T) {
+			assert.NoError(t, u.UnmarshalText([]byte(level.String())))
+			assert.Equal(t, level, u)
+		})
+	}
+	t.Run("invalid", func(t *testing.T) {
+		assert.Error(t, u.UnmarshalText([]byte("invalid")))
+	})
+}
+
+func TestLevelMarshalText(t *testing.T) {
+	levelStrings := []string{
+		"emergency",
+		"alert",
+		"critical",
+		"error",
+		"warning",
+		"notice",
+		"info",
+		"debug",
+	}
+	for idx, val := range Levels {
+		level := val
+		t.Run(level.String(), func(t *testing.T) {
+			var cmp Level
+			b, err := level.MarshalText()
+			assert.NoError(t, err)
+			assert.Equal(t, levelStrings[idx], string(b))
+			err = cmp.UnmarshalText(b)
+			assert.NoError(t, err)
+			assert.Equal(t, level, cmp)
+		})
+	}
+}

pkg/txt/time.go

@@ -0,0 +1,26 @@
+package txt
+
+import (
+	"fmt"
+	"time"
+)
+
+// TimeStamp converts a time to a timestamp string for reporting.
+func TimeStamp(t *time.Time) string {
+	if t == nil {
+		return ""
+	} else if t.IsZero() {
+		return ""
+	}
+
+	return t.Format("2006-01-02 15:04:05")
+}
+
+// NTimes converts an integer to a string in the format "n times" or returns an empty string if n is 0.
+func NTimes(n int) string {
+	if n < 2 {
+		return ""
+	} else {
+		return fmt.Sprintf("%d times", n)
+	}
+}

pkg/txt/time_test.go

@@ -0,0 +1,41 @@
+package txt
+
+import (
+	"testing"
+	"time"
+
+	"github.com/stretchr/testify/assert"
+)
+
+func TestTimeStamp(t *testing.T) {
+	t.Run("Nil", func(t *testing.T) {
+		assert.Equal(t, "", TimeStamp(nil))
+	})
+
+	t.Run("Zero", func(t *testing.T) {
+		assert.Equal(t, "", TimeStamp(&time.Time{}))
+	})
+
+	t.Run("1665389030", func(t *testing.T) {
+		now := time.Unix(1665389030, 0)
+		assert.Equal(t, "2022-10-10 08:03:50", TimeStamp(&now))
+	})
+}
+
+func TestNTimes(t *testing.T) {
+	t.Run("-2", func(t *testing.T) {
+		assert.Equal(t, "", NTimes(-2))
+	})
+	t.Run("-1", func(t *testing.T) {
+		assert.Equal(t, "", NTimes(-1))
+	})
+	t.Run("0", func(t *testing.T) {
+		assert.Equal(t, "", NTimes(0))
+	})
+	t.Run("1", func(t *testing.T) {
+		assert.Equal(t, "", NTimes(1))
+	})
+	t.Run("999", func(t *testing.T) {
+		assert.Equal(t, "999 times", NTimes(999))
+	})
+}