1
0
mirror of https://github.com/rclone/rclone.git synced 2025-08-10 06:09:44 +02:00

fs: Remove github.com/sirupsen/logrus and replace with log/slog

This removes logrus which is not developed any more and replaces it
with the new log/slog from the Go standard library.

It implements its own slog Handler which is backwards compatible with
all of rclone's previous logging modes.
This commit is contained in:
Nick Craig-Wood
2025-05-12 15:18:11 +01:00
parent 36b89960e3
commit dfa4d94827
17 changed files with 931 additions and 322 deletions

View File

@@ -3,20 +3,22 @@ package bilib
import ( import (
"bytes" "bytes"
"log" "log/slog"
"github.com/sirupsen/logrus" "github.com/rclone/rclone/fs/log"
) )
// CaptureOutput runs a function capturing its output. // CaptureOutput runs a function capturing its output at log level INFO.
func CaptureOutput(fun func()) []byte { func CaptureOutput(fun func()) []byte {
logSave := log.Writer()
logrusSave := logrus.StandardLogger().Out
buf := &bytes.Buffer{} buf := &bytes.Buffer{}
log.SetOutput(buf) oldLevel := log.Handler.SetLevel(slog.LevelInfo)
logrus.SetOutput(buf) log.Handler.SetOutput(func(level slog.Level, text string) {
buf.WriteString(text)
})
defer func() {
log.Handler.ResetOutput()
log.Handler.SetLevel(oldLevel)
}()
fun() fun()
log.SetOutput(logSave)
logrus.SetOutput(logrusSave)
return buf.Bytes() return buf.Bytes()
} }

View File

@@ -6,6 +6,8 @@ package ncdu
import ( import (
"context" "context"
"fmt" "fmt"
"log/slog"
"os"
"path" "path"
"reflect" "reflect"
"sort" "sort"
@@ -925,23 +927,19 @@ func (u *UI) Run() error {
return fmt.Errorf("screen init: %w", err) return fmt.Errorf("screen init: %w", err)
} }
// Hijack fs.LogOutput so that it doesn't corrupt the screen. // Hijack log output so that it doesn't corrupt the screen.
if logOutput := fs.LogOutput; !log.Redirected() { if !log.Redirected() {
type log struct { var logs []string
text string log.Handler.SetOutput(func(level slog.Level, text string) {
level fs.LogLevel
}
var logs []log
fs.LogOutput = func(level fs.LogLevel, text string) {
if len(logs) > 100 { if len(logs) > 100 {
logs = logs[len(logs)-100:] logs = logs[len(logs)-100:]
} }
logs = append(logs, log{level: level, text: text}) logs = append(logs, text)
} })
defer func() { defer func() {
fs.LogOutput = logOutput log.Handler.ResetOutput()
for i := range logs { for _, text := range logs {
logOutput(logs[i].level, logs[i].text) _, _ = os.Stderr.WriteString(text)
} }
}() }()
} }

View File

@@ -5,11 +5,11 @@ package cmd
import ( import (
"bytes" "bytes"
"fmt" "fmt"
"log/slog"
"strings" "strings"
"sync" "sync"
"time" "time"
"github.com/rclone/rclone/fs"
"github.com/rclone/rclone/fs/accounting" "github.com/rclone/rclone/fs/accounting"
"github.com/rclone/rclone/fs/log" "github.com/rclone/rclone/fs/log"
"github.com/rclone/rclone/fs/operations" "github.com/rclone/rclone/fs/operations"
@@ -19,8 +19,6 @@ import (
const ( const (
// interval between progress prints // interval between progress prints
defaultProgressInterval = 500 * time.Millisecond defaultProgressInterval = 500 * time.Millisecond
// time format for logging
logTimeFormat = "2006/01/02 15:04:05"
) )
// startProgress starts the progress bar printing // startProgress starts the progress bar printing
@@ -28,15 +26,13 @@ const (
// It returns a func which should be called to stop the stats. // It returns a func which should be called to stop the stats.
func startProgress() func() { func startProgress() func() {
stopStats := make(chan struct{}) stopStats := make(chan struct{})
oldLogOutput := fs.LogOutput
oldSyncPrint := operations.SyncPrintf oldSyncPrint := operations.SyncPrintf
if !log.Redirected() { if !log.Redirected() {
// Intercept the log calls if not logging to file or syslog // Intercept the log calls if not logging to file or syslog
fs.LogOutput = func(level fs.LogLevel, text string) { log.Handler.SetOutput(func(level slog.Level, text string) {
printProgress(fmt.Sprintf("%s %-6s: %s", time.Now().Format(logTimeFormat), level, text)) printProgress(text)
})
}
} }
// Intercept output from functions such as HashLister to stdout // Intercept output from functions such as HashLister to stdout
@@ -60,7 +56,10 @@ func startProgress() func() {
case <-stopStats: case <-stopStats:
ticker.Stop() ticker.Stop()
printProgress("") printProgress("")
fs.LogOutput = oldLogOutput if !log.Redirected() {
// Reset intercept of the log calls
log.Handler.ResetOutput()
}
operations.SyncPrintf = oldSyncPrint operations.SyncPrintf = oldSyncPrint
fmt.Println("") fmt.Println("")
return return

View File

@@ -48,7 +48,7 @@ func TestEnvironmentVariables(t *testing.T) {
env = "RCLONE_LOG_LEVEL=DEBUG" env = "RCLONE_LOG_LEVEL=DEBUG"
out, err = rcloneEnv(env, "version", "--quiet") out, err = rcloneEnv(env, "version", "--quiet")
if assert.Error(t, err) { if assert.Error(t, err) {
assert.Contains(t, out, " DEBUG : ") assert.Contains(t, out, " DEBUG ")
assert.Contains(t, out, "Can't set -q and --log-level") assert.Contains(t, out, "Can't set -q and --log-level")
assert.Contains(t, "exit status 1", err.Error()) assert.Contains(t, "exit status 1", err.Error())
} }
@@ -329,7 +329,7 @@ func TestEnvironmentVariables(t *testing.T) {
jsonLogOK := func() { jsonLogOK := func() {
t.Helper() t.Helper()
if assert.NoError(t, err) { if assert.NoError(t, err) {
assert.Contains(t, out, `{"level":"debug",`) assert.Contains(t, out, `"level":"debug"`)
assert.Contains(t, out, `"msg":"Version `) assert.Contains(t, out, `"msg":"Version `)
assert.Contains(t, out, `"}`) assert.Contains(t, out, `"}`)
} }

View File

@@ -1483,12 +1483,21 @@ have a signal to rotate logs.
### --log-format LIST ### ### --log-format LIST ###
Comma separated list of log format options. Accepted options are `date`, Comma separated list of log format options. The accepted options are:
`time`, `microseconds`, `pid`, `longfile`, `shortfile`, `UTC`. Any other
keywords will be silently ignored. `pid` will tag log messages with process - `date` - Add a date in the format YYYY/MM/YY to the log.
identifier which useful with `rclone mount --daemon`. Other accepted - `time` - Add a time to the log in format HH:MM:SS.
options are explained in the [go documentation](https://pkg.go.dev/log#pkg-constants). - `microseconds` - Add microseconds to the time in format HH:MM:SS.SSSSSS.
The default log format is "`date`,`time`". - `UTC` - Make the logs in UTC not localtime.
- `longfile` - Adds the source file and line number of the log statement.
- `shortfile` - Adds the source file and line number of the log statement.
- `pid` - Add the process ID to the log - useful with `rclone mount --daemon`.
- `nolevel` - Don't add the level to the log.
- `json` - Equivalent to adding `--use-json-log`
They are added to the log line in the order above.
The default log format is `"date,time"`.
### --log-level LEVEL ### ### --log-level LEVEL ###
@@ -1508,8 +1517,61 @@ warnings and significant events.
### --use-json-log ### ### --use-json-log ###
This switches the log format to JSON for rclone. The fields of json log This switches the log format to JSON for rclone. The fields of JSON
are level, msg, source, time. log are `level`, `msg`, `source`, `time`. The JSON logs will be
printed on a single line, but are shown expanded here for clarity.
```json
{
"time": "2025-05-13T17:30:51.036237518+01:00",
"level": "debug",
"msg": "4 go routines active\n",
"source": "cmd/cmd.go:298"
}
```
Completed data transfer logs will have extra `size` information. Logs
which are about a particular object will have `object` and
`objectType` fields also.
```json
{
"time": "2025-05-13T17:38:05.540846352+01:00",
"level": "info",
"msg": "Copied (new) to: file2.txt",
"size": 6,
"object": "file.txt",
"objectType": "*local.Object",
"source": "operations/copy.go:368"
}
```
Stats logs will contain a `stats` field which is the same as
returned from the rc call [core/stats](/rc/#core-stats).
```json
{
"time": "2025-05-13T17:38:05.540912847+01:00",
"level": "info",
"msg": "...text version of the stats...",
"stats": {
"bytes": 6,
"checks": 0,
"deletedDirs": 0,
"deletes": 0,
"elapsedTime": 0.000904825,
...truncated for clarity...
"totalBytes": 6,
"totalChecks": 0,
"totalTransfers": 1,
"transferTime": 0.000882794,
"transfers": 1
},
"source": "accounting/stats.go:569"
}
```
### --low-level-retries NUMBER ### ### --low-level-retries NUMBER ###

View File

@@ -671,9 +671,13 @@ func init() {
RegisterGlobalOptions(OptionsInfo{Name: "main", Opt: globalConfig, Options: ConfigOptionsInfo, Reload: globalConfig.Reload}) RegisterGlobalOptions(OptionsInfo{Name: "main", Opt: globalConfig, Options: ConfigOptionsInfo, Reload: globalConfig.Reload})
// initial guess at log level from the flags // initial guess at log level from the flags
globalConfig.LogLevel = initialLogLevel() globalConfig.LogLevel = InitialLogLevel()
} }
// LogReload is written by fs/log to set variables which should really
// be there but we can't move due to them being visible here in the rc.
var LogReload = func(*ConfigInfo) error { return nil }
// Reload assumes the config has been edited and does what is necessary to make it live // Reload assumes the config has been edited and does what is necessary to make it live
func (ci *ConfigInfo) Reload(ctx context.Context) error { func (ci *ConfigInfo) Reload(ctx context.Context) error {
// Set -vv if --dump is in use // Set -vv if --dump is in use
@@ -687,11 +691,6 @@ func (ci *ConfigInfo) Reload(ctx context.Context) error {
ci.StatsLogLevel = LogLevelNotice ci.StatsLogLevel = LogLevelNotice
} }
// If --use-json-log then start the JSON logger
if ci.UseJSONLog {
InstallJSONLogger(ci.LogLevel)
}
// Check --compare-dest and --copy-dest // Check --compare-dest and --copy-dest
if len(ci.CompareDest) > 0 && len(ci.CopyDest) > 0 { if len(ci.CompareDest) > 0 && len(ci.CopyDest) > 0 {
return fmt.Errorf("can't use --compare-dest with --copy-dest") return fmt.Errorf("can't use --compare-dest with --copy-dest")
@@ -731,13 +730,12 @@ func (ci *ConfigInfo) Reload(ctx context.Context) error {
nonZero(&ci.Transfers) nonZero(&ci.Transfers)
nonZero(&ci.Checkers) nonZero(&ci.Checkers)
return nil return LogReload(ci)
} }
// Initial logging level // InitialLogLevel performs a simple check for debug flags to enable
// // debug logging during the flag initialization.
// Perform a simple check for debug flags to enable debug logging during the flag initialization func InitialLogLevel() LogLevel {
func initialLogLevel() LogLevel {
logLevel := LogLevelNotice logLevel := LogLevelNotice
for argIndex, arg := range os.Args { for argIndex, arg := range os.Args {
if strings.HasPrefix(arg, "-vv") && strings.TrimRight(arg, "v") == "-" { if strings.HasPrefix(arg, "-vv") && strings.TrimRight(arg, "v") == "-" {

122
fs/log.go
View File

@@ -4,10 +4,9 @@ import (
"context" "context"
"encoding/json" "encoding/json"
"fmt" "fmt"
"log" "log/slog"
"os" "os"
"slices"
"github.com/sirupsen/logrus"
) )
// LogLevel describes rclone's logs. These are a subset of the syslog log levels. // LogLevel describes rclone's logs. These are a subset of the syslog log levels.
@@ -54,19 +53,31 @@ func (logLevelChoices) Type() string {
return "LogLevel" return "LogLevel"
} }
// LogPrintPid enables process pid in log // slogLevel definitions defined as slog.Level constants.
var LogPrintPid = false // The integer values determine severity for filtering.
// Lower values are less severe (e.g., Debug), higher values are more severe (e.g., Emergency).
// We fit our extra values into slog's scale.
const (
// slog.LevelDebug slog.Level = -4
// slog.LevelInfo slog.Level = 0
SlogLevelNotice = slog.Level(2) // Between Info (0) and Warn (4)
// slog.LevelWarn slog.Level = 4
// slog.LevelError slog.Level = 8
SlogLevelCritical = slog.Level(12) // More severe than Error
SlogLevelAlert = slog.Level(16) // More severe than Critical
SlogLevelEmergency = slog.Level(20) // Most severe
)
// InstallJSONLogger is a hook that --use-json-log calls // Map our level numbers to slog level numbers
var InstallJSONLogger = func(logLevel LogLevel) {} var levelToSlog = []slog.Level{
LogLevelEmergency: SlogLevelEmergency,
// LogOutput sends the text to the logger of level LogLevelAlert: SlogLevelAlert,
var LogOutput = func(level LogLevel, text string) { LogLevelCritical: SlogLevelCritical,
text = fmt.Sprintf("%-6s: %s", level, text) LogLevelError: slog.LevelError,
if LogPrintPid { LogLevelWarning: slog.LevelWarn,
text = fmt.Sprintf("[%d] %s", os.Getpid(), text) LogLevelNotice: SlogLevelNotice,
} LogLevelInfo: slog.LevelInfo,
_ = log.Output(4, text) LogLevelDebug: slog.LevelDebug,
} }
// LogValueItem describes keyed item for a JSON log entry // LogValueItem describes keyed item for a JSON log entry
@@ -108,76 +119,45 @@ func (j LogValueItem) String() string {
return fmt.Sprint(j.value) return fmt.Sprint(j.value)
} }
func logLogrus(level LogLevel, text string, fields logrus.Fields) { // LogLevelToSlog converts an rclone log level to log/slog log level.
switch level { func LogLevelToSlog(level LogLevel) slog.Level {
case LogLevelDebug: slogLevel := slog.LevelError
logrus.WithFields(fields).Debug(text) // NB level is unsigned so we don't check < 0 here
case LogLevelInfo: if int(level) < len(levelToSlog) {
logrus.WithFields(fields).Info(text) slogLevel = levelToSlog[level]
case LogLevelNotice, LogLevelWarning:
logrus.WithFields(fields).Warn(text)
case LogLevelError:
logrus.WithFields(fields).Error(text)
case LogLevelCritical:
logrus.WithFields(fields).Fatal(text)
case LogLevelEmergency, LogLevelAlert:
logrus.WithFields(fields).Panic(text)
} }
return slogLevel
} }
func logLogrusWithObject(level LogLevel, o any, text string, fields logrus.Fields) { func logSlog(level LogLevel, text string, attrs []any) {
slog.Log(context.Background(), LogLevelToSlog(level), text, attrs...)
}
func logSlogWithObject(level LogLevel, o any, text string, attrs []any) {
if o != nil { if o != nil {
if fields == nil { attrs = slices.Concat(attrs, []any{
fields = logrus.Fields{} "object", fmt.Sprintf("%+v", o),
} "objectType", fmt.Sprintf("%T", o),
fields["object"] = fmt.Sprintf("%+v", o) })
fields["objectType"] = fmt.Sprintf("%T", o)
} }
logLogrus(level, text, fields) logSlog(level, text, attrs)
}
func logJSON(level LogLevel, o any, text string) {
logLogrusWithObject(level, o, text, nil)
}
func logJSONf(level LogLevel, o any, text string, args ...any) {
text = fmt.Sprintf(text, args...)
fields := logrus.Fields{}
for _, arg := range args {
if item, ok := arg.(LogValueItem); ok {
fields[item.key] = item.value
}
}
logLogrusWithObject(level, o, text, fields)
}
func logPlain(level LogLevel, o any, text string) {
if o != nil {
text = fmt.Sprintf("%v: %s", o, text)
}
LogOutput(level, text)
}
func logPlainf(level LogLevel, o any, text string, args ...any) {
logPlain(level, o, fmt.Sprintf(text, args...))
} }
// LogPrint produces a log string from the arguments passed in // LogPrint produces a log string from the arguments passed in
func LogPrint(level LogLevel, o any, text string) { func LogPrint(level LogLevel, o any, text string) {
if GetConfig(context.TODO()).UseJSONLog { logSlogWithObject(level, o, text, nil)
logJSON(level, o, text)
} else {
logPlain(level, o, text)
}
} }
// LogPrintf produces a log string from the arguments passed in // LogPrintf produces a log string from the arguments passed in
func LogPrintf(level LogLevel, o any, text string, args ...any) { func LogPrintf(level LogLevel, o any, text string, args ...any) {
if GetConfig(context.TODO()).UseJSONLog { text = fmt.Sprintf(text, args...)
logJSONf(level, o, text, args...) var fields []any
} else { for _, arg := range args {
logPlainf(level, o, text, args...) if item, ok := arg.(LogValueItem); ok {
fields = append(fields, item.key, item.value)
}
} }
logSlogWithObject(level, o, text, fields)
} }
// LogLevelPrint writes logs at the given level // LogLevelPrint writes logs at the given level

View File

@@ -1,106 +0,0 @@
package log
import (
"fmt"
"runtime"
"strings"
"github.com/rclone/rclone/fs"
"github.com/sirupsen/logrus"
)
var loggerInstalled = false
// InstallJSONLogger installs the JSON logger at the specified log level
func InstallJSONLogger(logLevel fs.LogLevel) {
if !loggerInstalled {
logrus.AddHook(NewCallerHook())
loggerInstalled = true
}
logrus.SetFormatter(&logrus.JSONFormatter{
TimestampFormat: "2006-01-02T15:04:05.999999-07:00",
})
logrus.SetLevel(logrus.DebugLevel)
switch logLevel {
case fs.LogLevelEmergency, fs.LogLevelAlert:
logrus.SetLevel(logrus.PanicLevel)
case fs.LogLevelCritical:
logrus.SetLevel(logrus.FatalLevel)
case fs.LogLevelError:
logrus.SetLevel(logrus.ErrorLevel)
case fs.LogLevelWarning, fs.LogLevelNotice:
logrus.SetLevel(logrus.WarnLevel)
case fs.LogLevelInfo:
logrus.SetLevel(logrus.InfoLevel)
case fs.LogLevelDebug:
logrus.SetLevel(logrus.DebugLevel)
}
}
// install hook in fs to call to avoid circular dependency
func init() {
fs.InstallJSONLogger = InstallJSONLogger
}
// CallerHook for log the calling file and line of the fine
type CallerHook struct {
Field string
Skip int
levels []logrus.Level
}
// NewCallerHook use to make a hook
func NewCallerHook(levels ...logrus.Level) logrus.Hook {
hook := CallerHook{
Field: "source",
Skip: 7,
levels: levels,
}
if len(hook.levels) == 0 {
hook.levels = logrus.AllLevels
}
return &hook
}
// Levels implement applied hook to which levels
func (h *CallerHook) Levels() []logrus.Level {
return logrus.AllLevels
}
// Fire logs the information of context (filename and line)
func (h *CallerHook) Fire(entry *logrus.Entry) error {
entry.Data[h.Field] = findCaller(h.Skip)
return nil
}
// findCaller ignores the caller relevant to logrus or fslog then find out the exact caller
func findCaller(skip int) string {
file := ""
line := 0
for i := range 10 {
file, line = getCaller(skip + i)
if !strings.HasPrefix(file, "logrus") && !strings.Contains(file, "log.go") {
break
}
}
return fmt.Sprintf("%s:%d", file, line)
}
func getCaller(skip int) (string, int) {
_, file, line, ok := runtime.Caller(skip)
// fmt.Println(file,":",line)
if !ok {
return "", 0
}
n := 0
for i := len(file) - 1; i > 0; i-- {
if file[i] == '/' {
n++
if n >= 2 {
file = file[i+1:]
break
}
}
}
return file, line
}

View File

@@ -4,14 +4,12 @@ package log
import ( import (
"context" "context"
"io" "io"
"log"
"os" "os"
"reflect" "reflect"
"runtime" "runtime"
"strings" "strings"
"github.com/rclone/rclone/fs" "github.com/rclone/rclone/fs"
"github.com/sirupsen/logrus"
) )
// OptionsInfo descripts the Options in use // OptionsInfo descripts the Options in use
@@ -22,7 +20,7 @@ var OptionsInfo = fs.Options{{
Groups: "Logging", Groups: "Logging",
}, { }, {
Name: "log_format", Name: "log_format",
Default: "date,time", Default: logFormatDate | logFormatTime,
Help: "Comma separated list of log format options", Help: "Comma separated list of log format options",
Groups: "Logging", Groups: "Logging",
}, { }, {
@@ -44,11 +42,11 @@ var OptionsInfo = fs.Options{{
// Options contains options for controlling the logging // Options contains options for controlling the logging
type Options struct { type Options struct {
File string `config:"log_file"` // Log everything to this file File string `config:"log_file"` // Log everything to this file
Format string `config:"log_format"` // Comma separated list of log format options Format logFormat `config:"log_format"` // Comma separated list of log format options
UseSyslog bool `config:"syslog"` // Use Syslog for logging UseSyslog bool `config:"syslog"` // Use Syslog for logging
SyslogFacility string `config:"syslog_facility"` // Facility for syslog, e.g. KERN,USER,... SyslogFacility string `config:"syslog_facility"` // Facility for syslog, e.g. KERN,USER,...
LogSystemdSupport bool `config:"log_systemd"` // set if using systemd logging LogSystemdSupport bool `config:"log_systemd"` // set if using systemd logging
} }
func init() { func init() {
@@ -58,6 +56,37 @@ func init() {
// Opt is the options for the logger // Opt is the options for the logger
var Opt Options var Opt Options
// enum for the log format
type logFormat = fs.Bits[logFormatChoices]
const (
logFormatDate logFormat = 1 << iota
logFormatTime
logFormatMicroseconds
logFormatUTC
logFormatLongFile
logFormatShortFile
logFormatPid
logFormatNoLevel
logFormatJSON
)
type logFormatChoices struct{}
func (logFormatChoices) Choices() []fs.BitsChoicesInfo {
return []fs.BitsChoicesInfo{
{Bit: uint64(logFormatDate), Name: "date"},
{Bit: uint64(logFormatTime), Name: "time"},
{Bit: uint64(logFormatMicroseconds), Name: "microseconds"},
{Bit: uint64(logFormatUTC), Name: "UTC"},
{Bit: uint64(logFormatLongFile), Name: "longfile"},
{Bit: uint64(logFormatShortFile), Name: "shortfile"},
{Bit: uint64(logFormatPid), Name: "pid"},
{Bit: uint64(logFormatNoLevel), Name: "nolevel"},
{Bit: uint64(logFormatJSON), Name: "json"},
}
}
// fnName returns the name of the calling +2 function // fnName returns the name of the calling +2 function
func fnName() string { func fnName() string {
pc, _, _, ok := runtime.Caller(2) pc, _, _, ok := runtime.Caller(2)
@@ -114,31 +143,24 @@ func Stack(o any, info string) {
fs.LogPrintf(fs.LogLevelDebug, o, "%s\nStack trace:\n%s", info, buf) fs.LogPrintf(fs.LogLevelDebug, o, "%s\nStack trace:\n%s", info, buf)
} }
// This is called from fs when the config is reloaded
//
// The config should really be here but we can't move it as it is
// externally visible in the rc.
func logReload(ci *fs.ConfigInfo) error {
Handler.SetLevel(fs.LogLevelToSlog(ci.LogLevel))
return nil
}
func init() {
fs.LogReload = logReload
}
// InitLogging start the logging as per the command line flags // InitLogging start the logging as per the command line flags
func InitLogging() { func InitLogging() {
flagsStr := "," + Opt.Format + "," // Note that ci only has the defaults in at this point
var flags int // We set real values in logReload
if strings.Contains(flagsStr, ",date,") { ci := fs.GetConfig(context.Background())
flags |= log.Ldate
}
if strings.Contains(flagsStr, ",time,") {
flags |= log.Ltime
}
if strings.Contains(flagsStr, ",microseconds,") {
flags |= log.Lmicroseconds
}
if strings.Contains(flagsStr, ",UTC,") {
flags |= log.LUTC
}
if strings.Contains(flagsStr, ",longfile,") {
flags |= log.Llongfile
}
if strings.Contains(flagsStr, ",shortfile,") {
flags |= log.Lshortfile
}
log.SetFlags(flags)
fs.LogPrintPid = strings.Contains(flagsStr, ",pid,")
// Log file output // Log file output
if Opt.File != "" { if Opt.File != "" {
@@ -150,17 +172,27 @@ func InitLogging() {
if err != nil { if err != nil {
fs.Errorf(nil, "Failed to seek log file to end: %v", err) fs.Errorf(nil, "Failed to seek log file to end: %v", err)
} }
log.SetOutput(f)
logrus.SetOutput(f)
redirectStderr(f) redirectStderr(f)
Handler.setWriter(f)
} }
// --use-json-log implies JSON formatting
if ci.UseJSONLog {
Opt.Format |= logFormatJSON
}
// Set slog level to initial log level
Handler.SetLevel(fs.LogLevelToSlog(fs.InitialLogLevel()))
// Set the format to the configured format
Handler.setFormat(Opt.Format)
// Syslog output // Syslog output
if Opt.UseSyslog { if Opt.UseSyslog {
if Opt.File != "" { if Opt.File != "" {
fs.Fatalf(nil, "Can't use --syslog and --log-file together") fs.Fatalf(nil, "Can't use --syslog and --log-file together")
} }
startSysLog() startSysLog(Handler)
} }
// Activate systemd logger support if systemd invocation ID is // Activate systemd logger support if systemd invocation ID is
@@ -173,7 +205,7 @@ func InitLogging() {
// Systemd logging output // Systemd logging output
if Opt.LogSystemdSupport { if Opt.LogSystemdSupport {
startSystemdLog() startSystemdLog(Handler)
} }
} }

391
fs/log/slog.go Normal file
View File

@@ -0,0 +1,391 @@
// Interfaces for the slog package
package log
import (
"bytes"
"context"
"fmt"
"io"
"log/slog"
"os"
"runtime"
"strings"
"sync"
"time"
"github.com/rclone/rclone/fs"
)
// Handler is the standard handler for the logging.
var Handler = defaultHandler()
// Create the default OutputHandler
//
// This logs to stderr with standard go logger format at level INFO.
//
// This will be adjusted by InitLogging to be the configured levels
// but it is important we have a logger running regardless of whether
// InitLogging has been called yet or not.
func defaultHandler() *OutputHandler {
// Default options for default handler
var opts = &slog.HandlerOptions{
Level: fs.LogLevelToSlog(fs.InitialLogLevel()),
}
// Create our handler
h := NewOutputHandler(os.Stderr, opts, logFormatDate|logFormatTime)
// Set the slog default handler
slog.SetDefault(slog.New(h))
// Make log.Printf logs at level Notice
slog.SetLogLoggerLevel(fs.SlogLevelNotice)
return h
}
// Map slog level names to string
var slogNames = map[slog.Level]string{
slog.LevelDebug: "DEBUG",
slog.LevelInfo: "INFO",
fs.SlogLevelNotice: "NOTICE",
slog.LevelWarn: "WARNING",
slog.LevelError: "ERROR",
fs.SlogLevelCritical: "CRITICAL",
fs.SlogLevelAlert: "ALERT",
fs.SlogLevelEmergency: "EMERGENCY",
}
// Convert a slog level to string using rclone's extra levels
func slogLevelToString(level slog.Level) string {
levelStr := slogNames[level]
if levelStr == "" {
levelStr = level.String()
}
return levelStr
}
// ReplaceAttr function to customize the level key's string value in logs
func mapLogLevelNames(groups []string, a slog.Attr) slog.Attr {
if a.Key == slog.LevelKey {
level, ok := a.Value.Any().(slog.Level)
if !ok {
return a
}
levelStr := strings.ToLower(slogLevelToString(level))
a.Value = slog.StringValue(levelStr)
}
return a
}
// get the file and line number of the caller skipping skip levels
func getCaller(skip int) string {
var pc [64]uintptr
n := runtime.Callers(skip, pc[:])
if n == 0 {
return ""
}
frames := runtime.CallersFrames(pc[:n])
var more = true
var frame runtime.Frame
for more {
frame, more = frames.Next()
file := frame.File
if strings.Contains(file, "/log/") || strings.HasSuffix(file, "log.go") {
continue
}
line := frame.Line
// shorten file name
n := 0
for i := len(file) - 1; i > 0; i-- {
if file[i] == '/' {
n++
if n >= 2 {
file = file[i+1:]
break
}
}
}
return fmt.Sprintf("%s:%d", file, line)
}
return ""
}
// OutputHandler is a slog.Handler that writes log records in a format
// identical to the standard library's `log` package (e.g., "YYYY/MM/DD HH:MM:SS message").
//
// It can also write logs in JSON format identical to logrus.
type OutputHandler struct {
opts slog.HandlerOptions
levelVar slog.LevelVar
writer io.Writer
mu sync.Mutex
output []outputFn // log to writer if empty or the last item
outputExtra []outputExtra // log to all these additional places
format logFormat
jsonBuf bytes.Buffer
jsonHandler *slog.JSONHandler
}
// Records the type and function pointer for extra logging output.
type outputExtra struct {
json bool
output outputFn
}
// Define the type of the override logger
type outputFn func(level slog.Level, text string)
// NewOutputHandler creates a new OutputHandler with the specified flags.
//
// This is designed to use log/slog but produce output which is
// backwards compatible with previous rclone versions.
//
// If opts is nil, default options are used, with Level set to
// slog.LevelInfo.
func NewOutputHandler(out io.Writer, opts *slog.HandlerOptions, format logFormat) *OutputHandler {
h := &OutputHandler{
writer: out,
format: format,
}
if opts != nil {
h.opts = *opts
}
if h.opts.Level == nil {
h.opts.Level = slog.LevelInfo
}
// Set the level var with the configured level
h.levelVar.Set(h.opts.Level.Level())
// And use it from now on
h.opts.Level = &h.levelVar
// Create the JSON logger in case we need it
jsonOpts := slog.HandlerOptions{
Level: h.opts.Level,
ReplaceAttr: mapLogLevelNames,
}
h.jsonHandler = slog.NewJSONHandler(&h.jsonBuf, &jsonOpts)
return h
}
// SetOutput sets a new output handler for the log output.
//
// This is for temporarily overriding the output.
func (h *OutputHandler) SetOutput(fn outputFn) {
h.output = append(h.output, fn)
}
// ResetOutput resets the log output to what is was.
func (h *OutputHandler) ResetOutput() {
if len(h.output) > 0 {
h.output = h.output[:len(h.output)-1]
}
}
// AddOutput adds an additional logging destination of the type specified.
func (h *OutputHandler) AddOutput(json bool, fn outputFn) {
h.outputExtra = append(h.outputExtra, outputExtra{
json: json,
output: fn,
})
}
// SetLevel sets a new log level, returning the old one.
func (h *OutputHandler) SetLevel(level slog.Level) slog.Level {
oldLevel := h.levelVar.Level()
h.levelVar.Set(level)
return oldLevel
}
// Set the writer for the log to that passed.
func (h *OutputHandler) setWriter(writer io.Writer) {
h.writer = writer
}
// Set the format flags to that passed in.
func (h *OutputHandler) setFormat(format logFormat) {
h.format = format
}
// clear format flags that this output type doesn't want
func (h *OutputHandler) clearFormatFlags(bitMask logFormat) {
h.format &^= bitMask
}
// set format flags that this output type requires
func (h *OutputHandler) setFormatFlags(bitMask logFormat) {
h.format |= bitMask
}
// Enabled returns whether this logger is enabled for this level.
func (h *OutputHandler) Enabled(_ context.Context, level slog.Level) bool {
minLevel := slog.LevelInfo
if h.opts.Level != nil {
minLevel = h.opts.Level.Level()
}
return level >= minLevel
}
// Create a log header in Go standard log format.
func (h *OutputHandler) formatStdLogHeader(buf *bytes.Buffer, level slog.Level, t time.Time, object string, lineInfo string) {
// Add time in Go standard format if requested
if h.format&(logFormatDate|logFormatTime|logFormatMicroseconds) != 0 {
if h.format&logFormatUTC != 0 {
t = t.UTC()
}
if h.format&logFormatDate != 0 {
year, month, day := t.Date()
fmt.Fprintf(buf, "%04d/%02d/%02d ", year, month, day)
}
if h.format&(logFormatTime|logFormatMicroseconds) != 0 {
hour, min, sec := t.Clock()
fmt.Fprintf(buf, "%02d:%02d:%02d", hour, min, sec)
if h.format&logFormatMicroseconds != 0 {
fmt.Fprintf(buf, ".%06d", t.Nanosecond()/1e3)
}
buf.WriteByte(' ')
}
}
// Add source code filename:line if requested
if h.format&(logFormatShortFile|logFormatLongFile) != 0 && lineInfo != "" {
buf.WriteString(lineInfo)
buf.WriteByte(':')
buf.WriteByte(' ')
}
// Add PID if requested
if h.format&logFormatPid != 0 {
fmt.Fprintf(buf, "[%d] ", os.Getpid())
}
// Add log level if required
if h.format&logFormatNoLevel == 0 {
levelStr := slogLevelToString(level)
fmt.Fprintf(buf, "%-6s: ", levelStr)
}
// Add object if passed
if object != "" {
buf.WriteString(object)
buf.WriteByte(':')
buf.WriteByte(' ')
}
}
// Create a log in standard Go log format into buf.
func (h *OutputHandler) textLog(ctx context.Context, buf *bytes.Buffer, r slog.Record) error {
var lineInfo string
if h.format&(logFormatShortFile|logFormatLongFile) != 0 {
lineInfo = getCaller(2)
}
var object string
r.Attrs(func(attr slog.Attr) bool {
if attr.Key == "object" {
object = attr.Value.String()
return false
}
return true
})
h.formatStdLogHeader(buf, r.Level, r.Time, object, lineInfo)
buf.WriteString(r.Message)
if buf.Len() == 0 || buf.Bytes()[buf.Len()-1] != '\n' { // Ensure newline
buf.WriteByte('\n')
}
return nil
}
// Create a log in JSON format into buf.
func (h *OutputHandler) jsonLog(ctx context.Context, buf *bytes.Buffer, r slog.Record) (err error) {
// Call the JSON handler to create the JSON in buf
r.AddAttrs(
slog.String("source", getCaller(2)),
)
h.mu.Lock()
err = h.jsonHandler.Handle(ctx, r)
if err == nil {
_, err = h.jsonBuf.WriteTo(buf)
}
h.mu.Unlock()
return err
}
// Handle outputs a log in the current format
func (h *OutputHandler) Handle(ctx context.Context, r slog.Record) (err error) {
var (
bufJSON *bytes.Buffer
bufText *bytes.Buffer
buf *bytes.Buffer
)
// Check whether we need to build Text or JSON logs or both
needJSON := h.format&logFormatJSON != 0
needText := !needJSON
for _, out := range h.outputExtra {
if out.json {
needJSON = true
} else {
needText = true
}
}
if needJSON {
var bufJSONBack [256]byte
bufJSON = bytes.NewBuffer(bufJSONBack[:0])
err = h.jsonLog(ctx, bufJSON, r)
if err != nil {
return err
}
}
if needText {
var bufTextBack [256]byte
bufText = bytes.NewBuffer(bufTextBack[:0])
err = h.textLog(ctx, bufText, r)
if err != nil {
return err
}
}
h.mu.Lock()
defer h.mu.Unlock()
// Do the log, either to the default destination or to the alternate logging system
if h.format&logFormatJSON != 0 {
buf = bufJSON
} else {
buf = bufText
}
if len(h.output) > 0 {
h.output[len(h.output)-1](r.Level, buf.String())
err = nil
} else {
_, err = h.writer.Write(buf.Bytes())
}
// Log to any additional destinations required
for _, out := range h.outputExtra {
if out.json {
out.output(r.Level, bufJSON.String())
} else {
out.output(r.Level, bufText.String())
}
}
return err
}
// WithAttrs creates a new handler with the same writer, options, and flags.
// Attributes are ignored for the output format of this specific handler.
func (h *OutputHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
return NewOutputHandler(h.writer, &h.opts, h.format)
}
// WithGroup creates a new handler with the same writer, options, and flags.
// Groups are ignored for the output format of this specific handler.
func (h *OutputHandler) WithGroup(name string) slog.Handler {
return NewOutputHandler(h.writer, &h.opts, h.format)
}
// Check interface
var _ slog.Handler = (*OutputHandler)(nil)

264
fs/log/slog_test.go Normal file
View File

@@ -0,0 +1,264 @@
package log
import (
"bytes"
"context"
"fmt"
"os"
"regexp"
"strings"
"testing"
"time"
"log/slog"
"github.com/rclone/rclone/fs"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)
var (
utcPlusOne = time.FixedZone("UTC+1", 1*60*60)
t0 = time.Date(2020, 1, 2, 3, 4, 5, 123456000, utcPlusOne)
)
// Test slogLevelToString covers all mapped levels and an unknown level.
func TestSlogLevelToString(t *testing.T) {
tests := []struct {
level slog.Level
want string
}{
{slog.LevelDebug, "DEBUG"},
{slog.LevelInfo, "INFO"},
{fs.SlogLevelNotice, "NOTICE"},
{slog.LevelWarn, "WARNING"},
{slog.LevelError, "ERROR"},
{fs.SlogLevelCritical, "CRITICAL"},
{fs.SlogLevelAlert, "ALERT"},
{fs.SlogLevelEmergency, "EMERGENCY"},
// Unknown level should fall back to .String()
{slog.Level(1234), slog.Level(1234).String()},
}
for _, tc := range tests {
got := slogLevelToString(tc.level)
assert.Equal(t, tc.want, got)
}
}
// Test mapLogLevelNames replaces only the LevelKey attr and lowercases it.
func TestMapLogLevelNames(t *testing.T) {
a := slog.Any(slog.LevelKey, slog.LevelWarn)
mapped := mapLogLevelNames(nil, a)
val, ok := mapped.Value.Any().(string)
if !ok || val != "warning" {
t.Errorf("mapLogLevelNames did not lowercase level: got %v", mapped.Value.Any())
}
// non-level attr should remain unchanged
other := slog.String("foo", "bar")
out := mapLogLevelNames(nil, other)
assert.Equal(t, out.Value, other.Value, "mapLogLevelNames changed a non-level attr")
}
// Test getCaller returns a file:line string of the correct form.
func TestGetCaller(t *testing.T) {
out := getCaller(0)
assert.NotEqual(t, "", out)
match := regexp.MustCompile(`^([^:]+):(\d+)$`).FindStringSubmatch(out)
assert.NotNil(t, match)
// Can't test this as it skips the /log/ directory!
// assert.Equal(t, "slog_test.go", match[1])
}
// Test formatStdLogHeader for various flag combinations.
func TestFormatStdLogHeader(t *testing.T) {
cases := []struct {
name string
format logFormat
lineInfo string
object string
wantPrefix string
}{
{"dateTime", logFormatDate | logFormatTime, "", "", "2020/01/02 03:04:05 "},
{"time", logFormatTime, "", "", "03:04:05 "},
{"date", logFormatDate, "", "", "2020/01/02 "},
{"dateTimeUTC", logFormatDate | logFormatTime | logFormatUTC, "", "", "2020/01/02 02:04:05 "},
{"dateTimeMicro", logFormatDate | logFormatTime | logFormatMicroseconds, "", "", "2020/01/02 03:04:05.123456 "},
{"micro", logFormatMicroseconds, "", "", "03:04:05.123456 "},
{"shortFile", logFormatShortFile, "foo.go:10", "03:04:05 ", "foo.go:10: "},
{"longFile", logFormatLongFile, "foo.go:10", "03:04:05 ", "foo.go:10: "},
{"timePID", logFormatPid, "", "", fmt.Sprintf("[%d] ", os.Getpid())},
{"levelObject", 0, "", "myobj", "INFO : myobj: "},
}
for _, tc := range cases {
t.Run(tc.name, func(t *testing.T) {
h := &OutputHandler{format: tc.format}
buf := &bytes.Buffer{}
h.formatStdLogHeader(buf, slog.LevelInfo, t0, tc.object, tc.lineInfo)
if !strings.HasPrefix(buf.String(), tc.wantPrefix) {
t.Errorf("%s: got %q; want prefix %q", tc.name, buf.String(), tc.wantPrefix)
}
})
}
}
// Test Enabled honors the HandlerOptions.Level.
func TestEnabled(t *testing.T) {
h := NewOutputHandler(&bytes.Buffer{}, nil, 0)
assert.True(t, h.Enabled(context.Background(), slog.LevelInfo))
assert.False(t, h.Enabled(context.Background(), slog.LevelDebug))
opts := &slog.HandlerOptions{Level: slog.LevelDebug}
h2 := NewOutputHandler(&bytes.Buffer{}, opts, 0)
assert.True(t, h2.Enabled(context.Background(), slog.LevelDebug))
}
// Test clearFormatFlags and setFormatFlags bitwise ops.
func TestClearSetFormatFlags(t *testing.T) {
h := &OutputHandler{format: logFormatDate | logFormatTime}
h.clearFormatFlags(logFormatTime)
assert.True(t, h.format&logFormatTime == 0)
h.setFormatFlags(logFormatMicroseconds)
assert.True(t, h.format&logFormatMicroseconds != 0)
}
// Test SetOutput and ResetOutput override the default writer.
func TestSetResetOutput(t *testing.T) {
buf := &bytes.Buffer{}
h := NewOutputHandler(buf, nil, 0)
var gotOverride string
out := func(_ slog.Level, txt string) {
gotOverride = txt
}
h.SetOutput(out)
r := slog.NewRecord(t0, slog.LevelInfo, "hello", 0)
require.NoError(t, h.Handle(context.Background(), r))
assert.NotEqual(t, "", gotOverride)
require.Equal(t, "", buf.String())
h.ResetOutput()
require.NoError(t, h.Handle(context.Background(), r))
require.NotEqual(t, "", buf.String())
}
// Test AddOutput sends to extra destinations.
func TestAddOutput(t *testing.T) {
buf := &bytes.Buffer{}
h := NewOutputHandler(buf, nil, logFormatDate|logFormatTime)
var extraText string
out := func(_ slog.Level, txt string) {
extraText = txt
}
h.AddOutput(false, out)
r := slog.NewRecord(t0, slog.LevelInfo, "world", 0)
require.NoError(t, h.Handle(context.Background(), r))
assert.Equal(t, "2020/01/02 03:04:05 INFO : world\n", buf.String())
assert.Equal(t, "2020/01/02 03:04:05 INFO : world\n", extraText)
}
// Test AddOutputJSON sends JSON to extra destinations.
func TestAddOutputJSON(t *testing.T) {
buf := &bytes.Buffer{}
h := NewOutputHandler(buf, nil, logFormatDate|logFormatTime)
var extraText string
out := func(_ slog.Level, txt string) {
extraText = txt
}
h.AddOutput(true, out)
r := slog.NewRecord(t0, slog.LevelInfo, "world", 0)
require.NoError(t, h.Handle(context.Background(), r))
assert.NotEqual(t, "", extraText)
assert.Equal(t, "2020/01/02 03:04:05 INFO : world\n", buf.String())
assert.True(t, strings.HasPrefix(extraText, `{"time":"2020-01-02T03:04:05.123456+01:00","level":"info","msg":"world","source":"`))
assert.True(t, strings.HasSuffix(extraText, "\"}\n"))
}
// Test AddOutputUseJSONLog sends text to extra destinations.
func TestAddOutputUseJSONLog(t *testing.T) {
buf := &bytes.Buffer{}
h := NewOutputHandler(buf, nil, logFormatDate|logFormatTime|logFormatJSON)
var extraText string
out := func(_ slog.Level, txt string) {
extraText = txt
}
h.AddOutput(false, out)
r := slog.NewRecord(t0, slog.LevelInfo, "world", 0)
require.NoError(t, h.Handle(context.Background(), r))
assert.NotEqual(t, "", extraText)
assert.True(t, strings.HasPrefix(buf.String(), `{"time":"2020-01-02T03:04:05.123456+01:00","level":"info","msg":"world","source":"`))
assert.True(t, strings.HasSuffix(buf.String(), "\"}\n"))
assert.Equal(t, "2020/01/02 03:04:05 INFO : world\n", extraText)
}
// Test WithAttrs and WithGroup return new handlers with same settings.
func TestWithAttrsAndGroup(t *testing.T) {
buf := &bytes.Buffer{}
h := NewOutputHandler(buf, nil, logFormatDate)
h2 := h.WithAttrs([]slog.Attr{slog.String("k", "v")})
if _, ok := h2.(*OutputHandler); !ok {
t.Error("WithAttrs returned wrong type")
}
h3 := h.WithGroup("grp")
if _, ok := h3.(*OutputHandler); !ok {
t.Error("WithGroup returned wrong type")
}
}
// Test textLog and jsonLog directly for basic correctness.
func TestTextLogAndJsonLog(t *testing.T) {
h := NewOutputHandler(&bytes.Buffer{}, nil, logFormatDate|logFormatTime)
r := slog.NewRecord(t0, slog.LevelWarn, "msg!", 0)
r.AddAttrs(slog.String("object", "obj"))
// textLog
bufText := &bytes.Buffer{}
require.NoError(t, h.textLog(context.Background(), bufText, r))
out := bufText.String()
if !strings.Contains(out, "WARNING") || !strings.Contains(out, "obj:") || !strings.HasSuffix(out, "\n") {
t.Errorf("textLog output = %q", out)
}
// jsonLog
bufJSON := &bytes.Buffer{}
require.NoError(t, h.jsonLog(context.Background(), bufJSON, r))
j := bufJSON.String()
if !strings.Contains(j, `"level":"warning"`) || !strings.Contains(j, `"msg":"msg!"`) {
t.Errorf("jsonLog output = %q", j)
}
}
// Table-driven test for JSON vs text Handle behavior.
func TestHandleFormatFlags(t *testing.T) {
r := slog.NewRecord(t0, slog.LevelInfo, "hi", 0)
cases := []struct {
name string
format logFormat
wantJSON bool
}{
{"textMode", 0, false},
{"jsonMode", logFormatJSON, true},
}
for _, tc := range cases {
buf := &bytes.Buffer{}
h := NewOutputHandler(buf, nil, tc.format)
require.NoError(t, h.Handle(context.Background(), r))
out := buf.String()
if tc.wantJSON {
if !strings.HasPrefix(out, "{") || !strings.Contains(out, `"level":"info"`) {
t.Errorf("%s: got %q; want JSON", tc.name, out)
}
} else {
if !strings.Contains(out, "INFO") {
t.Errorf("%s: got %q; want text INFO", tc.name, out)
}
}
}
}

View File

@@ -11,7 +11,7 @@ import (
) )
// Starts syslog if configured, returns true if it was started // Starts syslog if configured, returns true if it was started
func startSysLog() bool { func startSysLog(handler *OutputHandler) bool {
fs.Fatalf(nil, "--syslog not supported on %s platform", runtime.GOOS) fs.Fatalf(nil, "--syslog not supported on %s platform", runtime.GOOS)
return false return false
} }

View File

@@ -5,7 +5,7 @@
package log package log
import ( import (
"log" "log/slog"
"log/syslog" "log/syslog"
"os" "os"
"path" "path"
@@ -39,7 +39,7 @@ var (
) )
// Starts syslog // Starts syslog
func startSysLog() bool { func startSysLog(handler *OutputHandler) bool {
facility, ok := syslogFacilityMap[Opt.SyslogFacility] facility, ok := syslogFacilityMap[Opt.SyslogFacility]
if !ok { if !ok {
fs.Fatalf(nil, "Unknown syslog facility %q - man syslog for list", Opt.SyslogFacility) fs.Fatalf(nil, "Unknown syslog facility %q - man syslog for list", Opt.SyslogFacility)
@@ -49,27 +49,27 @@ func startSysLog() bool {
if err != nil { if err != nil {
fs.Fatalf(nil, "Failed to start syslog: %v", err) fs.Fatalf(nil, "Failed to start syslog: %v", err)
} }
log.SetFlags(0) handler.clearFormatFlags(logFormatDate | logFormatTime | logFormatMicroseconds | logFormatUTC | logFormatLongFile | logFormatShortFile | logFormatPid)
log.SetOutput(w) handler.setFormatFlags(logFormatNoLevel)
fs.LogOutput = func(level fs.LogLevel, text string) { handler.SetOutput(func(level slog.Level, text string) {
switch level { switch level {
case fs.LogLevelEmergency: case fs.SlogLevelEmergency:
_ = w.Emerg(text) _ = w.Emerg(text)
case fs.LogLevelAlert: case fs.SlogLevelAlert:
_ = w.Alert(text) _ = w.Alert(text)
case fs.LogLevelCritical: case fs.SlogLevelCritical:
_ = w.Crit(text) _ = w.Crit(text)
case fs.LogLevelError: case slog.LevelError:
_ = w.Err(text) _ = w.Err(text)
case fs.LogLevelWarning: case slog.LevelWarn:
_ = w.Warning(text) _ = w.Warning(text)
case fs.LogLevelNotice: case fs.SlogLevelNotice:
_ = w.Notice(text) _ = w.Notice(text)
case fs.LogLevelInfo: case slog.LevelInfo:
_ = w.Info(text) _ = w.Info(text)
case fs.LogLevelDebug: case slog.LevelDebug:
_ = w.Debug(text) _ = w.Debug(text)
} }
} })
return true return true
} }

View File

@@ -11,7 +11,7 @@ import (
) )
// Enables systemd logs if configured or if auto-detected // Enables systemd logs if configured or if auto-detected
func startSystemdLog() bool { func startSystemdLog(handler *OutputHandler) bool {
fs.Fatalf(nil, "--log-systemd not supported on %s platform", runtime.GOOS) fs.Fatalf(nil, "--log-systemd not supported on %s platform", runtime.GOOS)
return false return false
} }

View File

@@ -7,54 +7,47 @@ package log
import ( import (
"fmt" "fmt"
"log" "log"
"log/slog"
"strconv" "strconv"
"strings"
"github.com/coreos/go-systemd/v22/journal" "github.com/coreos/go-systemd/v22/journal"
"github.com/rclone/rclone/fs" "github.com/rclone/rclone/fs"
) )
// Enables systemd logs if configured or if auto-detected // Enables systemd logs if configured or if auto-detected
func startSystemdLog() bool { func startSystemdLog(handler *OutputHandler) bool {
flagsStr := "," + Opt.Format + "," handler.clearFormatFlags(logFormatDate | logFormatTime | logFormatMicroseconds | logFormatUTC | logFormatLongFile | logFormatShortFile | logFormatPid)
var flags int handler.setFormatFlags(logFormatNoLevel)
if strings.Contains(flagsStr, ",longfile,") {
flags |= log.Llongfile
}
if strings.Contains(flagsStr, ",shortfile,") {
flags |= log.Lshortfile
}
log.SetFlags(flags)
// TODO: Use the native journal.Print approach rather than a custom implementation // TODO: Use the native journal.Print approach rather than a custom implementation
fs.LogOutput = func(level fs.LogLevel, text string) { handler.SetOutput(func(level slog.Level, text string) {
text = fmt.Sprintf("<%s>%-6s: %s", systemdLogPrefix(level), level, text) text = fmt.Sprintf("<%s>%-6s: %s", systemdLogPrefix(level), level, text)
_ = log.Output(4, text) _ = log.Output(4, text)
} })
return true return true
} }
var logLevelToSystemdPrefix = []journal.Priority{ var slogLevelToSystemdPrefix = map[slog.Level]journal.Priority{
fs.LogLevelEmergency: journal.PriEmerg, fs.SlogLevelEmergency: journal.PriEmerg,
fs.LogLevelAlert: journal.PriAlert, fs.SlogLevelAlert: journal.PriAlert,
fs.LogLevelCritical: journal.PriCrit, fs.SlogLevelCritical: journal.PriCrit,
fs.LogLevelError: journal.PriErr, slog.LevelError: journal.PriErr,
fs.LogLevelWarning: journal.PriWarning, slog.LevelWarn: journal.PriWarning,
fs.LogLevelNotice: journal.PriNotice, fs.SlogLevelNotice: journal.PriNotice,
fs.LogLevelInfo: journal.PriInfo, slog.LevelInfo: journal.PriInfo,
fs.LogLevelDebug: journal.PriDebug, slog.LevelDebug: journal.PriDebug,
} }
func systemdLogPrefix(l fs.LogLevel) string { func systemdLogPrefix(l slog.Level) string {
if l >= fs.LogLevel(len(logLevelToSystemdPrefix)) { prio, ok := slogLevelToSystemdPrefix[l]
if !ok {
return "" return ""
} }
return strconv.Itoa(int(logLevelToSystemdPrefix[l])) return strconv.Itoa(int(prio))
} }
func isJournalStream() bool { func isJournalStream() bool {
if usingJournald, _ := journal.StderrIsJournalStream(); usingJournald { if usingJournald, _ := journal.StderrIsJournalStream(); usingJournald {
return true return true
} }
return false return false
} }

View File

@@ -6,12 +6,11 @@ import (
"errors" "errors"
"fmt" "fmt"
"io" "io"
"log"
"os"
"sort" "sort"
"strings" "strings"
"testing" "testing"
"github.com/rclone/rclone/cmd/bisync/bilib"
"github.com/rclone/rclone/fs" "github.com/rclone/rclone/fs"
"github.com/rclone/rclone/fs/accounting" "github.com/rclone/rclone/fs/accounting"
"github.com/rclone/rclone/fs/hash" "github.com/rclone/rclone/fs/hash"
@@ -65,18 +64,16 @@ func testCheck(t *testing.T, checkFunction func(ctx context.Context, opt *operat
check := func(i int, wantErrors int64, wantChecks int64, oneway bool, wantOutput map[string]string) { check := func(i int, wantErrors int64, wantChecks int64, oneway bool, wantOutput map[string]string) {
t.Run(fmt.Sprintf("%d", i), func(t *testing.T) { t.Run(fmt.Sprintf("%d", i), func(t *testing.T) {
accounting.GlobalStats().ResetCounters() accounting.GlobalStats().ResetCounters()
var buf bytes.Buffer
log.SetOutput(&buf)
defer func() {
log.SetOutput(os.Stderr)
}()
opt := operations.CheckOpt{ opt := operations.CheckOpt{
Fdst: r.Fremote, Fdst: r.Fremote,
Fsrc: r.Flocal, Fsrc: r.Flocal,
OneWay: oneway, OneWay: oneway,
} }
addBuffers(&opt) addBuffers(&opt)
err := checkFunction(ctx, &opt) var err error
buf := bilib.CaptureOutput(func() {
err = checkFunction(ctx, &opt)
})
gotErrors := accounting.GlobalStats().GetErrors() gotErrors := accounting.GlobalStats().GetErrors()
gotChecks := accounting.GlobalStats().GetChecks() gotChecks := accounting.GlobalStats().GetChecks()
if wantErrors == 0 && err != nil { if wantErrors == 0 && err != nil {
@@ -88,7 +85,7 @@ func testCheck(t *testing.T, checkFunction func(ctx context.Context, opt *operat
if wantErrors != gotErrors { if wantErrors != gotErrors {
t.Errorf("%d: Expecting %d errors but got %d", i, wantErrors, gotErrors) t.Errorf("%d: Expecting %d errors but got %d", i, wantErrors, gotErrors)
} }
if gotChecks > 0 && !strings.Contains(buf.String(), "matching files") { if gotChecks > 0 && !strings.Contains(string(buf), "matching files") {
t.Errorf("%d: Total files matching line missing", i) t.Errorf("%d: Total files matching line missing", i)
} }
if wantChecks != gotChecks { if wantChecks != gotChecks {
@@ -389,9 +386,6 @@ func testCheckSum(t *testing.T, download bool) {
checkRun := func(runNo, wantChecks, wantErrors int, want wantType) { checkRun := func(runNo, wantChecks, wantErrors int, want wantType) {
accounting.GlobalStats().ResetCounters() accounting.GlobalStats().ResetCounters()
buf := new(bytes.Buffer)
log.SetOutput(buf)
defer log.SetOutput(os.Stderr)
opt := operations.CheckOpt{ opt := operations.CheckOpt{
Combined: new(bytes.Buffer), Combined: new(bytes.Buffer),
@@ -401,8 +395,10 @@ func testCheckSum(t *testing.T, download bool) {
MissingOnSrc: new(bytes.Buffer), MissingOnSrc: new(bytes.Buffer),
MissingOnDst: new(bytes.Buffer), MissingOnDst: new(bytes.Buffer),
} }
err := operations.CheckSum(ctx, dataFs, r.Fremote, sumFile, hashType, &opt, download) var err error
buf := bilib.CaptureOutput(func() {
err = operations.CheckSum(ctx, dataFs, r.Fremote, sumFile, hashType, &opt, download)
})
gotErrors := int(accounting.GlobalStats().GetErrors()) gotErrors := int(accounting.GlobalStats().GetErrors())
if wantErrors == 0 { if wantErrors == 0 {
assert.NoError(t, err, "unexpected error in run %d", runNo) assert.NoError(t, err, "unexpected error in run %d", runNo)
@@ -414,7 +410,7 @@ func testCheckSum(t *testing.T, download bool) {
gotChecks := int(accounting.GlobalStats().GetChecks()) gotChecks := int(accounting.GlobalStats().GetChecks())
if wantChecks > 0 || gotChecks > 0 { if wantChecks > 0 || gotChecks > 0 {
assert.Contains(t, buf.String(), "matching files", "missing matching files in run %d", runNo) assert.Contains(t, string(buf), "matching files", "missing matching files in run %d", runNo)
} }
assert.Equal(t, wantChecks, gotChecks, "wrong number of checks in run %d", runNo) assert.Equal(t, wantChecks, gotChecks, "wrong number of checks in run %d", runNo)

2
go.mod
View File

@@ -66,7 +66,6 @@ require (
github.com/rivo/uniseg v0.4.7 github.com/rivo/uniseg v0.4.7
github.com/rogpeppe/go-internal v1.14.1 github.com/rogpeppe/go-internal v1.14.1
github.com/shirou/gopsutil/v4 v4.25.1 github.com/shirou/gopsutil/v4 v4.25.1
github.com/sirupsen/logrus v1.9.3
github.com/skratchdot/open-golang v0.0.0-20200116055534-eef842397966 github.com/skratchdot/open-golang v0.0.0-20200116055534-eef842397966
github.com/spf13/cobra v1.9.1 github.com/spf13/cobra v1.9.1
github.com/spf13/pflag v1.0.6 github.com/spf13/pflag v1.0.6
@@ -208,6 +207,7 @@ require (
github.com/sabhiram/go-gitignore v0.0.0-20210923224102-525f6e181f06 // indirect github.com/sabhiram/go-gitignore v0.0.0-20210923224102-525f6e181f06 // indirect
github.com/samber/lo v1.47.0 // indirect github.com/samber/lo v1.47.0 // indirect
github.com/shabbyrobe/gocovmerge v0.0.0-20230507112040-c3350d9342df // indirect github.com/shabbyrobe/gocovmerge v0.0.0-20230507112040-c3350d9342df // indirect
github.com/sirupsen/logrus v1.9.3 // indirect
github.com/sony/gobreaker v0.5.0 // indirect github.com/sony/gobreaker v0.5.0 // indirect
github.com/spacemonkeygo/monkit/v3 v3.0.22 // indirect github.com/spacemonkeygo/monkit/v3 v3.0.22 // indirect
github.com/tklauser/go-sysconf v0.3.13 // indirect github.com/tklauser/go-sysconf v0.3.13 // indirect