Rclone is hang. There is no more log but rclone is still alive

greencacti · October 9, 2019, 3:27am

What is the problem you are having with rclone?

I have a bucket in Alibaba Cloud that has more than 40,000,000 files. I use rclone to sync the files from the bucket to a NAS mounted manually. First time rclone throws OutOfMemory issue. Then rclone is started again. It can work and skip the previous synced files. But after several hours, rclone is hang. There is no any log.

What is your rclone version (output from `rclone version`)

1.49.3

Which OS you are using and how many bits (eg Windows 7, 64 bit)

Cent OS 7.3 64bit

Which cloud storage system are you using? (eg Google Drive)

Alibaba cloud OSS

The command you were trying to run (eg `rclone copy /tmp remote:tmp`)

["/opt/alibabacloud/abr/bin/rclone" "sync" "oss:auto-builder" "/mnt/ds-0001480rtre19h6t3jb0/bp-0001480rtre19h6xp4jf/auto-builder" "--config=rclone.conf" "--s3-provider=Alibaba" "--s3-access-key-id=LTAIHBQlJet4VzJD" "--s3-secret-access-key=******" "--s3-endpoint=http://oss-cn-hangzhou-internal.aliyuncs.com" "--no-check-certificate" "--retries=3" "--retries-sleep=5s" "--stats=60s" "--transfers=10" "--checkers=1" "--log-level=DEBUG" "--log-file=backup_2019-10-08-14:10:46_auto-builder.log" "-P"]

A log from the command with the `-vv` flag (eg output from `rclone -vv copy /tmp remote:tmp`)

2019/10/08 14:10:46 DEBUG : rclone: Version "v1.49.1" starting with parameters ["/opt/alibabacloud/abr/bin/rclone" "sync" "oss:auto-builder" "/mnt/ds-0001480rtre19h6t3jb0/bp-0001480rtre19h6xp4jf/auto-builder" "--config=rclone.conf" "--s3-provider=Alibaba" "--s3-access-key-id=LTAIHBQlJet4VzJD" "--s3-secret-access-key=******" "--s3-endpoint=http://oss-cn-hangzhou-internal.aliyuncs.com" "--no-check-certificate" "--retries=3" "--retries-sleep=5s" "--stats=60s" "--transfers=10" "--checkers=1" "--log-level=DEBUG" "--log-file=backup_2019-10-08-14:10:46_auto-builder.log" "-P"]
2019/10/08 14:10:46 DEBUG : Using config file from "/opt/alibabacloud/abr/conf/rclone.conf"
2019/10/08 15:13:58 DEBUG : ISO/000020ecb2403b22f01c2df117cf6d72bc390ea4: Size and modification time the same (differ by 0s, within tolerance 1ns)
2019/10/08 15:13:58 DEBUG : ISO/000020ecb2403b22f01c2df117cf6d72bc390ea4: Unchanged skipping
2019/10/08 15:13:58 DEBUG : ISO/000045aa28178782c394d0485bc79eb08087d535: Size and modification time the same (differ by 0s, within tolerance 1ns)
2019/10/08 15:13:58 DEBUG : ISO/000045aa28178782c394d0485bc79eb08087d535: Unchanged skipping
...
2019/10/08 18:40:44 DEBUG : SGW/cloud.cfg: Size and modification time the same (differ by 0s, within tolerance 1ns)
2019/10/08 18:40:44 DEBUG : SGW/cloud.cfg: Unchanged skipping
2019/10/08 18:40:44 DEBUG : SGW/getinfo.sh: Size and modification time the same (differ by 0s, within tolerance 1ns)
2019/10/08 18:40:44 DEBUG : SGW/getinfo.sh: Unchanged skipping

ncw · October 9, 2019, 7:32am

Check this out from the FAQ - do you have a directory with millions of entries?

Rclone is using too much memory or appears to have a memory leak

Rclone is written in Go which uses a garbage collector. The default settings for the garbage collector mean that it runs when the heap size has doubled.

However it is possible to tune the garbage collector to use less memory by setting GOGC to a lower value, say export GOGC=20 . This will make the garbage collector work harder, reducing memory size at the expense of CPU usage.

The most common cause of rclone using lots of memory is a single directory with thousands or millions of files in. Rclone has to load this entirely into memory as rclone objects. Each Rclone object takes 0.5k-1k of memory.

ncw · October 9, 2019, 8:22am

Sorry we've talked about this before haven't we

Why is rclone hanging?

Does it stop printing stats messages every 60s?

If it has, then the best thing to do is to kill it with SIGQUIT or press CTRL-\

This will dump a very long list of running goroutines and it is usually possible to work out what rclone is doing at that point.

If you get a backtrace with SIGQUIT/CTRL-\ post it here and I'll try to work out what is going on.

However if rclone is running low on memory then it might just be swapping which will make it run very slowly. You can check this with vmstat 5 - look at the si and so columns

$ vmstat 5
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 0  0 999376 1743508 134772 2900692    0    0     0   125  767 2424  3  1 96  0  0
 0  0 999376 1725640 134788 2906100    0    0     0   226  830 3696  6  2 92  0  0

greencacti · October 9, 2019, 11:16am

Here is the output of vmstat:
[root@iZbp1bq4jlql6jptqhyy87Z rclone]# vmstat 5
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
1 0 0 51311460 139608 8837728 0 0 1 2 6 8 5 1 93 2 0
0 0 0 51305872 139608 8843968 0 0 0 7 2795 2367 0 1 99 0 0
0 0 0 51298380 139612 8850424 0 0 0 41 2779 2369 0 1 99 0 0
0 0 0 51293344 139612 8856624 0 0 0 10 3640 2281 13 1 86 0 0
0 0 0 51286848 139612 8863124 0 0 0 10 2752 2323 0 1 99 0 0

Here is the trace:
SIGQUIT: quit
PC=0x45ea31 m=0 sigcode=0

goroutine 0 [idle]:
runtime.futex(0x246bd48, 0x80, 0x0, 0x0, 0x0, 0xc006748800, 0x0, 0x0, 0x7ffeefb4a958, 0x40aa01, ...)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/runtime/sys_linux_amd64.s:535 +0x21
runtime.futexsleep(0x246bd48, 0x0, 0xffffffffffffffff)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/runtime/os_linux.go:46 +0x4b
runtime.notesleep(0x246bd48)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/runtime/lock_futex.go:151 +0xa1
runtime.stopm()
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/runtime/proc.go:1936 +0xc1
runtime.findrunnable(0xc00004a500, 0x0)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/runtime/proc.go:2399 +0x54a
runtime.schedule()
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/runtime/proc.go:2525 +0x21c
runtime.park_m(0xc000001200)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/runtime/proc.go:2605 +0xa1
runtime.mcall(0x0)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/runtime/asm_amd64.s:299 +0x5b

goroutine 1 [semacquire, 435 minutes]:
sync.runtime_Semacquire(0xc000141368)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/runtime/sema.go:56 +0x39
sync.(*WaitGroup).Wait(0xc000141360)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/sync/waitgroup.go:130 +0x65
github.com/rclone/rclone/fs/march.(*March).Run(0xc000144b00, 0xc000144b00, 0x1884d00)
/home/travis/gopath/src/github.com/rclone/rclone/fs/march/march.go:194 +0x2fb
github.com/rclone/rclone/fs/sync.(*syncCopyMove).run(0xc000422a80, 0xc000040080, 0x188e7e0)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:671 +0x204
github.com/rclone/rclone/fs/sync.runSyncCopyMove(0x1879e60, 0xc000040080, 0x188e7e0, 0xc000144a80, 0x188efe0, 0xc00043e420, 0xc000000003, 0xc000141310, 0xc0000a8720)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:889 +0x278
github.com/rclone/rclone/fs/sync.Sync(...)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:894
github.com/rclone/rclone/cmd/sync.glob..func1.1(0xc00000d8a0, 0x202b183200412e84)
/home/travis/gopath/src/github.com/rclone/rclone/cmd/sync/sync.go:51 +0x92
github.com/rclone/rclone/cmd.Run(0xc000450101, 0x245e360, 0xc0003ebd38)
/home/travis/gopath/src/github.com/rclone/rclone/cmd/cmd.go:234 +0xc7
github.com/rclone/rclone/cmd/sync.glob..func1(0x245e360, 0xc000453200, 0x2, 0x10)
/home/travis/gopath/src/github.com/rclone/rclone/cmd/sync/sync.go:49 +0x129
github.com/rclone/rclone/vendor/github.com/spf13/cobra.(*Command).execute(0x245e360, 0xc000453800, 0x10, 0x10, 0x245e360, 0xc000453800)
/home/travis/gopath/src/github.com/rclone/rclone/vendor/github.com/spf13/cobra/command.go:830 +0x2ae
github.com/rclone/rclone/vendor/github.com/spf13/cobra.(*Command).ExecuteC(0x24536e0, 0x5d9d5a06, 0x246a9c0, 0xc0000a8058)
/home/travis/gopath/src/github.com/rclone/rclone/vendor/github.com/spf13/cobra/command.go:914 +0x2fc
github.com/rclone/rclone/vendor/github.com/spf13/cobra.(*Command).Execute(...)
/home/travis/gopath/src/github.com/rclone/rclone/vendor/github.com/spf13/cobra/command.go:864
github.com/rclone/rclone/cmd.Main()
/home/travis/gopath/src/github.com/rclone/rclone/cmd/cmd.go:499 +0x96
main.main()
/home/travis/gopath/src/github.com/rclone/rclone/rclone.go:13 +0x20

goroutine 17 [syscall, 435 minutes]:
os/signal.signal_recv(0x0)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/runtime/sigqueue.go:139 +0x9c
os/signal.loop()
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/os/signal/signal_unix.go:23 +0x22
created by os/signal.init.0
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/os/signal/signal_unix.go:29 +0x41

goroutine 19 [select]:
github.com/rclone/rclone/vendor/go.opencensus.io/stats/view.(*worker).start(0xc000156960)
/home/travis/gopath/src/github.com/rclone/rclone/vendor/go.opencensus.io/stats/view/worker.go:154 +0x100
created by github.com/rclone/rclone/vendor/go.opencensus.io/stats/view.init.0
/home/travis/gopath/src/github.com/rclone/rclone/vendor/go.opencensus.io/stats/view/worker.go:32 +0x57

goroutine 10 [select]:
github.com/rclone/rclone/cmd.startProgress.func3(0xc000141310, 0xc0000a8720, 0x1616bb8)
/home/travis/gopath/src/github.com/rclone/rclone/cmd/progress.go:54 +0x116
created by github.com/rclone/rclone/cmd.startProgress
/home/travis/gopath/src/github.com/rclone/rclone/cmd/progress.go:46 +0xd1

goroutine 11 [select, 286 minutes]:
github.com/rclone/rclone/fs/sync.(*pipe).Get(0xc00013c780, 0x1879e20, 0xc00013c880, 0xc02a8b5c20, 0x188f060, 0xc02ac662a0, 0x188f000, 0xc02ac662a0)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/pipe.go:62 +0xe4
github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairChecker(0xc000422a80, 0xc00013c780, 0xc00013c800, 0xc000422b40)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:213 +0xa2
created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startCheckers
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:307 +0x9a

goroutine 12 [select, 435 minutes]:
github.com/rclone/rclone/fs/sync.(*pipe).Get(0xc00013c800, 0x1879e20, 0xc00013c880, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/pipe.go:62 +0xe4
github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove(0xc000422a80, 0x1879e20, 0xc00013c880, 0xc00013c800, 0x188e7e0, 0xc000144a80, 0xc000422b58)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:289 +0xa4
created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startTransfers
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:322 +0xb1

goroutine 13 [select, 435 minutes]:
github.com/rclone/rclone/fs/sync.(*pipe).Get(0xc00013c800, 0x1879e20, 0xc00013c880, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/pipe.go:62 +0xe4
github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove(0xc000422a80, 0x1879e20, 0xc00013c880, 0xc00013c800, 0x188e7e0, 0xc000144a80, 0xc000422b58)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:289 +0xa4
created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startTransfers
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:322 +0xb1

goroutine 14 [select, 435 minutes]:
github.com/rclone/rclone/fs/sync.(*pipe).Get(0xc00013c800, 0x1879e20, 0xc00013c880, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/pipe.go:62 +0xe4
github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove(0xc000422a80, 0x1879e20, 0xc00013c880, 0xc00013c800, 0x188e7e0, 0xc000144a80, 0xc000422b58)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:289 +0xa4
created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startTransfers
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:322 +0xb1

goroutine 15 [select, 435 minutes]:
github.com/rclone/rclone/fs/sync.(*pipe).Get(0xc00013c800, 0x1879e20, 0xc00013c880, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/pipe.go:62 +0xe4
github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove(0xc000422a80, 0x1879e20, 0xc00013c880, 0xc00013c800, 0x188e7e0, 0xc000144a80, 0xc000422b58)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:289 +0xa4
created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startTransfers
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:322 +0xb1

goroutine 16 [select, 435 minutes]:
github.com/rclone/rclone/fs/sync.(*pipe).Get(0xc00013c800, 0x1879e20, 0xc00013c880, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/pipe.go:62 +0xe4
github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove(0xc000422a80, 0x1879e20, 0xc00013c880, 0xc00013c800, 0x188e7e0, 0xc000144a80, 0xc000422b58)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:289 +0xa4
created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startTransfers
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:322 +0xb1

goroutine 49 [select, 435 minutes]:
github.com/rclone/rclone/fs/sync.(*pipe).Get(0xc00013c800, 0x1879e20, 0xc00013c880, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/pipe.go:62 +0xe4
github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove(0xc000422a80, 0x1879e20, 0xc00013c880, 0xc00013c800, 0x188e7e0, 0xc000144a80, 0xc000422b58)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:289 +0xa4
created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startTransfers
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:322 +0xb1

goroutine 50 [select, 435 minutes]:
github.com/rclone/rclone/fs/sync.(*pipe).Get(0xc00013c800, 0x1879e20, 0xc00013c880, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/pipe.go:62 +0xe4
github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove(0xc000422a80, 0x1879e20, 0xc00013c880, 0xc00013c800, 0x188e7e0, 0xc000144a80, 0xc000422b58)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:289 +0xa4
created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startTransfers
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:322 +0xb1

goroutine 51 [select, 435 minutes]:
github.com/rclone/rclone/fs/sync.(*pipe).Get(0xc00013c800, 0x1879e20, 0xc00013c880, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/pipe.go:62 +0xe4
github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove(0xc000422a80, 0x1879e20, 0xc00013c880, 0xc00013c800, 0x188e7e0, 0xc000144a80, 0xc000422b58)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:289 +0xa4
created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startTransfers
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:322 +0xb1

goroutine 52 [select, 435 minutes]:
github.com/rclone/rclone/fs/sync.(*pipe).Get(0xc00013c800, 0x1879e20, 0xc00013c880, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/pipe.go:62 +0xe4
github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove(0xc000422a80, 0x1879e20, 0xc00013c880, 0xc00013c800, 0x188e7e0, 0xc000144a80, 0xc000422b58)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:289 +0xa4
created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startTransfers
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:322 +0xb1

goroutine 53 [select, 435 minutes]:
github.com/rclone/rclone/fs/sync.(*pipe).Get(0xc00013c800, 0x1879e20, 0xc00013c880, 0x0, 0x0, 0x0, 0x0, 0x0)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/pipe.go:62 +0xe4
github.com/rclone/rclone/fs/sync.(*syncCopyMove).pairCopyOrMove(0xc000422a80, 0x1879e20, 0xc00013c880, 0xc00013c800, 0x188e7e0, 0xc000144a80, 0xc000422b58)
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:289 +0xa4
created by github.com/rclone/rclone/fs/sync.(*syncCopyMove).startTransfers
/home/travis/gopath/src/github.com/rclone/rclone/fs/sync/sync.go:322 +0xb1

goroutine 54 [semacquire, 288 minutes]:
sync.runtime_Semacquire(0xc028964178)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/runtime/sema.go:56 +0x39
sync.(*WaitGroup).Wait(0xc028964170)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/sync/waitgroup.go:130 +0x65
github.com/rclone/rclone/fs/march.(*March).processJob(0xc000144b00, 0xc00014e998, 0x7, 0xc0000b4222, 0x7, 0x7ffffffd, 0x7ffffffd, 0x0, 0xc02a1e3ea0, 0x3, ...)
/home/travis/gopath/src/github.com/rclone/rclone/fs/march/march.go:388 +0xec
github.com/rclone/rclone/fs/march.(*March).Run.func1(0xc000141350, 0xc000144b00, 0xc00012d080, 0xc000141340, 0xc00007faa0, 0xc000141348, 0xc000141360)
/home/travis/gopath/src/github.com/rclone/rclone/fs/march/march.go:148 +0x1fd
created by github.com/rclone/rclone/fs/march.(*March).Run
/home/travis/gopath/src/github.com/rclone/rclone/fs/march/march.go:138 +0x1d1

goroutine 55 [chan receive, 435 minutes]:
github.com/rclone/rclone/fs/march.(*March).Run.func2(0xc000144b00, 0xc00012d080, 0xc000141360)
/home/travis/gopath/src/github.com/rclone/rclone/fs/march/march.go:189 +0x4e
created by github.com/rclone/rclone/fs/march.(*March).Run
/home/travis/gopath/src/github.com/rclone/rclone/fs/march/march.go:187 +0x2ea

goroutine 98 [select, 288 minutes]:
github.com/rclone/rclone/fs/march.(*March).Run.func1.1(0xc000191100, 0x17, 0x20, 0xc000144b00, 0xc000141360, 0xc00012d080)
/home/travis/gopath/src/github.com/rclone/rclone/fs/march/march.go:164 +0x1a2
created by github.com/rclone/rclone/fs/march.(*March).Run.func1
/home/travis/gopath/src/github.com/rclone/rclone/fs/march/march.go:160 +0x2b0

goroutine 461799 [syscall]:
syscall.Syscall(0xd9, 0x9, 0xc02ae36000, 0x2000, 0x42c62f, 0xc01013c030, 0xc00038eac8)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/syscall/asm_linux_amd64.s:18 +0x5
syscall.Getdents(0x9, 0xc02ae36000, 0x2000, 0x2000, 0x12df520, 0xc02ae37fc0, 0xc077c22000)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/syscall/zsyscall_linux_amd64.go:465 +0x5a
syscall.ReadDirent(...)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/syscall/syscall_linux.go:863
internal/poll.(*FD).ReadDirent(0xc02a8b5c80, 0xc02ae36000, 0x2000, 0x2000, 0x0, 0x0, 0x0)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/internal/poll/fd_unix.go:416 +0xb6
os.(*File).readdirnames(0xc02ab09c38, 0x381, 0xc077b54d80, 0x7fccbdec00e8, 0xc077b54d80, 0x18858a0, 0xc07e407790)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/os/dir_unix.go:50 +0x1c1
os.(*File).Readdirnames(...)
/home/travis/.gimme/versions/go1.12.9.linux.amd64/src/os/dir.go:45
github.com/rclone/rclone/backend/local.(*Fs).List(0xc000144a80, 0x1879e20, 0xc00013c880, 0xc0000b4222, 0x7, 0xc0e4000000, 0xf9c00, 0x10f200, 0x0, 0x0)
/home/travis/gopath/src/github.com/rclone/rclone/backend/local/local.go:388 +0x11d9
github.com/rclone/rclone/fs/list.DirSorted(0x1879e20, 0xc00013c880, 0x188e7e0, 0xc000144a80, 0x405400, 0xc0000b4222, 0x7, 0x42c62f, 0xc000000008, 0xc0230bd200, ...)
/home/travis/gopath/src/github.com/rclone/rclone/fs/list/list.go:24 +0x7d
github.com/rclone/rclone/fs/march.(*March).makeListDir.func1(0xc0000b4222, 0x7, 0xc028964170, 0x0, 0x0, 0xc00077d7a0, 0x404fa5)
/home/travis/gopath/src/github.com/rclone/rclone/fs/march/march.go:76 +0x68
github.com/rclone/rclone/fs/march.(*March).processJob.func2(0xc028964170, 0xc000144b00, 0xc00014e998, 0x7, 0xc0000b4222, 0x7, 0x7ffffffd, 0x7ffffffd, 0x0, 0xc02a75f6a0, ...)
/home/travis/gopath/src/github.com/rclone/rclone/fs/march/march.go:383 +0x6c
created by github.com/rclone/rclone/fs/march.(*March).processJob
/home/travis/gopath/src/github.com/rclone/rclone/fs/march/march.go:381 +0x1216

goroutine 461797 [select, 288 minutes]:
github.com/rclone/rclone/fs/march.(*March).Run.func1.1(0xc02a1e3ea0, 0x3, 0x4, 0xc000144b00, 0xc000141360, 0xc00012d080)
/home/travis/gopath/src/github.com/rclone/rclone/fs/march/march.go:164 +0x1a2
created by github.com/rclone/rclone/fs/march.(*March).Run.func1
/home/travis/gopath/src/github.com/rclone/rclone/fs/march/march.go:160 +0x2b0

rax 0xca
rbx 0x246bc00
rcx 0xffffffffffffffff
rdx 0x0
rdi 0x246bd48
rsi 0x80
rbp 0x7ffeefb4a920
rsp 0x7ffeefb4a8d8
r8 0x0
r9 0x0
r10 0x0
r11 0x286
r12 0x77
r13 0x23f3660
r14 0x0
r15 0x0
rip 0x45ea31
rflags 0x286
cs 0x33
fs 0x0
gs 0x0

ncw · October 9, 2019, 11:38am

I ran panic parse on that to condense it down a bit.

It appears to be reading directory entries from local disk...

1: idle
    runtime sys_linux_amd64.s:535       futex(#1, 0x80, 0, 0, 0, 0xc006748800, 0, 0, 0x7ffeefb4a958, 0x40aa01, ...)
    runtime os_linux.go:46              futexsleep(*uint32(#1), 0, 18446744073709551615)
    runtime lock_futex.go:151           notesleep(*note(#1))
    runtime proc.go:1936                stopm()
    runtime proc.go:2399                findrunnable(0xc00004a500, 0x0)
    runtime proc.go:2525                schedule()
    runtime proc.go:2605                park_m(*g(0xc000001200))
    runtime asm_amd64.s:299             mcall(0)
1: semacquire [435 minutes]
    sync    sema.go:56                  runtime_Semacquire(*uint32(#34))
    sync    waitgroup.go:130            (*WaitGroup).Wait(*WaitGroup(#33))
    march   march.go:194                (*March).Run(*March(#36), #36, #6)
    sync    sync.go:671                 (*syncCopyMove).run(*syncCopyMove(#42), #20, #8)
    sync    sync.go:889                 runSyncCopyMove(Context(#5), Fs(#8), Fs(#9), DeleteMode(#17), bool(#23))
    sync    sync.go:894                 Sync(...)
    sync    sync.go:51                  glob..func1.1(#19, #67)
    cmd     cmd.go:234                  Run(bool(#46), bool(#41))
    sync    sync.go:49                  glob..func1(#13, #47, 0x2, 0x10)
    cobra   command.go:830              (*Command).execute(*Command(#13), []string(#48 len=16 cap=16), #13, #48)
    cobra   command.go:914              (*Command).ExecuteC(*Command(#12), #15, #14, #22)
    cobra   command.go:864              (*Command).Execute(...)
    cmd     cmd.go:499                  Main()
    main    rclone.go:13                main()
1: syscall [Created by march.(*March).processJob @ march.go:381]
    syscall asm_linux_amd64.s:18        Syscall(0xd9, 0x9, #60, 0x2000, 0x42c62f, #50, #40)
    syscall zsyscall_linux_amd64.go:465 Getdents(9, []byte(#60 len=8192 cap=8192), #2, #61, #63)
    syscall syscall_linux.go:863        ReadDirent(...)
    poll    fd_unix.go:416              (*FD).ReadDirent(*FD(#57), []byte(#60 len=8192 cap=8192), 0x0, 0x0, 0x0)
    os      dir_unix.go:50              (*File).readdirnames(*File(#58), 897, #62, #66, #62, #7, #64)
    os      dir.go:45                   (*File).Readdirnames(...)
    local   local.go:388                (*Fs).List(*Fs(#35), Context(#4), string(#24, len=7), #65, 0xf9c00, 0x10f200, 0x0, 0x0)
    list    list.go:24                  DirSorted(Context(#4), Fs(#8), bool(0x405400), string(0x7, len=4376111), #18, #51, ...)
    march   march.go:76                 (*March).makeListDir.func1(*March(#24), Fs(0x7), bool(0x0), #49, 0x404fa5)
    march   march.go:383                (*March).processJob.func2(#52, #36, #37, 0x7, #24, 0x7, #16, #16, 0, #55, ...)
1: select [286 minutes] [Created by sync.(*syncCopyMove).startCheckers @ sync.go:307]
    sync    pipe.go:62                  (*pipe).Get(*pipe(#26), Context(#4), #56, #11, #59, #10, #59)
    sync    sync.go:213                 (*syncCopyMove).pairChecker(#42, #26, #27, #43)
10: select [435 minutes] [Created by sync.(*syncCopyMove).startTransfers @ sync.go:322]
    sync    pipe.go:62                  (*pipe).Get(*pipe(#27), Context(#4), 0x0, 0x0, 0x0, 0x0, 0x0)
    sync    sync.go:289                 (*syncCopyMove).pairCopyOrMove(#42, #4, #28, #27, #8, #35, #44)
1: semacquire [288 minutes] [Created by march.(*March).Run @ march.go:138]
    sync    sema.go:56                  runtime_Semacquire(*uint32(#53))
    sync    waitgroup.go:130            (*WaitGroup).Wait(*WaitGroup(#52))
    march   march.go:388                (*March).processJob(*March(#36), listDirJob(#37), #24, 0x7, #16, #16, 0x0, #54, 0x3, ...)
    march   march.go:148                (*March).Run.func1(#32, #36, #25, #30, #21, #31, #33)
1: chan receive [435 minutes] [Created by march.(*March).Run @ march.go:187]
    march   march.go:189                (*March).Run.func2(#36, #25, #33)
2: select [288 minutes] [Created by march.(*March).Run.func1 @ march.go:160]
    march   march.go:164                (*March).Run.func1.1(*, *, *, #36, #33, #25)
1: select [Created by view.init.0 @ worker.go:32]
    view    worker.go:154               (*worker).start(#38)
1: select [Created by cmd.startProgress @ progress.go:46]
    cmd     progress.go:54              startProgress.func3(#29, #23, #3)
1: syscall [435 minutes] [Created by signal.init.0 @ signal_unix.go:29]
    signal  sigqueue.go:139             signal_recv(0x0)
    signal  signal_unix.go:23           loop()

system · January 7, 2020, 11:38am

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.