From 4ae16bce8c6aa8e3d96ca69015d2065badee3994 Mon Sep 17 00:00:00 2001 From: Daenney Date: Mon, 21 Aug 2023 20:07:55 +0200 Subject: [PATCH] [feature] Make log format configurable (#2130) * [feature] Don't emit timestamp in log lines When running gotosocial with a service manager like systemd, or a container runtime, the associated log driver usually emits timestamps itself. In those cases, having the extra timestamp from our own log lines ends up being a bit noisy and when centrally ingesting logs is duplicate information. This introduces a configuration flag that allows disabling emitting the timestamp. It's only wired up for "daemonised" processes, meaning server and testrig. * [chore] Add docs for log-timestamp * [feature] Simplify timestamp handling Co-Authored-By: kim <89579420+NyaaaWhatsUpDoc@users.noreply.github.com> * [chore] Less escaped double-quotes * [chore] Fix help string --------- Co-authored-by: kim <89579420+NyaaaWhatsUpDoc@users.noreply.github.com> --- cmd/gotosocial/common.go | 1 + docs/configuration/general.md | 11 +++++++++++ example/config.yaml | 11 +++++++++++ internal/config/config.go | 27 ++++++++++++++------------- internal/config/defaults.go | 23 ++++++++++++----------- internal/config/flags.go | 1 + internal/config/helpers.gen.go | 25 +++++++++++++++++++++++++ internal/log/log.go | 34 ++++++++++++++++++++++------------ internal/log/syslog_test.go | 16 ++++++++++++++++ test/envparsing.sh | 2 ++ testrig/config.go | 23 ++++++++++++----------- testrig/log.go | 1 + 12 files changed, 128 insertions(+), 47 deletions(-) diff --git a/cmd/gotosocial/common.go b/cmd/gotosocial/common.go index b797e6590..baf8a15b5 100644 --- a/cmd/gotosocial/common.go +++ b/cmd/gotosocial/common.go @@ -63,6 +63,7 @@ func preRun(a preRunArgs) error { // The idea here is to take a GTSAction and run it with the given // context, after initializing any last-minute things like loggers etc. func run(ctx context.Context, action action.GTSAction) error { + log.SetTimeFormat(config.GetLogTimestampFormat()) // Set the global log level from configuration if err := log.ParseLevel(config.GetLogLevel()); err != nil { return fmt.Errorf("error parsing log level: %w", err) diff --git a/docs/configuration/general.md b/docs/configuration/general.md index 285852afe..8ae2ec4f7 100644 --- a/docs/configuration/general.md +++ b/docs/configuration/general.md @@ -28,6 +28,17 @@ log-db-queries: false # Default: true log-client-ip: true +# String. Format to use for the timestamp in log lines. +# If set to the empty string, the timestamp will be +# ommitted from the logs entirely. +# +# The format must be compatible with Go's time.Layout, as +# documented on https://pkg.go.dev/time#pkg-constants. +# +# Examples: [true, false] +# Default: "02/01/2006 15:04:05.000" +log-timestamp-format: "02/01/2006 15:04:05.000" + # String. Application name to use internally. # Examples: ["My Application","gotosocial"] # Default: "gotosocial" diff --git a/example/config.yaml b/example/config.yaml index d3a6102bd..bc8e3d7c1 100644 --- a/example/config.yaml +++ b/example/config.yaml @@ -35,6 +35,17 @@ log-db-queries: false # Default: true log-client-ip: true +# String. Format to use for the timestamp in log lines. +# If set to the empty string, the timestamp will be +# ommitted from the logs entirely. +# +# The format must be compatible with Go's time.Layout, as +# documented on https://pkg.go.dev/time#pkg-constants. +# +# Examples: [true, false] +# Default: "02/01/2006 15:04:05.000" +log-timestamp-format: "02/01/2006 15:04:05.000" + # String. Application name to use internally. # Examples: ["My Application","gotosocial"] # Default: "gotosocial" diff --git a/internal/config/config.go b/internal/config/config.go index f1a5bf6e5..86f6b00dd 100644 --- a/internal/config/config.go +++ b/internal/config/config.go @@ -44,19 +44,20 @@ func fieldtag(field, tag string) string { // will need to regenerate the global Getter/Setter helpers by running: // `go run ./internal/config/gen/ -out ./internal/config/helpers.gen.go` type Configuration struct { - LogLevel string `name:"log-level" usage:"Log level to run at: [trace, debug, info, warn, fatal]"` - LogDbQueries bool `name:"log-db-queries" usage:"Log database queries verbosely when log-level is trace or debug"` - LogClientIP bool `name:"log-client-ip" usage:"Include the client IP in logs"` - ApplicationName string `name:"application-name" usage:"Name of the application, used in various places internally"` - LandingPageUser string `name:"landing-page-user" usage:"the user that should be shown on the instance's landing page"` - ConfigPath string `name:"config-path" usage:"Path to a file containing gotosocial configuration. Values set in this file will be overwritten by values set as env vars or arguments"` - Host string `name:"host" usage:"Hostname to use for the server (eg., example.org, gotosocial.whatever.com). DO NOT change this on a server that's already run!"` - AccountDomain string `name:"account-domain" usage:"Domain to use in account names (eg., example.org, whatever.com). If not set, will default to the setting for host. DO NOT change this on a server that's already run!"` - Protocol string `name:"protocol" usage:"Protocol to use for the REST api of the server (only use http if you are debugging or behind a reverse proxy!)"` - BindAddress string `name:"bind-address" usage:"Bind address to use for the GoToSocial server (eg., 0.0.0.0, 172.138.0.9, [::], localhost). For ipv6, enclose the address in square brackets, eg [2001:db8::fed1]. Default binds to all interfaces."` - Port int `name:"port" usage:"Port to use for GoToSocial. Change this to 443 if you're running the binary directly on the host machine."` - TrustedProxies []string `name:"trusted-proxies" usage:"Proxies to trust when parsing x-forwarded headers into real IPs."` - SoftwareVersion string `name:"software-version" usage:""` + LogLevel string `name:"log-level" usage:"Log level to run at: [trace, debug, info, warn, fatal]"` + LogTimestampFormat string `name:"log-timestamp-format" usage:"Format to use for the log timestamp, as supported by Go's time.Layout"` + LogDbQueries bool `name:"log-db-queries" usage:"Log database queries verbosely when log-level is trace or debug"` + LogClientIP bool `name:"log-client-ip" usage:"Include the client IP in logs"` + ApplicationName string `name:"application-name" usage:"Name of the application, used in various places internally"` + LandingPageUser string `name:"landing-page-user" usage:"the user that should be shown on the instance's landing page"` + ConfigPath string `name:"config-path" usage:"Path to a file containing gotosocial configuration. Values set in this file will be overwritten by values set as env vars or arguments"` + Host string `name:"host" usage:"Hostname to use for the server (eg., example.org, gotosocial.whatever.com). DO NOT change this on a server that's already run!"` + AccountDomain string `name:"account-domain" usage:"Domain to use in account names (eg., example.org, whatever.com). If not set, will default to the setting for host. DO NOT change this on a server that's already run!"` + Protocol string `name:"protocol" usage:"Protocol to use for the REST api of the server (only use http if you are debugging or behind a reverse proxy!)"` + BindAddress string `name:"bind-address" usage:"Bind address to use for the GoToSocial server (eg., 0.0.0.0, 172.138.0.9, [::], localhost). For ipv6, enclose the address in square brackets, eg [2001:db8::fed1]. Default binds to all interfaces."` + Port int `name:"port" usage:"Port to use for GoToSocial. Change this to 443 if you're running the binary directly on the host machine."` + TrustedProxies []string `name:"trusted-proxies" usage:"Proxies to trust when parsing x-forwarded headers into real IPs."` + SoftwareVersion string `name:"software-version" usage:""` DbType string `name:"db-type" usage:"Database type: eg., postgres"` DbAddress string `name:"db-address" usage:"Database ipv4 address, hostname, or filename"` diff --git a/internal/config/defaults.go b/internal/config/defaults.go index 61a037157..3703d8372 100644 --- a/internal/config/defaults.go +++ b/internal/config/defaults.go @@ -27,17 +27,18 @@ // Defaults contains a populated Configuration with reasonable defaults. Note that // if you use this, you will still need to set Host, and, if desired, ConfigPath. var Defaults = Configuration{ - LogLevel: "info", - LogDbQueries: false, - ApplicationName: "gotosocial", - LandingPageUser: "", - ConfigPath: "", - Host: "", - AccountDomain: "", - Protocol: "https", - BindAddress: "0.0.0.0", - Port: 8080, - TrustedProxies: []string{"127.0.0.1/32", "::1"}, // localhost + LogLevel: "info", + LogTimestampFormat: "02/01/2006 15:04:05.000", + LogDbQueries: false, + ApplicationName: "gotosocial", + LandingPageUser: "", + ConfigPath: "", + Host: "", + AccountDomain: "", + Protocol: "https", + BindAddress: "0.0.0.0", + Port: 8080, + TrustedProxies: []string{"127.0.0.1/32", "::1"}, // localhost DbType: "postgres", DbAddress: "", diff --git a/internal/config/flags.go b/internal/config/flags.go index 386e47293..927f4ddfb 100644 --- a/internal/config/flags.go +++ b/internal/config/flags.go @@ -38,6 +38,7 @@ func (s *ConfigState) AddGlobalFlags(cmd *cobra.Command) { cmd.PersistentFlags().String(AccountDomainFlag(), cfg.AccountDomain, fieldtag("AccountDomain", "usage")) cmd.PersistentFlags().String(ProtocolFlag(), cfg.Protocol, fieldtag("Protocol", "usage")) cmd.PersistentFlags().String(LogLevelFlag(), cfg.LogLevel, fieldtag("LogLevel", "usage")) + cmd.PersistentFlags().String(LogTimestampFormatFlag(), cfg.LogTimestampFormat, fieldtag("LogTimestampFormat", "usage")) cmd.PersistentFlags().Bool(LogDbQueriesFlag(), cfg.LogDbQueries, fieldtag("LogDbQueries", "usage")) cmd.PersistentFlags().String(ConfigPathFlag(), cfg.ConfigPath, fieldtag("ConfigPath", "usage")) diff --git a/internal/config/helpers.gen.go b/internal/config/helpers.gen.go index aed111129..ab7d38a8a 100644 --- a/internal/config/helpers.gen.go +++ b/internal/config/helpers.gen.go @@ -49,6 +49,31 @@ func GetLogLevel() string { return global.GetLogLevel() } // SetLogLevel safely sets the value for global configuration 'LogLevel' field func SetLogLevel(v string) { global.SetLogLevel(v) } +// GetLogTimestampFormat safely fetches the Configuration value for state's 'LogTimestampFormat' field +func (st *ConfigState) GetLogTimestampFormat() (v string) { + st.mutex.RLock() + v = st.config.LogTimestampFormat + st.mutex.RUnlock() + return +} + +// SetLogTimestampFormat safely sets the Configuration value for state's 'LogTimestampFormat' field +func (st *ConfigState) SetLogTimestampFormat(v string) { + st.mutex.Lock() + defer st.mutex.Unlock() + st.config.LogTimestampFormat = v + st.reloadToViper() +} + +// LogTimestampFormatFlag returns the flag name for the 'LogTimestampFormat' field +func LogTimestampFormatFlag() string { return "log-timestamp-format" } + +// GetLogTimestampFormat safely fetches the value for global configuration 'LogTimestampFormat' field +func GetLogTimestampFormat() string { return global.GetLogTimestampFormat() } + +// SetLogTimestampFormat safely sets the value for global configuration 'LogTimestampFormat' field +func SetLogTimestampFormat(v string) { global.SetLogTimestampFormat(v) } + // GetLogDbQueries safely fetches the Configuration value for state's 'LogDbQueries' field func (st *ConfigState) GetLogDbQueries() (v bool) { st.mutex.RLock() diff --git a/internal/log/log.go b/internal/log/log.go index ae8607fc3..15c917757 100644 --- a/internal/log/log.go +++ b/internal/log/log.go @@ -23,7 +23,6 @@ "log/syslog" "os" "strings" - "sync/atomic" "syscall" "time" @@ -33,7 +32,7 @@ var ( // loglvl is the currently set logging level. - loglvl atomic.Uint32 + loglvl level.LEVEL // lvlstrs is the lookup table of log levels to strings. lvlstrs = level.Default() @@ -41,8 +40,9 @@ // syslog output, only set if enabled. sysout *syslog.Writer - // timefmt is the logging time format used. - timefmt = "02/01/2006 15:04:05.000" + // timefmt is the logging time format used, which includes + // the full field and required quoting + timefmt = `timestamp="02/01/2006 15:04:05.000" ` // ctxhooks allows modifying log content based on context. ctxhooks []func(context.Context, []kv.Field) []kv.Field @@ -55,12 +55,26 @@ func Hook(hook func(ctx context.Context, kvs []kv.Field) []kv.Field) { // Level returns the currently set log level. func Level() level.LEVEL { - return level.LEVEL(loglvl.Load()) + return loglvl } // SetLevel sets the max logging level. func SetLevel(lvl level.LEVEL) { - loglvl.Store(uint32(lvl)) + loglvl = lvl +} + +// TimeFormat returns the currently-set timestamp format. +func TimeFormat() string { + return timefmt +} + +// SetTimeFormat sets the timestamp format to the given string. +func SetTimeFormat(format string) { + if format == "" { + timefmt = format + return + } + timefmt = `timestamp="` + format + `" ` } // New starts a new log entry. @@ -164,10 +178,8 @@ func printf(depth int, fields []kv.Field, s string, a ...interface{}) { // Acquire buffer buf := getBuf() - // Append formatted timestamp - buf.B = append(buf.B, `timestamp="`...) + // Append formatted timestamp according to `timefmt` buf.B = time.Now().AppendFormat(buf.B, timefmt) - buf.B = append(buf.B, `" `...) // Append formatted caller func buf.B = append(buf.B, `func=`...) @@ -217,10 +229,8 @@ func logf(ctx context.Context, depth int, lvl level.LEVEL, fields []kv.Field, s // Acquire buffer buf := getBuf() - // Append formatted timestamp - buf.B = append(buf.B, `timestamp="`...) + // Append formatted timestamp according to `timefmt` buf.B = time.Now().AppendFormat(buf.B, timefmt) - buf.B = append(buf.B, `" `...) // Append formatted caller func buf.B = append(buf.B, `func=`...) diff --git a/internal/log/syslog_test.go b/internal/log/syslog_test.go index e7e82ec58..7432e61b3 100644 --- a/internal/log/syslog_test.go +++ b/internal/log/syslog_test.go @@ -71,6 +71,22 @@ func (suite *SyslogTestSuite) TestSyslog() { suite.Regexp(regexp.MustCompile(`timestamp=.* func=.* level=INFO msg="this is a test of the emergency broadcast system!"`), entry["content"]) } +func (suite *SyslogTestSuite) TestSyslogDisableTimestamp() { + // Get the current format. + timefmt := log.TimeFormat() + + // Set an empty timestamp. + log.SetTimeFormat("") + + // Set old timestamp on return. + defer log.SetTimeFormat(timefmt) + + log.Info(nil, "this is a test of the emergency broadcast system!") + + entry := <-suite.syslogChannel + suite.Regexp(regexp.MustCompile(`func=.* level=INFO msg="this is a test of the emergency broadcast system!"`), entry["content"]) +} + func (suite *SyslogTestSuite) TestSyslogLongMessage() { log.Warn(nil, longMessage) diff --git a/test/envparsing.sh b/test/envparsing.sh index 0cad04416..2ab17dbfb 100755 --- a/test/envparsing.sh +++ b/test/envparsing.sh @@ -86,6 +86,7 @@ EXPECT=$(cat << "EOF" "log-client-ip": false, "log-db-queries": true, "log-level": "info", + "log-timestamp-format": "banana", "media-description-max-chars": 5000, "media-description-min-chars": 69, "media-emoji-local-max-size": 420, @@ -155,6 +156,7 @@ EOF # Set all the environment variables to # ensure that these are parsed without panic OUTPUT=$(GTS_LOG_LEVEL='info' \ +GTS_LOG_TIMESTAMP_FORMAT="banana" \ GTS_LOG_DB_QUERIES=true \ GTS_LOG_CLIENT_IP=false \ GTS_APPLICATION_NAME=gts \ diff --git a/testrig/config.go b/testrig/config.go index c5cbb2c80..a85a88477 100644 --- a/testrig/config.go +++ b/testrig/config.go @@ -33,17 +33,18 @@ func InitTestConfig() { } var testDefaults = config.Configuration{ - LogLevel: "info", - LogDbQueries: true, - ApplicationName: "gotosocial", - LandingPageUser: "", - ConfigPath: "", - Host: "localhost:8080", - AccountDomain: "localhost:8080", - Protocol: "http", - BindAddress: "127.0.0.1", - Port: 8080, - TrustedProxies: []string{"127.0.0.1/32", "::1"}, + LogLevel: "info", + LogTimestampFormat: "02/01/2006 15:04:05.000", + LogDbQueries: true, + ApplicationName: "gotosocial", + LandingPageUser: "", + ConfigPath: "", + Host: "localhost:8080", + AccountDomain: "localhost:8080", + Protocol: "http", + BindAddress: "127.0.0.1", + Port: 8080, + TrustedProxies: []string{"127.0.0.1/32", "::1"}, DbType: "sqlite", DbAddress: ":memory:", diff --git a/testrig/log.go b/testrig/log.go index 2761eb3f8..439ed72b0 100644 --- a/testrig/log.go +++ b/testrig/log.go @@ -26,6 +26,7 @@ // InitTestLog sets the global logger to trace level for logging func InitTestLog() { + log.SetTimeFormat(config.GetLogTimestampFormat()) // Set the global log level from configuration if err := log.ParseLevel(config.GetLogLevel()); err != nil { log.Panicf(nil, "error parsing log level: %v", err)