What is the problem you are having with rclone?
I am experiencing what appears to be a simultaneous freeze of macOS and rclone. Most likely due to some bug in macOS (Ventura 13.2.1).
rclone works normally until the "Finished making map for --track-renames + Waiting for checks to finish + Waiting for renames to finish" stage, where all activity seems to freeze, and macOS stops responding. Especially the Finder and any application that interacts with the hard drive.
The debug log is of this freezing moment.
Detail of SORCE / DEST
- The SOURCE is a hard drive connected to macOS via Thunderbolt. Formatted as HFS+ sensitive.
- The DEST is a TrueNAS CORE 13.0-U4 machine. Formatted as RAIDZ1.
- The connection between the two machines is via direct 1gbps Ethernet LAN (cable to cable, no switch).
- I am quite confident in the TrueNAS machine, it is stable. On the other hand, I am more wary of macOS.
- I have deliberately decided not to upgrade to macOS Ventura 13.3 (released yesterday).
Run the command 'rclone version' and share the full output of the command.
rclone v1.62.2
- os/version: darwin 13.2.1 (64 bit)
- os/kernel: 22.3.0 (x86_64)
- os/type: darwin
- os/arch: amd64
- go/version: go1.20.2
- go/linking: dynamic
- go/tags: cmount
Which cloud storage system are you using? (eg Google Drive)
sftp
The command you were trying to run (eg rclone copy /tmp remote:tmp
)
rclone /Volumes/Users/vicmarto nas:/mnt/zbackup/Users/vicmarto --rc -vv --copy-links --create-empty-src-dirs --track-renames --local-case-sensitive --progress --log-file=/Users/vicmarto/rclone_log.txt
The rclone config contents with secrets removed.
[nas]
type = sftp
host = 192.168.1.150
user = vicmarto
key_file = /Users/vicmarto/.ssh/id_rsa_nas
key_file_pass = EDITED
md5sum_command = md5 -r
sha1sum_command = sha1 -r
shell_type = unix
A log from the command with the -vv
flag
2023/03/28 16:24:47 INFO : sftp://vicmarto@192.168.1.150:22//mnt/zbackup/Users/vicmarto: Making map for --track-renames
2023/03/28 16:24:47 INFO : sftp://vicmarto@192.168.1.150:22//mnt/zbackup/Users/vicmarto: Finished making map for --track-renames
2023/03/28 16:24:47 DEBUG : sftp://vicmarto@192.168.1.150:22//mnt/zbackup/Users/vicmarto: Waiting for checks to finish
2023/03/28 16:24:47 DEBUG : sftp://vicmarto@192.168.1.150:22//mnt/zbackup/Users/vicmarto: Waiting for renames to finish
2023/03/28 16:25:47 DEBUG : sftp://vicmarto@192.168.1.150:22//mnt/zbackup/Users/vicmarto: Closing 9 unused connections
A debug log
goroutine profile: total 22
7 @ 0x100072e1f 0x10008f1a9 0x10010362e 0x100103616 0x100103396 0x10010e05e 0x10010e056 0x1004f5fb1 0x1000ad732 0x1001c8697 0x1001c8670 0x100cc5ccc 0x101472c96 0x101473df9 0x101470975 0x100076a81
# 0x100072e1e syscall.syscall+0x7e runtime/sys_darwin.go:23
# 0x10008f1a8 syscall.read+0x48 syscall/zsyscall_darwin_amd64.go:1209
# 0x10010362d syscall.Read+0x2cd syscall/syscall_unix.go:178
# 0x100103615 internal/poll.ignoringEINTRIO+0x2b5 internal/poll/fd_unix.go:794
# 0x100103395 internal/poll.(*FD).Read+0x35 internal/poll/fd_unix.go:163
# 0x10010e05d os.(*File).read+0x5d os/file_posix.go:31
# 0x10010e055 os.(*File).Read+0x55 os/file.go:118
# 0x1004f5fb0 github.com/rclone/rclone/lib/readers.(*contextReader).Read+0x70 github.com/rclone/rclone/lib/readers/context.go:28
# 0x1000ad731 io.copyBuffer+0x1b1 io/io.go:427
# 0x1001c8696 io.Copy+0x416 io/io.go:386
# 0x1001c866f github.com/rclone/rclone/fs/hash.StreamTypes+0x3ef github.com/rclone/rclone/fs/hash/hash.go:119
# 0x100cc5ccb github.com/rclone/rclone/backend/local.(*Object).Hash+0x64b github.com/rclone/rclone/backend/local/local.go:945
# 0x101472c95 github.com/rclone/rclone/fs/sync.(*syncCopyMove).renameID+0x115 github.com/rclone/rclone/fs/sync/sync.go:699
# 0x101473df8 github.com/rclone/rclone/fs/sync.(*syncCopyMove).tryRename+0x118 github.com/rclone/rclone/fs/sync/sync.go:816
# 0x101470974 github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairRenamer+0xd4 github.com/rclone/rclone/fs/sync/sync.go:408
4 @ 0x100040496 0x100050abe 0x10146d6b8 0x101470ba5 0x100076a81
# 0x10146d6b7 github.com/rclone/rclone/fs/sync.(*pipe).GetMax+0xb7 github.com/rclone/rclone/fs/sync/pipe.go:126
# 0x101470ba4 github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove+0xe4 github.com/rclone/rclone/fs/sync/sync.go:423
1 @ 0x100034f56 0x10006f045 0x100441db5 0x100441bcd 0x10043e96b 0x10044f365 0x10044feb3 0x1003a68af 0x1003a8a89 0x1004c2356 0x1003a68af 0x1013fb6fa 0x1003a68af 0x1013fb6fa 0x1003a68af 0x1004c0090 0x1003aa236 0x1003a53d2 0x100076a81
# 0x10006f044 runtime/pprof.runtime_goroutineProfileWithLabels+0x24 runtime/mprof.go:844
# 0x100441db4 runtime/pprof.writeRuntimeProfile+0xb4 runtime/pprof/pprof.go:734
# 0x100441bcc runtime/pprof.writeGoroutine+0x4c runtime/pprof/pprof.go:694
# 0x10043e96a runtime/pprof.(*Profile).WriteTo+0x14a runtime/pprof/pprof.go:329
# 0x10044f364 net/http/pprof.handler.ServeHTTP+0x4a4 net/http/pprof/pprof.go:259
# 0x10044feb2 net/http/pprof.Index+0xf2 net/http/pprof/pprof.go:376
# 0x1003a68ae net/http.HandlerFunc.ServeHTTP+0x2e net/http/server.go:2122
# 0x1003a8a88 net/http.(*ServeMux).ServeHTTP+0x148 net/http/server.go:2500
# 0x1004c2355 github.com/go-chi/chi/v5.(*Mux).routeHTTP+0x215 github.com/go-chi/chi/v5@v5.0.8/mux.go:444
# 0x1003a68ae net/http.HandlerFunc.ServeHTTP+0x2e net/http/server.go:2122
# 0x1013fb6f9 github.com/go-chi/chi/v5/middleware.SetHeader.func1.1+0x139 github.com/go-chi/chi/v5@v5.0.8/middleware/content_type.go:13
# 0x1003a68ae net/http.HandlerFunc.ServeHTTP+0x2e net/http/server.go:2122
# 0x1013fb6f9 github.com/go-chi/chi/v5/middleware.SetHeader.func1.1+0x139 github.com/go-chi/chi/v5@v5.0.8/middleware/content_type.go:13
# 0x1003a68ae net/http.HandlerFunc.ServeHTTP+0x2e net/http/server.go:2122
# 0x1004c008f github.com/go-chi/chi/v5.(*Mux).ServeHTTP+0x30f github.com/go-chi/chi/v5@v5.0.8/mux.go:90
# 0x1003aa235 net/http.serverHandler.ServeHTTP+0x315 net/http/server.go:2936
# 0x1003a53d1 net/http.(*conn).serve+0x611 net/http/server.go:1995
1 @ 0x10003a4be 0x100072468 0x100416499 0x100076a81
# 0x100072467 os/signal.signal_recv+0x27 runtime/sigqueue.go:149
# 0x100416498 os/signal.loop+0x18 os/signal/signal_unix.go:23
1 @ 0x100040496 0x100009edd 0x1000099d8 0x100416b8f 0x100076a81
# 0x100416b8e github.com/rclone/rclone/lib/atexit.Register.func1.1+0x2e github.com/rclone/rclone/lib/atexit/atexit.go:45
1 @ 0x100040496 0x100009edd 0x1000099d8 0x100784665 0x100076a81
# 0x100784664 github.com/rclone/rclone/fs/march.(*March).Run.func2+0x44 github.com/rclone/rclone/fs/march/march.go:208
1 @ 0x100040496 0x100009edd 0x100009a18 0x101466734 0x100076a81
# 0x101466733 github.com/rclone/rclone/cmd.SigInfoHandler.func1+0x93 github.com/rclone/rclone/cmd/siginfo_bsd.go:20
1 @ 0x100040496 0x1000392d7 0x10006f4c9 0x100102092 0x1001035f9 0x1001035e7 0x1001808a9 0x100194205 0x10039ee5f 0x100076a81
# 0x10006f4c8 internal/poll.runtime_pollWait+0x88 runtime/netpoll.go:306
# 0x100102091 internal/poll.(*pollDesc).wait+0x31 internal/poll/fd_poll_runtime.go:84
# 0x1001035f8 internal/poll.(*pollDesc).waitRead+0x298 internal/poll/fd_poll_runtime.go:89
# 0x1001035e6 internal/poll.(*FD).Read+0x286 internal/poll/fd_unix.go:167
# 0x1001808a8 net.(*netFD).Read+0x28 net/fd_posix.go:55
# 0x100194204 net.(*conn).Read+0x44 net/net.go:183
# 0x10039ee5e net/http.(*connReader).backgroundRead+0x3e net/http/server.go:674
1 @ 0x100040496 0x1000392d7 0x10006f4c9 0x100102092 0x100107b1d 0x100107b0b 0x100182a95 0x10019f305 0x10019df7d 0x1003aa865 0x1004c8c28 0x100076a81
# 0x10006f4c8 internal/poll.runtime_pollWait+0x88 runtime/netpoll.go:306
# 0x100102091 internal/poll.(*pollDesc).wait+0x31 internal/poll/fd_poll_runtime.go:84
# 0x100107b1c internal/poll.(*pollDesc).waitRead+0x2bc internal/poll/fd_poll_runtime.go:89
# 0x100107b0a internal/poll.(*FD).Accept+0x2aa internal/poll/fd_unix.go:614
# 0x100182a94 net.(*netFD).accept+0x34 net/fd_unix.go:172
# 0x10019f304 net.(*TCPListener).accept+0x24 net/tcpsock_posix.go:148
# 0x10019df7c net.(*TCPListener).Accept+0x3c net/tcpsock.go:297
# 0x1003aa864 net/http.(*Server).Serve+0x384 net/http/server.go:3059
# 0x1004c8c27 github.com/rclone/rclone/lib/http.instance.serve+0xa7 github.com/rclone/rclone/lib/http/server.go:132
1 @ 0x100040496 0x100050abe 0x1009c5f0d 0x100076a81
# 0x1009c5f0c go.opencensus.io/stats/view.(*worker).start+0xac go.opencensus.io@v0.24.0/stats/view/worker.go:292
1 @ 0x100040496 0x100050abe 0x101466027 0x100076a81
# 0x101466026 github.com/rclone/rclone/cmd.startProgress.func3+0x106 github.com/rclone/rclone/cmd/progress.go:57
1 @ 0x100040496 0x100051d6f 0x100051d46 0x100071c47 0x10008682b 0x101471597 0x101474492 0x10147588a 0x101475978 0x10168cc0c 0x101461fdd 0x10168cb65 0x101436627 0x101436f3d 0x101463c76 0x101463c6b 0x10169cdd7 0x100040067 0x100076a81
# 0x100071c46 sync.runtime_Semacquire+0x26 runtime/sema.go:62
# 0x10008682a sync.(*WaitGroup).Wait+0x4a sync/waitgroup.go:116
# 0x101471596 github.com/rclone/rclone/fs/sync.(*syncCopyMove).stopRenamers+0x76 github.com/rclone/rclone/fs/sync/sync.go:494
# 0x101474491 github.com/rclone/rclone/fs/sync.(*syncCopyMove).run+0x331 github.com/rclone/rclone/fs/sync/sync.go:908
# 0x101475889 github.com/rclone/rclone/fs/sync.runSyncCopyMove+0x229 github.com/rclone/rclone/fs/sync/sync.go:1130
# 0x101475977 github.com/rclone/rclone/fs/sync.Sync+0x77 github.com/rclone/rclone/fs/sync/sync.go:1136
# 0x10168cc0b github.com/rclone/rclone/cmd/sync.glob..func1.1+0x4b github.com/rclone/rclone/cmd/sync/sync.go:68
# 0x101461fdc github.com/rclone/rclone/cmd.Run+0x11c github.com/rclone/rclone/cmd/cmd.go:257
# 0x10168cb64 github.com/rclone/rclone/cmd/sync.glob..func1+0xc4 github.com/rclone/rclone/cmd/sync/sync.go:66
# 0x101436626 github.com/spf13/cobra.(*Command).execute+0x846 github.com/spf13/cobra@v1.6.1/command.go:920
# 0x101436f3c github.com/spf13/cobra.(*Command).ExecuteC+0x3bc github.com/spf13/cobra@v1.6.1/command.go:1044
# 0x101463c75 github.com/spf13/cobra.(*Command).Execute+0x75 github.com/spf13/cobra@v1.6.1/command.go:968
# 0x101463c6a github.com/rclone/rclone/cmd.Main+0x6a github.com/rclone/rclone/cmd/cmd.go:567
# 0x10169cdd6 main.main+0x16 github.com/rclone/rclone/rclone.go:14
# 0x100040066 runtime.main+0x206 runtime/proc.go:250
1 @ 0x100072e1f 0x10008e12f 0x100103071 0x100101973 0x10010310f 0x100111a8a 0x10010fc65 0x100cc5cf4 0x101472c96 0x101473df9 0x101470975 0x100076a81
# 0x100072e1e syscall.syscall+0x7e runtime/sys_darwin.go:23
# 0x10008e12e syscall.Close+0x2e syscall/zsyscall_darwin_amd64.go:509
# 0x100103070 internal/poll.(*FD).destroy+0x50 internal/poll/fd_unix.go:84
# 0x100101972 internal/poll.(*FD).decref+0x52 internal/poll/fd_mutex.go:213
# 0x10010310e internal/poll.(*FD).Close+0x4e internal/poll/fd_unix.go:107
# 0x100111a89 os.(*file).close+0x89 os/file_unix.go:262
# 0x10010fc64 os.(*File).Close+0x24 os/file_posix.go:25
# 0x100cc5cf3 github.com/rclone/rclone/backend/local.(*Object).Hash+0x673 github.com/rclone/rclone/backend/local/local.go:946
# 0x101472c95 github.com/rclone/rclone/fs/sync.(*syncCopyMove).renameID+0x115 github.com/rclone/rclone/fs/sync/sync.go:699
# 0x101473df8 github.com/rclone/rclone/fs/sync.(*syncCopyMove).tryRename+0x118 github.com/rclone/rclone/fs/sync/sync.go:816
# 0x101470974 github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairRenamer+0xd4 github.com/rclone/rclone/fs/sync/sync.go:408