rc: fix LogLevel in _config being ignored

Before this change setting LogLevel in the _config parameter of an rc
call had no effect as both the log functions and the log handler only
looked at the global log level.

The context aware log functions now use the log level from the config
in the context, and the log handler lets a log level in the context
which differs from the global one override its own level. This means
an rc call can be made more or less verbose than the rest of rclone
with, for example

    "_config": {"LogLevel": "DEBUG"}

This applies to the logs made with the context aware log functions, so
not to those made by the backends which still use the global log level.

Note that a config copied into a context no longer follows later
changes to the global log level.

docs/content/docs.md

@@ -778,6 +778,135 @@ modification time of the source object.
 Hashes are not included in system metadata as there is a well defined
 way of reading those already.
 
+## Performance {#performance}
+
+Rclone's defaults are fairly conservative. They are chosen to work on
+small machines, slow links and with cloud providers which rate limit
+heavily. If you have plenty of bandwidth, memory and a fast storage
+system then rclone can usually be made to run a great deal faster by
+adjusting a few flags.
+
+The right values depend on the size of your files, your network and
+the storage systems at each end, so treat the numbers below as
+starting points. Change one thing at a time and measure the result.
+
+### Measuring
+
+Use `rclone copy` with [-P/--progress](#p-progress) to watch the
+transfer rate while you are experimenting. For unattended runs log the
+stats instead, e.g. `--stats 1m --stats-one-line --stats-log-level
+NOTICE`.
+
+A transfer is always limited by something: the network bandwidth, the
+rate at which the storage system will accept requests, disk IO, CPU or
+memory. Tuning is working out which limit you are hitting and raising
+it until you hit the next one. Watch the network, disk, CPU and memory
+use of the machine rclone is running on as well as rclone's stats.
+
+### Lots of files
+
+The time taken to transfer small files is dominated by the round trip
+time of the requests rather than by the bandwidth, so the way to make
+them go faster is to do more of them at once.
+
+[--transfers](#transfers-int) sets the number of files transferred in
+parallel. The default is 4. Double this until the transfer rate stops
+increasing or the storage system starts returning errors. Values of 32
+to 64 are common and values in the hundreds work well with the large
+object storage systems (e.g. s3, azureblob, googlecloudstorage, b2)
+when transferring lots of small files.
+
+[--checkers](#checkers-int) sets the number of directory listings and
+file comparisons done in parallel. The default is 8. Raising this
+speeds up syncs where most of the files are already present on the
+destination and stops the checking being the bottleneck when
+`--transfers` is large. 16 to 64 is a reasonable range.
+
+Not all storage systems like lots of parallel requests. If you see rate
+limiting errors (e.g. HTTP 429 or 503 errors) or lots of low level
+retries in the log then you have gone too far, so reduce `--transfers`
+and `--checkers` or use [--tpslimit](#tpslimit-float) to cap the
+request rate. Local disks, especially spinning ones, and network file
+systems may get slower rather than faster with too much parallelism.
+
+### Large files
+
+A single stream often won't fill a fast link, so rclone can transfer a
+large file as several chunks in parallel. These are called multi-thread
+transfers and are used for files bigger than
+[--multi-thread-cutoff](#multi-thread-cutoff) on backends which
+support them.
+
+The number of chunks transferred in parallel is set by
+[--multi-thread-streams](#multi-thread-streams-int) (default 4) and
+this works for all backends so increase this first to make large files
+transfer faster.
+
+The size of the chunks is set by the backend, usually with a
+`--backend-chunk-size` flag, e.g. `--s3-chunk-size`. Backends without
+a natural chunk size (e.g. local, smb) use
+[--multi-thread-chunk-size](#multi-thread-chunk-size-sizesuffix).
+Larger chunks mean fewer requests which increases throughput on big
+files. See the docs for the backend you are using for details.
+
+Chunked uploads are usually buffered in memory, so in the worst case
+rclone will use
+
+```text
+--transfers * upload concurrency * chunk size
+```
+
+of memory for buffers. For example `--transfers 256` with an upload
+concurrency of 8 and a chunk size of 16 MiB could use up to 32 GiB.
+When you raise `--transfers` to speed up small files you may therefore
+need to lower the upload concurrency, or set
+[--max-buffer-memory](#max-buffer-memory) which limits the total
+memory used for buffers and makes transfers wait when the limit is
+reached.
+
+[--use-mmap](#use-mmap) makes rclone return buffer memory to the OS as
+soon as it has finished with it which is helpful when using lots of
+transfers or large chunks.
+
+### A mixture of large and small files
+
+By default rclone transfers files in roughly the order it finds them.
+With a mixture of file sizes this means that at times all the
+transfers are large files, which fill the bandwidth but make few
+requests, and at other times all the transfers are small files, which
+make lots of requests but use little of the bandwidth.
+
+Using [--order-by](#order-by-string) `size,mixed,50` makes half of the
+transfers take the smallest files in the backlog and half of them take
+the largest. This keeps both large and small files moving at once so
+the bandwidth and the request rate are both kept full for the whole of
+the run.
+
+This works best if rclone has lots of files to choose from so use it
+with a big [--max-backlog](#max-backlog-int), e.g. `--max-backlog
+2000000`. Each item in the backlog uses in the order of 1 KiB of memory.
+
+### Doing less work
+
+Fewer requests to the storage system means a faster transfer.
+
+- If the source and destination are on the same remote then rclone
+  will use [server-side copy](#server-side-copy) where it is supported
+  so the data doesn't need to be downloaded and uploaded again.
+- [--fast-list](#fast-list) lists bucket-based remotes with fewer
+  transactions at the cost of using more memory. This may be faster or
+  slower than the default so it is worth testing.
+- [--no-traverse](#no-traverse) stops rclone listing the destination
+  which helps when copying a small number of files into a large
+  destination.
+- [--size-only](#size-only) or [--checksum](#c-checksum) avoid reading
+  the modification time. On some object storage systems (e.g. s3,
+  swift) this needs an extra request for each file. Alternatively use
+  [--use-server-modtime](#use-server-modtime) with `--update`.
+- [--no-check-dest](#no-check-dest) skips checking the destination
+  entirely. Only use this if you know that none of the files are
+  there already.
+
 ## Options
 
 Rclone has a number of options to control its behaviour. These are

docs/content/rc.md

@@ -480,6 +480,16 @@ Or flat:
 If you wish to check the `_config` assignment has worked properly then
 calling `options/local` will show what the value got set to.
 
+Setting `LogLevel` sets the log level for the logs made by the rc call
+only, for example to debug a single call.
+
+```json
+"_config":{"LogLevel": "DEBUG"}
+```
+
+Note that not all of rclone's logs support this yet. In particular the
+backends log at the global log level.
+
 ### Setting filter flags with _filter
 
 If you wish to set filters for the duration of an rc call only then

fs/accounting/stats_groups.go

@@ -17,6 +17,9 @@ var groups *statsGroups
 func init() {
 	// Init stats container
 	groups = newStatsGroups()
+
+	// Attribute logs to stats groups
+	fs.StatsGroupFromContext = StatsGroupFromContext
 }
 
 func rcListStats(ctx context.Context, in rc.Params) (rc.Params, error) {

fs/accounting/stats_groups_test.go

@@ -310,3 +310,13 @@ func TestNewStatsGroupDoesNotStartAverageLoop(t *testing.T) {
 	assert.False(t, startedAfterDone,
 		"averageLoop should stop when the last transfer is done")
 }
+
+// Check fs can read the stats group to attribute logs to it
+func TestFsStatsGroupFromContext(t *testing.T) {
+	ctx := context.Background()
+	_, ok := fs.StatsGroupFromContext(ctx)
+	assert.False(t, ok)
+	group, ok := fs.StatsGroupFromContext(WithStatsGroup(ctx, "job/1"))
+	assert.True(t, ok)
+	assert.Equal(t, "job/1", group)
+}

fs/config.go

@@ -43,6 +43,22 @@ var (
 	// implementation from the fs
 	CountError = func(ctx context.Context, err error) error { return err }
 
+	// StatsGroupFromContext returns the stats group from ctx if set.
+	//
+	// This is used to attribute logs to stats groups.
+	//
+	// This is a function pointer to decouple the accounting
+	// implementation from the fs
+	StatsGroupFromContext = func(ctx context.Context) (string, bool) { return "", false }
+
+	// JobIDFromContext returns the ID of the rc job in ctx if set.
+	//
+	// This is used to attribute logs to the rc job which made them.
+	//
+	// This is a function pointer to decouple the rc jobs
+	// implementation from the fs
+	JobIDFromContext = func(ctx context.Context) (int64, bool) { return 0, false }
+
 	// ConfigProvider is the config key used for provider options
 	ConfigProvider = "provider"
 

fs/filter/filter.go

@@ -583,7 +583,7 @@ func (f *Filter) IncludeObject(ctx context.Context, o fs.Object) bool {
 		var err error
 		metadata, err = fs.GetMetadata(ctx, o)
 		if err != nil {
-			fs.Errorf(o, "Failed to read metadata: %v", err)
+			fs.ErrorfCtx(ctx, o, "Failed to read metadata: %v", err)
 			metadata = nil
 		}
 
@@ -653,7 +653,7 @@ func (f *Filter) MakeListR(ctx context.Context, NewObject func(ctx context.Conte
 						// Count and log the error but carry on so that one
 						// unreadable file (e.g. permission denied) doesn't stop
 						// the other --files-from files being processed.
-						fs.Errorf(remote, "--files-from failed to read file: %v", err)
+						fs.ErrorfCtx(ctx, remote, "--files-from failed to read file: %v", err)
 						_ = fs.CountError(gCtx, err)
 					} else {
 						err = callback(entries)

fs/list/list.go

@@ -67,7 +67,7 @@ func DirSorted(ctx context.Context, f fs.Fs, includeAll bool, dir string) (entri
 	// called.
 	fi := filter.GetConfig(ctx)
 	if !includeAll && fi.ListContainsExcludeFile(entries) {
-		fs.Debugf(dir, "Excluded")
+		fs.DebugfCtx(ctx, dir, "Excluded")
 		return nil, nil
 	}
 	return filterAndSortDir(ctx, entries, includeAll, dir, fi.IncludeObject, fi.IncludeDirectory(ctx, f))
@@ -113,7 +113,7 @@ func DirSortedFn(ctx context.Context, f fs.Fs, includeAll bool, dir string, call
 		// starting directory, otherwise ListDirSorted should not be
 		// called.
 		if !includeAll && fi.ListContainsExcludeFile(entries) {
-			fs.Debugf(dir, "Excluded")
+			fs.DebugfCtx(ctx, dir, "Excluded")
 			return nil
 		}
 
@@ -150,7 +150,7 @@ func filterDir(ctx context.Context, entries fs.DirEntries, includeAll bool, dir
 			// Make sure we don't delete excluded files if not required
 			if !includeAll && !IncludeObject(ctx, x) {
 				ok = false
-				fs.Debugf(x, "Excluded")
+				fs.DebugfCtx(ctx, x, "Excluded")
 			}
 		case fs.Directory:
 			if !includeAll {
@@ -160,7 +160,7 @@ func filterDir(ctx context.Context, entries fs.DirEntries, includeAll bool, dir
 				}
 				if !include {
 					ok = false
-					fs.Debugf(x, "Excluded")
+					fs.DebugfCtx(ctx, x, "Excluded")
 				}
 			}
 		default:
@@ -173,13 +173,13 @@ func filterDir(ctx context.Context, entries fs.DirEntries, includeAll bool, dir
 			// ignore
 		case !strings.HasPrefix(remote, prefix):
 			ok = false
-			fs.Errorf(entry, "Entry doesn't belong in directory %q (too short) - ignoring", dir)
+			fs.ErrorfCtx(ctx, entry, "Entry doesn't belong in directory %q (too short) - ignoring", dir)
 		case remote == dir:
 			ok = false
-			fs.Errorf(entry, "Entry doesn't belong in directory %q (same as directory) - ignoring", dir)
+			fs.ErrorfCtx(ctx, entry, "Entry doesn't belong in directory %q (same as directory) - ignoring", dir)
 		case strings.ContainsRune(remote[len(prefix):], '/') && !bucket.IsAllSlashes(remote[len(prefix):]):
 			ok = false
-			fs.Errorf(entry, "Entry doesn't belong in directory %q (contains subdir) - ignoring", dir)
+			fs.ErrorfCtx(ctx, entry, "Entry doesn't belong in directory %q (contains subdir) - ignoring", dir)
 		default:
 			// ok
 		}

fs/list/sorter.go

@@ -111,7 +111,7 @@ func (ls *Sorter) keyToEntry(ctx context.Context, key string) (entry fs.DirEntry
 	} else {
 		obj, err := ls.f.NewObject(ctx, remote)
 		if err != nil {
-			fs.Errorf(ls.f, "sorter: failed to re-create object %q: %v", remote, err)
+			fs.ErrorfCtx(ctx, ls.f, "sorter: failed to re-create object %q: %v", remote, err)
 			return nil, fmt.Errorf("sorter: failed to re-create object: %w", err)
 		}
 		entry = obj
@@ -137,7 +137,7 @@ func (ls *Sorter) sendEntriesToExtSort(entries fs.DirEntries) (err error) {
 }
 
 func (ls *Sorter) startExtSort() (err error) {
-	fs.Logf(ls.f, "Switching to on disk sorting as more than %d entries in one directory detected", ls.cutoff)
+	fs.LogfCtx(ls.ctx, ls.f, "Switching to on disk sorting as more than %d entries in one directory detected", ls.cutoff)
 	ls.inputChan = make(chan string, 100)
 	// Options to control the extsort
 	opt := extsort.Config{
@@ -171,9 +171,9 @@ func (ls *Sorter) startExtSort() (err error) {
 	ls.extSort = true
 
 	// Send the accumulated entries to the sorter
-	fs.Debugf(ls.f, "Sending accumulated directory entries to disk")
+	fs.DebugfCtx(ls.ctx, ls.f, "Sending accumulated directory entries to disk")
 	err = ls.sendEntriesToExtSort(ls.entries)
-	fs.Debugf(ls.f, "Done sending accumulated directory entries to disk")
+	fs.DebugfCtx(ls.ctx, ls.f, "Done sending accumulated directory entries to disk")
 	clear(ls.entries)
 	ls.entries = nil
 	return err

fs/log.go

@@ -140,11 +140,16 @@ func LogLevelToSlog(level LogLevel) slog.Level {
 	return slogLevel
 }
 
-func logSlog(level LogLevel, text string, attrs []any) {
-	logger.Log(context.Background(), LogLevelToSlog(level), text, attrs...)
+func logSlog(ctx context.Context, level LogLevel, text string, attrs []any) {
+	if ctx == nil {
+		ctx = context.Background()
+	}
+	// ctx is passed to the log handler which uses it to attribute
+	// the log to the rc job and stats group it was made by.
+	logger.Log(ctx, LogLevelToSlog(level), text, attrs...)
 }
 
-func logSlogWithObject(level LogLevel, o any, text string, attrs []any) {
+func logSlogWithObject(ctx context.Context, level LogLevel, o any, text string, attrs []any) {
 	if o != nil {
 		var object string
 		switch o.(type) {
@@ -160,24 +165,44 @@ func logSlogWithObject(level LogLevel, o any, text string, attrs []any) {
 			"objectType", fmt.Sprintf("%T", o),
 		})
 	}
-	logSlog(level, text, attrs)
+	logSlog(ctx, level, text, attrs)
 }
 
-// LogPrint produces a log string from the arguments passed in
-func LogPrint(level LogLevel, o any, text string) {
-	logSlogWithObject(level, o, text, nil)
-}
-
-// LogPrintf produces a log string from the arguments passed in
-func LogPrintf(level LogLevel, o any, text string, args ...any) {
-	text = fmt.Sprintf(text, args...)
+func logPrintf(ctx context.Context, level LogLevel, o any, text string, args ...any) {
+	// Note that text isn't assigned to here so go vet can see this
+	// is a printf wrapper and check the format strings of the
+	// callers.
+	msg := fmt.Sprintf(text, args...)
 	var fields []any
 	for _, arg := range args {
 		if item, ok := arg.(LogValueItem); ok {
 			fields = append(fields, item.key, item.value)
 		}
 	}
-	logSlogWithObject(level, o, text, fields)
+	logSlogWithObject(ctx, level, o, msg, fields)
+}
+
+func logLevelPrintf(ctx context.Context, level LogLevel, o any, text string, args ...any) {
+	if GetConfig(ctx).LogLevel >= level {
+		logPrintf(ctx, level, o, text, args...)
+	}
+}
+
+// LogPrint produces a log string from the arguments passed in
+func LogPrint(level LogLevel, o any, text string) {
+	logSlogWithObject(context.Background(), level, o, text, nil)
+}
+
+// LogPrintf produces a log string from the arguments passed in
+func LogPrintf(level LogLevel, o any, text string, args ...any) {
+	logPrintf(context.Background(), level, o, text, args...)
+}
+
+// LogPrintfCtx produces a log string from the arguments passed in.
+//
+// The log is attributed to the stats group in ctx, if any.
+func LogPrintfCtx(ctx context.Context, level LogLevel, o any, text string, args ...any) {
+	logPrintf(ctx, level, o, text, args...)
 }
 
 // LogLevelPrint writes logs at the given level
@@ -189,9 +214,7 @@ func LogLevelPrint(level LogLevel, o any, text string) {
 
 // LogLevelPrintf writes logs at the given level
 func LogLevelPrintf(level LogLevel, o any, text string, args ...any) {
-	if GetConfig(context.TODO()).LogLevel >= level {
-		LogPrintf(level, o, text, args...)
-	}
+	logLevelPrintf(context.Background(), level, o, text, args...)
 }
 
 // Panic writes alert log output for this Object or Fs and calls panic().
@@ -273,6 +296,11 @@ func Errorf(o any, text string, args ...any) {
 	LogLevelPrintf(LogLevelError, o, text, args...)
 }
 
+// ErrorfCtx is Errorf with the log attributed to the stats group in ctx, if any.
+func ErrorfCtx(ctx context.Context, o any, text string, args ...any) {
+	logLevelPrintf(ctx, LogLevelError, o, text, args...)
+}
+
 // Print writes log output for this Object or Fs, same as Logf.
 func Print(o any, text string) {
 	LogLevelPrint(LogLevelNotice, o, text)
@@ -301,6 +329,11 @@ func Logf(o any, text string, args ...any) {
 	LogLevelPrintf(LogLevelNotice, o, text, args...)
 }
 
+// LogfCtx is Logf with the log attributed to the stats group in ctx, if any.
+func LogfCtx(ctx context.Context, o any, text string, args ...any) {
+	logLevelPrintf(ctx, LogLevelNotice, o, text, args...)
+}
+
 // Infoc writes info on transfers for this Object or Fs.  Use this
 // level for logging transfers, deletions and things which should
 // appear with the -v flag.
@@ -316,6 +349,11 @@ func Infof(o any, text string, args ...any) {
 	LogLevelPrintf(LogLevelInfo, o, text, args...)
 }
 
+// InfofCtx is Infof with the log attributed to the stats group in ctx, if any.
+func InfofCtx(ctx context.Context, o any, text string, args ...any) {
+	logLevelPrintf(ctx, LogLevelInfo, o, text, args...)
+}
+
 // Debug writes debugging output for this Object or Fs.  Use this for
 // debug only.  The user must have to specify -vv to see this.
 func Debug(o any, text string) {
@@ -328,6 +366,11 @@ func Debugf(o any, text string, args ...any) {
 	LogLevelPrintf(LogLevelDebug, o, text, args...)
 }
 
+// DebugfCtx is Debugf with the log attributed to the stats group in ctx, if any.
+func DebugfCtx(ctx context.Context, o any, text string, args ...any) {
+	logLevelPrintf(ctx, LogLevelDebug, o, text, args...)
+}
+
 // LogDirName returns an object for the logger, logging a root
 // directory which would normally be "" as the Fs
 func LogDirName(f Fs, dir string) any {

fs/log/slog.go

@@ -258,11 +258,17 @@ func (h *OutputHandler) setFormatFlags(bitMask logFormat) {
 }
 
 // Enabled returns whether this logger is enabled for this level.
-func (h *OutputHandler) Enabled(_ context.Context, level slog.Level) bool {
+//
+// A log level in the config in ctx which differs from the global one
+// overrides the level of the handler.
+func (h *OutputHandler) Enabled(ctx context.Context, level slog.Level) bool {
 	minLevel := slog.LevelInfo
 	if h.opts.Level != nil {
 		minLevel = h.opts.Level.Level()
 	}
+	if ctxLevel := fs.GetConfig(ctx).LogLevel; ctxLevel != fs.GetConfig(context.Background()).LogLevel {
+		minLevel = fs.LogLevelToSlog(ctxLevel)
+	}
 	return level >= minLevel
 }
 

fs/log/slog_test.go

@@ -140,6 +140,16 @@ func TestEnabled(t *testing.T) {
 	opts := &slog.HandlerOptions{Level: slog.LevelDebug}
 	h2 := NewOutputHandler(&bytes.Buffer{}, opts, 0)
 	assert.True(t, h2.Enabled(context.Background(), slog.LevelDebug))
+
+	// A log level in the config in the context which differs from
+	// the global one overrides the level of the handler
+	ctx, ci := fs.AddConfig(context.Background())
+	assert.False(t, h.Enabled(ctx, slog.LevelDebug))
+	ci.LogLevel = fs.LogLevelDebug
+	assert.True(t, h.Enabled(ctx, slog.LevelDebug))
+	ci.LogLevel = fs.LogLevelError
+	assert.False(t, h.Enabled(ctx, slog.LevelInfo))
+	assert.True(t, h.Enabled(ctx, slog.LevelError))
 }
 
 // Test clearFormatFlags and setFormatFlags bitwise ops.

fs/log_test.go

@@ -2,6 +2,7 @@ package fs
 
 import (
 	"bytes"
+	"context"
 	"encoding/json"
 	"fmt"
 	"log/slog"
@@ -41,19 +42,19 @@ func TestLogSlogWithObject(t *testing.T) {
 	SetLogger(slog.NewTextHandler(&buf, nil))
 
 	// Objects with a String method are rendered with it
-	logSlogWithObject(LogLevelError, withString{}, "message", nil)
+	logSlogWithObject(context.Background(), LogLevelError, withString{}, "message", nil)
 	assert.Contains(t, buf.String(), "object=hello")
 
 	// Plain strings are rendered as themselves
 	buf.Reset()
-	logSlogWithObject(LogLevelError, "potato", "message", nil)
+	logSlogWithObject(context.Background(), LogLevelError, "potato", "message", nil)
 	assert.Contains(t, buf.String(), "object=potato")
 
 	// Anything else shows only its type as it may contain
 	// sensitive data such as credentials
 	buf.Reset()
 	type secrets struct{ Password string }
-	logSlogWithObject(LogLevelError, &secrets{Password: "SECRET"}, "message", nil)
+	logSlogWithObject(context.Background(), LogLevelError, &secrets{Password: "SECRET"}, "message", nil)
 	assert.Contains(t, buf.String(), "object=*fs.secrets")
 	assert.NotContains(t, buf.String(), "SECRET")
 }
@@ -119,3 +120,107 @@ func TestLogLevelUnmarshalJSON(t *testing.T) {
 		assert.Equal(t, test.want, logLevel, test.in)
 	}
 }
+
+type testGroupKey struct{}
+
+// ctxHandler records the contexts it was called with
+type ctxHandler struct {
+	slog.Handler
+	ctxs []context.Context
+}
+
+func (h *ctxHandler) Handle(ctx context.Context, r slog.Record) error {
+	h.ctxs = append(h.ctxs, ctx)
+	return h.Handler.Handle(ctx, r)
+}
+
+// The context aware log functions pass their context to the log
+// handler which uses it to attribute the log.
+func TestLogCtx(t *testing.T) {
+	var buf bytes.Buffer
+	oldLogger := logger
+	defer func() { logger = oldLogger }()
+	h := &ctxHandler{Handler: slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})}
+	SetLogger(h)
+	ci := GetConfig(context.Background())
+	oldLogLevel := ci.LogLevel
+	ci.LogLevel = LogLevelDebug
+	defer func() { ci.LogLevel = oldLogLevel }()
+
+	groupCtx := context.WithValue(context.Background(), testGroupKey{}, "job/1")
+	check := func(want string) {
+		t.Helper()
+		var got struct {
+			Level  string `json:"level"`
+			Msg    string `json:"msg"`
+			Object string `json:"object"`
+			Size   int    `json:"size"`
+		}
+		require.NoError(t, json.Unmarshal(buf.Bytes(), &got), buf.String())
+		assert.Equal(t, want, fmt.Sprintf("%s|%s|%s|%d", got.Level, got.Msg, got.Object, got.Size))
+		buf.Reset()
+	}
+
+	ErrorfCtx(groupCtx, "obj", "error %d", 1)
+	check("ERROR|error 1|obj|0")
+	LogfCtx(groupCtx, nil, "notice")
+	check("INFO+2|notice||0")
+	InfofCtx(groupCtx, nil, "info")
+	check("INFO|info||0")
+	DebugfCtx(groupCtx, nil, "debug")
+	check("DEBUG|debug||0")
+	LogPrintfCtx(groupCtx, LogLevelInfo, nil, "size %v", LogValue("size", 3))
+	check("INFO|size 3||3")
+
+	// All of those were passed the context they were called with
+	require.Len(t, h.ctxs, 5)
+	for _, ctx := range h.ctxs {
+		assert.Equal(t, "job/1", ctx.Value(testGroupKey{}))
+	}
+
+	// The non context functions and a nil context log with a
+	// context which isn't attributed to anything
+	h.ctxs = nil
+	Errorf(nil, "plain")
+	check("ERROR|plain||0")
+	ErrorfCtx(nil, nil, "nil ctx") //nolint:staticcheck // deliberately testing a nil context
+	check("ERROR|nil ctx||0")
+	require.Len(t, h.ctxs, 2)
+	for _, ctx := range h.ctxs {
+		require.NotNil(t, ctx)
+		assert.Nil(t, ctx.Value(testGroupKey{}))
+	}
+
+	// Logs below the log level are dropped
+	ci.LogLevel = LogLevelNotice
+	InfofCtx(groupCtx, nil, "dropped")
+	assert.Equal(t, "", buf.String())
+}
+
+// The log level in the config in the context overrides the global one
+func TestLogCtxLogLevel(t *testing.T) {
+	var buf bytes.Buffer
+	oldLogger := logger
+	defer func() { logger = oldLogger }()
+	SetLogger(slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug}))
+	ci := GetConfig(context.Background())
+	oldLogLevel := ci.LogLevel
+	ci.LogLevel = LogLevelNotice
+	defer func() { ci.LogLevel = oldLogLevel }()
+
+	// More verbose than the global log level
+	ctx, ctxCi := AddConfig(context.Background())
+	ctxCi.LogLevel = LogLevelDebug
+	DebugfCtx(ctx, nil, "debug")
+	assert.Contains(t, buf.String(), `"msg":"debug"`)
+	buf.Reset()
+	Debugf(nil, "dropped")
+	assert.Equal(t, "", buf.String())
+
+	// Less verbose than the global log level
+	ctxCi.LogLevel = LogLevelError
+	LogfCtx(ctx, nil, "dropped")
+	assert.Equal(t, "", buf.String())
+	ErrorfCtx(ctx, nil, "error")
+	assert.Contains(t, buf.String(), `"msg":"error"`)
+}

fs/march/march.go

@@ -347,7 +347,7 @@ func (m *March) matchListings(srcChan, dstChan <-chan fs.DirEntry, dstCancel fun
 		}
 		if src != nil && srcPrev != nil {
 			if srcName == srcPrevName && fs.DirEntryType(srcPrev) == fs.DirEntryType(src) {
-				fs.Logf(src, "Duplicate %s found in source - ignoring", fs.DirEntryType(src))
+				fs.LogfCtx(m.Ctx, src, "Duplicate %s found in source - ignoring", fs.DirEntryType(src))
 				srcDone() // skip the src and retry the dst
 				continue
 			} else if srcName < srcPrevName {
@@ -357,7 +357,7 @@ func (m *March) matchListings(srcChan, dstChan <-chan fs.DirEntry, dstCancel fun
 		}
 		if dst != nil && dstPrev != nil {
 			if dstName == dstPrevName && fs.DirEntryType(dst) == fs.DirEntryType(dstPrev) {
-				fs.Logf(dst, "Duplicate %s found in destination - ignoring", fs.DirEntryType(dst))
+				fs.LogfCtx(m.Ctx, dst, "Duplicate %s found in destination - ignoring", fs.DirEntryType(dst))
 				dstDone() // skip the dst and retry the src
 				continue
 			} else if dstName < dstPrevName {
@@ -563,9 +563,9 @@ func (m *March) processJob(job listDirJob) ([]listDirJob, error) {
 	wg.Wait()
 	if srcListErr != nil {
 		if job.srcRemote != "" {
-			fs.Errorf(job.srcRemote, "error reading source directory: %v", srcListErr)
+			fs.ErrorfCtx(m.Ctx, job.srcRemote, "error reading source directory: %v", srcListErr)
 		} else {
-			fs.Errorf(m.Fsrc, "error reading source root directory: %v", srcListErr)
+			fs.ErrorfCtx(m.Ctx, m.Fsrc, "error reading source root directory: %v", srcListErr)
 		}
 		srcListErr = fs.CountError(m.Ctx, srcListErr)
 		return nil, srcListErr
@@ -576,9 +576,9 @@ func (m *March) processJob(job listDirJob) ([]listDirJob, error) {
 		// Copy the stuff anyway
 	} else if dstListErr != nil {
 		if job.dstRemote != "" {
-			fs.Errorf(job.dstRemote, "error reading destination directory: %v", dstListErr)
+			fs.ErrorfCtx(m.Ctx, job.dstRemote, "error reading destination directory: %v", dstListErr)
 		} else {
-			fs.Errorf(m.Fdst, "error reading destination root directory: %v", dstListErr)
+			fs.ErrorfCtx(m.Ctx, m.Fdst, "error reading destination root directory: %v", dstListErr)
 		}
 		dstListErr = fs.CountError(m.Ctx, dstListErr)
 		return nil, dstListErr

fs/operations/check.go

@@ -83,7 +83,7 @@ func (c *checkMarch) DstOnly(dst fs.DirEntry) (recurse bool) {
 			return false
 		}
 		err := fmt.Errorf("file not in %v", c.opt.Fsrc)
-		fs.Errorf(dst, "%v", err)
+		fs.ErrorfCtx(c.ctx, dst, "%v", err)
 		_ = fs.CountError(c.ctx, err)
 		c.differences.Add(1)
 		c.srcFilesMissing.Add(1)
@@ -105,7 +105,7 @@ func (c *checkMarch) SrcOnly(src fs.DirEntry) (recurse bool) {
 	switch src.(type) {
 	case fs.Object:
 		err := fmt.Errorf("file not in %v", c.opt.Fdst)
-		fs.Errorf(src, "%v", err)
+		fs.ErrorfCtx(c.ctx, src, "%v", err)
 		_ = fs.CountError(c.ctx, err)
 		c.differences.Add(1)
 		c.dstFilesMissing.Add(1)
@@ -128,7 +128,7 @@ func (c *checkMarch) checkIdentical(ctx context.Context, dst, src fs.Object) (di
 	}()
 	if sizeDiffers(ctx, src, dst) {
 		err = fmt.Errorf("sizes differ")
-		fs.Errorf(src, "%v", err)
+		fs.ErrorfCtx(ctx, src, "%v", err)
 		return true, false, nil
 	}
 	if ci.SizeOnly {
@@ -155,7 +155,7 @@ func (c *checkMarch) Match(ctx context.Context, dst, src fs.DirEntry) (recurse b
 				}()
 				differ, noHash, err := c.checkIdentical(ctx, dstX, srcX)
 				if err != nil {
-					fs.Errorf(src, "%v", err)
+					fs.ErrorfCtx(ctx, src, "%v", err)
 					_ = fs.CountError(ctx, err)
 					c.report(src, c.opt.Error, '!')
 				} else if differ {
@@ -169,15 +169,15 @@ func (c *checkMarch) Match(ctx context.Context, dst, src fs.DirEntry) (recurse b
 					c.report(src, c.opt.Match, '=')
 					if noHash {
 						c.noHashes.Add(1)
-						fs.Debugf(dstX, "OK - could not check hash")
+						fs.DebugfCtx(ctx, dstX, "OK - could not check hash")
 					} else {
-						fs.Debugf(dstX, "OK")
+						fs.DebugfCtx(ctx, dstX, "OK")
 					}
 				}
 			}()
 		} else {
 			err := fmt.Errorf("is file on %v but directory on %v", c.opt.Fsrc, c.opt.Fdst)
-			fs.Errorf(src, "%v", err)
+			fs.ErrorfCtx(ctx, src, "%v", err)
 			_ = fs.CountError(ctx, err)
 			c.differences.Add(1)
 			c.dstFilesMissing.Add(1)
@@ -190,7 +190,7 @@ func (c *checkMarch) Match(ctx context.Context, dst, src fs.DirEntry) (recurse b
 			return true
 		}
 		err := fmt.Errorf("is file on %v but directory on %v", c.opt.Fdst, c.opt.Fsrc)
-		fs.Errorf(dst, "%v", err)
+		fs.ErrorfCtx(ctx, dst, "%v", err)
 		_ = fs.CountError(ctx, err)
 		c.differences.Add(1)
 		c.srcFilesMissing.Add(1)
@@ -230,7 +230,7 @@ func CheckFn(ctx context.Context, opt *CheckOpt) error {
 		NoTraverse:             ci.NoTraverse,
 		NoUnicodeNormalization: ci.NoUnicodeNormalization,
 	}
-	fs.Debugf(c.opt.Fdst, "Waiting for checks to finish")
+	fs.DebugfCtx(ctx, c.opt.Fdst, "Waiting for checks to finish")
 	err := m.Run(ctx)
 	c.wg.Wait() // wait for background go-routines
 
@@ -239,25 +239,25 @@ func CheckFn(ctx context.Context, opt *CheckOpt) error {
 
 func (c *checkMarch) reportResults(ctx context.Context, err error) error {
 	if c.dstFilesMissing.Load() > 0 {
-		fs.Logf(c.opt.Fdst, "%d files missing", c.dstFilesMissing.Load())
+		fs.LogfCtx(ctx, c.opt.Fdst, "%d files missing", c.dstFilesMissing.Load())
 	}
 	if c.srcFilesMissing.Load() > 0 {
 		entity := "files"
 		if c.opt.Fsrc == nil {
 			entity = "hashes"
 		}
-		fs.Logf(c.opt.Fsrc, "%d %s missing", c.srcFilesMissing.Load(), entity)
+		fs.LogfCtx(ctx, c.opt.Fsrc, "%d %s missing", c.srcFilesMissing.Load(), entity)
 	}
 
-	fs.Logf(c.opt.Fdst, "%d differences found", c.differences.Load())
+	fs.LogfCtx(ctx, c.opt.Fdst, "%d differences found", c.differences.Load())
 	if errs := accounting.Stats(ctx).GetErrors(); errs > 0 {
-		fs.Logf(c.opt.Fdst, "%d errors while checking", errs)
+		fs.LogfCtx(ctx, c.opt.Fdst, "%d errors while checking", errs)
 	}
 	if c.noHashes.Load() > 0 {
-		fs.Logf(c.opt.Fdst, "%d hashes could not be checked", c.noHashes.Load())
+		fs.LogfCtx(ctx, c.opt.Fdst, "%d hashes could not be checked", c.noHashes.Load())
 	}
 	if c.matches.Load() > 0 {
-		fs.Logf(c.opt.Fdst, "%d matching files", c.matches.Load())
+		fs.LogfCtx(ctx, c.opt.Fdst, "%d matching files", c.matches.Load())
 	}
 	if err != nil {
 		return err
@@ -284,7 +284,7 @@ func Check(ctx context.Context, opt *CheckOpt) error {
 		}
 		if !same {
 			err = fmt.Errorf("%v differ", ht)
-			fs.Errorf(src, "%v", err)
+			fs.ErrorfCtx(ctx, src, "%v", err)
 			return true, false, nil
 		}
 		return false, false, nil
@@ -375,7 +375,7 @@ func CheckDownload(ctx context.Context, opt *CheckOpt) error {
 		}
 		if !same {
 			err = errors.New("contents differ")
-			fs.Errorf(src, "%v", err)
+			fs.ErrorfCtx(ctx, src, "%v", err)
 			return true, false, nil
 		}
 		return false, false, nil
@@ -457,7 +457,7 @@ func CheckSum(ctx context.Context, fsrc, fsum fs.Fs, sumFile string, hashType ha
 		}
 		// filesystem missed the file, sum wasn't consumed
 		err := fmt.Errorf("file not in %v", opt.Fdst)
-		fs.Errorf(filename, "%v", err)
+		fs.ErrorfCtx(ctx, filename, "%v", err)
 		_ = fs.CountError(ctx, err)
 		if lastErr == nil {
 			lastErr = err
@@ -486,7 +486,7 @@ func (c *checkMarch) checkSum(ctx context.Context, obj fs.Object, download bool,
 	if !sumFound {
 		err := errors.New("sum not found")
 		_ = fs.CountError(ctx, err)
-		fs.Errorf(obj, "%v", err)
+		fs.ErrorfCtx(ctx, obj, "%v", err)
 		c.differences.Add(1)
 		c.srcFilesMissing.Add(1)
 		c.report(obj, c.opt.MissingOnSrc, '-')
@@ -534,29 +534,29 @@ func (c *checkMarch) matchSum(ctx context.Context, sumHash, objHash string, obj
 	switch {
 	case err != nil:
 		_ = fs.CountError(ctx, err)
-		fs.Errorf(obj, "Failed to calculate hash: %v", err)
+		fs.ErrorfCtx(ctx, obj, "Failed to calculate hash: %v", err)
 		c.report(obj, c.opt.Error, '!')
 	case sumHash == "":
 		err = errors.New("duplicate file")
 		_ = fs.CountError(ctx, err)
-		fs.Errorf(obj, "%v", err)
+		fs.ErrorfCtx(ctx, obj, "%v", err)
 		c.report(obj, c.opt.Error, '!')
 	case objHash == "":
-		fs.Debugf(nil, "%v = %s (sum)", hashType, sumHash)
-		fs.Debugf(obj, "%v - could not check hash (%v)", hashType, c.opt.Fdst)
+		fs.DebugfCtx(ctx, nil, "%v = %s (sum)", hashType, sumHash)
+		fs.DebugfCtx(ctx, obj, "%v - could not check hash (%v)", hashType, c.opt.Fdst)
 		c.noHashes.Add(1)
 		c.matches.Add(1)
 		c.report(obj, c.opt.Match, '=')
 	case objHash == sumHash:
-		fs.Debugf(obj, "%v = %s OK", hashType, sumHash)
+		fs.DebugfCtx(ctx, obj, "%v = %s OK", hashType, sumHash)
 		c.matches.Add(1)
 		c.report(obj, c.opt.Match, '=')
 	default:
 		err = errors.New("files differ")
 		_ = fs.CountError(ctx, err)
-		fs.Debugf(nil, "%v = %s (sum)", hashType, sumHash)
-		fs.Debugf(obj, "%v = %s (%v)", hashType, objHash, c.opt.Fdst)
-		fs.Errorf(obj, "%v", err)
+		fs.DebugfCtx(ctx, nil, "%v = %s (sum)", hashType, sumHash)
+		fs.DebugfCtx(ctx, obj, "%v = %s (%v)", hashType, objHash, c.opt.Fdst)
+		fs.ErrorfCtx(ctx, obj, "%v", err)
 		c.differences.Add(1)
 		c.report(obj, c.opt.Differ, '*')
 	}
@@ -595,7 +595,7 @@ func ParseSumFile(ctx context.Context, sumFile fs.Object) (HashSums, error) {
 		if fields == nil {
 			numWarn++
 			if numWarn <= maxWarn {
-				fs.Logf(sumFile, "improperly formatted checksum line %d", lineNo)
+				fs.LogfCtx(ctx, sumFile, "improperly formatted checksum line %d", lineNo)
 			}
 			continue
 		}
@@ -604,7 +604,7 @@ func ParseSumFile(ctx context.Context, sumFile fs.Object) (HashSums, error) {
 		if hashes[file] != "" {
 			numWarn++
 			if numWarn <= maxWarn {
-				fs.Logf(sumFile, "duplicate file on checksum line %d", lineNo)
+				fs.LogfCtx(ctx, sumFile, "duplicate file on checksum line %d", lineNo)
 			}
 			continue
 		}
@@ -614,7 +614,7 @@ func ParseSumFile(ctx context.Context, sumFile fs.Object) (HashSums, error) {
 	}
 
 	if numWarn > maxWarn {
-		fs.Logf(sumFile, "%d warning(s) suppressed...", numWarn-maxWarn)
+		fs.LogfCtx(ctx, sumFile, "%d warning(s) suppressed...", numWarn-maxWarn)
 	}
 	if err = rd.Close(); err != nil {
 		return nil, err

fs/operations/copy.go

@@ -45,10 +45,10 @@ func (c *copy) removeFailedCopy(ctx context.Context, o fs.Object) {
 	if o == nil {
 		return
 	}
-	fs.Infof(o, "Removing failed copy")
+	fs.InfofCtx(ctx, o, "Removing failed copy")
 	err := o.Remove(ctx)
 	if err != nil {
-		fs.Infof(o, "Failed to remove failed copy: %s", err)
+		fs.InfofCtx(ctx, o, "Failed to remove failed copy: %s", err)
 	}
 }
 
@@ -60,7 +60,7 @@ func (c *copy) removeFailedPartialCopy(ctx context.Context, f fs.Fs, remote stri
 		return
 	}
 	if err != nil {
-		fs.Infof(remote, "Failed to remove failed partial copy: %s", err)
+		fs.InfofCtx(ctx, remote, "Failed to remove failed partial copy: %s", err)
 		return
 	}
 	c.removeFailedCopy(ctx, o)
@@ -190,7 +190,7 @@ func (c *copy) rcat(ctx context.Context, in io.ReadCloser) (actionTaken string,
 	if c.ci.Metadata {
 		meta, err = fs.GetMetadata(ctx, c.src)
 		if err != nil {
-			fs.Errorf(c.src, "Failed to read metadata: %v", err)
+			fs.ErrorfCtx(ctx, c.src, "Failed to read metadata: %v", err)
 		}
 	}
 
@@ -269,7 +269,7 @@ func (c *copy) manualCopy(ctx context.Context) (actionTaken string, newDst fs.Ob
 		if !errors.Is(err, fs.ErrorRangeIgnored) {
 			return actionTaken, newDst, err
 		}
-		fs.Logf(c.src, "multi-thread copy: %v: downloading in a single stream", err)
+		fs.LogfCtx(ctx, c.src, "multi-thread copy: %v: downloading in a single stream", err)
 		c.tr.Reset(ctx)
 	}
 
@@ -336,7 +336,7 @@ func (c *copy) copy(ctx context.Context) (newDst fs.Object, err error) {
 		if fserrors.IsRetryError(err) || fserrors.ShouldRetry(err) {
 			retry = true
 		} else if t, ok := pacer.IsRetryAfter(err); ok && tries+1 < c.maxTries {
-			fs.Debugf(c.src, "Sleeping for %v (as indicated by the server) to obey Retry-After error: %v", t, err)
+			fs.DebugfCtx(ctx, c.src, "Sleeping for %v (as indicated by the server) to obey Retry-After error: %v", t, err)
 			if sleepWithContext(ctx, t) {
 				retry = true
 			} else {
@@ -344,14 +344,14 @@ func (c *copy) copy(ctx context.Context) (newDst fs.Object, err error) {
 			}
 		}
 		if retry {
-			fs.Debugf(c.src, "Received error: %v - low level retry %d/%d", err, tries+1, c.maxTries)
+			fs.DebugfCtx(ctx, c.src, "Received error: %v - low level retry %d/%d", err, tries+1, c.maxTries)
 			c.tr.Reset(ctx) // skip incomplete accounting - will be overwritten by retry
 			continue
 		}
 	}
 	if err != nil {
 		err = fs.CountError(ctx, err)
-		fs.Errorf(c.src, "Failed to copy: %v", err)
+		fs.ErrorfCtx(ctx, c.src, "Failed to copy: %v", err)
 		if !c.inplace {
 			c.removeFailedPartialCopy(ctx, c.f, c.remoteForCopy)
 		}
@@ -361,7 +361,7 @@ func (c *copy) copy(ctx context.Context) (newDst fs.Object, err error) {
 	// Verify the copy
 	err = c.verify(ctx, newDst)
 	if err != nil {
-		fs.Errorf(newDst, "%v", err)
+		fs.ErrorfCtx(ctx, newDst, "%v", err)
 		err = fs.CountError(ctx, err)
 		c.removeFailedCopy(ctx, newDst)
 		return nil, err
@@ -371,12 +371,12 @@ func (c *copy) copy(ctx context.Context) (newDst fs.Object, err error) {
 	if !c.inplace && c.remoteForCopy != c.remote {
 		movedNewDst, err := c.dstFeatures.Move(ctx, newDst, c.remote)
 		if err != nil {
-			fs.Errorf(newDst, "partial file rename failed: %v", err)
+			fs.ErrorfCtx(ctx, newDst, "partial file rename failed: %v", err)
 			err = fs.CountError(ctx, err)
 			c.removeFailedCopy(ctx, newDst)
 			return nil, err
 		}
-		fs.Debugf(newDst, "renamed to: %s", c.remote)
+		fs.DebugfCtx(ctx, newDst, "renamed to: %s", c.remote)
 		newDst = movedNewDst
 	}
 
@@ -384,7 +384,7 @@ func (c *copy) copy(ctx context.Context) (newDst fs.Object, err error) {
 	if newDst != nil && c.src.String() != newDst.String() {
 		actionTaken = fmt.Sprintf("%s to: %s", actionTaken, newDst.String())
 	}
-	fs.Infof(c.src, "%s%s", actionTaken, fs.LogValueHide("size", fs.SizeSuffix(c.src.Size())))
+	fs.InfofCtx(ctx, c.src, "%s%s", actionTaken, fs.LogValueHide("size", fs.SizeSuffix(c.src.Size())))
 
 	return newDst, nil
 }

fs/operations/dedupe.go

@@ -43,7 +43,7 @@ outer:
 		for {
 			suffix++
 			if suffix > maxDedupeSuffix {
-				fs.Errorf(o, "Could not find an available new name")
+				fs.ErrorfCtx(ctx, o, "Could not find an available new name")
 				continue outer
 			}
 			newName = fmt.Sprintf("%s-%d%s", base, suffix, ext)
@@ -56,7 +56,7 @@ outer:
 			}
 			if err != nil {
 				err = fs.CountError(ctx, err)
-				fs.Errorf(o, "Failed to check for existing object: %v", err)
+				fs.ErrorfCtx(ctx, o, "Failed to check for existing object: %v", err)
 				continue outer
 			}
 			files[newName] = append(files[newName], existing)
@@ -65,10 +65,10 @@ outer:
 			newObj, err := doMove(ctx, o, newName)
 			if err != nil {
 				err = fs.CountError(ctx, err)
-				fs.Errorf(o, "Failed to rename: %v", err)
+				fs.ErrorfCtx(ctx, o, "Failed to rename: %v", err)
 				continue
 			}
-			fs.Infof(newObj, "renamed from: %v", o)
+			fs.InfofCtx(ctx, newObj, "renamed from: %v", o)
 			files[newName] = append(files[newName], newObj)
 		}
 	}
@@ -87,7 +87,7 @@ func dedupeDeleteAllButOne(ctx context.Context, keep int, remote string, objs []
 		}
 	}
 	if count > 0 {
-		fs.Logf(remote, "Deleted %d extra copies", count)
+		fs.LogfCtx(ctx, remote, "Deleted %d extra copies", count)
 	}
 }
 
@@ -113,7 +113,7 @@ func dedupeDeleteIdentical(ctx context.Context, ht hash.Type, remote string, obj
 				if IDs[ID] <= 1 {
 					newObjs = append(newObjs, o)
 				} else {
-					fs.Logf(o, "Ignoring as it appears %d times in the listing and deleting would lead to data loss", IDs[ID])
+					fs.LogfCtx(ctx, o, "Ignoring as it appears %d times in the listing and deleting would lead to data loss", IDs[ID])
 				}
 			}
 		}
@@ -143,7 +143,7 @@ func dedupeDeleteIdentical(ctx context.Context, ht hash.Type, remote string, obj
 	for ID, dupes := range dupesByID {
 		remainingObjs = append(remainingObjs, dupes[0])
 		if len(dupes) > 1 {
-			fs.Logf(remote, "Deleting %d/%d identical duplicates (%s)", len(dupes)-1, len(dupes), ID)
+			fs.LogfCtx(ctx, remote, "Deleting %d/%d identical duplicates (%s)", len(dupes)-1, len(dupes), ID)
 			for _, o := range dupes[1:] {
 				err := DeleteFile(ctx, o)
 				if err != nil {
@@ -390,11 +390,11 @@ func dedupeMergeDuplicateDirs(ctx context.Context, f fs.Fs, duplicateDirs [][]*d
 		}
 		fsDirs[largestIdx], fsDirs[0] = fsDirs[0], fsDirs[largestIdx]
 
-		fs.Infof(fsDirs[0], "Merging contents of duplicate directories")
+		fs.InfofCtx(ctx, fsDirs[0], "Merging contents of duplicate directories")
 		err := mergeDirs(ctx, fsDirs)
 		if err != nil {
 			err = fs.CountError(ctx, err)
-			fs.Errorf(nil, "merge duplicate dirs: %v", err)
+			fs.ErrorfCtx(ctx, nil, "merge duplicate dirs: %v", err)
 		}
 	}
 	dirCacheFlush()
@@ -429,7 +429,7 @@ func Deduplicate(ctx context.Context, f fs.Fs, mode DeduplicateMode, byHash bool
 		}
 		what = ht.String() + " hashes"
 	}
-	fs.Infof(f, "Looking for duplicate %s using %v mode.", what, mode)
+	fs.InfofCtx(ctx, f, "Looking for duplicate %s using %v mode.", what, mode)
 
 	// Find duplicate directories first and fix them
 	if !byHash {
@@ -464,7 +464,7 @@ func Deduplicate(ctx context.Context, f fs.Fs, mode DeduplicateMode, byHash bool
 			if byHash {
 				remote, err = o.Hash(ctx, ht)
 				if err != nil {
-					fs.Errorf(o, "Failed to hash: %v", err)
+					fs.ErrorfCtx(ctx, o, "Failed to hash: %v", err)
 					remote = ""
 				}
 			} else {
@@ -487,11 +487,11 @@ func Deduplicate(ctx context.Context, f fs.Fs, mode DeduplicateMode, byHash bool
 		if len(objs) <= 1 {
 			continue
 		}
-		fs.Logf(remote, "Found %d files with duplicate %s", len(objs), what)
+		fs.LogfCtx(ctx, remote, "Found %d files with duplicate %s", len(objs), what)
 		if !byHash && mode != DeduplicateList {
 			objs = dedupeDeleteIdentical(ctx, ht, remote, objs)
 			if len(objs) <= 1 {
-				fs.Logf(remote, "All duplicates removed")
+				fs.LogfCtx(ctx, remote, "All duplicates removed")
 				continue
 			}
 		}
@@ -517,7 +517,7 @@ func Deduplicate(ctx context.Context, f fs.Fs, mode DeduplicateMode, byHash bool
 			sortSmallestFirst(objs)
 			dedupeDeleteAllButOne(ctx, 0, remote, objs)
 		case DeduplicateSkip:
-			fs.Logf(remote, "Skipping %d files with duplicate %s", len(objs), what)
+			fs.LogfCtx(ctx, remote, "Skipping %d files with duplicate %s", len(objs), what)
 		case DeduplicateList:
 			dedupeList(ctx, f, ht, remote, objs, byHash)
 		default:

fs/operations/index.go

@@ -407,7 +407,7 @@ func forEachIndexLine(name string, fn func(string) error) (err error) {
 // wouldn't walk them either.
 func (ix *index) walkChanged(ctx context.Context, changed []string) error {
 	if len(changed) == 0 {
-		fs.Infof(ix.f, "Nothing changed so nothing to index")
+		fs.InfofCtx(ctx, ix.f, "Nothing changed so nothing to index")
 		return nil
 	}
 	maxDepth := ConfigMaxDepth(ctx, true)
@@ -417,7 +417,7 @@ func (ix *index) walkChanged(ctx context.Context, changed []string) error {
 	var subtrees []string
 	for _, p := range changed {
 		if p == "/" {
-			fs.Infof(ix.f, "Root changed so doing a full index")
+			fs.InfofCtx(ctx, ix.f, "Root changed so doing a full index")
 			return ix.walkAll(ctx)
 		}
 		if strings.HasSuffix(p, "/") {
@@ -446,10 +446,10 @@ func (ix *index) walkChanged(ctx context.Context, changed []string) error {
 		}
 	}
 	if ix.opt.ChangedMaxDirs > 0 && len(list)+len(subtrees) > ix.opt.ChangedMaxDirs {
-		fs.Infof(ix.f, "Partial index would list %d directories, more than %d, so doing a full index", len(list)+len(subtrees), ix.opt.ChangedMaxDirs)
+		fs.InfofCtx(ctx, ix.f, "Partial index would list %d directories, more than %d, so doing a full index", len(list)+len(subtrees), ix.opt.ChangedMaxDirs)
 		return ix.walkAll(ctx)
 	}
-	fs.Infof(ix.f, "Partial index: listing %d directories and walking %d changed directories", len(list), len(subtrees))
+	fs.InfofCtx(ctx, ix.f, "Partial index: listing %d directories and walking %d changed directories", len(list), len(subtrees))
 	walkFn := ix.walkFn(ctx)
 	for dir := range list {
 		err := walk.Walk(ctx, ix.f, dir, true, 1, walkFn)
@@ -520,7 +520,7 @@ func (ix *index) readUnwalkedTime(ctx context.Context, sub fs.Directory) {
 	o, err := ix.f.NewObject(ctx, path.Join(sub.Remote(), ix.outputs[0].name))
 	if err != nil {
 		if !errors.Is(err, fs.ErrorObjectNotFound) {
-			fs.Debugf(sub, "Failed to read listing modtime: %v", err)
+			fs.DebugfCtx(ctx, sub, "Failed to read listing modtime: %v", err)
 		}
 		return
 	}
@@ -669,7 +669,7 @@ func (ix *index) processDir(ctx context.Context, d *indexDir) {
 		err := out.tmpl.Execute(&buf, dir)
 		if err != nil {
 			ix.ec.Add(err)
-			fs.Errorf(d.remote, "Failed to render %s: %v", out.name, fs.CountError(ctx, err))
+			fs.ErrorfCtx(ctx, d.remote, "Failed to render %s: %v", out.name, fs.CountError(ctx, err))
 			continue
 		}
 		remote := path.Join(d.remote, out.name)
@@ -679,11 +679,11 @@ func (ix *index) processDir(ctx context.Context, d *indexDir) {
 			equal, err := ix.equal(ctx, src, dst)
 			if err != nil {
 				ix.ec.Add(err)
-				fs.Errorf(dst, "Failed to check listing: %v", fs.CountError(ctx, err))
+				fs.ErrorfCtx(ctx, dst, "Failed to check listing: %v", fs.CountError(ctx, err))
 				continue
 			}
 			if equal {
-				fs.Debugf(dst, "Unchanged skipping")
+				fs.DebugfCtx(ctx, dst, "Unchanged skipping")
 				continue
 			}
 		}
@@ -691,7 +691,7 @@ func (ix *index) processDir(ctx context.Context, d *indexDir) {
 			_, err := Copy(ctx, ix.f, dst, remote, src)
 			if err != nil {
 				ix.ec.Add(err)
-				fs.Errorf(remote, "Failed to write listing: %v", fs.CountError(ctx, err))
+				fs.ErrorfCtx(ctx, remote, "Failed to write listing: %v", fs.CountError(ctx, err))
 			}
 			return nil
 		})

fs/operations/logger.go

@@ -137,7 +137,7 @@ func NewDefaultLoggerFn(opt *LoggerOpt) LoggerFn {
 		}
 		if opt.Combined != nil {
 			SyncFprintf(opt.Combined, "%c %s\n", sigil, filename)
-			fs.Debugf(nil, "Sync Logger: %s: %c %s\n", sigil.String(), sigil, filename)
+			fs.DebugfCtx(ctx, nil, "Sync Logger: %s: %c %s\n", sigil.String(), sigil, filename)
 		}
 		if opt.DestAfter != nil {
 			opt.PrintDestAfter(ctx, sigil, src, dst, err)
@@ -299,7 +299,7 @@ func WinningSide(ctx context.Context, sigil Sigil, src, dst fs.DirEntry, err err
 	// should only make it this far if it's TransferError and both src and dst are nil
 	winner.Side = "none"
 	winner.Err = fmt.Errorf("unknown case -- can't determine winner. %v", err)
-	fs.Debugf(winner.Obj, "%v", winner.Err)
+	fs.DebugfCtx(ctx, winner.Obj, "%v", winner.Err)
 	return winner
 }
 
@@ -372,13 +372,13 @@ func (opt *LoggerOpt) Init(ctx context.Context, fdst fs.Fs, cmdFlags *pflag.Flag
 
 	ci := fs.GetConfig(ctx)
 	if ci.NoTraverse && opt.Combined != nil {
-		fs.LogPrintf(fs.LogLevelWarning, nil, "--no-traverse does not list any deletes (-) in --combined output\n")
+		fs.LogPrintfCtx(ctx, fs.LogLevelWarning, nil, "--no-traverse does not list any deletes (-) in --combined output\n")
 	}
 	if ci.NoTraverse && opt.MissingOnSrc != nil {
-		fs.LogPrintf(fs.LogLevelWarning, nil, "--no-traverse makes --missing-on-src produce empty output\n")
+		fs.LogPrintfCtx(ctx, fs.LogLevelWarning, nil, "--no-traverse makes --missing-on-src produce empty output\n")
 	}
 	if ci.NoTraverse && opt.DestAfter != nil {
-		fs.LogPrintf(fs.LogLevelWarning, nil, "--no-traverse makes --dest-after produce incomplete output\n")
+		fs.LogPrintfCtx(ctx, fs.LogLevelWarning, nil, "--no-traverse makes --dest-after produce incomplete output\n")
 	}
 }
 
@@ -441,7 +441,7 @@ func (opt *LoggerOpt) SetListFormat(ctx context.Context, cmdFlags *pflag.FlagSet
 			list.AddMetadata()
 			JSONOpt.Metadata = true
 		default:
-			fs.Errorf(nil, "unknown format character %q", char)
+			fs.ErrorfCtx(ctx, nil, "unknown format character %q", char)
 		}
 	}
 	opt.ListFormat = list

fs/operations/lsjson.go

@@ -168,7 +168,7 @@ func (lj *listJSON) entry(ctx context.Context, entry fs.DirEntry) (*ListJSONItem
 			return nil, nil
 		}
 	default:
-		fs.Errorf(nil, "Unknown type %T in listing", entry)
+		fs.ErrorfCtx(ctx, nil, "Unknown type %T in listing", entry)
 	}
 
 	item := &ListJSONItem{
@@ -192,14 +192,14 @@ func (lj *listJSON) entry(ctx context.Context, entry fs.DirEntry) (*ListJSONItem
 		case fs.Object:
 			item.EncryptedPath = lj.cipher.EncryptFileName(entry.Remote())
 		default:
-			fs.Errorf(nil, "Unknown type %T in listing", entry)
+			fs.ErrorfCtx(ctx, nil, "Unknown type %T in listing", entry)
 		}
 		item.Encrypted = path.Base(item.EncryptedPath)
 	}
 	if lj.opt.Metadata {
 		metadata, err := fs.GetMetadata(ctx, entry)
 		if err != nil {
-			fs.Errorf(entry, "Failed to read metadata: %v", err)
+			fs.ErrorfCtx(ctx, entry, "Failed to read metadata: %v", err)
 		} else if metadata != nil {
 			item.Metadata = metadata
 		}
@@ -223,7 +223,7 @@ func (lj *listJSON) entry(ctx context.Context, entry fs.DirEntry) (*ListJSONItem
 			for _, hashType := range lj.hashTypes {
 				hash, err := x.Hash(ctx, hashType)
 				if err != nil {
-					fs.Errorf(x, "Failed to read hash: %v", err)
+					fs.ErrorfCtx(ctx, x, "Failed to read hash: %v", err)
 				} else if hash != "" {
 					item.Hashes[hashType.String()] = hash
 				}
@@ -235,7 +235,7 @@ func (lj *listJSON) entry(ctx context.Context, entry fs.DirEntry) (*ListJSONItem
 			}
 		}
 	default:
-		fs.Errorf(nil, "Unknown type %T in listing in ListJSON", entry)
+		fs.ErrorfCtx(ctx, nil, "Unknown type %T in listing in ListJSON", entry)
 	}
 	return item, nil
 }

fs/operations/multithread.go

@@ -70,11 +70,11 @@ func (mc *multiThreadCopyState) copyChunk(ctx context.Context, chunk int, writer
 			fs.CheckClose(rw, &err)
 		}
 		if err != nil {
-			fs.Debugf(mc.src, "multi-thread copy: chunk %d/%d failed: %v", chunk+1, mc.numChunks, err)
+			fs.DebugfCtx(ctx, mc.src, "multi-thread copy: chunk %d/%d failed: %v", chunk+1, mc.numChunks, err)
 		}
 	}()
 
-	fs.Debugf(mc.src, "multi-thread copy: chunk %d/%d (%d-%d) size %v starting", chunk+1, mc.numChunks, start, end, fs.SizeSuffix(size))
+	fs.DebugfCtx(ctx, mc.src, "multi-thread copy: chunk %d/%d (%d-%d) size %v starting", chunk+1, mc.numChunks, start, end, fs.SizeSuffix(size))
 
 	rc, err := Open(ctx, mc.src, &fs.RangeOption{Start: start, End: end - 1})
 	if err != nil {
@@ -105,7 +105,7 @@ func (mc *multiThreadCopyState) copyChunk(ctx context.Context, chunk int, writer
 		return fmt.Errorf("multi-thread copy: failed to write chunk: %w", err)
 	}
 
-	fs.Debugf(mc.src, "multi-thread copy: chunk %d/%d (%d-%d) size %v finished", chunk+1, mc.numChunks, start, end, fs.SizeSuffix(bytesWritten))
+	fs.DebugfCtx(ctx, mc.src, "multi-thread copy: chunk %d/%d (%d-%d) size %v finished", chunk+1, mc.numChunks, start, end, fs.SizeSuffix(bytesWritten))
 	return nil
 }
 
@@ -133,17 +133,17 @@ func multiThreadCopy(ctx context.Context, f fs.Fs, remote string, src fs.Object,
 		}
 		openChunkWriter = openChunkWriterFromOpenWriterAt(openWriterAt, int64(ci.MultiThreadChunkSize), int64(ci.MultiThreadWriteBufferSize), f)
 		// If we are using OpenWriterAt we don't seek the chunks so don't need to buffer
-		fs.Debugf(src, "multi-thread copy: disabling buffering because destination uses OpenWriterAt")
+		fs.DebugfCtx(ctx, src, "multi-thread copy: disabling buffering because destination uses OpenWriterAt")
 		noBuffering = true
 		usingOpenWriterAt = true
 	} else if src.Fs().Features().IsLocal {
 		// If the source fs is local we don't need to buffer
-		fs.Debugf(src, "multi-thread copy: disabling buffering because source is local disk")
+		fs.DebugfCtx(ctx, src, "multi-thread copy: disabling buffering because source is local disk")
 		noBuffering = true
 	} else if f.Features().ChunkWriterDoesntSeek {
 		// If the destination Fs promises not to seek its chunks
 		// (except for retries) then we don't need buffering.
-		fs.Debugf(src, "multi-thread copy: disabling buffering because destination has set ChunkWriterDoesntSeek")
+		fs.DebugfCtx(ctx, src, "multi-thread copy: disabling buffering because destination has set ChunkWriterDoesntSeek")
 		noBuffering = true
 	}
 
@@ -167,27 +167,27 @@ func multiThreadCopy(ctx context.Context, f fs.Fs, remote string, src fs.Object,
 		if info.LeavePartsOnError || uploadedOK {
 			return
 		}
-		fs.Debugf(src, "multi-thread copy: cancelling transfer on exit")
+		fs.DebugfCtx(ctx, src, "multi-thread copy: cancelling transfer on exit")
 		abortErr := chunkWriter.Abort(ctx)
 		if abortErr != nil {
-			fs.Debugf(src, "multi-thread copy: abort failed: %v", abortErr)
+			fs.DebugfCtx(ctx, src, "multi-thread copy: abort failed: %v", abortErr)
 		}
 	})()
 
 	if info.ChunkSize > src.Size() {
-		fs.Debugf(src, "multi-thread copy: chunk size %v was bigger than source file size %v", fs.SizeSuffix(info.ChunkSize), fs.SizeSuffix(src.Size()))
+		fs.DebugfCtx(ctx, src, "multi-thread copy: chunk size %v was bigger than source file size %v", fs.SizeSuffix(info.ChunkSize), fs.SizeSuffix(src.Size()))
 		info.ChunkSize = src.Size()
 	}
 
 	// Use the backend concurrency if it is higher than --multi-thread-streams or if --multi-thread-streams wasn't set explicitly
 	if !ci.MultiThreadSet || info.Concurrency > concurrency {
-		fs.Debugf(src, "multi-thread copy: using backend concurrency of %d instead of --multi-thread-streams %d", info.Concurrency, concurrency)
+		fs.DebugfCtx(ctx, src, "multi-thread copy: using backend concurrency of %d instead of --multi-thread-streams %d", info.Concurrency, concurrency)
 		concurrency = info.Concurrency
 	}
 
 	numChunks := calculateNumChunks(src.Size(), info.ChunkSize)
 	if concurrency > numChunks {
-		fs.Debugf(src, "multi-thread copy: number of streams %d was bigger than number of chunks %d", concurrency, numChunks)
+		fs.DebugfCtx(ctx, src, "multi-thread copy: number of streams %d was bigger than number of chunks %d", concurrency, numChunks)
 		concurrency = numChunks
 	}
 
@@ -210,7 +210,7 @@ func multiThreadCopy(ctx context.Context, f fs.Fs, remote string, src fs.Object,
 	// Make accounting
 	mc.acc = tr.Account(gCtx, nil)
 
-	fs.Debugf(src, "Starting multi-thread copy with %d chunks of size %v with %v parallel streams", mc.numChunks, fs.SizeSuffix(mc.partSize), concurrency)
+	fs.DebugfCtx(ctx, src, "Starting multi-thread copy with %d chunks of size %v with %v parallel streams", mc.numChunks, fs.SizeSuffix(mc.partSize), concurrency)
 	for chunk := range mc.numChunks {
 		// Fail fast, in case an errgroup managed function returns an error
 		if gCtx.Err() != nil {
@@ -271,7 +271,7 @@ func multiThreadCopy(ctx context.Context, f fs.Fs, remote string, src fs.Object,
 				}
 				setModTime = false
 			} else {
-				fs.Errorf(obj, "multi-thread copy: can't set metadata as SetMetadata isn't implemented in: %v", f)
+				fs.ErrorfCtx(ctx, obj, "multi-thread copy: can't set metadata as SetMetadata isn't implemented in: %v", f)
 			}
 		}
 		if setModTime {
@@ -284,7 +284,7 @@ func multiThreadCopy(ctx context.Context, f fs.Fs, remote string, src fs.Object,
 		}
 	}
 
-	fs.Debugf(src, "Finished multi-thread copy with %d parts of size %v", mc.numChunks, fs.SizeSuffix(mc.partSize))
+	fs.DebugfCtx(ctx, src, "Finished multi-thread copy with %d parts of size %v", mc.numChunks, fs.SizeSuffix(mc.partSize))
 	return obj, nil
 }
 
@@ -302,7 +302,7 @@ type writerAtChunkWriter struct {
 
 // WriteChunk writes chunkNumber from reader
 func (w *writerAtChunkWriter) WriteChunk(ctx context.Context, chunkNumber int, reader io.ReadSeeker) (int64, error) {
-	fs.Debugf(w.remote, "writing chunk %v", chunkNumber)
+	fs.DebugfCtx(ctx, w.remote, "writing chunk %v", chunkNumber)
 
 	bytesToWrite := w.chunkSize
 	if chunkNumber == (w.chunks-1) && w.size%w.chunkSize != 0 {
@@ -344,7 +344,7 @@ func (w *writerAtChunkWriter) Close(ctx context.Context) error {
 func (w *writerAtChunkWriter) Abort(ctx context.Context) error {
 	err := w.Close(ctx)
 	if err != nil {
-		fs.Errorf(w.remote, "multi-thread copy: failed to close file before aborting: %v", err)
+		fs.ErrorfCtx(ctx, w.remote, "multi-thread copy: failed to close file before aborting: %v", err)
 	}
 	obj, err := w.f.NewObject(ctx, w.remote)
 	if err != nil {
@@ -364,7 +364,7 @@ func openChunkWriterFromOpenWriterAt(openWriterAt fs.OpenWriterAtFn, chunkSize i
 		}
 
 		if writeBufferSize > 0 {
-			fs.Debugf(src.Remote(), "multi-thread copy: write buffer set to %v", writeBufferSize)
+			fs.DebugfCtx(ctx, src.Remote(), "multi-thread copy: write buffer set to %v", writeBufferSize)
 		}
 
 		chunkWriter := &writerAtChunkWriter{

fs/operations/operations.go

@@ -82,7 +82,7 @@ func checkHashes(ctx context.Context, src fs.ObjectInfo, dst fs.Object, ht hash.
 			return srcErr
 		}
 		if srcHash == "" {
-			fs.Debugf(src, "Src hash empty - aborting Dst hash check")
+			fs.DebugfCtx(ctx, src, "Src hash empty - aborting Dst hash check")
 			return errNoHash
 		}
 		return nil
@@ -93,7 +93,7 @@ func checkHashes(ctx context.Context, src fs.ObjectInfo, dst fs.Object, ht hash.
 			return dstErr
 		}
 		if dstHash == "" {
-			fs.Debugf(dst, "Dst hash empty - aborting Src hash check")
+			fs.DebugfCtx(ctx, dst, "Dst hash empty - aborting Src hash check")
 			return errNoHash
 		}
 		return nil
@@ -104,21 +104,21 @@ func checkHashes(ctx context.Context, src fs.ObjectInfo, dst fs.Object, ht hash.
 	}
 	if srcErr != nil {
 		err = fs.CountError(ctx, srcErr)
-		fs.Errorf(src, "Failed to calculate src hash: %v", err)
+		fs.ErrorfCtx(ctx, src, "Failed to calculate src hash: %v", err)
 	}
 	if dstErr != nil {
 		err = fs.CountError(ctx, dstErr)
-		fs.Errorf(dst, "Failed to calculate dst hash: %v", err)
+		fs.ErrorfCtx(ctx, dst, "Failed to calculate dst hash: %v", err)
 	}
 	if err != nil {
 		return false, ht, srcHash, dstHash, err
 	}
 	if srcHash != dstHash {
-		fs.Debugf(src, "%v = %s (%v)", ht, srcHash, src.Fs())
-		fs.Debugf(dst, "%v = %s (%v)", ht, dstHash, dst.Fs())
+		fs.DebugfCtx(ctx, src, "%v = %s (%v)", ht, srcHash, src.Fs())
+		fs.DebugfCtx(ctx, dst, "%v = %s (%v)", ht, dstHash, dst.Fs())
 		return false, ht, srcHash, dstHash, nil
 	}
-	fs.Debugf(src, "%v = %s OK", ht, srcHash)
+	fs.DebugfCtx(ctx, src, "%v = %s OK", ht, srcHash)
 	return true, ht, srcHash, dstHash, nil
 }
 
@@ -168,11 +168,11 @@ func DirsEqual(ctx context.Context, src, dst fs.Directory, opt DirsEqualOpt) (eq
 	}
 	dt := dstModTime.Sub(srcModTime)
 	if dt < opt.ModifyWindow && dt > -opt.ModifyWindow {
-		fs.Debugf(dst, "Directory modification time the same (differ by %s, within tolerance %s)", dt, opt.ModifyWindow)
+		fs.DebugfCtx(ctx, dst, "Directory modification time the same (differ by %s, within tolerance %s)", dt, opt.ModifyWindow)
 		return true
 	}
 	if ci.UpdateOlder && dt >= opt.ModifyWindow {
-		fs.Debugf(dst, "Destination directory is newer than source, skipping")
+		fs.DebugfCtx(ctx, dst, "Destination directory is newer than source, skipping")
 		return true
 	}
 	return false
@@ -186,11 +186,11 @@ func sizeDiffers(ctx context.Context, src, dst fs.ObjectInfo) bool {
 		return false
 	}
 	if src.Size() == dst.Size() {
-		fs.Debugf(dst, "size = %d OK", dst.Size())
+		fs.DebugfCtx(ctx, dst, "size = %d OK", dst.Size())
 		return false
 	}
-	fs.Debugf(src, "size = %d (%v)", src.Size(), src.Fs())
-	fs.Debugf(dst, "size = %d (%v)", dst.Size(), dst.Fs())
+	fs.DebugfCtx(ctx, src, "size = %d (%v)", src.Size(), src.Fs())
+	fs.DebugfCtx(ctx, dst, "size = %d (%v)", dst.Size(), dst.Fs())
 	return true
 }
 
@@ -225,9 +225,9 @@ type DirsEqualOpt struct {
 var modTimeUploadOnce sync.Once
 
 // emit a log if we are about to upload a file to set its modification time
-func logModTimeUpload(dst fs.Object) {
+func logModTimeUpload(ctx context.Context, dst fs.Object) {
 	modTimeUploadOnce.Do(func() {
-		fs.Logf(dst.Fs(), "Forced to upload files to set modification times on this backend.")
+		fs.LogfCtx(ctx, dst.Fs(), "Forced to upload files to set modification times on this backend.")
 	})
 }
 
@@ -248,12 +248,12 @@ func equal(ctx context.Context, src fs.ObjectInfo, dst fs.Object, opt equalOpt)
 	ci := fs.GetConfig(ctx)
 	logger, _ := GetLogger(ctx)
 	if sizeDiffers(ctx, src, dst) {
-		fs.Debug(src, "Sizes differ")
+		fs.DebugfCtx(ctx, src, "Sizes differ")
 		logger(ctx, Differ, src, dst, nil)
 		return false
 	}
 	if opt.sizeOnly {
-		fs.Debugf(src, "Sizes identical")
+		fs.DebugfCtx(ctx, src, "Sizes identical")
 		logger(ctx, Match, src, dst, nil)
 		return true
 	}
@@ -265,7 +265,7 @@ func equal(ctx context.Context, src fs.ObjectInfo, dst fs.Object, opt equalOpt)
 		// Check the hash
 		same, ht, _ := CheckHashes(ctx, src, dst)
 		if !same {
-			fs.Debugf(src, "%v differ", ht)
+			fs.DebugfCtx(ctx, src, "%v differ", ht)
 			logger(ctx, Differ, src, dst, nil)
 			return false
 		}
@@ -273,12 +273,12 @@ func equal(ctx context.Context, src fs.ObjectInfo, dst fs.Object, opt equalOpt)
 			common := src.Fs().Hashes().Overlap(dst.Fs().Hashes())
 			if common.Count() == 0 {
 				checksumWarning.Do(func() {
-					fs.Logf(dst.Fs(), "--checksum is in use but the source and destination have no hashes in common; falling back to --size-only")
+					fs.LogfCtx(ctx, dst.Fs(), "--checksum is in use but the source and destination have no hashes in common; falling back to --size-only")
 				})
 			}
-			fs.Debugf(src, "Size of src and dst objects identical")
+			fs.DebugfCtx(ctx, src, "Size of src and dst objects identical")
 		} else {
-			fs.Debugf(src, "Size and %v of src and dst objects identical", ht)
+			fs.DebugfCtx(ctx, src, "Size and %v of src and dst objects identical", ht)
 		}
 		logger(ctx, Match, src, dst, nil)
 		return true
@@ -289,25 +289,25 @@ func equal(ctx context.Context, src fs.ObjectInfo, dst fs.Object, opt equalOpt)
 		// Sizes the same so check the mtime
 		modifyWindow := fs.GetModifyWindow(ctx, src.Fs(), dst.Fs())
 		if modifyWindow == fs.ModTimeNotSupported {
-			fs.Debugf(src, "Sizes identical")
+			fs.DebugfCtx(ctx, src, "Sizes identical")
 			logger(ctx, Match, src, dst, nil)
 			return true
 		}
 		dstModTime := dst.ModTime(ctx)
 		dt := dstModTime.Sub(srcModTime)
 		if dt < modifyWindow && dt > -modifyWindow {
-			fs.Debugf(src, "Size and modification time the same (differ by %s, within tolerance %s)", dt, modifyWindow)
+			fs.DebugfCtx(ctx, src, "Size and modification time the same (differ by %s, within tolerance %s)", dt, modifyWindow)
 			logger(ctx, Match, src, dst, nil)
 			return true
 		}
 
-		fs.Debugf(src, "Modification times differ by %s: %v, %v", dt, srcModTime, dstModTime)
+		fs.DebugfCtx(ctx, src, "Modification times differ by %s: %v, %v", dt, srcModTime, dstModTime)
 	}
 
 	// Check if the hashes are the same
 	same, ht, _ := CheckHashes(ctx, src, dst)
 	if !same {
-		fs.Debugf(src, "%v differ", ht)
+		fs.DebugfCtx(ctx, src, "%v differ", ht)
 		logger(ctx, Differ, src, dst, nil)
 		return false
 	}
@@ -323,35 +323,35 @@ func equal(ctx context.Context, src fs.ObjectInfo, dst fs.Object, opt equalOpt)
 			// Size and hash the same but mtime different
 			// Error if objects are treated as immutable
 			if ci.Immutable {
-				fs.Errorf(dst, "Timestamp mismatch between immutable objects")
+				fs.ErrorfCtx(ctx, dst, "Timestamp mismatch between immutable objects")
 				logger(ctx, Differ, src, dst, nil)
 				return false
 			}
 			// Update the mtime of the dst object here
 			err := dst.SetModTime(ctx, srcModTime)
 			if errors.Is(err, fs.ErrorCantSetModTime) {
-				logModTimeUpload(dst)
-				fs.Infof(dst, "src and dst identical but can't set mod time without re-uploading")
+				logModTimeUpload(ctx, dst)
+				fs.InfofCtx(ctx, dst, "src and dst identical but can't set mod time without re-uploading")
 				logger(ctx, Differ, src, dst, nil)
 				return false
 			} else if errors.Is(err, fs.ErrorCantSetModTimeWithoutDelete) {
-				logModTimeUpload(dst)
-				fs.Infof(dst, "src and dst identical but can't set mod time without deleting and re-uploading")
+				logModTimeUpload(ctx, dst)
+				fs.InfofCtx(ctx, dst, "src and dst identical but can't set mod time without deleting and re-uploading")
 				// Remove the file if BackupDir isn't set.  If BackupDir is set we would rather have the old file
 				// put in the BackupDir than deleted which is what will happen if we don't delete it.
 				if ci.BackupDir == "" {
 					err = dst.Remove(ctx)
 					if err != nil {
-						fs.Errorf(dst, "failed to delete before re-upload: %v", err)
+						fs.ErrorfCtx(ctx, dst, "failed to delete before re-upload: %v", err)
 					}
 				}
 				logger(ctx, Differ, src, dst, nil)
 				return false
 			} else if err != nil {
 				err = fs.CountError(ctx, err)
-				fs.Errorf(dst, "Failed to set modification time: %v", err)
+				fs.ErrorfCtx(ctx, dst, "Failed to set modification time: %v", err)
 			} else {
-				fs.Infof(src, "Updated modification time in destination")
+				fs.InfofCtx(ctx, src, "Updated modification time in destination")
 			}
 		}
 	}
@@ -491,19 +491,19 @@ func move(ctx context.Context, fdst fs.Fs, dst fs.Object, remote string, src fs.
 		switch err {
 		case nil:
 			if newDst != nil && src.String() != newDst.String() {
-				fs.Infof(src, "Moved (server-side) to: %s", newDst.String())
+				fs.InfofCtx(ctx, src, "Moved (server-side) to: %s", newDst.String())
 			} else {
-				fs.Infof(src, "Moved (server-side)")
+				fs.InfofCtx(ctx, src, "Moved (server-side)")
 			}
 			in.ServerSideMoveEnd(newDst.Size()) // account the bytes for the server-side transfer
 			_ = in.Close()
 			return newDst, nil
 		case fs.ErrorCantMove:
-			fs.Debugf(src, "Can't move, switching to copy")
+			fs.DebugfCtx(ctx, src, "Can't move, switching to copy")
 			_ = in.Close()
 		default:
 			err = fs.CountError(ctx, err)
-			fs.Errorf(src, "Couldn't move: %v", err)
+			fs.ErrorfCtx(ctx, src, "Couldn't move: %v", err)
 			_ = in.Close()
 			return newDst, err
 		}
@@ -514,7 +514,7 @@ func move(ctx context.Context, fdst fs.Fs, dst fs.Object, remote string, src fs.
 	}
 	newDst, err = Copy(ctx, fdst, dst, origRemote, src)
 	if err != nil {
-		fs.Errorf(src, "Not deleting source as copy failed: %v", err)
+		fs.ErrorfCtx(ctx, src, "Not deleting source as copy failed: %v", err)
 		return newDst, err
 	}
 	// Delete src if no error on copy
@@ -576,10 +576,10 @@ func DeleteFileWithBackupDir(ctx context.Context, dst fs.Object, backupDir fs.Fs
 		err = dst.Remove(ctx)
 	}
 	if err != nil {
-		fs.Errorf(dst, "Couldn't %s: %v", action, err)
+		fs.ErrorfCtx(ctx, dst, "Couldn't %s: %v", action, err)
 		err = fs.CountError(ctx, err)
 	} else if !skip {
-		fs.Infof(dst, "%s", actioned)
+		fs.InfofCtx(ctx, dst, "%s", actioned)
 	}
 	return err
 }
@@ -616,14 +616,14 @@ func DeleteFilesWithBackupDir(ctx context.Context, toBeDeleted fs.ObjectsChan, b
 					logger, _ := GetLogger(ctx)
 					logger(ctx, TransferError, nil, dst, err)
 					if fserrors.IsFatalError(err) {
-						fs.Errorf(dst, "Got fatal error on delete: %s", err)
+						fs.ErrorfCtx(ctx, dst, "Got fatal error on delete: %s", err)
 						fatalErrorCount.Add(1)
 					}
 				}
 			}
 		}()
 	}
-	fs.Debugf(nil, "Waiting for deletions to finish")
+	fs.DebugfCtx(ctx, nil, "Waiting for deletions to finish")
 	wg.Wait()
 	if errorCount.Load() > 0 {
 		err := fmt.Errorf("failed to delete %d files", errorCount.Load())
@@ -726,7 +726,7 @@ func filterCheck(ctx context.Context, f fs.Fs, dir string) bool {
 	includeDirectory := fi.IncludeDirectory(ctx, f)
 	include, err := includeDirectory(dir)
 	if err != nil {
-		fs.Errorf(f, "Failed to discover whether directory is included: %v", err)
+		fs.ErrorfCtx(ctx, f, "Failed to discover whether directory is included: %v", err)
 		return true
 	}
 	return include
@@ -770,13 +770,13 @@ func Retry(ctx context.Context, o any, maxTries int, fn func() error) (err error
 		}
 		// Retry if err returned a retry error
 		if fserrors.IsRetryError(err) || fserrors.ShouldRetry(err) {
-			fs.Debugf(o, "Received error: %v - low level retry %d/%d", err, tries, maxTries)
+			fs.DebugfCtx(ctx, o, "Received error: %v - low level retry %d/%d", err, tries, maxTries)
 			continue
 		} else if t, ok := pacer.IsRetryAfter(err); ok {
 			if tries >= maxTries {
 				break
 			}
-			fs.Debugf(o, "Sleeping for %v (as indicated by the server) to obey Retry-After error: %v", t, err)
+			fs.DebugfCtx(ctx, o, "Sleeping for %v (as indicated by the server) to obey Retry-After error: %v", t, err)
 			if !sleepWithContext(ctx, t) {
 				fserrors.ContextError(ctx, &err)
 				break
@@ -1005,7 +1005,7 @@ func HashLister(ctx context.Context, ht hash.Type, outputBase64 bool, downloadFl
 			}()
 			sum, err := HashSum(ctx, ht, outputBase64, downloadFlag, o)
 			if err != nil {
-				fs.Errorf(o, "%v", fs.CountError(ctx, err))
+				fs.ErrorfCtx(ctx, o, "%v", fs.CountError(ctx, err))
 				return
 			}
 			SyncFprintf(w, "%*s  %s\n", width, sum, o.Remote())
@@ -1085,7 +1085,7 @@ func Mkdir(ctx context.Context, f fs.Fs, dir string) (err error) {
 	if SkipDestructive(ctx, fs.LogDirName(f, dir), "make directory") {
 		return nil
 	}
-	fs.Infof(fs.LogDirName(f, dir), "Making directory")
+	fs.InfofCtx(ctx, fs.LogDirName(f, dir), "Making directory")
 	err = f.Mkdir(ctx, dir)
 	if err != nil {
 		err = fs.CountError(ctx, err)
@@ -1111,7 +1111,7 @@ func MkdirMetadata(ctx context.Context, f fs.Fs, dir string, metadata fs.Metadat
 	if SkipDestructive(ctx, logName, "make directory") {
 		return nil, nil
 	}
-	fs.Debugf(fs.LogDirName(f, dir), "Making directory with metadata")
+	fs.DebugfCtx(ctx, fs.LogDirName(f, dir), "Making directory with metadata")
 	newDst, err = do(ctx, dir, metadata)
 	if err != nil {
 		err = fs.CountError(ctx, err)
@@ -1119,9 +1119,9 @@ func MkdirMetadata(ctx context.Context, f fs.Fs, dir string, metadata fs.Metadat
 	}
 	accounting.Stats(ctx).UpdatedDirs(1)
 	if mtime, ok := metadata["mtime"]; ok {
-		fs.Infof(logName, "Made directory with metadata (mtime=%s)", mtime)
+		fs.InfofCtx(ctx, logName, "Made directory with metadata (mtime=%s)", mtime)
 	} else {
-		fs.Infof(logName, "Made directory with metadata")
+		fs.InfofCtx(ctx, logName, "Made directory with metadata")
 	}
 	return newDst, err
 }
@@ -1165,7 +1165,7 @@ func TryRmdir(ctx context.Context, f fs.Fs, dir string) error {
 	if SkipDestructive(ctx, fs.LogDirName(f, dir), "remove directory") {
 		return nil
 	}
-	fs.Infof(fs.LogDirName(f, dir), "Removing directory")
+	fs.InfofCtx(ctx, fs.LogDirName(f, dir), "Removing directory")
 	return f.Rmdir(ctx, dir)
 }
 
@@ -1257,23 +1257,23 @@ func RemoveExisting(ctx context.Context, f fs.Fs, remote string, operation strin
 		remoteSaved = remote + suffix
 	}
 
-	fs.Debugf(existingObj, "%s: renaming existing object to %q before starting", operation, remoteSaved)
+	fs.DebugfCtx(ctx, existingObj, "%s: renaming existing object to %q before starting", operation, remoteSaved)
 	existingObj, err = doMove(ctx, existingObj, remoteSaved)
 	if err != nil {
 		return nil, fmt.Errorf("%s: failed to rename existing file: %w", operation, err)
 	}
 	return func(perr *error) {
 		if *perr == nil {
-			fs.Debugf(existingObj, "%s: removing renamed existing file after operation", operation)
+			fs.DebugfCtx(ctx, existingObj, "%s: removing renamed existing file after operation", operation)
 			err := existingObj.Remove(ctx)
 			if err != nil {
 				*perr = fmt.Errorf("%s: failed to remove renamed existing file: %w", operation, err)
 			}
 		} else {
-			fs.Debugf(existingObj, "%s: renaming existing back after failed operation", operation)
+			fs.DebugfCtx(ctx, existingObj, "%s: renaming existing back after failed operation", operation)
 			_, renameErr := doMove(ctx, existingObj, remote)
 			if renameErr != nil {
-				fs.Errorf(existingObj, "%s: failed to restore existing file after failed operation: %v", operation, renameErr)
+				fs.ErrorfCtx(ctx, existingObj, "%s: failed to restore existing file after failed operation: %v", operation, renameErr)
 			}
 		}
 	}, nil
@@ -1299,7 +1299,7 @@ func listToChan(ctx context.Context, f fs.Fs, dir string) fs.ObjectsChan {
 		if err != nil && err != fs.ErrorDirNotFound {
 			err = fmt.Errorf("failed to list: %w", err)
 			err = fs.CountError(ctx, err)
-			fs.Errorf(nil, "%v", err)
+			fs.ErrorfCtx(ctx, nil, "%v", err)
 		}
 	}()
 	return o
@@ -1338,13 +1338,13 @@ func Cat(ctx context.Context, f fs.Fs, w io.Writer, offset, count int64, sep []b
 		defer mu.Unlock()
 		err := catObject(ctx, o, w, offset, count)
 		if err != nil {
-			fs.Errorf(o, "Failed to send to output: %v", err)
+			fs.ErrorfCtx(ctx, o, "Failed to send to output: %v", err)
 			return
 		}
 		if len(sep) > 0 {
 			if _, err := w.Write(sep); err != nil {
 				err = fs.CountError(ctx, err)
-				fs.Errorf(o, "Failed to send separator to output: %v", err)
+				fs.ErrorfCtx(ctx, o, "Failed to send separator to output: %v", err)
 			}
 		}
 	})
@@ -1466,10 +1466,10 @@ func rcatSrc(ctx context.Context, fdst fs.Fs, dstFileName string, in io.ReadClos
 	if fileIsSmall || doPutStream == nil {
 		var rs io.ReadSeeker
 		if fileIsSmall {
-			fs.Debugf(fdst, "File to upload is small (%d bytes), uploading instead of streaming", len(buf))
+			fs.DebugfCtx(ctx, fdst, "File to upload is small (%d bytes), uploading instead of streaming", len(buf))
 			rs = bytes.NewReader(buf)
 		} else {
-			fs.Debugf(fdst, "Target remote doesn't support streaming uploads, creating temporary local FS to spool file")
+			fs.DebugfCtx(ctx, fdst, "Target remote doesn't support streaming uploads, creating temporary local FS to spool file")
 			spool, err := os.CreateTemp("", "rclone-spool")
 			if err != nil {
 				return nil, fmt.Errorf("failed to create temporary spool file: %v", err)
@@ -1478,11 +1478,11 @@ func rcatSrc(ctx context.Context, fdst fs.Fs, dstFileName string, in io.ReadClos
 			defer func() {
 				err := spool.Close()
 				if err != nil {
-					fs.Errorf(fileName, "Failed to close temporary spool file: %v", err)
+					fs.ErrorfCtx(ctx, fileName, "Failed to close temporary spool file: %v", err)
 				}
 				err = os.Remove(fileName)
 				if err != nil {
-					fs.Errorf(fileName, "Failed to delete temporary spool file: %v", err)
+					fs.ErrorfCtx(ctx, fileName, "Failed to delete temporary spool file: %v", err)
 				}
 			}()
 			_, err = io.Copy(spool, streamIn)
@@ -1523,7 +1523,7 @@ func rcatSrc(ctx context.Context, fdst fs.Fs, dstFileName string, in io.ReadClos
 	if !equal(ctx, src, dst, opt) {
 		err = fmt.Errorf("corrupted on transfer")
 		err = fs.CountError(ctx, err)
-		fs.Errorf(dst, "%v", err)
+		fs.ErrorfCtx(ctx, dst, "%v", err)
 		return dst, err
 	}
 	return dst, nil
@@ -1550,7 +1550,7 @@ func Rmdirs(ctx context.Context, f fs.Fs, dir string, leaveRoot bool) error {
 	err := walk.Walk(ctx, f, dir, false, ci.MaxDepth, func(dirPath string, entries fs.DirEntries, err error) error {
 		if err != nil {
 			err = fs.CountError(ctx, err)
-			fs.Errorf(f, "Failed to list %q: %v", dirPath, err)
+			fs.ErrorfCtx(ctx, f, "Failed to list %q: %v", dirPath, err)
 			return nil
 		}
 		for _, entry := range entries {
@@ -1611,7 +1611,7 @@ func Rmdirs(ctx context.Context, f fs.Fs, dir string, leaveRoot bool) error {
 		if len(dirs) == 0 {
 			continue
 		}
-		fs.Debugf(nil, "removing %d level %d directories", len(dirs), level)
+		fs.DebugfCtx(ctx, nil, "removing %d level %d directories", len(dirs), level)
 		sort.Strings(dirs)
 		g, gCtx := errgroup.WithContext(ctx)
 		g.SetLimit(ci.Checkers)
@@ -1625,7 +1625,7 @@ func Rmdirs(ctx context.Context, f fs.Fs, dir string, leaveRoot bool) error {
 				err := TryRmdir(gCtx, f, dir)
 				if err != nil {
 					err = fs.CountError(ctx, err)
-					fs.Errorf(dir, "Failed to rmdir: %v", err)
+					fs.ErrorfCtx(gCtx, dir, "Failed to rmdir: %v", err)
 					errCount.Add(err)
 				}
 				return nil // don't return errors, just count them
@@ -1672,7 +1672,7 @@ func compareDest(ctx context.Context, dst, src fs.Object, CompareDest fs.Fs) (No
 	opt := defaultEqualOpt(ctx)
 	opt.updateModTime = false
 	if equal(ctx, src, CompareDestFile, opt) {
-		fs.Debugf(src, "Destination found in --compare-dest, skipping")
+		fs.DebugfCtx(ctx, src, "Destination found in --compare-dest, skipping")
 		return true, nil
 	}
 	return false, nil
@@ -1735,16 +1735,16 @@ func copyDest(ctx context.Context, fdst fs.Fs, dst, src fs.Object, CopyDest, bac
 			}
 			_, err := Copy(ctx, fdst, dst, remote, CopyDestFile)
 			if err != nil {
-				fs.Errorf(src, "Destination found in --copy-dest, error copying")
+				fs.ErrorfCtx(ctx, src, "Destination found in --copy-dest, error copying")
 				return false, nil
 			}
-			fs.Debugf(src, "Destination found in --copy-dest, using server-side copy")
+			fs.DebugfCtx(ctx, src, "Destination found in --copy-dest, using server-side copy")
 			return true, nil
 		}
-		fs.Debugf(src, "Unchanged skipping")
+		fs.DebugfCtx(ctx, src, "Unchanged skipping")
 		return true, nil
 	}
-	fs.Debugf(src, "Destination not found in --copy-dest")
+	fs.DebugfCtx(ctx, src, "Destination not found in --copy-dest")
 	return false, nil
 }
 
@@ -1781,19 +1781,19 @@ func NeedTransfer(ctx context.Context, dst, src fs.Object) bool {
 	ci := fs.GetConfig(ctx)
 	logger, _ := GetLogger(ctx)
 	if dst == nil {
-		fs.Debugf(src, "Need to transfer - File not found at Destination")
+		fs.DebugfCtx(ctx, src, "Need to transfer - File not found at Destination")
 		logger(ctx, MissingOnDst, src, nil, nil)
 		return true
 	}
 	// If we should ignore existing files, don't transfer
 	if ci.IgnoreExisting {
-		fs.Debugf(src, "Destination exists, skipping")
+		fs.DebugfCtx(ctx, src, "Destination exists, skipping")
 		logger(ctx, Match, src, dst, nil)
 		return false
 	}
 	// If we should upload unconditionally
 	if ci.IgnoreTimes {
-		fs.Debugf(src, "Transferring unconditionally as --ignore-times is in use")
+		fs.DebugfCtx(ctx, src, "Transferring unconditionally as --ignore-times is in use")
 		logger(ctx, Differ, src, dst, nil)
 		return true
 	}
@@ -1812,7 +1812,7 @@ func NeedTransfer(ctx context.Context, dst, src fs.Object) bool {
 		}
 		switch {
 		case dt >= modifyWindow:
-			fs.Debugf(src, "Destination is newer than source, skipping")
+			fs.DebugfCtx(ctx, src, "Destination is newer than source, skipping")
 			logger(ctx, Match, src, dst, nil)
 			return false
 		case dt <= -modifyWindow:
@@ -1820,7 +1820,7 @@ func NeedTransfer(ctx context.Context, dst, src fs.Object) bool {
 			opt := defaultEqualOpt(ctx)
 			opt.forceModTimeMatch = true
 			if equal(ctx, src, dst, opt) {
-				fs.Debugf(src, "Unchanged skipping")
+				fs.DebugfCtx(ctx, src, "Unchanged skipping")
 				return false
 			}
 		default:
@@ -1828,10 +1828,10 @@ func NeedTransfer(ctx context.Context, dst, src fs.Object) bool {
 			opt := defaultEqualOpt(ctx)
 			opt.sizeOnly = !ci.CheckSum
 			if equal(ctx, src, dst, opt) {
-				fs.Debugf(src, "Destination mod time is within %v of source and files identical, skipping", modifyWindow)
+				fs.DebugfCtx(ctx, src, "Destination mod time is within %v of source and files identical, skipping", modifyWindow)
 				return false
 			}
-			fs.Debugf(src, "Destination mod time is within %v of source but files differ, transferring", modifyWindow)
+			fs.DebugfCtx(ctx, src, "Destination mod time is within %v of source but files differ, transferring", modifyWindow)
 		}
 	} else {
 		// Check to see if changed or not
@@ -1840,7 +1840,7 @@ func NeedTransfer(ctx context.Context, dst, src fs.Object) bool {
 			return !equalFn(ctx, src, dst)
 		}
 		if Equal(ctx, src, dst) && !SameObject(src, dst) {
-			fs.Debugf(src, "Unchanged skipping")
+			fs.DebugfCtx(ctx, src, "Unchanged skipping")
 			return false
 		}
 	}
@@ -1887,7 +1887,7 @@ func RcatSize(ctx context.Context, fdst fs.Fs, dstFileName string, in io.ReadClo
 		info := object.NewStaticObjectInfo(dstFileName, modTime, size, true, nil, fdst).WithMetadata(meta)
 		obj, err = fdst.Put(ctx, in, info, options...)
 		if err != nil {
-			fs.Errorf(dstFileName, "Post request put error: %v", err)
+			fs.ErrorfCtx(ctx, dstFileName, "Post request put error: %v", err)
 
 			return nil, err
 		}
@@ -1905,10 +1905,10 @@ func RcatSize(ctx context.Context, fdst fs.Fs, dstFileName string, in io.ReadClo
 		}
 		if err != nil {
 			err = fs.CountError(ctx, err)
-			fs.Errorf(obj, "%v", err)
-			fs.Infof(obj, "Removing failed copy")
+			fs.ErrorfCtx(ctx, obj, "%v", err)
+			fs.InfofCtx(ctx, obj, "Removing failed copy")
 			if removeErr := obj.Remove(ctx); removeErr != nil {
-				fs.Infof(obj, "Failed to remove failed copy: %s", removeErr)
+				fs.InfofCtx(ctx, obj, "Failed to remove failed copy: %s", removeErr)
 			}
 			return nil, err
 		}
@@ -1916,7 +1916,7 @@ func RcatSize(ctx context.Context, fdst fs.Fs, dstFileName string, in io.ReadClo
 		// Size unknown use Rcat
 		obj, err = Rcat(ctx, fdst, dstFileName, in, modTime, meta)
 		if err != nil {
-			fs.Errorf(dstFileName, "Post request rcat error: %v", err)
+			fs.ErrorfCtx(ctx, dstFileName, "Post request rcat error: %v", err)
 
 			return nil, err
 		}
@@ -1957,7 +1957,7 @@ func copyURLFn(ctx context.Context, dstFileName string, url string, autoFilename
 			if err != nil || headerFilename == "" {
 				return fmt.Errorf("CopyURL failed: filename not found in the Content-Disposition header")
 			}
-			fs.Debugf(headerFilename, "filename found in Content-Disposition header.")
+			fs.DebugfCtx(ctx, headerFilename, "filename found in Content-Disposition header.")
 			return fn(ctx, headerFilename, resp.Body, resp.ContentLength, modTime)
 		}
 
@@ -1965,7 +1965,7 @@ func copyURLFn(ctx context.Context, dstFileName string, url string, autoFilename
 		if dstFileName == "." || dstFileName == "/" {
 			return fmt.Errorf("CopyURL failed: file name wasn't found in url")
 		}
-		fs.Debugf(dstFileName, "File name found in url")
+		fs.DebugfCtx(ctx, dstFileName, "File name found in url")
 	}
 	return fn(ctx, dstFileName, resp.Body, resp.ContentLength, modTime)
 }
@@ -2079,13 +2079,13 @@ func MoveCaseInsensitive(ctx context.Context, fdst fs.Fs, fsrc fs.Fs, dstFileNam
 		logger(ctx, TransferError, nil, tmpObjFail, err)
 		return nil, fmt.Errorf("error while attempting to move file to a temporary location: %w", err)
 	}
-	fs.Debugf(srcObj, "moving to %v", tmpObjName)
+	fs.DebugfCtx(ctx, srcObj, "moving to %v", tmpObjName)
 	tmpObj, err := Op(ctx, fdst, nil, tmpObjName, srcObj)
 	if err != nil {
 		logger(ctx, TransferError, srcObj, tmpObj, err)
 		return nil, fmt.Errorf("error while moving file to temporary location: %w", err)
 	}
-	fs.Debugf(srcObj, "moving to %v", dstFileName)
+	fs.DebugfCtx(ctx, srcObj, "moving to %v", dstFileName)
 	newDst, err = Op(ctx, fdst, nil, dstFileName, tmpObj)
 	logger(ctx, MissingOnDst, tmpObj, nil, err)
 	return newDst, err
@@ -2101,7 +2101,7 @@ func moveOrCopyFile(ctx context.Context, fdst fs.Fs, fsrc fs.Fs, dstFileName str
 	dstFilePath := path.Join(fdst.Root(), dstFileName)
 	srcFilePath := path.Join(fsrc.Root(), srcFileName)
 	if fdst.Name() == fsrc.Name() && dstFilePath == srcFilePath && !allowOverlap {
-		fs.Debugf(fdst, "don't need to copy/move %s, it is already at target location", dstFileName)
+		fs.DebugfCtx(ctx, fdst, "don't need to copy/move %s, it is already at target location", dstFileName)
 		if usingLogger {
 			srcObj, _ := fsrc.NewObject(ctx, srcFileName)
 			dstObj, _ := fsrc.NewObject(ctx, dstFileName)
@@ -2181,7 +2181,7 @@ func moveOrCopyFile(ctx context.Context, fdst fs.Fs, fsrc fs.Fs, dstFileName str
 		// If files are treated as immutable, fail if destination exists and does not match
 		if ci.Immutable && dstObj != nil {
 			err = fs.CountError(ctx, fserrors.NoRetryError(fs.ErrorImmutableModified))
-			fs.Errorf(dstObj, "Source and destination exist but do not match: %v", err)
+			fs.ErrorfCtx(ctx, dstObj, "Source and destination exist but do not match: %v", err)
 			logger(ctx, TransferError, srcObj, dstObj, err)
 			return err
 		}
@@ -2200,7 +2200,7 @@ func moveOrCopyFile(ctx context.Context, fdst fs.Fs, fsrc fs.Fs, dstFileName str
 		_, err = Op(ctx, fdst, dstObj, dstFileName, srcObj)
 	} else if !cp {
 		if ci.IgnoreExisting {
-			fs.Debugf(srcObj, "Not removing source file as destination file exists and --ignore-existing is set")
+			fs.DebugfCtx(ctx, srcObj, "Not removing source file as destination file exists and --ignore-existing is set")
 			logger(ctx, Match, srcObj, dstObj, nil)
 		} else if !SameObject(srcObj, dstObj) {
 			err = DeleteFile(ctx, srcObj)
@@ -2229,12 +2229,12 @@ func SetTier(ctx context.Context, fsrc fs.Fs, tier string) error {
 	return ListFn(ctx, fsrc, func(o fs.Object) {
 		objImpl, ok := o.(fs.SetTierer)
 		if !ok {
-			fs.Errorf(fsrc, "Remote object does not implement SetTier")
+			fs.ErrorfCtx(ctx, fsrc, "Remote object does not implement SetTier")
 			return
 		}
 		err := objImpl.SetTier(tier)
 		if err != nil {
-			fs.Errorf(fsrc, "Failed to do SetTier, %v", err)
+			fs.ErrorfCtx(ctx, fsrc, "Failed to do SetTier, %v", err)
 		}
 	})
 }
@@ -2247,7 +2247,7 @@ func SetTierFile(ctx context.Context, o fs.Object, tier string) error {
 	}
 	err := do.SetTier(tier)
 	if err != nil {
-		fs.Errorf(o, "Failed to do SetTier, %v", err)
+		fs.ErrorfCtx(ctx, o, "Failed to do SetTier, %v", err)
 		return err
 	}
 	return nil
@@ -2262,12 +2262,12 @@ func TouchDir(ctx context.Context, f fs.Fs, remote string, t time.Time, recursiv
 		entries.ForObject(func(o fs.Object) {
 			if !SkipDestructive(ctx, o, "touch") {
 				g.Go(func() error {
-					fs.Debugf(f, "Touching %q", o.Remote())
+					fs.DebugfCtx(ctx, f, "Touching %q", o.Remote())
 					err := o.SetModTime(gCtx, t)
 					if err != nil {
 						err = fmt.Errorf("failed to touch: %w", err)
 						err = fs.CountError(gCtx, err)
-						fs.Errorf(o, "%v", err)
+						fs.ErrorfCtx(ctx, o, "%v", err)
 					}
 					return nil
 				})
@@ -2501,7 +2501,7 @@ func DirMove(ctx context.Context, f fs.Fs, srcRemote, dstRemote string) (err err
 		if err != fs.ErrorCantDirMove && err != fs.ErrorDirExists {
 			return err
 		}
-		fs.Infof(f, "Can't DirMove - falling back to file moves: %v", err)
+		fs.InfofCtx(ctx, f, "Can't DirMove - falling back to file moves: %v", err)
 	}
 
 	// Load the directory tree into memory
@@ -2667,18 +2667,18 @@ func skipDestructiveChoose(ctx context.Context, subject any, action string) (ski
 	case 's':
 		skip = true
 		skipped[action] = true
-		fs.Logf(nil, "Skipping all %s operations from now on without asking", action)
+		fs.LogfCtx(ctx, nil, "Skipping all %s operations from now on without asking", action)
 	case '!':
 		skip = false
 		skipped[action] = false
-		fs.Logf(nil, "Doing all %s operations from now on without asking", action)
+		fs.LogfCtx(ctx, nil, "Doing all %s operations from now on without asking", action)
 	case 'q':
-		fs.Logf(nil, "Quitting rclone now")
+		fs.LogfCtx(ctx, nil, "Quitting rclone now")
 		atexit.Run()
 		os.Exit(0)
 	default:
 		skip = true
-		fs.Errorf(nil, "Bad choice %c", i)
+		fs.ErrorfCtx(ctx, nil, "Bad choice %c", i)
 	}
 	return skip
 }
@@ -2718,9 +2718,9 @@ func SkipDestructive(ctx context.Context, subject any, action string) (skip bool
 			size = do.Size()
 		}
 		if size >= 0 {
-			fs.Logf(subject, "Skipped %s as %s is set (size %v)", fs.LogValue("skipped", action), flag, fs.LogValue("size", fs.SizeSuffix(size)))
+			fs.LogfCtx(ctx, subject, "Skipped %s as %s is set (size %v)", fs.LogValue("skipped", action), flag, fs.LogValue("size", fs.SizeSuffix(size)))
 		} else {
-			fs.Logf(subject, "Skipped %s as %s is set", fs.LogValue("skipped", action), flag)
+			fs.LogfCtx(ctx, subject, "Skipped %s as %s is set", fs.LogValue("skipped", action), flag)
 		}
 	}
 	return skip
@@ -2808,7 +2808,7 @@ func CopyDirMetadata(ctx context.Context, f fs.Fs, dst fs.Directory, dir string,
 		return nil, err
 	}
 	accounting.Stats(ctx).UpdatedDirs(1)
-	fs.Infof(logName, "Updated directory metadata")
+	fs.InfofCtx(ctx, logName, "Updated directory metadata")
 	return newDst, nil
 }
 
@@ -2824,7 +2824,7 @@ func SetDirModTime(ctx context.Context, f fs.Fs, dst fs.Directory, dir string, m
 	logName := dirName(f, dst, dir)
 	ci := fs.GetConfig(ctx)
 	if ci.NoUpdateDirModTime {
-		fs.Debugf(logName, "Skipping set directory modification time as --no-update-dir-modtime is set")
+		fs.DebugfCtx(ctx, logName, "Skipping set directory modification time as --no-update-dir-modtime is set")
 		return nil, nil
 	}
 	tr := accounting.Stats(ctx).NewCheckingTransferNoHistory(dirTransferEntry(f, dst, dir), "setting modtime")
@@ -2851,7 +2851,7 @@ func SetDirModTime(ctx context.Context, f fs.Fs, dst fs.Directory, dir string, m
 				return dst, err
 			} else {
 				accounting.Stats(ctx).UpdatedDirs(1)
-				fs.Infof(logName, "Set directory modification time (using SetModTime)")
+				fs.InfofCtx(ctx, logName, "Set directory modification time (using SetModTime)")
 				return dst, nil
 			}
 		}
@@ -2864,7 +2864,7 @@ func SetDirModTime(ctx context.Context, f fs.Fs, dst fs.Directory, dir string, m
 			return dst, err
 		}
 		accounting.Stats(ctx).UpdatedDirs(1)
-		fs.Infof(logName, "Set directory modification time (using DirSetModTime)")
+		fs.InfofCtx(ctx, logName, "Set directory modification time (using DirSetModTime)")
 		return dst, nil
 	}
 

fs/operations/rc.go

@@ -315,7 +315,7 @@ func rcSingleCommand(ctx context.Context, in rc.Params, name string, noRemote bo
 					if err != nil {
 						return nil, err
 					}
-					fs.Debugf(obj, "Upload Succeeded")
+					fs.DebugfCtx(ctx, obj, "Upload Succeeded")
 				}
 			}
 		}

fs/operations/reopen.go

@@ -149,7 +149,7 @@ func (h *ReOpen) open() error {
 	}
 	if h.err != nil {
 		if h.tries > 1 {
-			fs.Debugf(h.src, "Reopen failed after offset %d bytes read: %v", h.offset, h.err)
+			fs.DebugfCtx(h.ctx, h.src, "Reopen failed after offset %d bytes read: %v", h.offset, h.err)
 		}
 		return h.err
 	}
@@ -194,7 +194,7 @@ func (h *ReOpen) Read(p []byte) (n int, err error) {
 	// re-open if seek needed
 	if h.newOffset >= 0 {
 		if h.offset != h.newOffset {
-			fs.Debugf(h.src, "Seek from %d to %d", h.offset, h.newOffset)
+			fs.DebugfCtx(h.ctx, h.src, "Seek from %d to %d", h.offset, h.newOffset)
 			h.offset = h.newOffset
 			err = h.reopen()
 			if err != nil {
@@ -214,7 +214,7 @@ func (h *ReOpen) Read(p []byte) (n int, err error) {
 		if err != nil && err != io.EOF {
 			h.err = err
 			if !fserrors.IsNoLowLevelRetryError(err) {
-				fs.Debugf(h.src, "Reopening on read failure after offset %d bytes: retry %d/%d: %v", h.offset, h.tries, h.maxTries, err)
+				fs.DebugfCtx(h.ctx, h.src, "Reopening on read failure after offset %d bytes: retry %d/%d: %v", h.offset, h.tries, h.maxTries, err)
 				if h.reopen() == nil {
 					err = nil
 				}

fs/rc/jobs/job_test.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"encoding/json"
 	"errors"
+	"log/slog"
 	"runtime"
 	"testing"
 	"time"
@@ -11,6 +12,7 @@ import (
 	"github.com/rclone/rclone/fs"
 	"github.com/rclone/rclone/fs/accounting"
 	"github.com/rclone/rclone/fs/filter"
+	"github.com/rclone/rclone/fs/log"
 	"github.com/rclone/rclone/fs/rc"
 	"github.com/rclone/rclone/fstest/testy"
 	"github.com/stretchr/testify/assert"
@@ -308,6 +310,34 @@ func TestExecuteJobWithConfig(t *testing.T) {
 	assert.NotEqual(t, 42*fs.Mebi, ci.BufferSize)
 }
 
+// Check LogLevel in _config sets the log level for the logs of the call
+func TestExecuteJobWithConfigLogLevel(t *testing.T) {
+	ctx := context.Background()
+	require.Less(t, fs.GetConfig(ctx).LogLevel, fs.LogLevelDebug)
+	var logs []string
+	log.Handler.SetOutput(func(level slog.Level, text string) {
+		logs = append(logs, text)
+	})
+	defer log.Handler.ResetOutput()
+	jobFn := func(ctx context.Context, in rc.Params) (rc.Params, error) {
+		fs.DebugfCtx(ctx, nil, "debug from job")
+		return nil, nil
+	}
+
+	_, _, err := NewJob(ctx, jobFn, rc.Params{})
+	require.NoError(t, err)
+	assert.Empty(t, logs)
+
+	_, _, err = NewJob(ctx, jobFn, rc.Params{
+		"_config": rc.Params{
+			"LogLevel": "DEBUG",
+		},
+	})
+	require.NoError(t, err)
+	require.Len(t, logs, 1)
+	assert.Contains(t, logs[0], "debug from job")
+}
+
 // NewJob must mark the context as a remote control (rc) request, including for
 // asynchronous jobs whose context is detached
 func TestNewJobMarksRCRequest(t *testing.T) {

fs/sync/sync.go

@@ -157,7 +157,7 @@ func newSyncCopyMove(ctx context.Context, fdst, fsrc fs.Fs, deleteMode fs.Delete
 
 	backlog := ci.MaxBacklog
 	if s.checkFirst {
-		fs.Infof(s.fdst, "Running all checks before starting transfers")
+		fs.InfofCtx(ctx, s.fdst, "Running all checks before starting transfers")
 		backlog = -1
 	}
 	var err error
@@ -175,7 +175,7 @@ func newSyncCopyMove(ctx context.Context, fdst, fsrc fs.Fs, deleteMode fs.Delete
 	}
 	if ci.MaxDuration > 0 {
 		s.maxDurationEndTime = time.Now().Add(time.Duration(ci.MaxDuration))
-		fs.Infof(s.fdst, "Transfer session %v deadline: %s", ci.CutoffMode, s.maxDurationEndTime.Format("2006/01/02 15:04:05"))
+		fs.InfofCtx(ctx, s.fdst, "Transfer session %v deadline: %s", ci.CutoffMode, s.maxDurationEndTime.Format("2006/01/02 15:04:05"))
 	}
 	// If a max session duration has been defined add a deadline
 	// to the main context if cutoff mode is hard. This will cut
@@ -198,7 +198,7 @@ func newSyncCopyMove(ctx context.Context, fdst, fsrc fs.Fs, deleteMode fs.Delete
 	}
 	if s.noTraverse && s.deleteMode != fs.DeleteModeOff {
 		if !fi.HaveFilesFrom() {
-			fs.Errorf(nil, "Ignoring --no-traverse with sync")
+			fs.ErrorfCtx(ctx, nil, "Ignoring --no-traverse with sync")
 		}
 		s.noTraverse = false
 	}
@@ -222,12 +222,12 @@ func newSyncCopyMove(ctx context.Context, fdst, fsrc fs.Fs, deleteMode fs.Delete
 		s.commonHash = commonHash
 		s.modifyWindow = modifyWindow
 		for _, reason := range unsupported {
-			fs.Errorf(fdst, "Ignoring --track-renames as %s", reason)
+			fs.ErrorfCtx(ctx, fdst, "Ignoring --track-renames as %s", reason)
 			s.trackRenames = false
 		}
 
 		if s.deleteMode == fs.DeleteModeOff {
-			fs.Errorf(fdst, "Ignoring --track-renames as it doesn't work with copy or move, only sync")
+			fs.ErrorfCtx(ctx, fdst, "Ignoring --track-renames as it doesn't work with copy or move, only sync")
 			s.trackRenames = false
 		}
 	}
@@ -237,7 +237,7 @@ func newSyncCopyMove(ctx context.Context, fdst, fsrc fs.Fs, deleteMode fs.Delete
 			s.deleteMode = fs.DeleteModeAfter
 		}
 		if s.noTraverse {
-			fs.Errorf(nil, "Ignoring --no-traverse with --track-renames")
+			fs.ErrorfCtx(ctx, nil, "Ignoring --no-traverse with --track-renames")
 			s.noTraverse = false
 		}
 	}
@@ -297,7 +297,7 @@ func (s *syncCopyMove) processError(err error) {
 		err = fserrors.NoRetryError(err)
 	} else if err == accounting.ErrorMaxTransferLimitReachedGraceful {
 		if s.inCtx.Err() == nil {
-			fs.Logf(nil, "%v - stopping transfers", err)
+			fs.LogfCtx(s.ctx, nil, "%v - stopping transfers", err)
 			// Cancel the march and stop the pipes
 			s.inCancel()
 		}
@@ -310,7 +310,7 @@ func (s *syncCopyMove) processError(err error) {
 	switch {
 	case fserrors.IsFatalError(err):
 		if !s.aborting() {
-			fs.Errorf(nil, "Cancelling sync due to fatal error: %v", err)
+			fs.ErrorfCtx(s.ctx, nil, "Cancelling sync due to fatal error: %v", err)
 			s.cancel()
 		}
 		s.fatalErr = err
@@ -373,16 +373,16 @@ func (s *syncCopyMove) pairChecker(in *pipe, out *pipe, fraction int, wg *sync.W
 				// src.Remote() (the correctly-cased name).
 				if needTransfer {
 					if _, statErr := s.fdst.NewObject(s.ctx, pair.Dst.Remote()); errors.Is(statErr, fs.ErrorObjectNotFound) {
-						fs.Debugf(pair.Dst, "Skipping fix-case rename: destination removed for re-upload, will recreate at %s", src.Remote())
+						fs.DebugfCtx(s.ctx, pair.Dst, "Skipping fix-case rename: destination removed for re-upload, will recreate at %s", src.Remote())
 						pair.Dst = nil
 					}
 				}
 				if pair.Dst != nil {
 					if newDst, err := operations.Move(s.ctx, s.fdst, nil, src.Remote(), pair.Dst); err != nil {
-						fs.Errorf(pair.Dst, "Error while attempting to rename to %s: %v", src.Remote(), err)
+						fs.ErrorfCtx(s.ctx, pair.Dst, "Error while attempting to rename to %s: %v", src.Remote(), err)
 						s.processError(err)
 					} else {
-						fs.Infof(pair.Dst, "Fixed case by renaming to: %s", src.Remote())
+						fs.InfofCtx(s.ctx, pair.Dst, "Fixed case by renaming to: %s", src.Remote())
 						pair.Dst = newDst
 					}
 				}
@@ -391,7 +391,7 @@ func (s *syncCopyMove) pairChecker(in *pipe, out *pipe, fraction int, wg *sync.W
 				// If files are treated as immutable, fail if destination exists and does not match
 				if s.ci.Immutable && pair.Dst != nil {
 					err := fs.CountError(s.ctx, fserrors.NoRetryError(fs.ErrorImmutableModified))
-					fs.Errorf(pair.Dst, "Source and destination exist but do not match: %v", err)
+					fs.ErrorfCtx(s.ctx, pair.Dst, "Source and destination exist but do not match: %v", err)
 					s.processError(err)
 				} else {
 					if pair.Dst != nil {
@@ -425,9 +425,9 @@ func (s *syncCopyMove) pairChecker(in *pipe, out *pipe, fraction int, wg *sync.W
 				if s.DoMove {
 					// Delete src if no error on copy
 					if operations.SameObject(src, pair.Dst) {
-						fs.Logf(src, "Not removing source file as it is the same file as the destination")
+						fs.LogfCtx(s.ctx, src, "Not removing source file as it is the same file as the destination")
 					} else if s.ci.IgnoreExisting {
-						fs.Debugf(src, "Not removing source file as destination file exists and --ignore-existing is set")
+						fs.DebugfCtx(s.ctx, src, "Not removing source file as destination file exists and --ignore-existing is set")
 					} else if s.checkFirst && s.ci.OrderBy != "" {
 						// If we want perfect ordering then use the transfers to delete the file
 						//
@@ -460,7 +460,7 @@ func (s *syncCopyMove) pairRenamer(in *pipe, out *pipe, fraction int, wg *sync.W
 		src := pair.Src
 		if !s.tryRename(src) {
 			// pass on if not renamed
-			fs.Debugf(src, "Need to transfer - No matching file found at Destination")
+			fs.DebugfCtx(s.ctx, src, "Need to transfer - No matching file found at Destination")
 			ok = out.Put(s.inCtx, pair)
 			if !ok {
 				return
@@ -509,7 +509,7 @@ func (s *syncCopyMove) startCheckers() {
 // This stops the background checkers
 func (s *syncCopyMove) stopCheckers() {
 	s.toBeChecked.Close()
-	fs.Debugf(s.fdst, "Waiting for checks to finish")
+	fs.DebugfCtx(s.ctx, s.fdst, "Waiting for checks to finish")
 	s.checkerWg.Wait()
 }
 
@@ -525,7 +525,7 @@ func (s *syncCopyMove) startTransfers() {
 // This stops the background transfers
 func (s *syncCopyMove) stopTransfers() {
 	s.toBeUploaded.Close()
-	fs.Debugf(s.fdst, "Waiting for transfers to finish")
+	fs.DebugfCtx(s.ctx, s.fdst, "Waiting for transfers to finish")
 	s.transfersWg.Wait()
 }
 
@@ -547,7 +547,7 @@ func (s *syncCopyMove) stopRenamers() {
 		return
 	}
 	s.toBeRenamed.Close()
-	fs.Debugf(s.fdst, "Waiting for renames to finish")
+	fs.DebugfCtx(s.ctx, s.fdst, "Waiting for renames to finish")
 	s.renamerWg.Wait()
 }
 
@@ -599,7 +599,7 @@ func (s *syncCopyMove) stopDeleters() {
 // have been found have been removed from dstFiles already.
 func (s *syncCopyMove) deleteFiles(checkSrcMap bool) error {
 	if accounting.Stats(s.ctx).Errored() && !s.ci.IgnoreErrors {
-		fs.Errorf(s.fdst, "%v", fs.ErrorNotDeleting)
+		fs.ErrorfCtx(s.ctx, s.fdst, "%v", fs.ErrorNotDeleting)
 		// log all deletes as errors
 		for remote, o := range s.dstFiles {
 			if checkSrcMap {
@@ -645,7 +645,7 @@ func (s *syncCopyMove) deleteEmptyDirectories(ctx context.Context, f fs.Fs, entr
 		return nil
 	}
 	if accounting.Stats(ctx).Errored() && !s.ci.IgnoreErrors {
-		fs.Errorf(f, "%v", fs.ErrorNotDeletingDirs)
+		fs.ErrorfCtx(ctx, f, "%v", fs.ErrorNotDeletingDirs)
 		return fs.ErrorNotDeletingDirs
 	}
 
@@ -663,20 +663,20 @@ func (s *syncCopyMove) deleteEmptyDirectories(ctx context.Context, f fs.Fs, entr
 			// TryRmdir only deletes empty directories
 			err := operations.TryRmdir(ctx, f, dir.Remote())
 			if err != nil {
-				fs.Debugf(fs.LogDirName(f, dir.Remote()), "Failed to Rmdir: %v", err)
+				fs.DebugfCtx(ctx, fs.LogDirName(f, dir.Remote()), "Failed to Rmdir: %v", err)
 				errorCount++
 			} else {
 				okCount++
 			}
 		} else {
-			fs.Errorf(f, "Not a directory: %v", entry)
+			fs.ErrorfCtx(ctx, f, "Not a directory: %v", entry)
 		}
 	}
 	if errorCount > 0 {
-		fs.Debugf(f, "failed to delete %d directories", errorCount)
+		fs.DebugfCtx(ctx, f, "failed to delete %d directories", errorCount)
 	}
 	if okCount > 0 {
-		fs.Debugf(f, "deleted %d directories", okCount)
+		fs.DebugfCtx(ctx, f, "deleted %d directories", okCount)
 	}
 	return nil
 }
@@ -722,7 +722,7 @@ func (s *syncCopyMove) markParentNotEmpty(entry fs.DirEntry) {
 // makeRenameMap builds a map of the destination files by hash that
 // match sizes in the slice of objects in s.renameCheck
 func (s *syncCopyMove) makeRenameMap() {
-	fs.Infof(s.fdst, "Making map for --track-renames")
+	fs.InfofCtx(s.ctx, s.fdst, "Making map for --track-renames")
 
 	// first make a map of possible sizes we need to check
 	possibleSizes := map[int64]struct{}{}
@@ -752,7 +752,7 @@ func (s *syncCopyMove) makeRenameMap() {
 		}()
 	}
 	wg.Wait()
-	fs.Infof(s.fdst, "Finished making map for --track-renames")
+	fs.InfofCtx(s.ctx, s.fdst, "Finished making map for --track-renames")
 }
 
 // tryRename renames an src object when doing track renames if
@@ -770,7 +770,7 @@ func (s *syncCopyMove) tryRename(src fs.Object) bool {
 	// Rename dst to have name src.Remote()
 	_, err := operations.Move(s.ctx, s.fdst, dstOverwritten, src.Remote(), dst)
 	if err != nil {
-		fs.Debugf(src, "Failed to rename to %q: %v", dst.Remote(), err)
+		fs.DebugfCtx(s.ctx, src, "Failed to rename to %q: %v", dst.Remote(), err)
 		return false
 	}
 
@@ -779,7 +779,7 @@ func (s *syncCopyMove) tryRename(src fs.Object) bool {
 	delete(s.dstFiles, dst.Remote())
 	s.dstFilesMu.Unlock()
 
-	fs.Infof(src, "Renamed from %q", dst.Remote())
+	fs.InfofCtx(s.ctx, src, "Renamed from %q", dst.Remote())
 	return true
 }
 
@@ -792,7 +792,7 @@ func (s *syncCopyMove) tryRename(src fs.Object) bool {
 // dir is the start directory, "" for root
 func (s *syncCopyMove) run() error {
 	if operations.Same(s.fdst, s.fsrc) && !s.allowOverlap {
-		fs.Errorf(s.fdst, "Nothing to do as source and destination are the same")
+		fs.ErrorfCtx(s.ctx, s.fdst, "Nothing to do as source and destination are the same")
 		return nil
 	}
 
@@ -838,7 +838,7 @@ func (s *syncCopyMove) run() error {
 	// Stop background checking and transferring pipeline
 	s.stopCheckers()
 	if s.checkFirst {
-		fs.Infof(s.fdst, "Checks finished, now starting transfers")
+		fs.InfofCtx(s.ctx, s.fdst, "Checks finished, now starting transfers")
 		s.startTransfers()
 	}
 	s.stopRenamers()
@@ -848,7 +848,7 @@ func (s *syncCopyMove) run() error {
 	// Delete files after
 	if s.deleteMode == fs.DeleteModeAfter {
 		if s.currentError() != nil && !s.ci.IgnoreErrors {
-			fs.Errorf(s.fdst, "%v", fs.ErrorNotDeleting)
+			fs.ErrorfCtx(s.ctx, s.fdst, "%v", fs.ErrorNotDeleting)
 		} else {
 			s.processError(s.deleteFiles(false))
 		}
@@ -862,7 +862,7 @@ func (s *syncCopyMove) run() error {
 	// Prune empty directories
 	if s.deleteMode != fs.DeleteModeOff {
 		if s.currentError() != nil && !s.ci.IgnoreErrors {
-			fs.Errorf(s.fdst, "%v", fs.ErrorNotDeletingDirs)
+			fs.ErrorfCtx(s.ctx, s.fdst, "%v", fs.ErrorNotDeletingDirs)
 		} else {
 			s.processError(s.deleteEmptyDirectories(s.ctx, s.fdst, s.dstEmptyDirs))
 		}
@@ -881,13 +881,13 @@ func (s *syncCopyMove) run() error {
 
 	// If the duration was exceeded then add a Fatal Error so we don't retry
 	if !s.maxDurationEndTime.IsZero() && time.Since(s.maxDurationEndTime) > 0 {
-		fs.Errorf(s.fdst, "%v", ErrorMaxDurationReachedFatal)
+		fs.ErrorfCtx(s.ctx, s.fdst, "%v", ErrorMaxDurationReachedFatal)
 		s.processError(ErrorMaxDurationReachedFatal)
 	}
 
 	// Print nothing to transfer message if there were no transfers and no errors
 	if s.deleteMode != fs.DeleteModeOnly && accounting.Stats(s.ctx).GetTransfers() == 0 && s.currentError() == nil {
-		fs.Infof(nil, "There was nothing to transfer")
+		fs.InfofCtx(s.ctx, nil, "There was nothing to transfer")
 	}
 
 	// cancel the contexts to free resources
@@ -1034,7 +1034,7 @@ func (s *syncCopyMove) copyDirMetadata(ctx context.Context, f fs.Fs, dst fs.Dire
 		}
 		s.setDirModTimes = append(s.setDirModTimes, set)
 		s.setDirModTimeMu.Unlock()
-		fs.Debugf(nil, "Added delayed dir = %q, newDst=%v", dir, newDst)
+		fs.DebugfCtx(ctx, nil, "Added delayed dir = %q, newDst=%v", dir, newDst)
 	}
 	s.processError(err)
 	if err != nil {
@@ -1089,7 +1089,7 @@ func (s *syncCopyMove) setDelayedDirModTimes(ctx context.Context) error {
 					_, err = operations.SetDirModTime(gCtx, s.fdst, item.dst, item.dir, item.modTime)
 				}
 				if err != nil {
-					fs.Errorf(item.dir, "Failed to update directory timestamp or metadata: %v", err)
+					fs.ErrorfCtx(gCtx, item.dir, "Failed to update directory timestamp or metadata: %v", err)
 					errCount.Add(err)
 				}
 				return nil // don't return errors, just count them
@@ -1129,7 +1129,7 @@ func (s *syncCopyMove) SrcOnly(src fs.DirEntry) (recurse bool) {
 			}
 			if !NoNeedTransfer {
 				// No need to check since doesn't exist
-				fs.Debugf(src, "Need to transfer - File not found at Destination")
+				fs.DebugfCtx(s.ctx, src, "Need to transfer - File not found at Destination")
 				s.markDirModifiedObject(x)
 				ok := s.toBeUploaded.Put(s.inCtx, fs.ObjectPair{Src: x, Dst: nil})
 				if !ok {
@@ -1171,7 +1171,7 @@ func (s *syncCopyMove) Match(ctx context.Context, dst, src fs.DirEntry) (recurse
 		} else {
 			// FIXME src is file, dst is directory
 			err := errors.New("can't overwrite directory with file")
-			fs.Errorf(dst, "%v", err)
+			fs.ErrorfCtx(ctx, dst, "%v", err)
 			s.processError(err)
 			s.logger(ctx, operations.TransferError, srcX, dstX, err)
 		}
@@ -1193,10 +1193,10 @@ func (s *syncCopyMove) Match(ctx context.Context, dst, src fs.DirEntry) (recurse
 				// Fix each dir before recursing into subdirs and files
 				err := operations.DirMoveCaseInsensitive(s.ctx, s.fdst, dst.Remote(), src.Remote())
 				if err != nil {
-					fs.Errorf(dst, "Error while attempting to rename to %s: %v", src.Remote(), err)
+					fs.ErrorfCtx(ctx, dst, "Error while attempting to rename to %s: %v", src.Remote(), err)
 					s.processError(err)
 				} else {
-					fs.Infof(dst, "Fixed case by renaming to: %s", src.Remote())
+					fs.InfofCtx(ctx, dst, "Fixed case by renaming to: %s", src.Remote())
 				}
 			}
 
@@ -1204,7 +1204,7 @@ func (s *syncCopyMove) Match(ctx context.Context, dst, src fs.DirEntry) (recurse
 		}
 		// FIXME src is dir, dst is file
 		err := errors.New("can't overwrite file with directory")
-		fs.Errorf(dst, "%v", err)
+		fs.ErrorfCtx(ctx, dst, "%v", err)
 		s.processError(err)
 		s.logger(ctx, operations.TransferError, src.(fs.ObjectInfo), dst.(fs.ObjectInfo), err)
 	default:
@@ -1274,7 +1274,7 @@ func Transform(ctx context.Context, fdst fs.Fs, deleteEmptySrcDirs bool, copyEmp
 func MoveDir(ctx context.Context, fdst, fsrc fs.Fs, deleteEmptySrcDirs bool, copyEmptySrcDirs bool) error {
 	fi := filter.GetConfig(ctx)
 	if operations.Same(fdst, fsrc) {
-		fs.Errorf(fdst, "Nothing to do as source and destination are the same")
+		fs.ErrorfCtx(ctx, fdst, "Nothing to do as source and destination are the same")
 		return nil
 	}
 
@@ -1283,17 +1283,17 @@ func MoveDir(ctx context.Context, fdst, fsrc fs.Fs, deleteEmptySrcDirs bool, cop
 		if operations.SkipDestructive(ctx, fdst, "server-side directory move") {
 			return nil
 		}
-		fs.Debugf(fdst, "Using server-side directory move")
+		fs.DebugfCtx(ctx, fdst, "Using server-side directory move")
 		err := fdstDirMove(ctx, fsrc, "", "")
 		switch err {
 		case fs.ErrorCantDirMove, fs.ErrorDirExists:
-			fs.Infof(fdst, "Server side directory move failed - fallback to file moves: %v", err)
+			fs.InfofCtx(ctx, fdst, "Server side directory move failed - fallback to file moves: %v", err)
 		case nil:
-			fs.Infof(fdst, "Server side directory move succeeded")
+			fs.InfofCtx(ctx, fdst, "Server side directory move succeeded")
 			return nil
 		default:
 			err = fs.CountError(ctx, err)
-			fs.Errorf(fdst, "Server side directory move failed: %v", err)
+			fs.ErrorfCtx(ctx, fdst, "Server side directory move failed: %v", err)
 			return err
 		}
 	}

fs/sync/sync_test.go

@@ -2793,7 +2793,7 @@ func TestSyncConcurrentTruncate(t *testing.T) {
 // Test that sync replaces dir modtimes in dst if they've changed
 func testSyncReplaceDirModTime(t *testing.T, copyEmptySrcDirs bool) {
 	accounting.GlobalStats().ResetCounters()
-	ctx, _ := fs.AddConfig(context.Background())
+	ctx, ci := fs.AddConfig(context.Background())
 	r := fstest.NewRun(t)
 
 	file1 := r.WriteFile("file1", "file1", t2)
@@ -2812,10 +2812,7 @@ func testSyncReplaceDirModTime(t *testing.T, copyEmptySrcDirs bool) {
 
 	// set logging
 	// (this checks log output as DirModtime operations do not yet have stats, and r.CheckDirectoryModTimes also does not tell us what actions were taken)
-	oldLogLevel := fs.GetConfig(context.Background()).LogLevel
-	defer func() { fs.GetConfig(context.Background()).LogLevel = oldLogLevel }() // reset to old val after test
-	// need to do this as fs.Infof only respects the globalConfig
-	fs.GetConfig(context.Background()).LogLevel = fs.LogLevelInfo
+	ci.LogLevel = fs.LogLevelInfo
 
 	// First run
 	accounting.GlobalStats().ResetCounters()
@@ -2902,7 +2899,7 @@ func TestSyncSetDirModTimeOnce(t *testing.T) {
 // Run the same sync twice, ensure no action is taken the second time
 func testNothingToTransfer(t *testing.T, copyEmptySrcDirs bool) {
 	accounting.GlobalStats().ResetCounters()
-	ctx, _ := fs.AddConfig(context.Background())
+	ctx, ci := fs.AddConfig(context.Background())
 	r := fstest.NewRun(t)
 	file1 := r.WriteFile("sub dir/hello world", "hello world", t1)
 	file2 := r.WriteFile("sub dir2/very/very/very/very/very/nested/subdir/hello world", "hello world", t1)
@@ -2917,10 +2914,7 @@ func testNothingToTransfer(t *testing.T, copyEmptySrcDirs bool) {
 
 	// set logging
 	// (this checks log output as DirModtime operations do not yet have stats, and r.CheckDirectoryModTimes also does not tell us what actions were taken)
-	oldLogLevel := fs.GetConfig(context.Background()).LogLevel
-	defer func() { fs.GetConfig(context.Background()).LogLevel = oldLogLevel }() // reset to old val after test
-	// need to do this as fs.Infof only respects the globalConfig
-	fs.GetConfig(context.Background()).LogLevel = fs.LogLevelInfo
+	ci.LogLevel = fs.LogLevelInfo
 
 	accounting.GlobalStats().ResetCounters()
 	ctx = predictDstFromLogger(ctx)

fs/sync/trackrenames/trackrenames.go

@@ -244,7 +244,7 @@ func (m *Matcher) renameID(obj fs.Object) string {
 		var err error
 		sum, err = obj.Hash(m.ctx, m.hashType)
 		if err != nil {
-			fs.Debugf(obj, "Hash failed: %v", err)
+			fs.DebugfCtx(m.ctx, obj, "Hash failed: %v", err)
 			return ""
 		}
 	}

fs/walk/walk.go

@@ -172,7 +172,7 @@ func listRwalk(ctx context.Context, f fs.Fs, path string, includeAll bool, maxLe
 		if err != nil {
 			listErr = err
 			err = fs.CountError(ctx, err)
-			fs.Errorf(path, "error listing: %v", err)
+			fs.ErrorfCtx(ctx, path, "error listing: %v", err)
 			return nil
 		}
 		listType.Filter(&entries)
@@ -424,7 +424,7 @@ func walk(ctx context.Context, f fs.Fs, path string, includeAll bool, maxLevel i
 					if err != nil && err != ErrorSkipDir {
 						traversing.Done()
 						err = fs.CountError(ctx, err)
-						fs.Errorf(job.remote, "error listing: %v", err)
+						fs.ErrorfCtx(ctx, job.remote, "error listing: %v", err)
 						closeQuit()
 						// Send error to error channel if space
 						select {