Cache feature issues

Help and Support
1

I’ve more or less been unable to get the caching feature working in my testing. I have a google drive remote (non-crypt for now) that I’ve wrapped the cache around. When I attempt to access files in the cache, I get lots of low level retries and then failures. When I access the original non-cached one it seems to work just fine so I do not think this is a gdrive issue. I’ve tried different cache sizes (below was large for 200M but i’ve tried smaller too) just to play with and i’ve set actual times for the ages rather than the defaults but I’ve yet to actually download a file from the cached mount.

[robgd]
type = drive

[robgsc]
type = cache
remote = robgs:cams
chunk_size = 200M
info_age =
chunk_age =
warmup_age =

HS -> env | grep RCLO
RCLONE_TRANSFERS=64
RCLONE_BUFFER_SIZE=0M
RCLONE_CHECKERS=64
RCLONE_RETRIES=5
RCLONE_STATS=0
RCLONE_DRIVE_USE_TRASH=false
RCLONE_TIMEOUT=10m
RCLONE_LOG_LEVEL=INFO
RCLONE_CONFIG=/home/robert/.rclone.conf

/usr/sbin/rclone -vv --cache-workers=2 mount robgsc: /home/robert/camc --allow-other --default-permissions --gid $gid --uid $uid --dir-cache-time=1m --umask $UMASK

HS -> cp 01_20171107234210000.MP4 ~/
2017/11/20 10:57:13 DEBUG : frontyard/20171107/: Lookup: name=“01_20171107234210000.MP4”
2017/11/20 10:57:13 DEBUG : frontyard/20171107/: >Lookup: node=frontyard/20171107/01_20171107234210000.MP4, err=
2017/11/20 10:57:13 DEBUG : frontyard/20171107/01_20171107234210000.MP4: Attr:
2017/11/20 10:57:13 DEBUG : frontyard/20171107/01_20171107234210000.MP4: >Attr: a=valid=1m0s ino=0 size=458316208 mode=-rw-rw-r–, err=
2017/11/20 10:57:13 DEBUG : frontyard/20171107/01_20171107234210000.MP4: Open: flags=OpenReadOnly
2017/11/20 10:57:13 DEBUG : frontyard/20171107/01_20171107234210000.MP4: Open: flags=O_RDONLY|O_CREATE
2017/11/20 10:57:13 DEBUG : frontyard/20171107/01_20171107234210000.MP4: >Open: fd=frontyard/20171107/01_20171107234210000.MP4 ®, err=
2017/11/20 10:57:13 DEBUG : frontyard/20171107/01_20171107234210000.MP4: >Open: fh=&{frontyard/20171107/01_20171107234210000.MP4 ®}, err=
2017/11/20 10:57:13 DEBUG : &{frontyard/20171107/01_20171107234210000.MP4 ®}: Read: len=131072, offset=0
2017/11/20 10:57:13 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 0
2017/11/20 10:57:14 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 1
2017/11/20 10:57:15 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 2
2017/11/20 10:57:16 ERROR : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.Read error: low level retry 1/10: EOF
2017/11/20 10:57:16 DEBUG : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.seek from 0 to 0
2017/11/20 10:57:22 DEBUG : frontyard/20171107/01_20171107234210000.MP4: cache reader closed 0
2017/11/20 10:57:22 DEBUG : frontyard/20171107/01_20171107234210000.MP4: moving offset set from 0 to 0
2017/11/20 10:57:22 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 0
2017/11/20 10:57:23 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 1
2017/11/20 10:57:24 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 2
2017/11/20 10:57:25 ERROR : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.Read error: low level retry 2/10: EOF
2017/11/20 10:57:25 DEBUG : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.seek from 0 to 0
2017/11/20 10:57:31 DEBUG : frontyard/20171107/01_20171107234210000.MP4: cache reader closed 0
2017/11/20 10:57:31 DEBUG : frontyard/20171107/01_20171107234210000.MP4: moving offset set from 0 to 0
2017/11/20 10:57:31 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 0
2017/11/20 10:57:32 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 1
2017/11/20 10:57:33 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 2
2017/11/20 10:57:34 ERROR : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.Read error: low level retry 3/10: EOF
2017/11/20 10:57:34 DEBUG : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.seek from 0 to 0
2017/11/20 10:57:40 DEBUG : frontyard/20171107/01_20171107234210000.MP4: cache reader closed 0
2017/11/20 10:57:40 DEBUG : frontyard/20171107/01_20171107234210000.MP4: moving offset set from 0 to 0
2017/11/20 10:57:40 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 0
2017/11/20 10:57:41 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 1
2017/11/20 10:57:42 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 2
2017/11/20 10:57:43 ERROR : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.Read error: low level retry 4/10: EOF
2017/11/20 10:57:43 DEBUG : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.seek from 0 to 0
2017/11/20 10:57:49 DEBUG : frontyard/20171107/01_20171107234210000.MP4: cache reader closed 0
2017/11/20 10:57:49 DEBUG : frontyard/20171107/01_20171107234210000.MP4: moving offset set from 0 to 0
2017/11/20 10:57:49 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 0
2017/11/20 10:57:50 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 1
2017/11/20 10:57:51 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 2
2017/11/20 10:57:52 ERROR : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.Read error: low level retry 5/10: EOF
2017/11/20 10:57:52 DEBUG : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.seek from 0 to 0
2017/11/20 10:57:58 DEBUG : frontyard/20171107/01_20171107234210000.MP4: cache reader closed 0
2017/11/20 10:57:58 DEBUG : frontyard/20171107/01_20171107234210000.MP4: moving offset set from 0 to 0
2017/11/20 10:57:58 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 0
2017/11/20 10:57:59 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 1
2017/11/20 10:58:00 DEBUG : /: Attr:
2017/11/20 10:58:00 DEBUG : /: >Attr: attr=valid=1m0s ino=0 size=0 mode=drwxrwxr-x, err=
2017/11/20 10:58:00 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 2
2017/11/20 10:58:01 ERROR : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.Read error: low level retry 6/10: EOF
2017/11/20 10:58:01 DEBUG : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.seek from 0 to 0
2017/11/20 10:58:07 DEBUG : frontyard/20171107/01_20171107234210000.MP4: cache reader closed 0
2017/11/20 10:58:07 DEBUG : frontyard/20171107/01_20171107234210000.MP4: moving offset set from 0 to 0
2017/11/20 10:58:07 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 0
2017/11/20 10:58:08 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 1
2017/11/20 10:58:09 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 2
2017/11/20 10:58:10 ERROR : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.Read error: low level retry 7/10: EOF
2017/11/20 10:58:10 DEBUG : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.seek from 0 to 0
2017/11/20 10:58:16 DEBUG : frontyard/20171107/01_20171107234210000.MP4: cache reader closed 0
2017/11/20 10:58:16 DEBUG : frontyard/20171107/01_20171107234210000.MP4: moving offset set from 0 to 0
2017/11/20 10:58:16 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 0
2017/11/20 10:58:17 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 1
2017/11/20 10:58:18 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 2
2017/11/20 10:58:19 ERROR : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.Read error: low level retry 8/10: EOF
2017/11/20 10:58:19 DEBUG : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.seek from 0 to 0
2017/11/20 10:58:25 DEBUG : frontyard/20171107/01_20171107234210000.MP4: cache reader closed 0
2017/11/20 10:58:25 DEBUG : frontyard/20171107/01_20171107234210000.MP4: moving offset set from 0 to 0
2017/11/20 10:58:25 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 0
2017/11/20 10:58:26 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 1
2017/11/20 10:58:27 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 2
2017/11/20 10:58:28 ERROR : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.Read error: low level retry 9/10: EOF
2017/11/20 10:58:28 DEBUG : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.seek from 0 to 0
2017/11/20 10:58:34 DEBUG : frontyard/20171107/01_20171107234210000.MP4: cache reader closed 0
2017/11/20 10:58:34 DEBUG : frontyard/20171107/01_20171107234210000.MP4: moving offset set from 0 to 0
2017/11/20 10:58:34 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 0
2017/11/20 10:58:35 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 1
2017/11/20 10:58:36 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 2
2017/11/20 10:58:37 ERROR : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.Read error: low level retry 10/10: EOF
2017/11/20 10:58:37 DEBUG : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.seek from 0 to 0
2017/11/20 10:58:43 DEBUG : frontyard/20171107/01_20171107234210000.MP4: cache reader closed 0
2017/11/20 10:58:43 DEBUG : frontyard/20171107/01_20171107234210000.MP4: moving offset set from 0 to 0
2017/11/20 10:58:43 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 0
2017/11/20 10:58:44 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 1
2017/11/20 10:58:45 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 2
2017/11/20 10:58:46 ERROR : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.Read error: EOF
2017/11/20 10:58:46 DEBUG : &{frontyard/20171107/01_20171107234210000.MP4 ®}: >Read: read=0, err=
2017/11/20 10:58:46 DEBUG : &{frontyard/20171107/01_20171107234210000.MP4 ®}: Flush:
2017/11/20 10:58:46 DEBUG : &{frontyard/20171107/01_20171107234210000.MP4 ®}: >Flush: err=
2017/11/20 10:58:46 DEBUG : &{frontyard/20171107/01_20171107234210000.MP4 ®}: Release:
2017/11/20 10:58:46 DEBUG : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.Release closing
✓ robert [~/camc/frontyard/20171107] $
HS -> 2017/11/20 10:58:52 DEBUG : frontyard/20171107/01_20171107234210000.MP4: cache reader closed 0
2017/11/20 10:58:52 DEBUG : &{frontyard/20171107/01_20171107234210000.MP4 ®}: >Release: err=
2017/11/20 10:59:16 DEBUG : /: Attr:
2017/11/20 10:59:16 DEBUG : /: >Attr: attr=valid=1m0s ino=0 size=0 mode=drwxrwxr-x, err=
2017/11/20 11:00:17 DEBUG : worker-0 <01_20171107234210000.MP4>: downloaded chunk 0
2017/11/20 11:01:13 DEBUG : worker-1 <01_20171107234210000.MP4>: downloaded chunk 200M

2

Which rclone version are you using? I think I’ve broken something important just recently :frowning:

3

HS -> rclone --version
rclone v1.38-160-gaf50f31fβ

  • os/arch: linux/amd64
  • go version: go1.9.2
4

2017/11/20 10:57:13 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 0
2017/11/20 10:57:14 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 1
2017/11/20 10:57:15 DEBUG : frontyard/20171107/01_20171107234210000.MP4: 0: chunk retry storage: 2
2017/11/20 10:57:16 ERROR : frontyard/20171107/01_20171107234210000.MP4: ReadFileHandle.Read error: low level retry 1/10: EOF

This is a good indication of what’s wrong. You’re using a very large chunk size for the bandwidth you’re having. You could have 1Gbps link and I bet it wouldn’t be enough.
What’s happening is that rclone doesn’t have enough time to download the individual chunks so that the reader can access them. Since the reader is independent of the downloader it has no way of knowing when a chunk is downloaded or not. That’s why this limitation.

I think this can be improved but I wouldn’t really recommend these chunk sizes anyway. If you’re using Plex (or any other metadata reader like: Windows Explorer, Finder) they will require small bytes of the files and rclone will download these huge chunks for some couple of bytes.
It’s explained in the docs too which I can’t seem to find. @ncw I think I forgot a step to update the docs or is that something you do in a separate process?

You did mentioned that you you tried smaller chunk sizes. I would be curious what’s your bandwidth and other sizes tried.

Thanks

5

The docs are here - they will make it to the web site at the next release.

6

The chunk size isn’t the issue. I’ve tried 1M, 5M, 10M chunks and I have a gigabit connection. The reader here is a simple ‘cp’ command.

Here is 5M chunks
[robgsc]
type = cache
remote = robgs:
chunk_size = 5M
info_age =
chunk_age =
warmup_age =

/usr/sbin/rclone -vv --cache-workers=2 mount robgsc: /home/robert/camc --allow-other --default-permissions --gid $gid --uid $uid --dir-cache-time=1m --umask $UMASK

S -> cp ./01_20171111234207000.MP4 ~/
2017/11/20 14:30:39 DEBUG : cams/frontyard/20171111/: Lookup: name=“01_20171111234207000.MP4”
2017/11/20 14:30:39 DEBUG : cams/frontyard/20171111: Re-reading directory (2m11.910853882s old)
2017/11/20 14:30:39 DEBUG : cams/frontyard/20171111/: >Lookup: node=cams/frontyard/20171111/01_20171111234207000.MP4, err=
2017/11/20 14:30:39 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: Attr:
2017/11/20 14:30:39 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: >Attr: a=valid=1m0s ino=0 size=524011013 mode=-rw-rw-r–, err=
2017/11/20 14:30:39 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: Open: flags=OpenReadOnly
2017/11/20 14:30:39 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: Open: flags=O_RDONLY|O_CREATE
2017/11/20 14:30:39 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: >Open: fd=cams/frontyard/20171111/01_20171111234207000.MP4 ®, err=
2017/11/20 14:30:39 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: >Open: fh=&{cams/frontyard/20171111/01_20171111234207000.MP4 ®}, err=
2017/11/20 14:30:39 DEBUG : &{cams/frontyard/20171111/01_20171111234207000.MP4 ®}: Read: len=131072, offset=0
2017/11/20 14:30:39 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: 0: chunk retry storage: 0
2017/11/20 14:30:40 DEBUG : worker-0 <01_20171111234207000.MP4>: downloaded chunk 5M
2017/11/20 14:30:40 ERROR : worker-0 <01_20171111234207000.MP4>: failed caching chunk in storage 5242880: open /home/robert/cache/robgsc/cams/frontyard/20171111/01_20171111234207000.MP4/5242880: no such file or directory
2017/11/20 14:30:40 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: 0: chunk retry storage: 1
2017/11/20 14:30:40 DEBUG : worker-1 <01_20171111234207000.MP4>: downloaded chunk 0
2017/11/20 14:30:40 ERROR : worker-1 <01_20171111234207000.MP4>: failed caching chunk in storage 0: open /home/robert/cache/robgsc/cams/frontyard/20171111/01_20171111234207000.MP4/0: no such file or directory
2017/11/20 14:30:41 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: 0: chunk retry storage: 2
2017/11/20 14:30:42 ERROR : cams/frontyard/20171111/01_20171111234207000.MP4: ReadFileHandle.Read error: low level retry 1/10: EOF
2017/11/20 14:30:42 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: ReadFileHandle.seek from 0 to 0
2017/11/20 14:30:43 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: cache reader closed 0
2017/11/20 14:30:43 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: moving offset set from 0 to 0
2017/11/20 14:30:43 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: 0: chunk retry storage: 0
2017/11/20 14:30:44 DEBUG : worker-0 <01_20171111234207000.MP4>: downloaded chunk 0
2017/11/20 14:30:44 ERROR : worker-0 <01_20171111234207000.MP4>: failed caching chunk in storage 0: open /home/robert/cache/robgsc/cams/frontyard/20171111/01_20171111234207000.MP4/0: no such file or directory
2017/11/20 14:30:44 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: 0: chunk retry storage: 1
2017/11/20 14:30:45 DEBUG : worker-1 <01_20171111234207000.MP4>: downloaded chunk 5M
2017/11/20 14:30:45 ERROR : worker-1 <01_20171111234207000.MP4>: failed caching chunk in storage 5242880: open /home/robert/cache/robgsc/cams/frontyard/20171111/01_20171111234207000.MP4/5242880: no such file or directory
2017/11/20 14:30:45 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: 0: chunk retry storage: 2
^C2017/11/20 14:30:46 ERROR : cams/frontyard/20171111/01_20171111234207000.MP4: ReadFileHandle.Read error: low level retry 2/10: EOF
2017/11/20 14:30:46 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: ReadFileHandle.seek from 0 to 0
2017/11/20 14:30:47 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: cache reader closed 0
2017/11/20 14:30:47 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: moving offset set from 0 to 0
2017/11/20 14:30:47 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: 0: chunk retry storage: 0

HS -> ls -al ./01_20171111234207000.MP4
2017/11/20 14:32:04 DEBUG : cams/frontyard/20171111/: Attr:
2017/11/20 14:32:04 DEBUG : cams/frontyard/20171111/: >Attr: attr=valid=1m0s ino=0 size=0 mode=drwxrwxr-x, err=
2017/11/20 14:32:04 DEBUG : cams/frontyard/20171111/: Lookup: name=“01_20171111234207000.MP4”
2017/11/20 14:32:04 DEBUG : cams/frontyard/20171111: Re-reading directory (1m24.583686465s old)
2017/11/20 14:32:04 DEBUG : cams/frontyard/20171111/: >Lookup: node=cams/frontyard/20171111/01_20171111234207000.MP4, err=
2017/11/20 14:32:04 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: Attr:
2017/11/20 14:32:04 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: >Attr: a=valid=1m0s ino=0 size=524011013 mode=-rw-rw-r–, err=
2017/11/20 14:32:04 DEBUG : cams/frontyard/20171111/: Lookup: name=“01_20171111234207000.MP4”
2017/11/20 14:32:04 DEBUG : cams/frontyard/20171111/: >Lookup: node=cams/frontyard/20171111/01_20171111234207000.MP4, err=
2017/11/20 14:32:04 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: Attr:
2017/11/20 14:32:04 DEBUG : cams/frontyard/20171111/01_20171111234207000.MP4: >Attr: a=valid=1m0s ino=0 size=524011013 mode=-rw-rw-r–, err=
-rw-rw-r-- 1 deluge mediashare 524011013 Nov 11 23:57 ./01_20171111234207000.MP4

7

Yes, in this case it’s something else. In the first example it wasn’t visible because of the size issue I mentioned.
Is rclone’s config path in /home/robert/cache ?

failed caching chunk in storage 5242880: open /home/robert/cache/robgsc/cams/frontyard/20171111/01_20171111234207000.MP4/5242880: no such file or directory

It seems rclone can’t write the cache data in this folder for some reason. I assume disk space isn’t an issue, these would be only a couple of MB.
Would you be so kind to tell me if you see something in /home/robert/cache/robgsc ? All those paths should be there if it actually worked.

8 
HS -> ls -al
total 8508
drwxrwxr-x   3 robert robert         4096 Nov 20 10:01 .
drwxrwxr-x 126 robert mediashare    45056 Nov 20 14:36 ..
drwxrwxr-x   5 robert robert         4096 Nov 20 14:26 robgsc
-rw-r--r--   1 robert robert     25169920 Nov 20 14:30 robgsc.db
✓ robert [~/cache] $
HS -> find . robgsc
.
./robgsc.db
./robgsc
./robgsc/cams
./robgsc/cams/backyard
./robgsc/cams/backyard/20171107
./robgsc/cams/backyard/20171107/01_20171107004405.JPG
./robgsc/cams/backyard/20171107/01_20171107004405.JPG/0
./robgsc/cams/backyard/20171107/01_20171107003533.JPG
./robgsc/cams/backyard/20171107/01_20171107003533.JPG/0
./robgsc/cams/backyard/20171107/01_20171107002700.JPG
./robgsc/cams/backyard/20171107/01_20171107002700.JPG/0
./robgsc/cams/backyard/20171107/01_20171107001828.JPG
./robgsc/cams/backyard/20171107/01_20171107001828.JPG/0
./robgsc/cams/backyard/20171107/01_20171107005238.JPG
./robgsc/cams/backyard/20171107/01_20171107005238.JPG/0
./robgsc/cams/backyard/20171107/01_20171107000954.JPG
./robgsc/cams/backyard/20171107/01_20171107213304.JPG
./robgsc/cams/backyard/20171107/01_20171107014350000.MP4
./robgsc/cams/backyard/20171107/01_20171107000123.JPG
./robgsc/cams/backyard/20171107/01_20171107071522000.MP4
./robgsc/cams/backyard/20171107/01_20171107071522000.MP4/262144000
./robgsc/cams/backyard/20171107/01_20171107071522000.MP4/0
./robgsc/cams/backyard/20171107/01_20171107071522000.MP4/524288000
./robgsc/cams/backyard/20171107/01_20171107071522000.MP4/251658240
./robgsc/cams/backyard/20171107/01_20171107071522000.MP4/513802240
./robgsc/cams/backyard/20171114
./robgsc/cams/backyard/20171114/01_20171114231204000.MP4
./robgsc/cams/backyard/20171114/01_20171114231204000.MP4/503316480
./robgsc/cams/backyard/20171114/01_20171114231204000.MP4/0
./robgsc/cams/backyard/20171114/01_20171114231204000.MP4/10485760
./robgsc/cams/backyard/20171114/01_20171114231204000.MP4/20971520
./robgsc/cams/backyard/20171114/01_20171114231204000.MP4/31457280
./robgsc/cams/backyard/20171114/01_20171114231204000.MP4/513802240
./robgsc/Media
./robgsc/Media/Videos
./robgsc/Media/Videos/Movies
./robgsc/Media/Videos/Movies/Up.Bdrip
./robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi
./robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/47185920
./robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/52428800
./robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/26214400
./robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/41943040
./robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/36700160
./robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/15728640
./robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/0
./robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/5242880
./robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/10485760
./robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/57671680
./robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/20971520
./robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/31457280
./robgsc/frontyard
./robgsc/frontyard/20171107
./robgsc/frontyard/20171107/01_20171107234210000.MP4
robgsc
robgsc/cams
robgsc/cams/backyard
robgsc/cams/backyard/20171107
robgsc/cams/backyard/20171107/01_20171107004405.JPG
robgsc/cams/backyard/20171107/01_20171107004405.JPG/0
robgsc/cams/backyard/20171107/01_20171107003533.JPG
robgsc/cams/backyard/20171107/01_20171107003533.JPG/0
robgsc/cams/backyard/20171107/01_20171107002700.JPG
robgsc/cams/backyard/20171107/01_20171107002700.JPG/0
robgsc/cams/backyard/20171107/01_20171107001828.JPG
robgsc/cams/backyard/20171107/01_20171107001828.JPG/0
robgsc/cams/backyard/20171107/01_20171107005238.JPG
robgsc/cams/backyard/20171107/01_20171107005238.JPG/0
robgsc/cams/backyard/20171107/01_20171107000954.JPG
robgsc/cams/backyard/20171107/01_20171107213304.JPG
robgsc/cams/backyard/20171107/01_20171107014350000.MP4
robgsc/cams/backyard/20171107/01_20171107000123.JPG
robgsc/cams/backyard/20171107/01_20171107071522000.MP4
robgsc/cams/backyard/20171107/01_20171107071522000.MP4/262144000
robgsc/cams/backyard/20171107/01_20171107071522000.MP4/0
robgsc/cams/backyard/20171107/01_20171107071522000.MP4/524288000
robgsc/cams/backyard/20171107/01_20171107071522000.MP4/251658240
robgsc/cams/backyard/20171107/01_20171107071522000.MP4/513802240
robgsc/cams/backyard/20171114
robgsc/cams/backyard/20171114/01_20171114231204000.MP4
robgsc/cams/backyard/20171114/01_20171114231204000.MP4/503316480
robgsc/cams/backyard/20171114/01_20171114231204000.MP4/0
robgsc/cams/backyard/20171114/01_20171114231204000.MP4/10485760
robgsc/cams/backyard/20171114/01_20171114231204000.MP4/20971520
robgsc/cams/backyard/20171114/01_20171114231204000.MP4/31457280
robgsc/cams/backyard/20171114/01_20171114231204000.MP4/513802240
robgsc/Media
robgsc/Media/Videos
robgsc/Media/Videos/Movies
robgsc/Media/Videos/Movies/Up.Bdrip
robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi
robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/47185920
robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/52428800
robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/26214400
robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/41943040
robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/36700160
robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/15728640
robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/0
robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/5242880
robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/10485760
robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/57671680
robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/20971520
robgsc/Media/Videos/Movies/Up.Bdrip/Up.Bdrip.avi/31457280
robgsc/frontyard
robgsc/frontyard/20171107
robgsc/frontyard/20171107/01_20171107234210000.MP4
✓ robert [~/cache] $

HS -> df -k /home
Filesystem 1K-blocks Used Available Use% Mounted on
/dev/sda5 102249808 66956740 30076000 70% /home

9

I think I see the issue.

HS -> ls -al robgsc
total 20
drwxrwxr-x 5 robert robert 4096 Nov 20 14:26 .
drwxrwxr-x 3 robert robert 4096 Nov 20 10:01 …
drwxr-xr-x 3 root root 4096 Nov 20 10:03 cams
drwxrwxr-x 3 robert robert 4096 Nov 20 11:00 frontyard
drwxrwxr-x 3 robert robert 4096 Nov 20 14:26 Media
✓ robert [~/cache] $
HS -> ls -al robgsc/*
robgsc/cams:
total 12
drwxr-xr-x 3 root root 4096 Nov 20 10:03 .
drwxrwxr-x 5 robert robert 4096 Nov 20 14:26 …
drwxr-xr-x 4 root root 4096 Nov 20 10:11 backyard

robgsc/frontyard:
total 12
drwxrwxr-x 3 robert robert 4096 Nov 20 11:00 .
drwxrwxr-x 5 robert robert 4096 Nov 20 14:26 …
drwxrwxr-x 3 robert robert 4096 Nov 20 11:00 20171107

10

Woau, ok. This really just looks like standard stuff. It’s interesting that other files made it too. I’m just fishing here so bear with me: is this maybe a NTFS drive mounted on a Linux? Again, just fishing for special details that might give me a lead on what to try.

Give me some details like the ones I mentioned earlier about the environment and I’ll try to run the tests on them, maybe even try to reproduce it too.

LE: Ok. Permission issue would do that. The error isn’t very clear I must say. How did the other files made it though?

11

I’m going to assume its human error. I must have ran as root and then ran as a user. Deleting the cache entirely and it seems to be working again. I’m quite used to being able to run as root and a user without issues but the cache complicates that a bit.

12

Note that I committed a change which changes the default cache location if you aren’t using --cache-db-path , and I also just committed a fix to mount which could possibly be related, so if you want to try both they are in

https://beta.rclone.org/v1.38-166-gcb6de4a2/ (uploaded in 15-30 mins)

13

Although the permission issue was a real issue and I can now copy files… I still cannot stream anything through the cache.

But I think I found the issue. It appears that my source file is getting whacked on open by VLC???

HS -> ls -al 01_20171111231146000.MP4
-rw-rw-r-- 1 deluge mediashare 524452729 Nov 11 23:27 01_20171111231146000.MP4

HS -> vlc /data/camc/frontyard/20171111/01_20171111231146000.MP4
VLC media player 2.1.6 Rincewind (revision 2.1.6-0-gea01d28)
[0x10b0118] main libvlc: Running vlc with the default interface. Use ‘cvlc’ to use vlc without interface.
Qt at-spi: error getting the accessibility dbus address: “Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.”
Connected to accessibility bus at: “unix:abstract=/tmp/dbus-54G74b3s8r,guid=b1796ab5327b7c77f376952b5a088058”
Registered DEC: true
Registered event listener change listener: true
[0x7f5208001388] main stream error: cannot pre fill buffer
^C✓ robert [/data/camc/frontyard/20171111] $

HS -> ls -al 01_20171111231146000.MP4
-rw-rw-r-- 1 deluge mediashare 0 Nov 20 15:11 01_20171111231146000.MP4
✓ robert [/data/camc/frontyard/20171111] $

14

I’m starting to think this is a MUCH bigger issue than VLC. Check this out with parole:

HS -> parole  ./01_20171111193217000.MP4
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name=".hidden"
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: Open: flags=OpenReadWrite
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: Open: flags=O_RDWR|O_CREATE
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: >Open: fd=cams/frontyard/20171111/01_20171111193217000.MP4 (w), err=<nil>
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: >Open: fh=&{cams/frontyard/20171111/01_20171111193217000.MP4 (w)}, err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (w)}: Flush: 
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: WriteFileHandle.Flush ignoring flush on unwritten handle
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (w)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (w)}: Release: 
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: WriteFileHandle.Release closing
2017/11/20 15:23:59 DEBUG : robgsc:: File to upload is small (0 bytes), uploading instead of streaming
2017/11/20 15:23:59 DEBUG : robgsc:: put data at 'cams/frontyard/20171111/01_20171111193217000.MP4'
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: Open: flags=OpenReadWrite
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: Open: flags=O_RDWR|O_CREATE
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: >Open: fd=cams/frontyard/20171111/01_20171111193217000.MP4 (w), err=<nil>
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: >Open: fh=&{cams/frontyard/20171111/01_20171111193217000.MP4 (w)}, err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (w)}: Flush: 
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: WriteFileHandle.Flush ignoring flush on unwritten handle
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (w)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (w)}: Release: 
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: WriteFileHandle.Release closing
2017/11/20 15:23:59 DEBUG : robgsc:: File to upload is small (0 bytes), uploading instead of streaming
2017/11/20 15:23:59 DEBUG : robgsc:: put data at 'cams/frontyard/20171111/01_20171111193217000.MP4'
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="01_20171111193217000.asc"
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="01_20171111193217000.asc"
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="01_20171111193217000.txt"
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="01_20171111193217000.txt"
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="01_20171111193217000.sub"
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="01_20171111193217000.sub"
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="01_20171111193217000.srt"
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="01_20171111193217000.srt"
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="01_20171111193217000.smi"
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="01_20171111193217000.smi"
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="01_20171111193217000.ssa"
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="01_20171111193217000.ssa"
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="01_20171111193217000.ass"
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="01_20171111193217000.ass"
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="..."
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: Open: flags=OpenReadOnly
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: Open: flags=O_RDONLY|O_CREATE
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: >Open: fd=cams/frontyard/20171111/01_20171111193217000.MP4 (r), err=<nil>
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: >Open: fh=&{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}, err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Release: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Release: err=<nil>
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: Open: flags=OpenReadOnly
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: Open: flags=O_RDONLY|O_CREATE
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: >Open: fd=cams/frontyard/20171111/01_20171111193217000.MP4 (r), err=<nil>
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: >Open: fh=&{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}, err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Release: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Release: err=<nil>
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: Open: flags=OpenReadOnly
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: Open: flags=O_RDONLY|O_CREATE
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: >Open: fd=cams/frontyard/20171111/01_20171111193217000.MP4 (r), err=<nil>
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: >Open: fh=&{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}, err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Read: len=16384, offset=0
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="..."
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: reached EOF 0
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Read: read=0, err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: Attr: 
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: >Attr: a=valid=1m0s ino=0 size=0 mode=-rw-rw-r--, err=<nil>
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: object hash cached: d41d8cd98f00b204e9800998ecf8427e
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Read: len=4096, offset=0
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: reached EOF 0
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Read: read=0, err=<nil>
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: Attr: 
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: >Attr: a=valid=1m0s ino=0 size=0 mode=-rw-rw-r--, err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Read: len=4096, offset=133054464
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: ReadFileHandle.Read attempt to read beyond end of file: 133054464 > 0
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Read: read=0, err=<nil>
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: Attr: 
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: >Attr: a=valid=1m0s ino=0 size=0 mode=-rw-rw-r--, err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Flush: 
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: Release: 
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: ReadFileHandle.Release closing
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: cache reader closed 0
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (r)}: >Release: err=<nil>
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="..."
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: Lookup: name="..."
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
2017/11/20 15:23:59 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: Size and modification time the same (differ by -412.389µs, within tolerance 1ms)
2017/11/20 15:23:59 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (w)}: >Release: err=<nil>
2017/11/20 15:24:00 DEBUG : cams/frontyard/20171111/01_20171111193217000.MP4: Size and modification time the same (differ by -361.627µs, within tolerance 1ms)
2017/11/20 15:24:00 DEBUG : &{cams/frontyard/20171111/01_20171111193217000.MP4 (w)}: >Release: err=<nil>

(parole:13476): GLib-CRITICAL **: Source ID 56 was not found when attempting to remove it
2017/11/20 15:24:03 DEBUG : cams/frontyard/20171111/: Lookup: name="..."
2017/11/20 15:24:03 DEBUG : cams/frontyard/20171111/: >Lookup: node=<nil>, err=no such file or directory
✓ robert [~/camc/cams/frontyard/20171111] $
HS -> ls -al ./01_20171111193217000.MP4
-rw-rw-r-- 1 deluge mediashare 0 Nov 11 00:07 ./01_20171111193217000.MP4
✓ robert [~/camc/cams/frontyard/20171111] $

If you look at the bytes, its now ZERO after trying to play it. This happened with both parole and VLC. Something fishy is going on here and its whacking the files.

15

That is what I’ve just fixed!

1 Like
16

Ah Good!!! I’ll check out hte new version.

17

It has made it to https://beta.rclone.org/v1.38-166-gcb6de4a2/ now

18

BTW what happened is VLC opens the file read/write when it only wanted to read… rclone truncated the file at this point assuming that write intent meant I am going to overwrite the whole file :frowning_face: I put in a check for this and a test too.

Luckily this has only been in the repo for a few hours today!

19

haha. Yea. Thats why I test on data on dont care about. Looks better now. Let me play with streaming now. THanks!!

1 Like
20

streaming now works. I’ve had it freeze though and start consuming a whole cpu core. I had to terminate it. The latest run generated this stack trace after a little while.

2017/11/20 15:54:26 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: >Read: read=131072, err=<nil>
2017/11/20 15:54:27 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: Read: len=131072, offset=191934464
2017/11/20 15:54:27 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: >Read: read=131072, err=<nil>
2017/11/20 15:54:27 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: Read: len=131072, offset=192065536
2017/11/20 15:54:27 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: >Read: read=131072, err=<nil>
2017/11/20 15:54:27 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: Read: len=131072, offset=192196608
2017/11/20 15:54:27 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: >Read: read=131072, err=<nil>
2017/11/20 15:54:28 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: Read: len=131072, offset=192327680
2017/11/20 15:54:28 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: >Read: read=131072, err=<nil>
2017/11/20 15:54:28 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: Read: len=131072, offset=192458752
2017/11/20 15:54:28 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: >Read: read=131072, err=<nil>
2017/11/20 15:54:28 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: Read: len=131072, offset=192589824
2017/11/20 15:54:28 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: >Read: read=131072, err=<nil>
2017/11/20 15:54:28 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: Read: len=131072, offset=192720896
2017/11/20 15:54:28 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: >Read: read=131072, err=<nil>
2017/11/20 15:54:28 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: Read: len=131072, offset=192851968
2017/11/20 15:54:28 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: >Read: read=131072, err=<nil>
2017/11/20 15:54:28 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: Read: len=131072, offset=192983040
2017/11/20 15:54:28 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: >Read: read=131072, err=<nil>
2017/11/20 15:54:29 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: Read: len=12288, offset=345751552
2017/11/20 15:54:29 DEBUG : cams/frontyard/20171111/01_20171111220713000.MP4: ReadFileHandle.seek from 193114112 to 345751552 (io.Seeker)
2017/11/20 15:54:29 DEBUG : cams/frontyard/20171111/01_20171111220713000.MP4: moving offset set from 193114112 to 345751552
2017/11/20 15:54:29 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: >Read: read=0, err=<nil>
2017/11/20 15:54:29 fuse: panic in handler for Read [ID=0x1ac2 Node=0xb72 Uid=1000 Gid=1000 Pid=31253] 0x2 12288 @0x149bc000 dir=false fl=0 lock=0 ffl=OpenReadOnly: runtime error: slice bounds out of range
goroutine 1927 [running]:
github.com/ncw/rclone/vendor/bazil.org/fuse/fs.(*Server).serve.func2(0x157a300, 0xc42060e150, 0xc42050def8, 0xc42050de6f)
	/home/travis/gopath/src/github.com/ncw/rclone/vendor/bazil.org/fuse/fs/serve.go:857 +0x1b1
panic(0xe553c0, 0x15c2c40)
	/home/travis/.gimme/versions/go1.9.2.linux.amd64/src/runtime/panic.go:491 +0x283
github.com/ncw/rclone/cache.(*Handle).getChunk(0xc420a06500, 0x14000000, 0xc420a06538, 0x2, 0x2, 0x73deeb, 0xf99f07)
	/home/travis/gopath/src/github.com/ncw/rclone/cache/handle.go:213 +0x65a
github.com/ncw/rclone/cache.(*Handle).Read(0xc420a06500, 0xc4234cd000, 0x3000, 0x3000, 0x0, 0x0, 0x0)
	/home/travis/gopath/src/github.com/ncw/rclone/cache/handle.go:226 +0xa4
github.com/ncw/rclone/fs.(*Account).read(0xc420287290, 0x7f292fec1b90, 0xc420a06500, 0xc4234cd000, 0x3000, 0x3000, 0x2, 0xc42029cfc0, 0x77)
	/home/travis/gopath/src/github.com/ncw/rclone/fs/accounting.go:470 +0x115
github.com/ncw/rclone/fs.(*Account).Read(0xc420287290, 0xc4234cd000, 0x3000, 0x3000, 0x0, 0x0, 0x0)
	/home/travis/gopath/src/github.com/ncw/rclone/fs/accounting.go:502 +0x152
io.ReadAtLeast(0x1570900, 0xc420287290, 0xc4234cd000, 0x3000, 0x3000, 0x3000, 0xc42023a0a8, 0xde10c0, 0xc42023a0c0)
	/home/travis/.gimme/versions/go1.9.2.linux.amd64/src/io/io.go:309 +0x86
io.ReadFull(0x1570900, 0xc420287290, 0xc4234cd000, 0x3000, 0x3000, 0xc4202c2220, 0x2, 0xc42050d948)
	/home/travis/.gimme/versions/go1.9.2.linux.amd64/src/io/io.go:327 +0x58
github.com/ncw/rclone/vfs.(*ReadFileHandle).readAt(0xc42060e070, 0xc4234cd000, 0x3000, 0x3000, 0x149bc000, 0xde1cc0, 0xc42050da01, 0xc4234cd000)
	/home/travis/gopath/src/github.com/ncw/rclone/vfs/read.go:219 +0x55e
github.com/ncw/rclone/vfs.(*ReadFileHandle).ReadAt(0xc42060e070, 0xc4234cd000, 0x3000, 0x3000, 0x149bc000, 0x0, 0x0, 0x0)
	/home/travis/gopath/src/github.com/ncw/rclone/vfs/read.go:179 +0xae
github.com/ncw/rclone/cmd/mount.(*FileHandle).Read(0xc420452270, 0x157bfc0, 0xc420712140, 0xc42060e150, 0xc4202ce080, 0x3001, 0x0)
	/home/travis/gopath/src/github.com/ncw/rclone/cmd/mount/handle.go:28 +0x294
github.com/ncw/rclone/vendor/bazil.org/fuse/fs.(*Server).handleRequest(0xc4204640c0, 0x157bfc0, 0xc420712140, 0x1570880, 0xc420ab30a0, 0xc4206e4fc0, 0x157a300, 0xc42060e150, 0xc42050def8, 0xc4209da428, ...)
	/home/travis/gopath/src/github.com/ncw/rclone/vendor/bazil.org/fuse/fs/serve.go:1249 +0x941
github.com/ncw/rclone/vendor/bazil.org/fuse/fs.(*Server).serve(0xc4204640c0, 0x157a300, 0xc42060e150)
	/home/travis/gopath/src/github.com/ncw/rclone/vendor/bazil.org/fuse/fs/serve.go:878 +0x468
github.com/ncw/rclone/vendor/bazil.org/fuse/fs.(*Server).Serve.func1(0xc4204640c0, 0x157a300, 0xc42060e150)
	/home/travis/gopath/src/github.com/ncw/rclone/vendor/bazil.org/fuse/fs/serve.go:425 +0x6e
created by github.com/ncw/rclone/vendor/bazil.org/fuse/fs.(*Server).Serve
	/home/travis/gopath/src/github.com/ncw/rclone/vendor/bazil.org/fuse/fs/serve.go:423 +0x35f
2017/11/20 15:54:29 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: Read: len=4096, offset=345751552
2017/11/20 15:54:29 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: >Read: read=0, err=<nil>
2017/11/20 15:54:29 fuse: panic in handler for Read [ID=0x1ac3 Node=0xb72 Uid=1000 Gid=1000 Pid=31253] 0x2 4096 @0x149bc000 dir=false fl=0 lock=0 ffl=OpenReadOnly: runtime error: slice bounds out of range
goroutine 1928 [running]:
github.com/ncw/rclone/vendor/bazil.org/fuse/fs.(*Server).serve.func2(0x157a300, 0xc42060e1c0, 0xc42050def8, 0xc42050de6f)
	/home/travis/gopath/src/github.com/ncw/rclone/vendor/bazil.org/fuse/fs/serve.go:857 +0x1b1
panic(0xe553c0, 0x15c2c40)
	/home/travis/.gimme/versions/go1.9.2.linux.amd64/src/runtime/panic.go:491 +0x283
github.com/ncw/rclone/cache.(*Handle).getChunk(0xc420a06500, 0x14000000, 0xc420a06538, 0x0, 0x0, 0x0, 0x36)
	/home/travis/gopath/src/github.com/ncw/rclone/cache/handle.go:213 +0x65a
github.com/ncw/rclone/cache.(*Handle).Read(0xc420a06500, 0xc4202d9000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/home/travis/gopath/src/github.com/ncw/rclone/cache/handle.go:226 +0xa4
github.com/ncw/rclone/fs.(*Account).read(0xc420287290, 0x7f292fec1b90, 0xc420a06500, 0xc4202d9000, 0x1000, 0x1000, 0xc42006e0f0, 0xc42089d900, 0x76)
	/home/travis/gopath/src/github.com/ncw/rclone/fs/accounting.go:470 +0x115
github.com/ncw/rclone/fs.(*Account).Read(0xc420287290, 0xc4202d9000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/home/travis/gopath/src/github.com/ncw/rclone/fs/accounting.go:502 +0x152
io.ReadAtLeast(0x1570900, 0xc420287290, 0xc4202d9000, 0x1000, 0x1000, 0x1000, 0x2, 0xc420984310, 0x61)
	/home/travis/.gimme/versions/go1.9.2.linux.amd64/src/io/io.go:309 +0x86
io.ReadFull(0x1570900, 0xc420287290, 0xc4202d9000, 0x1000, 0x1000, 0xc4204041c0, 0x2, 0xc42050d948)
	/home/travis/.gimme/versions/go1.9.2.linux.amd64/src/io/io.go:327 +0x58
github.com/ncw/rclone/vfs.(*ReadFileHandle).readAt(0xc42060e070, 0xc4202d9000, 0x1000, 0x1000, 0x149bc000, 0xde1cc0, 0xc42050da01, 0xc4202d9000)
	/home/travis/gopath/src/github.com/ncw/rclone/vfs/read.go:219 +0x55e
github.com/ncw/rclone/vfs.(*ReadFileHandle).ReadAt(0xc42060e070, 0xc4202d9000, 0x1000, 0x1000, 0x149bc000, 0x0, 0x0, 0x0)
	/home/travis/gopath/src/github.com/ncw/rclone/vfs/read.go:179 +0xae
github.com/ncw/rclone/cmd/mount.(*FileHandle).Read(0xc420452270, 0x157bfc0, 0xc420a6c400, 0xc42060e1c0, 0xc4201c4cc0, 0x1001, 0x0)
	/home/travis/gopath/src/github.com/ncw/rclone/cmd/mount/handle.go:28 +0x294
github.com/ncw/rclone/vendor/bazil.org/fuse/fs.(*Server).handleRequest(0xc4204640c0, 0x157bfc0, 0xc420a6c400, 0x1570880, 0xc420ab30a0, 0xc4206e4fc0, 0x157a300, 0xc42060e1c0, 0xc42050def8, 0xc4209da2c8, ...)
	/home/travis/gopath/src/github.com/ncw/rclone/vendor/bazil.org/fuse/fs/serve.go:1249 +0x941
github.com/ncw/rclone/vendor/bazil.org/fuse/fs.(*Server).serve(0xc4204640c0, 0x157a300, 0xc42060e1c0)
	/home/travis/gopath/src/github.com/ncw/rclone/vendor/bazil.org/fuse/fs/serve.go:878 +0x468
github.com/ncw/rclone/vendor/bazil.org/fuse/fs.(*Server).Serve.func1(0xc4204640c0, 0x157a300, 0xc42060e1c0)
	/home/travis/gopath/src/github.com/ncw/rclone/vendor/bazil.org/fuse/fs/serve.go:425 +0x6e
created by github.com/ncw/rclone/vendor/bazil.org/fuse/fs.(*Server).Serve
	/home/travis/gopath/src/github.com/ncw/rclone/vendor/bazil.org/fuse/fs/serve.go:423 +0x35f
[0x7f31f4c04e38] filesystem access error: read error: Input/output error
FIXME: handle dialog start. 
2017/11/20 15:54:29 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: Flush: 
2017/11/20 15:54:29 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: >Flush: err=<nil>
2017/11/20 15:54:29 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: Release: 
2017/11/20 15:54:29 DEBUG : cams/frontyard/20171111/01_20171111220713000.MP4: ReadFileHandle.Release closing
2017/11/20 15:54:30 DEBUG : worker-3 <01_20171111220713000.MP4>: downloaded chunk 350M
2017/11/20 15:54:31 DEBUG : worker-2 <01_20171111220713000.MP4>: downloaded chunk 310M
2017/11/20 15:54:32 DEBUG : cams/frontyard/20171111/01_20171111220713000.MP4: cache reader closed 345751552
2017/11/20 15:54:32 DEBUG : &{cams/frontyard/20171111/01_20171111220713000.MP4 (r)}: >Release: err=<nil>
^CFIXME: handle dialog end.