My VFS SweetSpot - Updated 30-Aug-2018


#121

Hi,

I’m using the values from the first post and although it worked great when I had some media with both scanning and streaming, once I added a large amount of media, I keep getting “Rate Limit Exceeded” errors from google drive. I do have thousands of files in TV shows folder now and when I start the service, after either a “find” or a plex scan, it fails. I can not start the service until after a reboot. Here’s the error I’m getting when trying to remount:

2018/08/21 12:19:45 DEBUG : pacer: Rate limited, sleeping for 1.542017021s (1 consecutive low level retries)
2018/08/21 12:19:45 DEBUG : pacer: low level retry 1/10 (error googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded)
2018/08/21 12:19:45 DEBUG : pacer: Rate limited, sleeping for 2.75577138s (2 consecutive low level retries)
2018/08/21 12:19:45 DEBUG : pacer: low level retry 2/10 (error googleapi: Error 403: Rate Limit Exceeded, rateLimitExceeded)
2018/08/21 12:19:46 DEBUG : pacer: Resetting sleep to minimum 10ms on success
2018/08/21 12:19:46 Fatal error: Can not open: /GDcrypt: open /GDcrypt: transport endpoint is not connected

#122

What’s your actual version and mount command you are executing?

root@gemini:~ rclone -V
rclone v1.42
- os/arch: linux/amd64
- go version: go1.10.1
root@gemini:~ ps -ef | grep rclone
felix      541     1  0 Aug20 ?        00:03:37 /usr/bin/rclone mount gcrypt: /GD --allow-other --dir-cache-time 72h --buffer-size 1G --vfs-read-chunk-size 64M --vfs-read-chunk-size-limit off --umask 002 --bind 192.168.1.30 --log-level DEBUG --log-file /home/felix/logs/rclone.log

#123
rclone v1.42-DEV
- os/arch: linux/amd64
- go version: go1.10.1

I tried both cmount and mount, same result. Here’s the one I’m trying at the moment:

aptalca    833     1  0 12:25 ?        00:00:00 /home/aptalca/go/bin/rclone mount GDcrypt: /GDcrypt --allow-other --dir-cache-time 72h --vfs-read-chunk-size 64M --vfs-read-chunk-size-limit 512M --buffer-size 256M --umask 002 --log-file /home/aptalca/logs/rclone.log --log-level DEBUG

#124

Been looking into it more, and the issue may have been memory related.

I’m running this on a vps with 1GB of ram + 1GB of swap and watching htop while doing a plex scan shows as soon as memory is maxed out, rclone mount dies


#125

That should be pretty solid as I’m surprised you seeing so many rate limit errors. Are you using the standard rclone API key or your own API key?

I’m using my own and barely see any API hits coming once items are scanned:

That is a good char to check out to see if you are hitting a lot of queries per second. I can see when I was initially seeding, some 403s and such are expected as it just slows it down a bit.


#126

Oh yeah, that would kill it as plex opens up many files so the 256M buffer size would way too big for a 1G of RAM. I’d leave it at the default of 16M. My server has 32GB of memory :slight_smile:


#127

Thanks, setting buffer to 16MB fixed the issue. Memory keeps slowly creeping up during a scan but stays below the max.

I guess I need to read up on the rclone options more


#128

The scans are always going to be tight with that low memory so you may want to go ever lower. To get an idea, you can run as root “lsof /mountpoint” and see how many files are actually open.

You can go down to 8MB or even 4MB.


#129

Great tip, thanks.

Should that low of a buffer affect streams whether transcode or direct stream?


#130

If you are seeing “Direct Play”, having a bigger buffer would be helpful if you have any latency.

If you are seeing “Direct Stream” or “Transcode”, it wouldn’t matter much as it’s going to transcode up to your throttle settings in Plex. I usually keep my throttle setting at 600 or 900 seconds so 10 or 15 minutes of buffer.


#131

That worked great. So I watched the rclone log while set to debug, and holy moly, does plex access a lot of files during a scan.

With the buffer set to 16MB, scans of large amounts of files work, so do direct play and direct stream.

For reference, plex is running on a DO vps (the cheapest $5 per month one). However, since the bandwidth is limited on DO, I’m uploading content to gdrive from a local vm, set up with the same rclone config as the DO vps.

I uploaded several terabytes over a couple of weeks and it works great.

The vps has 1GB of ram, 1GB of swap (may up it to 2GB) and a single core processor. It can handle one transcoded stream, but barely. I try to do direct play or direct stream only.


#132

You could always set the buffer to 0 for the initial scan. After that set it to a low amount. Ran like that on a 2GB VPS for some time and that was the only way I could scan my 25TB at the time.


#133

@Animosity022 Thanks for the info, really helped me understand a lot of things. This settings and scripts I got at the Unraid forums really made things easy.

Have a odd problem, wondering if anyone had encountered it. It’s to do with Direct Play on Plex. Direct streaming on Plex works fine, either because the file is an MKV or if I turn off direct play in the app settings. However, when direct playing all that happens is a black screen with the loading icon. I’ve played with various settings on buffer and chunk size and limit. It makes no difference. The exact same files direct play when stored locally through the exact same Plex server. In a nutshell, to play files from gdrive I have to direct stream. Any attempt to direct play them causes a black screen with infinite load. However, these same files direct play when accessed locally through that same Plex server. Client - Apple TV 4K , All files are formatted as MP4, with ac3 and mov_text - compatible with direct play.

Please let me know if anyone has encountered this or have found a solution. Thanks.


#134

Can you do me a favor and turn on DEBUG level in logging and share the log once you try to direct play?

--log-level DEBUG --log-file /home/felix/logs/rclone.log

on the mount command.


#135

I’ve just done that. Thanks for the steps. Nothing turns up on the log. It just displays the scanning of other files. No mention whatsoever of the file i’m trying to play. Tried it four to five times. However, plex logs show the file being selected for Direct Play. Is it normal for the log file to be growing at a rapid rate? It 42 mb in less than 2 hours. Since I might not know what i’m looking for, will be helpful if i just posted the log file at the time i start playing? I asking since there are so many lines even within a minute. And will the plex logs be useful to you? Thanks.


#136

I’m not sure about Unraid but if you aren’t see any logs, something isn’t right as it you hit play, it should add some debug lines to the rclone log.

Example for me playing a show:

2018/08/23 20:34:15 DEBUG : TV_Ended/Skins/: >Lookup: node=TV_Ended/Skins/Skins.S06E03.mkv, err=<nil>
2018/08/23 20:34:15 DEBUG : TV_Ended/Skins/Skins.S06E03.mkv: Attr:
2018/08/23 20:34:15 DEBUG : TV_Ended/Skins/Skins.S06E03.mkv: >Attr: a=valid=1s ino=0 size=3542394102 mode=-rw-rw-r--, err=<nil>
2018/08/23 20:34:15 DEBUG : TV_Ended/Skins/Skins.S06E03.mkv: Open: flags=OpenReadOnly
2018/08/23 20:34:15 DEBUG : TV_Ended/Skins/Skins.S06E03.mkv: Open: flags=O_RDONLY
2018/08/23 20:34:15 DEBUG : TV_Ended/Skins/Skins.S06E03.mkv: >Open: fd=TV_Ended/Skins/Skins.S06E03.mkv (r), err=<nil>
2018/08/23 20:34:15 DEBUG : TV_Ended/Skins/Skins.S06E03.mkv: >Open: fh=&{TV_Ended/Skins/Skins.S06E03.mkv (r)}, err=<nil>
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: Flush:
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: >Flush: err=<nil>
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: Flush:
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: >Flush: err=<nil>
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: Release:
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: >Release: err=<nil>
2018/08/23 20:34:15 DEBUG : TV_Ended/Skins/Skins.S06E03.mkv: ChunkedReader.Read at 40890368 length 1048576 chunkOffset 0 chunkSize 67108864
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: >Read: read=131072, err=<nil>
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: Read: len=131072, offset=39911424
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: >Read: read=131072, err=<nil>
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: Read: len=131072, offset=40042496
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: >Read: read=131072, err=<nil>
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: Read: len=131072, offset=40173568
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: >Read: read=131072, err=<nil>
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: Read: len=131072, offset=40304640
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: >Read: read=131072, err=<nil>
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: Read: len=131072, offset=40435712
2018/08/23 20:34:15 DEBUG : &{TV_Ended/Skins/Skins.S06E03.mkv (r)}: >Read: read=131072, err=<nil>

#137

Thanks. Found what you mentioned, I hope. It goes on much longer than this while I see a black loading screen on TV. I’ve linked the whole part of the log, while this black screen is going on, if needed. I’ve also kept Plex logs when Direct Playing and Rclone logs when it Direct Streams and works correctly which is all the time with your setup. Thanks.

Direct Playing RClone Log - Onedrive Link: https://1drv.ms/t/s!AvtLStMhHJGAiLBVCpemxoD54O1XKg

2018/08/25 19:54:02 DEBUG : media/letchu/tv_shows/: >Lookup: node=media/letchu/tv_shows/The Daily Show/, err=<nil>
2018/08/25 19:54:02 DEBUG : media/letchu/tv_shows/The Daily Show/: Attr: 
2018/08/25 19:54:02 DEBUG : media/letchu/tv_shows/The Daily Show/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxrwx, err=<nil>
2018/08/25 19:54:02 DEBUG : media/letchu/tv_shows/The Daily Show/: Lookup: name="Season 23"
2018/08/25 19:54:02 DEBUG : media/letchu/tv_shows/The Daily Show/: >Lookup: node=media/letchu/tv_shows/The Daily Show/Season 23/, err=<nil>
2018/08/25 19:54:02 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/: Attr: 
2018/08/25 19:54:02 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxrwx, err=<nil>
2018/08/25 19:54:02 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/: Lookup: name="The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4"
2018/08/25 19:54:02 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/: >Lookup: node=media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4, err=<nil>
2018/08/25 19:54:02 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4: Attr: 
2018/08/25 19:54:02 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4: >Attr: a=valid=1s ino=0 size=570488267 mode=-rw-rw-rw-, err=<nil>
2018/08/25 19:54:02 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4: Open: flags=OpenReadOnly
2018/08/25 19:54:02 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4: Open: flags=O_RDONLY
2018/08/25 19:54:02 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4: >Open: fd=media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4 (r), err=<nil>
2018/08/25 19:54:02 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4: >Open: fh=&{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4 (r)}, err=<nil>
2018/08/25 19:54:02 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4 (r)}: Flush: 
2018/08/25 19:54:02 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4 (r)}: >Flush: err=<nil>
2018/08/25 19:54:02 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4 (r)}: Flush: 
2018/08/25 19:54:02 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4 (r)}: >Flush: err=<nil>
2018/08/25 19:54:02 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4 (r)}: Release: 
2018/08/25 19:54:02 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.13.Spike.Lee.EXTENDED.720p.WEB.x264-TBS[rarbg].mp4 (r)}: >Release: err=

#138

What’s your actual mount command that you using? The strange part in the log is that you can see it open and close the file quite a bit which is strange. I was seeing that behavior at one point but I could not figure out what parameters were causing it and I haven’t been able to recreate it:

egrep 'O_RDONLY|Flush' Direct\ Stream.txt
2018/08/25 20:15:14 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv: Open: flags=O_RDONLY
2018/08/25 20:15:14 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:14 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:14 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:14 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv: Open: flags=O_RDONLY
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv: Open: flags=O_RDONLY
2018/08/25 20:15:16 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv: Open: flags=O_RDONLY
2018/08/25 20:15:16 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv: Open: flags=O_RDONLY
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv: Open: flags=O_RDONLY
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv: Open: flags=O_RDONLY
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv: Open: flags=O_RDONLY
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv: Open: flags=O_RDONLY
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv: Open: flags=O_RDONLY
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv: Open: flags=O_RDONLY
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv: Open: flags=O_RDONLY
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:16 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:19 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv: Open: flags=O_RDONLY
2018/08/25 20:15:21 DEBUG : media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv: Open: flags=O_RDONLY
2018/08/25 20:15:21 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:21 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>
2018/08/25 20:15:21 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: Flush:
2018/08/25 20:15:21 DEBUG : &{media/letchu/tv_shows/The Daily Show/Season 23/The.Daily.Show.2018.08.09.Emma.Gonzales.EXTENDED.WEB.x264-TBS[rarbg].mkv (r)}: >Flush: err=<nil>

Is there any unionfs or mergerfs or anything else or that just a direct rclone mount? It is basically showing the black screen as the client you are playing from keeps opening and closing the file quite a bit instead of actually just reading the file.

What’s the client that’s direct playing? Can you try also playing from the Plex Media Player from your PC/Laptop? That should direct play just about everything as well as it a good place to validate it.


#139

My apologies. That text file was for the direct streaming - the file was .mkv as seen. This works consistently across all players. Start up is at about 5 sec. I do notice the behavior you notice, the opening and closing, but it’s not felt in playback.

The log for the direct play, the one that shows black screen. https://1drv.ms/t/s!AvtLStMhHJGAiLBTPpUIKpp-DeA_xQ

The log for plex while using direct play. https://1drv.ms/t/s!AvtLStMhHJGAiLBUDZXFZgCOhYby_g

Using Infuse or any other application (laptop native plex client) that doesn’t use Apple TV native player works since they support a wide range of formats and buffer ahead I believe. The specific problem happens when playing Direct Play compatible media using the Plex app in AppleTV. For example when a Direct Play compatible media file which is stored locally is played through the Plex server it plays well - Direct Play. When playing the same media file on an unionfs mount while the media file is local (before upload cron job is run) it plays well - Direct Play. When playing the same file in the same Plex server using the same unionfs mount (after it’s uploaded to gdrive) it goes to black screen. I noticed a bunch of posts on this topic with people using Apple TVs. I figured someone might know what’s up.

Thanks for your help. Settings are below.

These are the settings for rclone mount.

rclone mount --allow-other --cache-dir /tmp/rclone/vfs --dir-cache-time 72h --vfs-read-chunk-size 128M --vfs-read-chunk-size-limit off --buffer-size 128M --log-level DEBUG --log-file /mnt/user/mount_rclone/rclone.log gdrive_media_vfs: /mnt/user/mount_rclone/google_vfs --stats 1m &

These are the settings for unionfs mount.

unionfs -o cow,allow_other,direct_io,auto_cache,sync_read /mnt/user/rclone_upload/google_vfs=RW:/mnt/user/mount_rclone/google_vfs=RO /mnt/user/mount_unionfs/google_vfs

These are the settings for rclone settings.

[gsuite]
type = drive
client_id = 
client_secret = 
scope = drive
root_folder_id = 
service_account_file = 
token = 

[gdrive_media_vfs]
type = crypt
remote = gsuite:/crypt
filename_encryption = standard
directory_name_encryption = true
password = 
password2 =

#140

Are you able to test without the unionfs mount for the same media? I did that by adding just another mount and adding a test library in plex with just the one specific item / show I want to play.

I basically had the same issue you are talking about and it was able to be detected by the debug log and the player opening and closing the files repeatedly.

If you want to add to the topic I posted in regards to Direct Play, it is here ->

I’ve yet to recreate the issue on my setup as I’ve desperately tried. If you can get the same thing on the rclone mount, I’d be interested in seeing that debug to see if the same pattern shows.

My gut is a particular setting that doesn’t jive with the ATV (4k and regular one) but I can’t figure out which either so have to go through the process of eliminating all the variables.