ashyni
January 18, 2020, 4:23pm
1
Hello,rclone mount , and i noticed when i use a mv command on linux from local to remote, the file are upload twice because of difference in the modification time, so the file is upload 1 time with the correct modTime then a check is performed with the file in cache wich have a newly created modTime and then reupload with this new modTime.
ls -l remote after first upload thendéc. 21 08:02 'Joker (2019).mkv'ls -l cache/remote same result for both, after second uploadjanv. 18 17:02 'Joker (2019).mkv'
It's like a step is missing when creating the cache file with the correct modTime before uploading it.
2020/01/18 16:06:59 INFO : Films/Joker (2019)/Joker (2019).mkv: Copied (new)
2020/01/18 16:06:59 DEBUG : Films/Joker (2019)/Joker (2019).mkv: File._applyPendingModTime OK
2020/01/18 16:06:59 DEBUG : Films/Joker (2019)/Joker (2019).mkv: transferred to remote
2020/01/18 16:06:59 DEBUG : &{Films/Joker (2019)/Joker (2019).mkv (rw)}: >Flush: err=<nil>
2020/01/18 16:06:59 DEBUG : &{Films/Joker (2019)/Joker (2019).mkv (rw)}: Release:
2020/01/18 16:06:59 DEBUG : Films/Joker (2019)/Joker (2019).mkv(0xc000ae2380): WFileHandle.Release closing
2020/01/18 16:06:59 DEBUG : Films/Joker (2019)/Joker (2019).mkv(0xc000ae2380): close:
2020/01/18 16:06:59 DEBUG : Films/Joker (2019)/Joker (2019).mkv: File.delWriter couldn't find handle
2020/01/18 16:06:59 DEBUG : Films/Joker (2019)/Joker (2019).mkv: Modification times differ by -680h59m56.36034991s: 2020-01-18 16:02:19.36034991 +0000 UTC, 2019-12-21 07:02:23 +0000 UTC
2020/01/18 16:06:59 DEBUG : Films/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/01/18 16:09:12 INFO : Films/Joker (2019)/Joker (2019).mkv: Copied (replaced existing)
with cp the problem is bit different, the file is upload directly with a wrong/fresh modTime, no check are perform.
This problem doesn't occur if i use rclone copy/move local remote: .
Using docker latest and i try beta too.
I hope it's clear enough to be understood, i apologize if not.
What's your mount command?
When command are you running specifically?
ashyni
January 18, 2020, 4:38pm
3
Docker latest 1.50.2, i also try Beta.
gdrive with crypt
rclone mount --log-level DEBUG --allow-other --buffer-size 32M --cache-dir /cache --dir-cache-time 168h --drive-chunk-size 512M --vfs-read-chunk-size 64M --vfs-read-chunk-size-limit 512M --vfs-cache-mode writes tcrypt: /data/rclone
command in host:mv /mnt/media/Films/Joker\ \(2019\)/ /mnt/rclone/Films/
So to make sure, you are using the cache backend but you are using vfs-cache-mode writes to handle your tmp writes? I don't see the cache-tmp-upload anywhere and just want to make sure I'm correct as I will try to replicate it.
ashyni
January 18, 2020, 5:51pm
5
no cache backend, only gdrive with crypt and mount with vfs
[tdrive]
type = drive
client_id = ---
client_secret = -----
scope = drive
token = {-}
team_drive = ------
[tcrypt]
type = crypt
remote = tdrive:Team
filename_encryption = standard
directory_name_encryption = true
password = -----
password2 = -----
What does:
felix@gemini:~$ stat /etc/hosts
File: /etc/hosts
Size: 227 Blocks: 8 IO Block: 4096 regular file
Device: 802h/2050d Inode: 268641004 Links: 1
Access: (0644/-rw-r--r--) Uid: ( 0/ root) Gid: ( 0/ root)
Access: 2020-01-18 12:25:05.721080702 -0500
Modify: 2019-11-29 12:21:40.797519988 -0500
Change: 2019-11-29 12:21:40.805520026 -0500
Birth: -
show on the file before it was copied?
ashyni
January 18, 2020, 6:04pm
7
It's another movie, already remove the other one, it was similar, with almost the same modTime.
stat /mnt/media/Films/Jexi\ \(2019\)/Jexi\ \(2019\).mkv
File: /mnt/media/Films/Jexi (2019)/Jexi (2019).mkv
Size: 8972290260 Blocks: 17524008 IO Block: 4096 regular file
Device: 36h/54d Inode: 2517025 Links: 1
Access: (0644/-rw-r--r--) Uid: ( 1000/ ashyni) Gid: ( 1000/ ashyni)
Access: 2020-01-17 20:50:32.000000000
Modify: 2019-12-27 00:00:00.000000000
Change: 2020-01-17 23:52:39.000000000
during a cp, file in cache
stat /cache/vfs/tcrypt/Jexi\ \(2019\)/Jexi\ \(2019\).mkv
File: /cache/vfs/tcrypt/Jexi (2019)/Jexi (2019).mkv
Size: 8972290260 Blocks: 17524016 IO Block: 4096 regular file
Device: fd04h/64772d Inode: 3490609 Links: 1
Access: (0600/-rw-------) Uid: ( 1000/ ashyni) Gid: ( 1000/ ashyni)
Access: 2020-01-18 18:07:20.000000000
Modify: 2020-01-18 18:07:20.000000000
Change: 2020-01-18 18:07:20.0000000000
on remote
stat /mnt/rclone/Jexi\ \(2019\)/Jexi\ \(2019\).mkv
File: /mnt/rclone/Jexi (2019)/Jexi (2019).mkv
Size: 8972290260 Blocks: 17524005 IO Block: 4096 regular file
Device: 90h/144d Inode: 15559171817887241978 Links: 1
Access: (0644/-rw-r--r--) Uid: ( 1000/ ashyni) Gid: ( 1000/ ashyni)
Access: 2020-01-18 18:07:20.000000000
Modify: 2020-01-18 18:07:20.000000000
Change: 2020-01-18 18:07:20.000000000
I can recreate it as I just used a small file to produce the same results:
felix@gemini:~$ rclone mount gcrypt: /Test -vv --vfs-cache-mode writes
2020/01/18 13:43:00 DEBUG : rclone: Version "v1.50.2" starting with parameters ["rclone" "mount" "gcrypt:" "/Test" "-vv" "--vfs-cache-mode" "writes"]
2020/01/18 13:43:00 DEBUG : Using config file from "/opt/rclone/rclone.conf"
2020/01/18 13:43:01 DEBUG : Encrypted drive 'gcrypt:': Mounting on "/Test"
2020/01/18 13:43:01 DEBUG : vfs cache root is "/home/felix/.cache/rclone/vfs/gcrypt"
2020/01/18 13:43:01 DEBUG : Adding path "vfs/forget" to remote control registry
2020/01/18 13:43:01 DEBUG : Adding path "vfs/refresh" to remote control registry
2020/01/18 13:43:01 DEBUG : Adding path "vfs/poll-interval" to remote control registry
2020/01/18 13:43:01 DEBUG : : Root:
2020/01/18 13:43:01 DEBUG : : >Root: node=/, err=<nil>
2020/01/18 13:43:01 DEBUG : hosts: updateTime: setting atime to 2020-01-18 12:52:29.160120652 -0500 EST
2020/01/18 13:43:01 INFO : Cleaned the cache: objects 2 (was 0), total size 227 (was 0)
2020/01/18 13:43:50 DEBUG : /: Attr:
2020/01/18 13:43:50 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2020/01/18 13:43:50 DEBUG : /: Lookup: name="test1"
2020/01/18 13:43:50 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/01/18 13:43:50 DEBUG : /: Lookup: name="test1"
2020/01/18 13:43:50 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/01/18 13:43:50 DEBUG : /: Lookup: name="test1"
2020/01/18 13:43:50 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/01/18 13:43:50 DEBUG : /: Create: name="test1"
2020/01/18 13:43:50 DEBUG : test1: Open: flags=O_WRONLY|O_CREATE|O_EXCL
2020/01/18 13:43:50 DEBUG : test1(0xc001dbc120): Opening cached copy with flags=O_WRONLY|O_CREATE|O_EXCL
2020/01/18 13:43:50 DEBUG : test1: >Open: fd=test1 (rw), err=<nil>
2020/01/18 13:43:50 DEBUG : /: >Create: node=test1, handle=&{test1 (rw)}, err=<nil>
2020/01/18 13:43:50 DEBUG : test1: Attr:
2020/01/18 13:43:50 DEBUG : test1: >Attr: a=valid=1s ino=0 size=0 mode=-rw-rw-r--, err=<nil>
2020/01/18 13:43:50 DEBUG : &{test1 (rw)}: Write: len=221, offset=0
2020/01/18 13:43:50 DEBUG : &{test1 (rw)}: >Write: written=221, err=<nil>
2020/01/18 13:43:50 DEBUG : test1: Setattr: a=Setattr [ID=0x9 Node=0x2 Uid=1000 Gid=1000 Pid=4224] atime=2020-01-18 13:43:42.144765598 -0500 EST mtime=2019-11-29 10:03:32.235951748 -0500 EST handle=INVALID-0x0
2020/01/18 13:43:50 DEBUG : test1: >Setattr: err=<nil>
2020/01/18 13:43:50 DEBUG : test1: Attr:
2020/01/18 13:43:50 DEBUG : test1: >Attr: a=valid=1s ino=0 size=221 mode=-rw-rw-r--, err=<nil>
2020/01/18 13:43:50 DEBUG : test1: Setattr: a=Setattr [ID=0xb Node=0x2 Uid=1000 Gid=1000 Pid=4224] mode=-rw-rw-r-- handle=INVALID-0x0
2020/01/18 13:43:50 DEBUG : test1: >Setattr: err=<nil>
2020/01/18 13:43:50 DEBUG : test1: Attr:
2020/01/18 13:43:50 DEBUG : test1: >Attr: a=valid=1s ino=0 size=221 mode=-rw-rw-r--, err=<nil>
2020/01/18 13:43:50 DEBUG : &{test1 (rw)}: Flush:
2020/01/18 13:43:50 DEBUG : test1: Need to transfer - File not found at Destination
2020/01/18 13:43:52 INFO : test1: Copied (new)
2020/01/18 13:43:52 DEBUG : test1: File.applyPendingModTime OK
2020/01/18 13:43:52 DEBUG : test1: transferred to remote
2020/01/18 13:43:52 DEBUG : &{test1 (rw)}: >Flush: err=<nil>
2020/01/18 13:43:52 DEBUG : &{test1 (rw)}: Release:
2020/01/18 13:43:52 DEBUG : test1(0xc001dbc120): RWFileHandle.Release closing
2020/01/18 13:43:52 DEBUG : test1(0xc001dbc120): close:
2020/01/18 13:43:52 DEBUG : test1: File.delWriter couldn't find handle
2020/01/18 13:43:52 DEBUG : test1: Modification times differ by -1203h40m18.009798119s: 2020-01-18 13:43:50.244798119 -0500 EST, 2019-11-29 15:03:32.235 +0000 UTC
2020/01/18 13:43:53 INFO : test1: Copied (replaced existing)
2020/01/18 13:43:53 DEBUG : test1: transferred to remote
2020/01/18 13:43:53 DEBUG : test1(0xc001dbc120): >close: err=<nil>
2020/01/18 13:43:53 DEBUG : &{test1 (rw)}: >Release: err=<nil>
2020/01/18 13:44:01 DEBUG : Google drive root 'crypt': Checking for changes on remote
2020/01/18 13:44:01 INFO : Cleaned the cache: objects 3 (was 3), total size 448 (was 227)
2020/01/18 13:44:01 DEBUG : : changeNotify: relativePath="test1", type=3
2020/01/18 13:44:01 DEBUG : : invalidating directory cache
2020/01/18 13:44:01 DEBUG : : >changeNotify:
and if I do just a cp:
2020/01/18 13:46:00 DEBUG : /: Lookup: name="cptest"
2020/01/18 13:46:00 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/01/18 13:46:00 DEBUG : /: Lookup: name="cptest"
2020/01/18 13:46:00 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/01/18 13:46:00 DEBUG : /: Lookup: name="cptest"
2020/01/18 13:46:00 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2020/01/18 13:46:00 DEBUG : /: Create: name="cptest"
2020/01/18 13:46:00 DEBUG : cptest: Open: flags=O_WRONLY|O_CREATE|O_EXCL
2020/01/18 13:46:00 DEBUG : cptest(0xc00008c180): Opening cached copy with flags=O_WRONLY|O_CREATE|O_EXCL
2020/01/18 13:46:00 DEBUG : cptest: >Open: fd=cptest (rw), err=<nil>
2020/01/18 13:46:00 DEBUG : /: >Create: node=cptest, handle=&{cptest (rw)}, err=<nil>
2020/01/18 13:46:00 DEBUG : cptest: Attr:
2020/01/18 13:46:00 DEBUG : cptest: >Attr: a=valid=1s ino=0 size=0 mode=-rw-rw-r--, err=<nil>
2020/01/18 13:46:00 DEBUG : &{cptest (rw)}: Write: len=227, offset=0
2020/01/18 13:46:00 DEBUG : &{cptest (rw)}: >Write: written=227, err=<nil>
2020/01/18 13:46:00 DEBUG : &{cptest (rw)}: Flush:
2020/01/18 13:46:00 DEBUG : cptest: Need to transfer - File not found at Destination
2020/01/18 13:46:01 DEBUG : Google drive root 'crypt': Checking for changes on remote
2020/01/18 13:46:01 DEBUG : cptest: updateTime: setting atime to 2020-01-18 13:46:00.697323085 -0500 EST
2020/01/18 13:46:01 INFO : Cleaned the cache: objects 4 (was 4), total size 675 (was 448)
2020/01/18 13:46:01 INFO : cptest: Copied (new)
2020/01/18 13:46:01 DEBUG : cptest: transferred to remote
2020/01/18 13:46:01 DEBUG : &{cptest (rw)}: >Flush: err=<nil>
2020/01/18 13:46:01 DEBUG : &{cptest (rw)}: Release:
2020/01/18 13:46:01 DEBUG : cptest(0xc00008c180): RWFileHandle.Release closing
2020/01/18 13:46:01 DEBUG : cptest(0xc00008c180): close:
2020/01/18 13:46:01 DEBUG : cptest: File.delWriter couldn't find handle
2020/01/18 13:46:01 DEBUG : cptest: Size and modification time the same (differ by -322.489µs, within tolerance 1ms)
2020/01/18 13:46:01 DEBUG : cptest: Unchanged skipping
2020/01/18 13:46:01 DEBUG : cptest: transferred to remote
2020/01/18 13:46:01 DEBUG : cptest(0xc00008c180): >close: err=<nil>
2020/01/18 13:46:01 DEBUG : &{cptest (rw)}: >Release: err=<nil>
That does seem to be a neat one.
@ncw - do you see something here as well? I think it merits a bug report.
ncw
January 19, 2020, 1:01pm
9
I can replicate this... If I take crypt out of the equation then I can't replicate it.
What is happending is that on Flush
the file is uploaded
then the modification time is changed
And on Release
we check one last time to see if the file is OK
however the modification time on the file in the cache wasn't changed
so we upload it again since we can't check checksums (crypt).
I had a go at fixing this here - can you have a go?
https://beta.rclone.org/branch/v1.50.2-171-g84191ac6-fix-vfs-modtime-beta/ (uploaded in 15-30 mins)
ashyni
January 19, 2020, 2:53pm
11
Seems good with mv command.
2020/01/19 15:36:32 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).mkv: Setattr: a=Setattr [ID=0x2bb8a Node=0x3 Uid=1000 Gid=1000 Pid=15601] atime=2020-01-19 15:30:43.891402938 +0100 CET mtime=2011-09-09 13:37:24 +0200 CEST handle=INVALID-0x0
2020/01/19 15:44:48 INFO : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).mkv: Copied (new)
2020/01/19 15:44:48 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).mkv: File._applyPendingModTime OK
2020/01/19 15:44:48 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).mkv: transferred to remote
2020/01/19 15:44:48 DEBUG : &{Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).mkv (rw)}: >Flush: err=<nil>
2020/01/19 15:44:48 DEBUG : &{Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).mkv (rw)}: Release:
2020/01/19 15:44:48 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).mkv(0xc0000e0980): RWFileHandle.Release closing
2020/01/19 15:44:48 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).mkv(0xc0000e0980): close:
2020/01/19 15:44:48 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).mkv: File.delWriter couldn't find handle
2020/01/19 15:44:48 DEBUG : /: Lookup: name="Films"
2020/01/19 15:44:48 DEBUG : /: >Lookup: node=Films/, err=<nil>
2020/01/19 15:44:48 DEBUG : Films/: Attr:
2020/01/19 15:44:48 DEBUG : Films/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/01/19 15:44:48 DEBUG : /: Lookup: name="Films"
2020/01/19 15:44:48 DEBUG : /: >Lookup: node=Films/, err=<nil>
2020/01/19 15:44:48 DEBUG : Films/: Attr:
2020/01/19 15:44:48 DEBUG : Films/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/01/19 15:44:48 DEBUG : Films/: Lookup: name="Le Retour du Jedi (1983)"
2020/01/19 15:44:48 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).mkv: Size and modification time the same (differ by 0s, within tolerance 1ms)
2020/01/19 15:44:48 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).mkv: Unchanged skipping
2020/01/19 15:44:48 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).mkv: transferred to remote
2020/01/19 15:44:48 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).mkv(0xc0000e0980): >close: err=<nil>
2020/01/19 15:44:48 DEBUG : &{Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).mkv (rw)}: >Release: err=<nil>
2020/01/19 15:44:49 DEBUG : Films/: >Lookup: node=Films/Le Retour du Jedi (1983)/, err=<nil>
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/: Attr:
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/: Lookup: name="Le Retour du Jedi (1983).nfo"
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/: >Lookup: node=<nil>, err=no such file or directory
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/: Lookup: name="Le Retour du Jedi (1983).nfo"
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/: >Lookup: node=<nil>, err=no such file or directory
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/: Lookup: name="Le Retour du Jedi (1983).nfo"
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/: >Lookup: node=<nil>, err=no such file or directory
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/: Create: name="Le Retour du Jedi (1983).nfo"
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: Open: flags=O_WRONLY|O_CREATE|O_EXCL
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo(0xc001e9a580): Opening cached copy with flags=O_WRONLY|O_CREATE|O_EXCL
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: >Open: fd=Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo (rw), err=<nil>
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/: >Create: node=Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo, handle=&{Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo (rw)}, err=<nil>
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: Attr:
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: >Attr: a=valid=1s ino=0 size=0 mode=-rw-r--r--, err=<nil>
2020/01/19 15:44:49 DEBUG : &{Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo (rw)}: Write: len=26259, offset=0
2020/01/19 15:44:49 DEBUG : &{Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo (rw)}: >Write: written=26259, err=<nil>
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: Setattr: a=Setattr [ID=0x2bbb0 Node=0x2 Uid=1000 Gid=1000 Pid=15601] atime=2020-01-19 15:31:18.595249856 +0100 CET mtime=2020-01-19 15:31:23.551228 +0100 CET handle=INVALID-0x0
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: >Setattr: err=<nil>
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: Attr:
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: >Attr: a=valid=1s ino=0 size=26259 mode=-rw-r--r--, err=<nil>
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: Attr:
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: >Attr: a=valid=1s ino=0 size=26259 mode=-rw-r--r--, err=<nil>
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: Setattr: a=Setattr [ID=0x2bbb4 Node=0x2 Uid=1000 Gid=1000 Pid=15601] uid=1000 gid=1000 handle=INVALID-0x0
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: >Setattr: err=<nil>
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: Attr:
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: >Attr: a=valid=1s ino=0 size=26259 mode=-rw-r--r--, err=<nil>
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: Setattr: a=Setattr [ID=0x2bbb6 Node=0x2 Uid=1000 Gid=1000 Pid=15601] mode=-rw-r--r-- handle=INVALID-0x0
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: >Setattr: err=<nil>
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: Attr:
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: >Attr: a=valid=1s ino=0 size=26259 mode=-rw-r--r--, err=<nil>
2020/01/19 15:44:49 DEBUG : &{Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo (rw)}: Flush:
2020/01/19 15:44:49 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: Need to transfer - File not found at Destination
2020/01/19 15:44:50 INFO : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: Copied (new)
2020/01/19 15:44:51 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: File._applyPendingModTime OK
2020/01/19 15:44:51 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: transferred to remote
2020/01/19 15:44:51 DEBUG : &{Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo (rw)}: >Flush: err=<nil>
2020/01/19 15:44:51 DEBUG : &{Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo (rw)}: Release:
2020/01/19 15:44:51 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo(0xc001e9a580): RWFileHandle.Release closing
2020/01/19 15:44:51 DEBUG : /: Lookup: name="Films"
2020/01/19 15:44:51 DEBUG : /: >Lookup: node=Films/, err=<nil>
2020/01/19 15:44:51 DEBUG : Films/: Attr:
2020/01/19 15:44:51 DEBUG : Films/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2020/01/19 15:44:51 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo(0xc001e9a580): close:
2020/01/19 15:44:51 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: File.delWriter couldn't find handle
2020/01/19 15:44:51 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: Size and modification time the same (differ by -228µs, within tolerance 1ms)
2020/01/19 15:44:51 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: Unchanged skipping
2020/01/19 15:44:51 DEBUG : Films/Le Retour du Jedi (1983)/Le Retour du Jedi (1983).nfo: transferred to remote
1 Like
ncw
January 20, 2020, 10:11am
12
Thanks for testing.
I've merged this fix to master now which means it will be in the latest beta in 15-30 mins and released in v1.51
system
April 19, 2020, 10:17am
13
This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.