Mounted with vfs-cache-mode writes randomly hangs

JuRaSSiCBoY · October 27, 2022, 1:33pm

What is the problem you are having with rclone?

I've got a Google Drive remote mounted with "vfs-cache-mode writes" to be able to unzip a bunch of files (locally cached) and then auto-upload them to the GDrive folder. So far everything worked perfectly but after upgrading from rclone 1.58 to rclone version 1.59.2 seems like something is not working as it should. The mounted remote "hangs" randomly (or so it seems) and if I try to list files of the remote via shell then the shell hangs too and I can't kill it with "Ctrl-C", "Ctrl-X" or any typical combination.

If I restart rclone everything works fine for a while but fails again at some point (hangs in different files or at different times) when I resend the unzip command.

Run the command 'rclone version' and share the full output of the command.

rclone v1.59.2

os/version: qts 5.0.1 (20221001) (64 bit)
os/kernel: 5.10.60-qnap (x86_64)
os/type: linux
os/arch: amd64
go/version: go1.18.6
go/linking: static
go/tags: none

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

Google Drive.

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

Mount command:

rclone mount rclonecrypt:Downloads /share/homes/rclone/Downloads --config=/share/homes/rclone/.config/rclone/rclone.conf --allow-other --allow-non-empty --bwlimit 8M --dir-cache-time 1000h --umask 002 --vfs-cache-mode writes --vfs-cache-max-age 0h0m0s --cache-dir /share/homes/rclone/cacherclone --log-level DEBUG --log-file /share/homes/rclone/logs/rclonelog --poll-interval 15s --user-agent my_rclones --rc-addr=localhost:5575

Unzip command launched from /share/homes/rclone/Downloads:

 find . -type f -name "B*.zip" -execdir 7z x {} \; >> /share/homes/rclone/UnzipLog

The rclone config contents with secrets removed.

[rclone]
type = drive
client_id = myclient_ID.apps.googleusercontent.com
client_secret = myclient_secret
token = {"access_token":"Mytoken"}
team_drive =

[rclonecrypt]
type = crypt
remote = rclone:rclonefoldertoencrypt
filename_encryption = standard
directory_name_encryption = true
password = my_password1
password2 = my_password2

A log from the command with the `-vv` flag

2022/10/27 11:09:47 DEBUG : sfo2mrfr42m3kmhuvq3km1hhuo/ja6dmo7qeh12ge03m8o88p854g/n08v7egfs7ld75rbsblc3363ivl3d6h6kn10md45jisa3hihe19172o0369c9d2mqo250lipnvi9pej4a8ohlvt87lf403g7cro364o: Sending chunk 1920991232 length 8388608
2022/10/27 11:09:48 DEBUG : sfo2mrfr42m3kmhuvq3km1hhuo/ja6dmo7qeh12ge03m8o88p854g/n08v7egfs7ld75rbsblc3363ivl3d6h6kn10md45jisa3hihe19172o0369c9d2mqo250lipnvi9pej4a8ohlvt87lf403g7cro364o: Sending chunk 1929379840 length 8388608
2022/10/27 11:09:49 DEBUG : sfo2mrfr42m3kmhuvq3km1hhuo/ja6dmo7qeh12ge03m8o88p854g/n08v7egfs7ld75rbsblc3363ivl3d6h6kn10md45jisa3hihe19172o0369c9d2mqo250lipnvi9pej4a8ohlvt87lf403g7cro364o: Sending chunk 1937768448 length 8388608
2022/10/27 11:09:50 DEBUG : /: Attr:
2022/10/27 11:09:50 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2022/10/27 11:09:50 DEBUG : sfo2mrfr42m3kmhuvq3km1hhuo/ja6dmo7qeh12ge03m8o88p854g/n08v7egfs7ld75rbsblc3363ivl3d6h6kn10md45jisa3hihe19172o0369c9d2mqo250lipnvi9pej4a8ohlvt87lf403g7cro364o: Sending chunk 1946157056 length 8388608
2022/10/27 11:09:51 DEBUG : sfo2mrfr42m3kmhuvq3km1hhuo/ja6dmo7qeh12ge03m8o88p854g/n08v7egfs7ld75rbsblc3363ivl3d6h6kn10md45jisa3hihe19172o0369c9d2mqo250lipnvi9pej4a8ohlvt87lf403g7cro364o: Sending chunk 1954545664 length 8388608
2022/10/27 11:09:52 DEBUG : sfo2mrfr42m3kmhuvq3km1hhuo/ja6dmo7qeh12ge03m8o88p854g/n08v7egfs7ld75rbsblc3363ivl3d6h6kn10md45jisa3hihe19172o0369c9d2mqo250lipnvi9pej4a8ohlvt87lf403g7cro364o: Sending chunk 1962934272 length 8388608
2022/10/27 11:09:53 DEBUG : sfo2mrfr42m3kmhuvq3km1hhuo/ja6dmo7qeh12ge03m8o88p854g/n08v7egfs7ld75rbsblc3363ivl3d6h6kn10md45jisa3hihe19172o0369c9d2mqo250lipnvi9pej4a8ohlvt87lf403g7cro364o: Sending chunk 1971322880 length 8388608
2022/10/27 11:09:54 DEBUG : sfo2mrfr42m3kmhuvq3km1hhuo/ja6dmo7qeh12ge03m8o88p854g/n08v7egfs7ld75rbsblc3363ivl3d6h6kn10md45jisa3hihe19172o0369c9d2mqo250lipnvi9pej4a8ohlvt87lf403g7cro364o: Sending chunk 1979711488 length 8388608
2022/10/27 11:09:55 DEBUG : sfo2mrfr42m3kmhuvq3km1hhuo/ja6dmo7qeh12ge03m8o88p854g/n08v7egfs7ld75rbsblc3363ivl3d6h6kn10md45jisa3hihe19172o0369c9d2mqo250lipnvi9pej4a8ohlvt87lf403g7cro364o: Sending chunk 1988100096 length 8388608
2022/10/27 11:09:56 DEBUG : sfo2mrfr42m3kmhuvq3km1hhuo/ja6dmo7qeh12ge03m8o88p854g/n08v7egfs7ld75rbsblc3363ivl3d6h6kn10md45jisa3hihe19172o0369c9d2mqo250lipnvi9pej4a8ohlvt87lf403g7cro364o: Sending chunk 1996488704 length 8388608
2022/10/27 11:09:57 DEBUG : sfo2mrfr42m3kmhuvq3km1hhuo/ja6dmo7qeh12ge03m8o88p854g/n08v7egfs7ld75rbsblc3363ivl3d6h6kn10md45jisa3hihe19172o0369c9d2mqo250lipnvi9pej4a8ohlvt87lf403g7cro364o: Sending chunk 2004877312 length 8388608
2022/10/27 11:09:58 DEBUG : sfo2mrfr42m3kmhuvq3km1hhuo/ja6dmo7qeh12ge03m8o88p854g/n08v7egfs7ld75rbsblc3363ivl3d6h6kn10md45jisa3hihe19172o0369c9d2mqo250lipnvi9pej4a8ohlvt87lf403g7cro364o: Sending chunk 2013265920 length 8388608
2022/10/27 11:09:59 DEBUG : sfo2mrfr42m3kmhuvq3km1hhuo/ja6dmo7qeh12ge03m8o88p854g/n08v7egfs7ld75rbsblc3363ivl3d6h6kn10md45jisa3hihe19172o0369c9d2mqo250lipnvi9pej4a8ohlvt87lf403g7cro364o: Sending chunk 2021654528 length 8388608
2022/10/27 11:10:00 DEBUG : sfo2mrfr42m3kmhuvq3km1hhuo/ja6dmo7qeh12ge03m8o88p854g/n08v7egfs7ld75rbsblc3363ivl3d6h6kn10md45jisa3hihe19172o0369c9d2mqo250lipnvi9pej4a8ohlvt87lf403g7cro364o: Sending chunk 2030043136 length 1446160
2022/10/27 11:10:01 DEBUG : Folder 2/Subfolder/Biker.iso: md5 = f2829bd38060da0582986101ba874d13 OK
2022/10/27 11:10:01 INFO  : Folder 2/Subfolder/Biker.iso: Copied (new)
2022/10/27 11:10:01 DEBUG : Folder 2/Subfolder/Biker.iso: vfs cache: fingerprint now "2030993408,2016-03-23 23:21:30 +0000 UTC"
2022/10/27 11:10:01 DEBUG : Folder 2/Subfolder/Biker.iso: vfs cache: writeback object to VFS layer
2022/10/27 11:10:01 DEBUG : Folder 2/Subfolder/Biker.iso: Not setting pending mod time 2016-03-24 00:21:30 +0100 CET as it is already set
2022/10/27 11:17:33 DEBUG : /: Lookup: name=".qsync"
2022/10/27 11:17:33 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2022/10/27 11:19:50 DEBUG : /: Attr:
2022/10/27 11:19:50 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2022/10/27 11:29:50 DEBUG : /: Attr:
2022/10/27 11:29:50 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2022/10/27 11:39:50 DEBUG : /: Attr:
2022/10/27 11:39:50 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2022/10/27 11:49:50 DEBUG : /: Attr:
2022/10/27 11:49:50 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2022/10/27 11:59:51 DEBUG : /: Attr:
2022/10/27 11:59:51 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>

Then rclone stop showing logs and the "UnzipLog" generated by my unzip command too. Remote seems to hang.

I've updated the QTS OS before the rclone update, so maybe it's something related to QTS/qsync?

2022/10/27 11:17:33 DEBUG : /: Lookup: name=".qsync" <-- it seems that the hang comes after this.

Thank you very much in advance!

ncw · October 27, 2022, 4:38pm

First try 1.60

If it still has the problem, when it hangs

kill -QUIT rclone-pid

And collect the backtrace from rclone and paste it here.

JuRaSSiCBoY · October 28, 2022, 11:32am

Thank you! I didn't realize that the latest version is on 1.60. I'll wait until QNAP Club repository updates the version.

JuRaSSiCBoY · November 2, 2022, 9:48am

Still having the same problem with v1.60.0

Here's the backtrace (or so I think), hope it means something to you. Thank you very much! please let me know if you need anything else:

2022/10/28 04:32:20 DEBUG : Folder 2/Subfolder/Liverpool.iso(0xc003657880): >_writeAt: n=32768, err=<nil>

SIGQUIT: quit
PC=0x470561 m=0 sigcode=0

goroutine 0 [idle]:
runtime.futex()
	runtime/sys_linux_amd64.s:559 +0x21 fp=0x7fff2e445880 sp=0x7fff2e445878 pc=0x470561
runtime.futexsleep(0x58296?, 0x31df7e0?, 0xc000065400?)
	runtime/os_linux.go:69 +0x36 fp=0x7fff2e4458d0 sp=0x7fff2e445880 pc=0x4360b6
runtime.notesleep(0x31df928)
	runtime/lock_futex.go:160 +0x87 fp=0x7fff2e445908 sp=0x7fff2e4458d0 pc=0x40c0c7
runtime.mPark()
	runtime/proc.go:1457 +0x25 fp=0x7fff2e445928 sp=0x7fff2e445908 pc=0x43f305
runtime.stoplockedm()
	runtime/proc.go:2440 +0x65 fp=0x7fff2e445978 sp=0x7fff2e445928 pc=0x440ee5
runtime.schedule()
	runtime/proc.go:3185 +0x3d fp=0x7fff2e4459b0 sp=0x7fff2e445978 pc=0x442bbd
runtime.park_m(0xc000102ea0?)
	runtime/proc.go:3355 +0x14d fp=0x7fff2e4459e0 sp=0x7fff2e4459b0 pc=0x44316d
runtime.mcall()
	runtime/asm_amd64.s:448 +0x43 fp=0x7fff2e4459f0 sp=0x7fff2e4459e0 pc=0x46c563

goroutine 1 [select, 989 minutes]:
runtime.gopark(0xc00067dc78?, 0x2?, 0x1?, 0x30?, 0xc00067dc04?)
	runtime/proc.go:363 +0xd6 fp=0xc00082ba80 sp=0xc00082ba60 pc=0x43c976
runtime.selectgo(0xc00082bc78, 0xc00067dc00, 0x1?, 0x0, 0xc0004d1290?, 0x1)
	runtime/select.go:328 +0x7bc fp=0xc00082bbc0 sp=0xc00082ba80 pc=0x44c83c
github.com/rclone/rclone/cmd/mountlib.(*MountPoint).Wait(0xc000295080)
	github.com/rclone/rclone/cmd/mountlib/mount.go:299 +0x27c fp=0xc00082bcb0 sp=0xc00082bbc0 pc=0x17554fc
github.com/rclone/rclone/cmd/mountlib.NewMountCommand.func1(0xc00019db80?, {0xc000102b60?, 0x2, 0x1a?})
	github.com/rclone/rclone/cmd/mountlib/mount.go:188 +0x2d8 fp=0xc00082bd80 sp=0xc00082bcb0 pc=0x1754ab8
github.com/spf13/cobra.(*Command).execute(0xc00019db80, {0xc0001029c0, 0x1a, 0x1a})
	github.com/spf13/cobra@v1.5.0/command.go:876 +0x67b fp=0xc00082be58 sp=0xc00082bd80 pc=0x16b089b
github.com/spf13/cobra.(*Command).ExecuteC(0x31bbc00)
	github.com/spf13/cobra@v1.5.0/command.go:990 +0x3bd fp=0xc00082bf10 sp=0xc00082be58 pc=0x16b0f3d
github.com/spf13/cobra.(*Command).Execute(...)
	github.com/spf13/cobra@v1.5.0/command.go:918
github.com/rclone/rclone/cmd.Main()
	github.com/rclone/rclone/cmd/cmd.go:559 +0x76 fp=0xc00082bf70 sp=0xc00082bf10 pc=0x16daa36
main.main()
	github.com/rclone/rclone/rclone.go:14 +0x17 fp=0xc00082bf80 sp=0xc00082bf70 pc=0x18b73f7
runtime.main()
	runtime/proc.go:250 +0x212 fp=0xc00082bfe0 sp=0xc00082bf80 pc=0x43c5b2
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc00082bfe8 sp=0xc00082bfe0 pc=0x46e661

goroutine 2 [force gc (idle), 2 minutes]:
runtime.gopark(0x17e5e6e368e5a?, 0x0?, 0x0?, 0x0?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc00007cfb0 sp=0xc00007cf90 pc=0x43c976
runtime.goparkunlock(...)
	runtime/proc.go:369
runtime.forcegchelper()
	runtime/proc.go:302 +0xad fp=0xc00007cfe0 sp=0xc00007cfb0 pc=0x43c80d
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc00007cfe8 sp=0xc00007cfe0 pc=0x46e661
created by runtime.init.6
	runtime/proc.go:290 +0x25

goroutine 3 [GC sweep wait]:
runtime.gopark(0x31dda01?, 0x0?, 0x0?, 0x0?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc00007d790 sp=0xc00007d770 pc=0x43c976
runtime.goparkunlock(...)
	runtime/proc.go:369
runtime.bgsweep(0x0?)
	runtime/mgcsweep.go:297 +0xd7 fp=0xc00007d7c8 sp=0xc00007d790 pc=0x427137
runtime.gcenable.func1()
	runtime/mgc.go:178 +0x26 fp=0xc00007d7e0 sp=0xc00007d7c8 pc=0x41bda6
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc00007d7e8 sp=0xc00007d7e0 pc=0x46e661
created by runtime.gcenable
	runtime/mgc.go:178 +0x6b

goroutine 4 [GC scavenge wait]:
runtime.gopark(0x15f7164809988?, 0xa9704d?, 0x0?, 0x0?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc00007df70 sp=0xc00007df50 pc=0x43c976
runtime.goparkunlock(...)
	runtime/proc.go:369
runtime.(*scavengerState).park(0x31de680)
	runtime/mgcscavenge.go:389 +0x53 fp=0xc00007dfa0 sp=0xc00007df70 pc=0x425193
runtime.bgscavenge(0x0?)
	runtime/mgcscavenge.go:622 +0x65 fp=0xc00007dfc8 sp=0xc00007dfa0 pc=0x425785
runtime.gcenable.func2()
	runtime/mgc.go:179 +0x26 fp=0xc00007dfe0 sp=0xc00007dfc8 pc=0x41bd46
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc00007dfe8 sp=0xc00007dfe0 pc=0x46e661
created by runtime.gcenable
	runtime/mgc.go:179 +0xaa

goroutine 5 [finalizer wait, 986 minutes]:
runtime.gopark(0x0?, 0x1f840a8?, 0x20?, 0xe0?, 0x2000000020?)
	runtime/proc.go:363 +0xd6 fp=0xc00007c628 sp=0xc00007c608 pc=0x43c976
runtime.goparkunlock(...)
	runtime/proc.go:369
runtime.runfinq()
	runtime/mfinal.go:180 +0x10f fp=0xc00007c7e0 sp=0xc00007c628 pc=0x41aeaf
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc00007c7e8 sp=0xc00007c7e0 pc=0x46e661
created by runtime.createfing
	runtime/mfinal.go:157 +0x45

goroutine 17 [select]:
runtime.gopark(0xc0000aef88?, 0x3?, 0x9?, 0x18?, 0xc0000aef72?)
	runtime/proc.go:363 +0xd6 fp=0xc0000aedf8 sp=0xc0000aedd8 pc=0x43c976
runtime.selectgo(0xc0000aef88, 0xc0000aef6c, 0x0?, 0x0, 0x3?, 0x1)
	runtime/select.go:328 +0x7bc fp=0xc0000aef38 sp=0xc0000aedf8 pc=0x44c83c
go.opencensus.io/stats/view.(*worker).start(0xc000149300)
	go.opencensus.io@v0.23.0/stats/view/worker.go:276 +0xad fp=0xc0000aefc8 sp=0xc0000aef38 pc=0xcc748d
go.opencensus.io/stats/view.init.0.func1()
	go.opencensus.io@v0.23.0/stats/view/worker.go:34 +0x26 fp=0xc0000aefe0 sp=0xc0000aefc8 pc=0xcc6706
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc0000aefe8 sp=0xc0000aefe0 pc=0x46e661
created by go.opencensus.io/stats/view.init.0
	go.opencensus.io@v0.23.0/stats/view/worker.go:34 +0x8d

goroutine 8 [GC worker (idle), 581 minutes]:
runtime.gopark(0x15eac42bbdf96?, 0x3?, 0xa6?, 0x30?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc000078750 sp=0xc000078730 pc=0x43c976
runtime.gcBgMarkWorker()
	runtime/mgc.go:1235 +0xf1 fp=0xc0000787e0 sp=0xc000078750 pc=0x41def1
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc0000787e8 sp=0xc0000787e0 pc=0x46e661
created by runtime.gcBgMarkStartWorkers
	runtime/mgc.go:1159 +0x25

goroutine 9 [GC worker (idle), 2 minutes]:
runtime.gopark(0x17e5e6e8c7e31?, 0x3?, 0x17?, 0x4e?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc00007ef50 sp=0xc00007ef30 pc=0x43c976
runtime.gcBgMarkWorker()
	runtime/mgc.go:1235 +0xf1 fp=0xc00007efe0 sp=0xc00007ef50 pc=0x41def1
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc00007efe8 sp=0xc00007efe0 pc=0x46e661
created by runtime.gcBgMarkStartWorkers
	runtime/mgc.go:1159 +0x25

goroutine 33 [GC worker (idle), 260 minutes]:
runtime.gopark(0x170439cdfae59?, 0x3?, 0xf4?, 0x97?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc00007e750 sp=0xc00007e730 pc=0x43c976
runtime.gcBgMarkWorker()
	runtime/mgc.go:1235 +0xf1 fp=0xc00007e7e0 sp=0xc00007e750 pc=0x41def1
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc00007e7e8 sp=0xc00007e7e0 pc=0x46e661
created by runtime.gcBgMarkStartWorkers
	runtime/mgc.go:1159 +0x25

goroutine 10 [GC worker (idle), 581 minutes]:
runtime.gopark(0x15eac42bbdcf6?, 0x1?, 0xde?, 0xf?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc00007f750 sp=0xc00007f730 pc=0x43c976
runtime.gcBgMarkWorker()
	runtime/mgc.go:1235 +0xf1 fp=0xc00007f7e0 sp=0xc00007f750 pc=0x41def1
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc00007f7e8 sp=0xc00007f7e0 pc=0x46e661
created by runtime.gcBgMarkStartWorkers
	runtime/mgc.go:1159 +0x25

goroutine 34 [GC worker (idle), 581 minutes]:
runtime.gopark(0x15eac42bbdf4c?, 0x3?, 0x60?, 0x7f?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc000584750 sp=0xc000584730 pc=0x43c976
runtime.gcBgMarkWorker()
	runtime/mgc.go:1235 +0xf1 fp=0xc0005847e0 sp=0xc000584750 pc=0x41def1
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc0005847e8 sp=0xc0005847e0 pc=0x46e661
created by runtime.gcBgMarkStartWorkers
	runtime/mgc.go:1159 +0x25

goroutine 11 [GC worker (idle), 2 minutes]:
runtime.gopark(0x17e5e6e8ba6bd?, 0x1?, 0xb4?, 0x2?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc00007ff50 sp=0xc00007ff30 pc=0x43c976
runtime.gcBgMarkWorker()
	runtime/mgc.go:1235 +0xf1 fp=0xc00007ffe0 sp=0xc00007ff50 pc=0x41def1
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc00007ffe8 sp=0xc00007ffe0 pc=0x46e661
created by runtime.gcBgMarkStartWorkers
	runtime/mgc.go:1159 +0x25

goroutine 35 [GC worker (idle), 581 minutes]:
runtime.gopark(0x32114c0?, 0x3?, 0x40?, 0x17?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc0000b2f50 sp=0xc0000b2f30 pc=0x43c976
runtime.gcBgMarkWorker()
	runtime/mgc.go:1235 +0xf1 fp=0xc0000b2fe0 sp=0xc0000b2f50 pc=0x41def1
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc0000b2fe8 sp=0xc0000b2fe0 pc=0x46e661
created by runtime.gcBgMarkStartWorkers
	runtime/mgc.go:1159 +0x25

goroutine 12 [GC worker (idle), 581 minutes]:
runtime.gopark(0x15eac42bbda06?, 0x3?, 0x8f?, 0x9f?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc000580750 sp=0xc000580730 pc=0x43c976
runtime.gcBgMarkWorker()
	runtime/mgc.go:1235 +0xf1 fp=0xc0005807e0 sp=0xc000580750 pc=0x41def1
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc0005807e8 sp=0xc0005807e0 pc=0x46e661
created by runtime.gcBgMarkStartWorkers
	runtime/mgc.go:1159 +0x25

goroutine 14 [select, 989 minutes, locked to thread]:
runtime.gopark(0xc000580fa8?, 0x2?, 0xce?, 0xc5?, 0xc000580fa4?)
	runtime/proc.go:363 +0xd6 fp=0xc000580e18 sp=0xc000580df8 pc=0x43c976
runtime.selectgo(0xc000580fa8, 0xc000580fa0, 0x0?, 0x0, 0x0?, 0x1)
	runtime/select.go:328 +0x7bc fp=0xc000580f58 sp=0xc000580e18 pc=0x44c83c
runtime.ensureSigM.func1()
	runtime/signal_unix.go:991 +0x1b0 fp=0xc000580fe0 sp=0xc000580f58 pc=0x450c70
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc000580fe8 sp=0xc000580fe0 pc=0x46e661
created by runtime.ensureSigM
	runtime/signal_unix.go:974 +0xbd

goroutine 23 [syscall, 989 minutes]:
runtime.notetsleepg(0x0?, 0x0?)
	runtime/lock_futex.go:236 +0x34 fp=0xc00007afa0 sp=0xc00007af68 pc=0x40c3d4
os/signal.signal_recv()
	runtime/sigqueue.go:152 +0x2f fp=0xc00007afc0 sp=0xc00007afa0 pc=0x46aaaf
os/signal.loop()
	os/signal/signal_unix.go:23 +0x19 fp=0xc00007afe0 sp=0xc00007afc0 pc=0x7a1919
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc00007afe8 sp=0xc00007afe0 pc=0x46e661
created by os/signal.Notify.func1.1
	os/signal/signal.go:151 +0x2a

goroutine 24 [chan receive, 989 minutes]:
runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc00007b690 sp=0xc00007b670 pc=0x43c976
runtime.chanrecv(0xc0007ec000, 0x0, 0x1)
	runtime/chan.go:583 +0x49b fp=0xc00007b720 sp=0xc00007b690 pc=0x406cdb
runtime.chanrecv1(0x0?, 0x0?)
	runtime/chan.go:442 +0x18 fp=0xc00007b748 sp=0xc00007b720 pc=0x4067d8
github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler.func1()
	github.com/rclone/rclone/fs/accounting/accounting_unix.go:25 +0xdb fp=0xc00007b7e0 sp=0xc00007b748 pc=0x93a91b
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc00007b7e8 sp=0xc00007b7e0 pc=0x46e661
created by github.com/rclone/rclone/fs/accounting.(*tokenBucket).startSignalHandler
	github.com/rclone/rclone/fs/accounting/accounting_unix.go:22 +0xb9

goroutine 28 [semacquire, 583 minutes]:
runtime.gopark(0x451af2?, 0x20?, 0x0?, 0x85?, 0xc005d63401?)
	runtime/proc.go:363 +0xd6 fp=0xc0010559d8 sp=0xc0010559b8 pc=0x43c976
runtime.goparkunlock(...)
	runtime/proc.go:369
runtime.semacquire1(0xc0002ce924, 0x60?, 0x3, 0x1)
	runtime/sema.go:150 +0x1fe fp=0xc001055a40 sp=0xc0010559d8 pc=0x44d8fe
sync.runtime_SemacquireMutex(0xc0018ad6e0?, 0x9e?, 0x3?)
	runtime/sema.go:77 +0x25 fp=0xc001055a70 sp=0xc001055a40 pc=0x46a465
sync.(*Mutex).lockSlow(0xc0002ce920)
	sync/mutex.go:171 +0x165 fp=0xc001055ac0 sp=0xc001055a70 pc=0x478985
sync.(*Mutex).Lock(...)
	sync/mutex.go:90
sync.(*RWMutex).Lock(0xc001ddae40?)
	sync/rwmutex.go:147 +0x36 fp=0xc001055af0 sp=0xc001055ac0 pc=0x479f76
github.com/rclone/rclone/vfs.(*Dir).invalidateDir(0xc005d5e990?, {0xc005d5e990?, 0x1e6d5c1?})
	github.com/rclone/rclone/vfs/dir.go:222 +0x5b fp=0xc001055b48 sp=0xc001055af0 pc=0x173667b
github.com/rclone/rclone/vfs.(*Dir).changeNotify(0xc001ddae40, {0xc005d5e930, 0x2b}, 0x1)
	github.com/rclone/rclone/vfs/dir.go:240 +0x215 fp=0xc001055c08 sp=0xc001055b48 pc=0x1736975
github.com/rclone/rclone/vfs.(*Dir).changeNotify-fm({0xc005d5e930?, 0xc005d57ea0?}, 0xc005dac720?)
	<autogenerated>:1 +0x37 fp=0xc001055c38 sp=0xc001055c08 pc=0x1752fd7
github.com/rclone/rclone/backend/crypt.(*Fs).ChangeNotify.func1({0xc005d57ea0, 0x6a}, 0x1)
	github.com/rclone/rclone/backend/crypt/crypt.go:783 +0x1ac fp=0xc001055cd8 sp=0xc001055c38 pc=0xabe9ec
github.com/rclone/rclone/backend/drive.(*Fs).changeNotifyRunner(0xc00029aa00, {0x2334168?, 0xc0000540a8}, 0xc001e0aa50, {0xc0009f4ad0, 0x7})
	github.com/rclone/rclone/backend/drive/drive.go:2932 +0x7f3 fp=0xc001055ee8 sp=0xc001055cd8 pc=0xd7d193
github.com/rclone/rclone/backend/drive.(*Fs).ChangeNotify.func1()
	github.com/rclone/rclone/backend/drive/drive.go:2836 +0x2c9 fp=0xc001055fe0 sp=0xc001055ee8 pc=0xd7c429
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc001055fe8 sp=0xc001055fe0 pc=0x46e661
created by github.com/rclone/rclone/backend/drive.(*Fs).ChangeNotify
	github.com/rclone/rclone/backend/drive/drive.go:2802 +0xd1

goroutine 113 [syscall, 6 minutes]:
syscall.Syscall(0x478fd2?, 0x31ac440?, 0x0?, 0x0?)
	syscall/syscall_linux.go:68 +0x27 fp=0xc000a19448 sp=0xc000a193d8 pc=0x4859a7
syscall.read(0x31ac440?, {0xc00141c000?, 0x12?, 0x20000?})
	syscall/zsyscall_linux_amd64.go:696 +0x45 fp=0xc000a19488 sp=0xc000a19448 pc=0x483525
syscall.Read(...)
	syscall/syscall_unix.go:183
bazil.org/fuse.(*Conn).ReadRequest(0xc000814de0)
	bazil.org/fuse@v0.0.0-20200524192727-fb710f7dfd05/fuse.go:580 +0xc6 fp=0xc000a19ea0 sp=0xc000a19488 pc=0x1704986
bazil.org/fuse/fs.(*Server).Serve(0xc0018b2000, {0x231f0e0?, 0xc0018ac060})
	bazil.org/fuse@v0.0.0-20200524192727-fb710f7dfd05/fs/serve.go:501 +0x3ef fp=0xc000a19f88 sp=0xc000a19ea0 pc=0x17169cf
github.com/rclone/rclone/cmd/mount.mount.func2()
	github.com/rclone/rclone/cmd/mount/mount.go:98 +0x3e fp=0xc000a19fe0 sp=0xc000a19f88 pc=0x175f6fe
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc000a19fe8 sp=0xc000a19fe0 pc=0x46e661
created by github.com/rclone/rclone/cmd/mount.mount
	github.com/rclone/rclone/cmd/mount/mount.go:97 +0x38a

goroutine 63 [chan receive, 583 minutes]:
runtime.gopark(0xc0028868d0?, 0x19f1680?, 0xe0?, 0x61?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc0015da950 sp=0xc0015da930 pc=0x43c976
runtime.chanrecv(0xc00e136060, 0x0, 0x1)
	runtime/chan.go:583 +0x49b fp=0xc0015da9e0 sp=0xc0015da950 pc=0x406cdb
runtime.chanrecv1(0x1a08500?, 0xc001e29d90?)
	runtime/chan.go:442 +0x18 fp=0xc0015daa08 sp=0xc0015da9e0 pc=0x4067d8
github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack)._cancelUpload(0xc0002f9810, 0xc00c5de5b0)
	github.com/rclone/rclone/vfs/vfscache/writeback/writeback.go:403 +0xae fp=0xc0015daa58 sp=0xc0015daa08 pc=0x172384e
github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack)._remove(0xc0002f9810, 0xc0008cb4e0?)
	github.com/rclone/rclone/vfs/vfscache/writeback/writeback.go:290 +0x112 fp=0xc0015daae8 sp=0xc0015daa58 pc=0x1722cd2
github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).Remove(0xc0015dabb8?, 0x40d8bf?)
	github.com/rclone/rclone/vfs/vfscache/writeback/writeback.go:308 +0x99 fp=0xc0015dab40 sp=0xc0015daae8 pc=0x1722e19
github.com/rclone/rclone/vfs/vfscache.(*Item)._remove(0xc001cb7600, {0x1e8ecbf, 0x22})
	github.com/rclone/rclone/vfs/vfscache/item.go:862 +0x69 fp=0xc0015dab78 sp=0xc0015dab40 pc=0x1731f89
github.com/rclone/rclone/vfs/vfscache.(*Item).RemoveNotInUse(0xc001cb7600, 0x0, 0x0)
	github.com/rclone/rclone/vfs/vfscache/item.go:910 +0x1e7 fp=0xc0015dabf0 sp=0xc0015dab78 pc=0x1732447
github.com/rclone/rclone/vfs/vfscache.(*Cache).removeNotInUse(0xc0002fa780, 0xc001cb7600, 0x0?, 0x0)
	github.com/rclone/rclone/vfs/vfscache/cache.go:573 +0x50 fp=0xc0015dac98 sp=0xc0015dabf0 pc=0x172abf0
github.com/rclone/rclone/vfs/vfscache.(*Cache).purgeOld(0xc0002fa780, 0x0?)
	github.com/rclone/rclone/vfs/vfscache/cache.go:662 +0x105 fp=0xc0015dad58 sp=0xc0015dac98 pc=0x172b785
github.com/rclone/rclone/vfs/vfscache.(*Cache).clean(0xc0002fa780, 0x0)
	github.com/rclone/rclone/vfs/vfscache/cache.go:743 +0x112 fp=0xc0015daf00 sp=0xc0015dad58 pc=0x172c152
github.com/rclone/rclone/vfs/vfscache.(*Cache).cleaner(0xc0002fa780, {0x2334130, 0xc001e22300})
	github.com/rclone/rclone/vfs/vfscache/cache.go:801 +0x18c fp=0xc0015dafb8 sp=0xc0015daf00 pc=0x172c78c
github.com/rclone/rclone/vfs/vfscache.New.func1()
	github.com/rclone/rclone/vfs/vfscache/cache.go:144 +0x2e fp=0xc0015dafe0 sp=0xc0015dafb8 pc=0x1727dae
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc0015dafe8 sp=0xc0015dafe0 pc=0x46e661
created by github.com/rclone/rclone/vfs/vfscache.New
	github.com/rclone/rclone/vfs/vfscache/cache.go:144 +0x6fe

goroutine 114 [chan receive, 989 minutes]:
runtime.gopark(0x100000000000000?, 0x0?, 0x1?, 0x0?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc000582eb0 sp=0xc000582e90 pc=0x43c976
runtime.chanrecv(0xc001882360, 0xc000582fc0, 0x1)
	runtime/chan.go:583 +0x49b fp=0xc000582f40 sp=0xc000582eb0 pc=0x406cdb
runtime.chanrecv1(0x0?, 0x0?)
	runtime/chan.go:442 +0x18 fp=0xc000582f68 sp=0xc000582f40 pc=0x4067d8
github.com/rclone/rclone/lib/atexit.Register.func1.1()
	github.com/rclone/rclone/lib/atexit/atexit.go:45 +0x2f fp=0xc000582fe0 sp=0xc000582f68 pc=0x7a19cf
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc000582fe8 sp=0xc000582fe0 pc=0x46e661
created by github.com/rclone/rclone/lib/atexit.Register.func1
	github.com/rclone/rclone/lib/atexit/atexit.go:44 +0x6b

goroutine 5055270 [semacquire, 582 minutes]:
runtime.gopark(0x3a?, 0x0?, 0x40?, 0x3d?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc0006c5428 sp=0xc0006c5408 pc=0x43c976
runtime.goparkunlock(...)
	runtime/proc.go:369
runtime.semacquire1(0xc0002fa7fc, 0xb0?, 0x3, 0x1)
	runtime/sema.go:150 +0x1fe fp=0xc0006c5490 sp=0xc0006c5428 pc=0x44d8fe
sync.runtime_SemacquireMutex(0x0?, 0x3a?, 0xc009c63500?)
	runtime/sema.go:77 +0x25 fp=0xc0006c54c0 sp=0xc0006c5490 pc=0x46a465
sync.(*Mutex).lockSlow(0xc0002fa7f8)
	sync/mutex.go:171 +0x165 fp=0xc0006c5510 sp=0xc0006c54c0 pc=0x478985
sync.(*Mutex).Lock(...)
	sync/mutex.go:90
github.com/rclone/rclone/vfs/vfscache.(*Cache).InUse(0xc0002fa780, {0xc0072d3500?, 0xc004753320?})
	github.com/rclone/rclone/vfs/vfscache/cache.go:302 +0x65 fp=0xc0006c5560 sp=0xc0006c5510 pc=0x1728ea5
github.com/rclone/rclone/vfs.(*Dir)._purgeVirtual(0xc0002ce900)
	github.com/rclone/rclone/vfs/dir.go:530 +0x199 fp=0xc0006c5610 sp=0xc0006c5560 pc=0x1738759
github.com/rclone/rclone/vfs.(*Dir)._newManageVirtuals(...)
	github.com/rclone/rclone/vfs/dir.go:552
github.com/rclone/rclone/vfs.(*Dir)._readDirFromEntries(0xc0002ce900, {0xc006d8a000, 0xe51, 0xc00051a9a0?}, 0x0, {0xc000795980?, 0x11?, 0x0?})
	github.com/rclone/rclone/vfs/dir.go:614 +0xc6 fp=0xc0006c57c0 sp=0xc0006c5610 pc=0x1738ba6
github.com/rclone/rclone/vfs.(*Dir)._readDir(0xc0002ce900)
	github.com/rclone/rclone/vfs/dir.go:461 +0x1aa fp=0xc0006c5870 sp=0xc0006c57c0 pc=0x173828a
github.com/rclone/rclone/vfs.(*Dir).ReadDirAll(0xc0002ce900)
	github.com/rclone/rclone/vfs/dir.go:814 +0x54 fp=0xc0006c5980 sp=0xc0006c5870 pc=0x173a3f4
github.com/rclone/rclone/cmd/mount.(*Dir).ReadDirAll(0xc0002365c0, {0x1e24e40?, 0xc0002365c0?})
	github.com/rclone/rclone/cmd/mount/dir.go:108 +0x14a fp=0xc0006c5ae0 sp=0xc0006c5980 pc=0x17591aa
bazil.org/fuse/fs.(*Server).handleRequest(0xc0018b2000, {0x2334130, 0xc000960340}, {0x231f0c0?, 0xc0002365c0}, 0xc000840140, {0x232d778?, 0xc000b8e070?}, 0xc0006c5f08)
	bazil.org/fuse@v0.0.0-20200524192727-fb710f7dfd05/fs/serve.go:1378 +0x1cff fp=0xc0006c5de0 sp=0xc0006c5ae0 pc=0x171bd3f
bazil.org/fuse/fs.(*Server).serve(0xc0018b2000, {0x232d778, 0xc000b8e070})
	bazil.org/fuse@v0.0.0-20200524192727-fb710f7dfd05/fs/serve.go:1015 +0x625 fp=0xc0006c5f98 sp=0xc0006c5de0 pc=0x17198e5
bazil.org/fuse/fs.(*Server).Serve.func1()
	bazil.org/fuse@v0.0.0-20200524192727-fb710f7dfd05/fs/serve.go:512 +0x69 fp=0xc0006c5fe0 sp=0xc0006c5f98 pc=0x1716be9
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc0006c5fe8 sp=0xc0006c5fe0 pc=0x46e661
created by bazil.org/fuse/fs.(*Server).Serve
	bazil.org/fuse@v0.0.0-20200524192727-fb710f7dfd05/fs/serve.go:510 +0x3df

goroutine 5056874 [semacquire, 187 minutes]:
runtime.gopark(0xc001fc57f8?, 0x40d8bf?, 0xb8?, 0x45?, 0x40d807?)
	runtime/proc.go:363 +0xd6 fp=0xc001fc5780 sp=0xc001fc5760 pc=0x43c976
runtime.goparkunlock(...)
	runtime/proc.go:369
runtime.semacquire1(0xc0002fa7fc, 0x8?, 0x3, 0x1)
	runtime/sema.go:150 +0x1fe fp=0xc001fc57e8 sp=0xc001fc5780 pc=0x44d8fe
sync.runtime_SemacquireMutex(0x0?, 0x12?, 0xc001fc5858?)
	runtime/sema.go:77 +0x25 fp=0xc001fc5818 sp=0xc001fc57e8 pc=0x46a465
sync.(*Mutex).lockSlow(0xc0002fa7f8)
	sync/mutex.go:171 +0x165 fp=0xc001fc5868 sp=0xc001fc5818 pc=0x478985
sync.(*Mutex).Lock(...)
	sync/mutex.go:90
github.com/rclone/rclone/vfs/vfscache.(*Cache).DirtyItem(0xc0002fa780, {0xc0000537e8?, 0x40d8bf?})
	github.com/rclone/rclone/vfs/vfscache/cache.go:317 +0x7c fp=0xc001fc58d8 sp=0xc001fc5868 pc=0x1728fdc
github.com/rclone/rclone/vfs.(*File).ModTime(0xc0018fe180)
	github.com/rclone/rclone/vfs/file.go:315 +0x179 fp=0xc001fc5990 sp=0xc001fc58d8 pc=0x173e0d9
github.com/rclone/rclone/cmd/mount.(*File).Attr(0xc000dc6300, {0xc000dc62d0?, 0xc000dc62e0?}, 0xc0002cf758)
	github.com/rclone/rclone/cmd/mount/file.go:30 +0x134 fp=0xc001fc5a78 sp=0xc001fc5990 pc=0x175bf74
bazil.org/fuse/fs.nodeAttr({0x2334130?, 0xc00602e400?}, {0x231f100?, 0xc000dc6300?}, 0xc000dc62e0?)
	bazil.org/fuse@v0.0.0-20200524192727-fb710f7dfd05/fs/serve.go:261 +0x10c fp=0xc001fc5aa8 sp=0xc001fc5a78 pc=0x171656c
bazil.org/fuse/fs.(*Server).saveLookup(0xc0018b2000, {0x2334130?, 0xc00602e400?}, 0xc0002cf740, 0xc0018ae040, {0xc0017c8018, 0x12}, {0x231f100, 0xc000dc6300})
	bazil.org/fuse@v0.0.0-20200524192727-fb710f7dfd05/fs/serve.go:1685 +0x5f fp=0xc001fc5ae0 sp=0xc001fc5aa8 pc=0x171d29f
bazil.org/fuse/fs.(*Server).handleRequest(0xc0018b2000, {0x2334130, 0xc00602e400}, {0x231f0c0?, 0xc0018900a0}, 0xc0018ae040, {0x232d628?, 0xc0069a0d80?}, 0xc001fc5f08)
	bazil.org/fuse@v0.0.0-20200524192727-fb710f7dfd05/fs/serve.go:1194 +0x252 fp=0xc001fc5de0 sp=0xc001fc5ae0 pc=0x171a292
bazil.org/fuse/fs.(*Server).serve(0xc0018b2000, {0x232d628, 0xc0069a0d80})
	bazil.org/fuse@v0.0.0-20200524192727-fb710f7dfd05/fs/serve.go:1015 +0x625 fp=0xc001fc5f98 sp=0xc001fc5de0 pc=0x17198e5
bazil.org/fuse/fs.(*Server).Serve.func1()
	bazil.org/fuse@v0.0.0-20200524192727-fb710f7dfd05/fs/serve.go:512 +0x69 fp=0xc001fc5fe0 sp=0xc001fc5f98 pc=0x1716be9
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc001fc5fe8 sp=0xc001fc5fe0 pc=0x46e661
created by bazil.org/fuse/fs.(*Server).Serve
	bazil.org/fuse@v0.0.0-20200524192727-fb710f7dfd05/fs/serve.go:510 +0x3df

(continue in the next post)

JuRaSSiCBoY · November 2, 2022, 9:48am


goroutine 4213716 [semacquire, 575 minutes]:
runtime.gopark(0xc007257bc0?, 0x40d8bf?, 0xd4?, 0x44?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc00689db48 sp=0xc00689db28 pc=0x43c976
runtime.goparkunlock(...)
	runtime/proc.go:369
runtime.semacquire1(0xc0002ce924, 0xd0?, 0x3, 0x1)
	runtime/sema.go:150 +0x1fe fp=0xc00689dbb0 sp=0xc00689db48 pc=0x44d8fe
sync.runtime_SemacquireMutex(0xc0006c1ac0?, 0x30?, 0xc0006c1ac0?)
	runtime/sema.go:77 +0x25 fp=0xc00689dbe0 sp=0xc00689dbb0 pc=0x46a465
sync.(*Mutex).lockSlow(0xc0002ce920)
	sync/mutex.go:171 +0x165 fp=0xc00689dc30 sp=0xc00689dbe0 pc=0x478985
sync.(*Mutex).Lock(...)
	sync/mutex.go:90
sync.(*RWMutex).Lock(0x1d9afe0?)
	sync/rwmutex.go:147 +0x36 fp=0xc00689dc60 sp=0xc00689dc30 pc=0x479f76
github.com/rclone/rclone/vfs.(*Dir).addObject(0xc0002ce900, {0x234a588, 0xc0006c1a40})
	github.com/rclone/rclone/vfs/dir.go:373 +0x51 fp=0xc00689dcf0 sp=0xc00689dc60 pc=0x17379d1
github.com/rclone/rclone/vfs.(*File).setObject(0xc0006c1a40, {0x23450d0?, 0xc006f0d9f8})
	github.com/rclone/rclone/vfs/file.go:462 +0xa5 fp=0xc00689dd30 sp=0xc00689dcf0 pc=0x173f2e5
github.com/rclone/rclone/vfs.(*File).setObject-fm({0x23450d0?, 0xc006f0d9f8?})
	<autogenerated>:1 +0x39 fp=0xc00689dd58 sp=0xc00689dd30 pc=0x1752f59
github.com/rclone/rclone/vfs/vfscache.(*Item)._store(0xc008fbcb00, {0x2334130, 0xc000984740}, 0xc00091ae00)
	github.com/rclone/rclone/vfs/vfscache/item.go:604 +0x426 fp=0xc00689de38 sp=0xc00689dd58 pc=0x1730546
github.com/rclone/rclone/vfs/vfscache.(*Item).store(0x40b587?, {0x2334130?, 0xc000984740?}, 0xb0888e8c3bf2501?)
	github.com/rclone/rclone/vfs/vfscache/item.go:615 +0xcc fp=0xc00689deb0 sp=0xc00689de38 pc=0x173068c
github.com/rclone/rclone/vfs/vfscache.(*Item).Close.func2({0x2334130?, 0xc000984740?})
	github.com/rclone/rclone/vfs/vfscache/item.go:714 +0x34 fp=0xc00689dee0 sp=0xc00689deb0 pc=0x1731254
github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).upload(0xc0002f9810, {0x2334130, 0xc000984740}, 0xc0009dd810)
	github.com/rclone/rclone/vfs/vfscache/writeback/writeback.go:354 +0x137 fp=0xc00689dfb0 sp=0xc00689dee0 pc=0x1723377
github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).processItems.func2()
	github.com/rclone/rclone/vfs/vfscache/writeback/writeback.go:450 +0x32 fp=0xc00689dfe0 sp=0xc00689dfb0 pc=0x1723cf2
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc00689dfe8 sp=0xc00689dfe0 pc=0x46e661
created by github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).processItems
	github.com/rclone/rclone/vfs/vfscache/writeback/writeback.go:450 +0x2af

goroutine 4893699 [semacquire, 569 minutes]:
runtime.gopark(0xc009c5fbc0?, 0x40d8bf?, 0xd4?, 0x44?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc001136b48 sp=0xc001136b28 pc=0x43c976
runtime.goparkunlock(...)
	runtime/proc.go:369
runtime.semacquire1(0xc0002ce924, 0xd0?, 0x3, 0x1)
	runtime/sema.go:150 +0x1fe fp=0xc001136bb0 sp=0xc001136b48 pc=0x44d8fe
sync.runtime_SemacquireMutex(0xc000abb4c0?, 0xb8?, 0xc000abb4c0?)
	runtime/sema.go:77 +0x25 fp=0xc001136be0 sp=0xc001136bb0 pc=0x46a465
sync.(*Mutex).lockSlow(0xc0002ce920)
	sync/mutex.go:171 +0x165 fp=0xc001136c30 sp=0xc001136be0 pc=0x478985
sync.(*Mutex).Lock(...)
	sync/mutex.go:90
sync.(*RWMutex).Lock(0x1d9afe0?)
	sync/rwmutex.go:147 +0x36 fp=0xc001136c60 sp=0xc001136c30 pc=0x479f76
github.com/rclone/rclone/vfs.(*Dir).addObject(0xc0002ce900, {0x234a588, 0xc000abb440})
	github.com/rclone/rclone/vfs/dir.go:373 +0x51 fp=0xc001136cf0 sp=0xc001136c60 pc=0x17379d1
github.com/rclone/rclone/vfs.(*File).setObject(0xc000abb440, {0x23450d0?, 0xc0013ae690})
	github.com/rclone/rclone/vfs/file.go:462 +0xa5 fp=0xc001136d30 sp=0xc001136cf0 pc=0x173f2e5
github.com/rclone/rclone/vfs.(*File).setObject-fm({0x23450d0?, 0xc0013ae690?})
	<autogenerated>:1 +0x39 fp=0xc001136d58 sp=0xc001136d30 pc=0x1752f59
github.com/rclone/rclone/vfs/vfscache.(*Item)._store(0xc0019a9000, {0x2334130, 0xc000590a40}, 0xc00018dd90)
	github.com/rclone/rclone/vfs/vfscache/item.go:604 +0x426 fp=0xc001136e38 sp=0xc001136d58 pc=0x1730546
github.com/rclone/rclone/vfs/vfscache.(*Item).store(0x40b587?, {0x2334130?, 0xc000590a40?}, 0x1?)
	github.com/rclone/rclone/vfs/vfscache/item.go:615 +0xcc fp=0xc001136eb0 sp=0xc001136e38 pc=0x173068c
github.com/rclone/rclone/vfs/vfscache.(*Item).Close.func2({0x2334130?, 0xc000590a40?})
	github.com/rclone/rclone/vfs/vfscache/item.go:714 +0x34 fp=0xc001136ee0 sp=0xc001136eb0 pc=0x1731254
github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).upload(0xc0002f9810, {0x2334130, 0xc000590a40}, 0xc000a41c00)
	github.com/rclone/rclone/vfs/vfscache/writeback/writeback.go:354 +0x137 fp=0xc001136fb0 sp=0xc001136ee0 pc=0x1723377
github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).processItems.func2()
	github.com/rclone/rclone/vfs/vfscache/writeback/writeback.go:450 +0x32 fp=0xc001136fe0 sp=0xc001136fb0 pc=0x1723cf2
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc001136fe8 sp=0xc001136fe0 pc=0x46e661
created by github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).processItems
	github.com/rclone/rclone/vfs/vfscache/writeback/writeback.go:450 +0x2af

goroutine 4598084 [semacquire, 569 minutes]:
runtime.gopark(0xc0004d7bc0?, 0x40d8bf?, 0xd4?, 0x44?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc00072ab48 sp=0xc00072ab28 pc=0x43c976
runtime.goparkunlock(...)
	runtime/proc.go:369
runtime.semacquire1(0xc0002ce924, 0xd0?, 0x3, 0x1)
	runtime/sema.go:150 +0x1fe fp=0xc00072abb0 sp=0xc00072ab48 pc=0x44d8fe
sync.runtime_SemacquireMutex(0xc000abb1c0?, 0x50?, 0xc000abb1c0?)
	runtime/sema.go:77 +0x25 fp=0xc00072abe0 sp=0xc00072abb0 pc=0x46a465
sync.(*Mutex).lockSlow(0xc0002ce920)
	sync/mutex.go:171 +0x165 fp=0xc00072ac30 sp=0xc00072abe0 pc=0x478985
sync.(*Mutex).Lock(...)
	sync/mutex.go:90
sync.(*RWMutex).Lock(0x1d9afe0?)
	sync/rwmutex.go:147 +0x36 fp=0xc00072ac60 sp=0xc00072ac30 pc=0x479f76
github.com/rclone/rclone/vfs.(*Dir).addObject(0xc0002ce900, {0x234a588, 0xc000abb140})
	github.com/rclone/rclone/vfs/dir.go:373 +0x51 fp=0xc00072acf0 sp=0xc00072ac60 pc=0x17379d1
github.com/rclone/rclone/vfs.(*File).setObject(0xc000abb140, {0x23450d0?, 0xc001e93ef0})
	github.com/rclone/rclone/vfs/file.go:462 +0xa5 fp=0xc00072ad30 sp=0xc00072acf0 pc=0x173f2e5
github.com/rclone/rclone/vfs.(*File).setObject-fm({0x23450d0?, 0xc001e93ef0?})
	<autogenerated>:1 +0x39 fp=0xc00072ad58 sp=0xc00072ad30 pc=0x1752f59
github.com/rclone/rclone/vfs/vfscache.(*Item)._store(0xc008fbc800, {0x2334130, 0xc000841000}, 0xc001e3b600)
	github.com/rclone/rclone/vfs/vfscache/item.go:604 +0x426 fp=0xc00072ae38 sp=0xc00072ad58 pc=0x1730546
github.com/rclone/rclone/vfs/vfscache.(*Item).store(0x40b587?, {0x2334130?, 0xc000841000?}, 0xc0012a3e01?)
	github.com/rclone/rclone/vfs/vfscache/item.go:615 +0xcc fp=0xc00072aeb0 sp=0xc00072ae38 pc=0x173068c
github.com/rclone/rclone/vfs/vfscache.(*Item).Close.func2({0x2334130?, 0xc000841000?})
	github.com/rclone/rclone/vfs/vfscache/item.go:714 +0x34 fp=0xc00072aee0 sp=0xc00072aeb0 pc=0x1731254
github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).upload(0xc0002f9810, {0x2334130, 0xc000841000}, 0xc0002d6770)
	github.com/rclone/rclone/vfs/vfscache/writeback/writeback.go:354 +0x137 fp=0xc00072afb0 sp=0xc00072aee0 pc=0x1723377
github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).processItems.func2()
	github.com/rclone/rclone/vfs/vfscache/writeback/writeback.go:450 +0x32 fp=0xc00072afe0 sp=0xc00072afb0 pc=0x1723cf2
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc00072afe8 sp=0xc00072afe0 pc=0x46e661
created by github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).processItems
	github.com/rclone/rclone/vfs/vfscache/writeback/writeback.go:450 +0x2af

goroutine 5055232 [semacquire, 583 minutes]:
runtime.gopark(0xc007253bc0?, 0x40d8bf?, 0xc0?, 0xa9?, 0x0?)
	runtime/proc.go:363 +0xd6 fp=0xc00137bb48 sp=0xc00137bb28 pc=0x43c976
runtime.goparkunlock(...)
	runtime/proc.go:369
runtime.semacquire1(0xc0002ce924, 0xd0?, 0x3, 0x1)
	runtime/sema.go:150 +0x1fe fp=0xc00137bbb0 sp=0xc00137bb48 pc=0x44d8fe
sync.runtime_SemacquireMutex(0xc000abbb80?, 0x88?, 0xc000abbb80?)
	runtime/sema.go:77 +0x25 fp=0xc00137bbe0 sp=0xc00137bbb0 pc=0x46a465
sync.(*Mutex).lockSlow(0xc0002ce920)
	sync/mutex.go:171 +0x165 fp=0xc00137bc30 sp=0xc00137bbe0 pc=0x478985
sync.(*Mutex).Lock(...)
	sync/mutex.go:90
sync.(*RWMutex).Lock(0x1d9afe0?)
	sync/rwmutex.go:147 +0x36 fp=0xc00137bc60 sp=0xc00137bc30 pc=0x479f76
github.com/rclone/rclone/vfs.(*Dir).addObject(0xc0002ce900, {0x234a588, 0xc000abbb00})
	github.com/rclone/rclone/vfs/dir.go:373 +0x51 fp=0xc00137bcf0 sp=0xc00137bc60 pc=0x17379d1
github.com/rclone/rclone/vfs.(*File).setObject(0xc000abbb00, {0x23450d0?, 0xc00e08b440})
	github.com/rclone/rclone/vfs/file.go:462 +0xa5 fp=0xc00137bd30 sp=0xc00137bcf0 pc=0x173f2e5
github.com/rclone/rclone/vfs.(*File).setObject-fm({0x23450d0?, 0xc00e08b440?})
	<autogenerated>:1 +0x39 fp=0xc00137bd58 sp=0xc00137bd30 pc=0x1752f59
github.com/rclone/rclone/vfs/vfscache.(*Item)._store(0xc001cb7600, {0x2334130, 0xc0028868c0}, 0xc000a10b30)
	github.com/rclone/rclone/vfs/vfscache/item.go:604 +0x426 fp=0xc00137be38 sp=0xc00137bd58 pc=0x1730546
github.com/rclone/rclone/vfs/vfscache.(*Item).store(0x40b587?, {0x2334130?, 0xc0028868c0?}, 0xc0017c8101?)
	github.com/rclone/rclone/vfs/vfscache/item.go:615 +0xcc fp=0xc00137beb0 sp=0xc00137be38 pc=0x173068c
github.com/rclone/rclone/vfs/vfscache.(*Item).Close.func2({0x2334130?, 0xc0028868c0?})
	github.com/rclone/rclone/vfs/vfscache/item.go:714 +0x34 fp=0xc00137bee0 sp=0xc00137beb0 pc=0x1731254
github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).upload(0xc0002f9810, {0x2334130, 0xc0028868c0}, 0xc00c5de5b0)
	github.com/rclone/rclone/vfs/vfscache/writeback/writeback.go:354 +0x137 fp=0xc00137bfb0 sp=0xc00137bee0 pc=0x1723377
github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).processItems.func2()
	github.com/rclone/rclone/vfs/vfscache/writeback/writeback.go:450 +0x32 fp=0xc00137bfe0 sp=0xc00137bfb0 pc=0x1723cf2
runtime.goexit()
	runtime/asm_amd64.s:1594 +0x1 fp=0xc00137bfe8 sp=0xc00137bfe0 pc=0x46e661
created by github.com/rclone/rclone/vfs/vfscache/writeback.(*WriteBack).processItems
	github.com/rclone/rclone/vfs/vfscache/writeback/writeback.go:450 +0x2af

rax    0xca
rbx    0x0
rcx    0x470563
rdx    0x0
rdi    0x31df928
rsi    0x80
rbp    0x7fff2e4458c0
rsp    0x7fff2e445878
r8     0x0
r9     0x0
r10    0x0
r11    0x286
r12    0x443020
r13    0x0
r14    0x31ded60
r15    0x1
rip    0x470561
rflags 0x286
cs     0x33
fs     0x0
gs     0x0

ncw · November 2, 2022, 11:01am

I think this deadlock may be the same as one I've already identified.

Can you try this please?

v1.61.0-beta.6506.159e29485.fix-vfs-deadlock on branch fix-vfs-deadlock (uploaded in 15-30 mins)

JuRaSSiCBoY · November 2, 2022, 2:46pm

Of course, is there a way to easily update the rclone with that fix on a QNAP NAS? I've always updated it from Qnap Club or MyQnap.org repositories and I'm not sure if QTS accepts typical Linux packages without "recompile" them to QTS (qpkg package).
I'll take a look tonight to see what can I do.

Thanks again!!!

EDIT: Ok!!! I think I got it! I've put the contents of the "rclone-v1.61.0-beta.6506.159e29485.fix-vfs-deadlock-linux-amd64.zip" file at /share/CACHEDEV1_DATA/.qpkg/RClone/ and reset the QNAP app service.
Now my rclone is in the 1.61 beta version:

[~] # rclone version
rclone v1.61.0-beta.6506.159e29485.fix-vfs-deadlock

os/version: qts 5.0.1 (20221022) (64 bit)
os/kernel: 5.10.60-qnap (x86_64)
os/type: linux
os/arch: amd64
go/version: go1.19.2
go/linking: static
go/tags: none

I'll let you know about how it went. Thanks!!

ncw · November 3, 2022, 4:53pm

Glad you've figured it out, because I know nothing about QNAP.

Very interested in the result - thank you

JuRaSSiCBoY · November 3, 2022, 7:36pm

Thanks again Nick, especially for your effort and for sharing your work with us.

Almost 24 hours without a hang/freeze!! unzipping files uninterrupted.. everything seems to be working fine. I'll keep an eye out for any other unexpected errors.
Very impressive how fast you locate and solve the issue, congratulations!

Let me know if you need to try something else!

ncw · November 3, 2022, 10:03pm

Good news! I think just keep running it and report back in a few days whether it is still OK.

If it is, I'll consider merging the patch!

JuRaSSiCBoY · November 15, 2022, 1:09pm

@ncw everything's ok since the beta update!!
No more hangs, stucks or similar problems detected on my side.

Thanks a lot for everything!

ncw · November 15, 2022, 6:02pm

Thanks for testing - a good long test is great

I've merged this to master now which means it will be in the latest beta in 15-30 minutes and released in v1.61 and also I'll put it in v1.60.1

system · November 18, 2022, 6:02pm

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