Playback crashes direct streaming to Roku but only w/MKVs on new USB drive

General Discussions
1

Doing tech support for my dad and we’ve run into a weird one. He recently added a new 8TB USB drive (Seagate Backup Plus Hub which apparently uses an SMR Archive drive inside) and every movie (all full rip blurays) he tries direct streaming from that drive crashes within the first 5 to 10 minutes as if the movie completed (screen shows similar recommended movies and no progress is saved where the movie crashed so when you start it again it’s from the beginning). PMS is 1.5.5.3634 on Win 7 Enterprise SP1 (32 bit) and watching Windows Resource Monitor on his server while the movie is playing the one thing that stands out is that under the Disk tab, the graph line for the new USB drive queue length will at some point flatline and then a second or 2 after the line has moved off screen entirely to the left and the graph is empty, playback on the Roku stops. It’s as if Windows or Plex simply stops recognizing that the movie is still playing. Meanwhile the exact same files copied to any other drive (internal or USB) play fine when direct streamed from those other drives, and the few bluray rips with only lossy audio that we can direct play off the 8TB Seagate also work fine. Lastly, when I attach the Seagate drive to my own Win 10 laptop running PMS and direct stream to the same Roku within his home network, that also works fine. So there appears to be nothing wrong with the Seagate drive itself (no bad sectors or SMART errors according to SeaTools or Stablebit Scanner) and it’s only the combination of using the drive with his server and where any transcoding is involved where the issue surfaces, consistently, with every movie we try to direct stream from that drive.

Log attached and please note especially the entries around the last mention of the movie “Birdman” where it stopped playing. Entries like “Killing Job… Job was already killed, not killing again… Stopping transcode session… Whacked session”, etc.

Would really appreciate any feedback or suggestions on how to solve this since unfortunately we’re already passed the window to return the drive to the seller and I’m not sure we could RMA it either when the problem appears to be with Plex only and not with the drive itself. Thanks.

2

Initial inspection does not show the drive to be the problem. Your DNS resolution fails.

May 11, 2017 06:42:47.412 [5536] ERROR - Error issuing curl_easy_perform(handle): 6
May 11, 2017 06:42:47.412 [5536] WARN - HTTP error requesting GET http://plex.tv/pms/:/ip (0, No error) (Could not resolve host: plex.tv)
May 11, 2017 06:42:47.412 [5536] ERROR - PublicAddressManager: Unable to get public IP adddress from myPlex (httpCode=-6): 
May 11, 2017 06:42:47.428 [5536] DEBUG - It took 0.0 sec to serialize a list with 7 elements.
May 11, 2017 06:42:47.428 [5536] DEBUG - MyPlex: Sending Server Info to myPlex (user=jarcy827@msn.com, ip=, port=0)
May 11, 2017 06:42:47.428 [5536] DEBUG - HTTP requesting POST https://plex.tv/servers.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&async=1&asyncIdentifier=7e4893bd-6222-4ef1-95df-43e3889d8d17
May 11, 2017 06:42:47.443 [5536] ERROR - Error issuing curl_easy_perform(handle): 6

A little further down and the computers networking completely dies off

May 11, 2017 06:47:07.560 [4528] DEBUG - EventSource: Failure in Connect (10065 - A socket operation was attempted to an unreachable host).
May 11, 2017 06:47:18.059 [4528] WARN - PubSubManager: Connection to 23.96.218.59 failed: Unknown error.
May 11, 2017 06:47:18.059 [4528] WARN - PubSubManager: Connection to 139.162.7.93 failed: Unknown error.
May 11, 2017 06:47:18.059 [4528] WARN - PubSubManager: Connection to 184.105.148.83 failed: Unknown error.
May 11, 2017 06:47:18.059 [4528] WARN - PubSubManager: Connection to 139.162.177.42 failed: Unknown error.
May 11, 2017 06:47:18.059 [4528] WARN - PubSubManager: Connection to 139.162.115.125 failed: Unknown error.
May 11, 2017 06:47:18.059 [4528] WARN - PubSubManager: Connection to 139.162.202.171 failed: Unknown error.
May 11, 2017 06:47:18.059 [4528] WARN - PubSubManager: Connection to 45.79.210.23 failed: Unknown error.
May 11, 2017 06:47:18.059 [4528] WARN - PubSubManager: Connection to 45.79.11.43 failed: Unknown error.
May 11, 2017 06:47:18.059 [4528] WARN - PubSubManager: Connection to 45.33.75.206 failed: Unknown error.
May 11, 2017 06:47:18.059 [4528] WARN - PubSubManager: Connection to 82.94.168.54 failed: Unknown error.

(I’m not a windows guy but this is clearly a networking issue at the top-most level)

3

Thanks for the reply Chuck however those network errors are from well before the playback crashes when I temporarily unplugged the ethernet cord from my dad’s server to test playback from my Win 10 laptop as the server instead. Could you look again from 08:45:12.366 where the transcode session for Birdman starts? Here are the only error codes I see from that point on:

May 11, 2017 08:49:29.004 [3340] ERROR - [Transcoder] [ac3_eae @ 03500880] EAE timeout! EAE not running, or wrong folder? Could not read ‘\?\C:\Users\Logan\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\EasyAudioEncoder\Convert to Dolby Digital (High Quality - 640 kbps)\9384f3030813203b16e4a71f10ad01b8_4356-1-557.ac3’
May 11, 2017 08:49:29.004 [6636] ERROR - [Transcoder] [ac3_eae @ 03500880] error reading output
May 11, 2017 08:49:29.004 [7572] ? - [Transcoder] Audio encoding failed

Followed by this section where it appears that playback actually crashes:

May 11, 2017 08:50:39.115 [0828] DEBUG - Killing job.
May 11, 2017 08:50:39.115 [0828] DEBUG - Job was already killed, not killing again.
May 11, 2017 08:50:39.115 [0828] DEBUG - Stopping transcode session 9384f3030813203b16e4a71f10ad01b8
May 11, 2017 08:50:39.115 [0828] DEBUG - Cleaning directory for session 9384f3030813203b16e4a71f10ad01b8 (C:\Users\Logan\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-9384f3030813203b16e4a71f10ad01b8-d059413c-beba-4518-8527-ba572505bb79)
May 11, 2017 08:50:39.115 [4528] DEBUG - Completed: [192.168.0.101:52841] 200 GET /video/:/transcode/universal/stop?session=9384f3030813203b16e4a71f10ad01b8 (5 live) TLS GZIP 4ms 195 bytes (pipelined: 53)
May 11, 2017 08:50:39.115 [4524] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
May 11, 2017 08:50:39.115 [4524] DEBUG - Auth: authenticated user 1 as jrc827
May 11, 2017 08:50:39.115 [4524] DEBUG - Auth: Came in with a super-token, authorization succeeded.
May 11, 2017 08:50:39.115 [7572] DEBUG - Request: [192.168.0.101:52889 (Subnet)] GET /:/timeline?time=7157000&duration=7157195&key=%2Flibrary%2Fmetadata%2F12373&ratingKey=12373&state=stopped&guid=com.plexapp.agents.imdb%3A%2F%2Ftt2562232%3Flang%3Den&playQueueItemID=14792 (5 live) TLS GZIP Signed-in Token (jrc827)
May 11, 2017 08:50:39.115 [7572] DEBUG - Client [9384f3030813203b16e4a71f10ad01b8] reporting timeline state stopped, progress of 7157000/7157195ms for guid=com.plexapp.agents.imdb://tt2562232?lang=en, ratingKey=12373 url=, key=/library/metadata/12373, containerKey=, metadataId=12373
May 11, 2017 08:50:39.130 [7572] DEBUG - Library item 12373 ‘Birdman’ got played by account 1!
May 11, 2017 08:50:39.177 [4528] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
May 11, 2017 08:50:39.177 [4528] DEBUG - Auth: authenticated user 1 as jrc827
May 11, 2017 08:50:39.177 [4528] DEBUG - Auth: Came in with a super-token, authorization succeeded.
May 11, 2017 08:50:39.177 [6636] DEBUG - Request: [192.168.0.101:52841 (Subnet)] GET /hubs/metadata/12373/postplay (5 live) TLS GZIP Signed-in Token (jrc827)
May 11, 2017 08:50:39.411 [0828] DEBUG - Cleaning old transcode directories.
May 11, 2017 08:50:39.411 [0828] DEBUG - Whacked session 9384f3030813203b16e4a71f10ad01b8, 0 remaining.

I did a quick search of the forum and found people having EAE timeout errors with 1.5.x versions of PMS but only running on linux or using network drives, not on Windows with a USB drive. Any ideas on what to do about it?

4

Read a few lines below that

May 11, 2017 08:50:39.411 [0828] DEBUG - It took 0.0 sec to serialize a list with 0 elements.
May 11, 2017 08:50:39.427 [7572] DEBUG - [Now] User is jrc827 (ID: 1)
May 11, 2017 08:50:39.427 [7572] DEBUG - [Now] Device is Roku (Roku 3 - 4124CJ193192).
May 11, 2017 08:50:39.427 [7572] DEBUG - [Now] Profile is Roku-7.x
May 11, 2017 08:50:39.427 [7572] DEBUG - [Now] Updated play state for /library/metadata/12373.
May 11, 2017 08:50:39.427 [7572] DEBUG - Statistics: (9384f3030813203b16e4a71f10ad01b8) Reporting active playback in state 3 of type 1 (scrobble: 1) for account 1
May 11, 2017 08:50:39.427 [7572] DEBUG - Cleaning directory for session 9384f3030813203b16e4a71f10ad01b8 (C:\Users\Logan\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-9384f3030813203b16e4a71f10ad01b8-d059413c-beba-4518-8527-ba572505bb79)
May 11, 2017 08:50:39.427 [7572] DEBUG - Deleting stale file \\?\C:\Users\Logan\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\EasyAudioEncoder\Convert to Dolby Digital (High Quality - 640 kbps)\9384f3030813203b16e4a71f10ad01b8_4356-1-557.ac3
May 11, 2017 08:50:39.427 [7572] DEBUG - Streaming Resource: Terminated session 03EBBDD8:9384f3030813203b16e4a71f10ad01b8 with reason Client stopped playback.

The Roku stopped the playback.

5

Okay the Roku stopped the playback but if that’s a minute after the transcoding failed then that’s still a server and not a client issue, yes? My dad has 2 Roku 3’s he’s been using as Plex clients for more than a year and both have played everything thrown at them with the sole exception now of any movie requiring transcoding that happens to sit on this one particular USB drive (every time vs. everything else playing fine including the exact same MKVs if I move them to any other USB or internal drive). So regardless of that particular log entry, I don’t really see how the Roku could be the problem here.

I really do appreciate your help and I don’t mean to be difficult but can we focus on why the transcoding failed in the first place? What is this EAE timeout business and inability to read the transcode file from it’s default C drive location? Does that mean that the read speed of the source file from the Seagate USB + the time it takes for Plex to transcode the audio and write it to the C drive is too slow to keep up with the playback? My dad does have an older computer and OS but it’s still got a USB 2.0 motherboard w/a 5900 rpm drive inside along with an SSD for the C drive so I don’t see why that should be an issue in itself however it’s the only explanation I can think of that would track with what’s going on.

Maybe you could suggest some tweaks to the server transcode settings to see if that helps (segmented timeout, default throttle buffer, etc.)? Pretty sure I already have the quality set to prefer higher speed encoding but I really don’t know what those advanced settings do so if there’s anything else that could make the transcoding faster then maybe that would be worth a shot? Or let me know if you have any other ideas. Thanks again.

6

I’m going one step better… and do apologize for reaching too far out of my expertise… I’ve asked one of the Windows guys to step in.
He’ll ‘translate’ for me if needed, otherwise he will help you resolve it himself.

7

I just briefly read through this quickly. Sure seems like the culprit is the USB 8TB drive.

Check and make sure the drive is plugged into a USB3 port and not a USB2 port.
Try running a checkdisk on both this 8TB drive and you C drive on this computer.

Download/install/run CrystalDiskMark on that drive as well as the C drive and report back what speeds you get.

If you happen to notice slow speeds try a different USB cable if you have one.

Have you tried playing a file back from the 8TB drive using VLC directly?

Can you try Plex Media Player on the same LAN trying to play back via Direct Play as well as a forced transcode and let us know how this goes. Especially interested if DP works but transcode doesn’t and if you get the same error in the logs about the EAE timeout!

These should be enough things to check for a first pass that will get us some additional information to work with.

Carlo

PS you mention you only have a problem with MKVs on this drive. Have you tried MP4, AVIs?

8

Hi Carlo, thanks for jumping in on this (and thank you too Chuck). I’ll be back at my dad’s this weekend to run CrystalDiskMark and post those results but to reply to what I can for now:

  1. I can’t plug the 8TB Seagate into a USB3 port on my dad’s computer because he doesn’t have any. It’s an older AM3 motherboard w/USB2 only. However when I tried playing the same movies off the same drive with my Win 10 laptop w/USB3 as the server instead (borrowing the ethernet cord to dad’s computer so employing the same network config) they played fine. Then again my laptop also has an i7 processor vs. Phenom II X4 955 (passmark 3969) in my Dad’s so the USB port speed was not the only difference.

  2. I’ve only spot checked playing the 8TB USB housed movies that crash on the Roku with VLC instead but I’m sure they’d all play through fine in their entirety because the problem is only where any Plex transcoding is involved. As I mentioned in my first post, the few movies on that drive w/lossy audio only that we can direct play through the Roku play fine. It’s only movies that require transcoding (most of them audio only to convert DTS HD to Dolby for the Roku while the video is direct streamed) that crash. And what’s weird about that to me is that is that I can watch Windows Resource Monitor on my dad’s computer while those movies are playing on the Roku right up to the point that they crash and the CPU utilization will never go above 50%. What we see instead is that on the Disk tab, the Queue Length graph for the USB drive will start to flatline at some point 5-10 min in the movie and when that graph line disappears entirely offscreen to the left, that’s when playback on the Roku dies. So it’s not that the processor can’t transcode fast enough, it’s that somehow the source file itself simply stops being read from the USB drive. I assume this is why Plex isn’t saving the progress in the movie or generating any crash reports when it happens. It’s reading it like the movie is simply over.

  3. I haven’t tried any MP4, AVIs etc because all the movies we have are ripped using MakeMKV and I don’t want to run them through Handbrake or anything else to convert them. These are full rip blurays, typically 20-30GB w/lossless audio, and we want to keep them in their original quality. So if you know of tools that can convert them to MP4 or AVI without any compression I’ll be happy to try them and post back the results, otherwise it’s a non-starter to me whether files w/other containers will play off that drive or not.

Let me know if you have any other input or questions for now otherwise I’ll post the CrystalDiskMark results later this weekend.

9

Alright, running CrystalDiskMark I think I found the culprit as a bad USB port. With the 8TB Seagate plugged into the port we’d been using before, the sequential read speeds were unbelievably slow. Here:

CrystalDiskMark 5.2.1 © 2007-2017 hiyohiyo
Crystal Dew World : http://crystalmark.info/

  • MB/s = 1,000,000 bytes/s [SATA/600 = 600,000,000 bytes/s]

  • KB = 1000 bytes, KiB = 1024 bytes

    Sequential Read (Q= 32,T= 1) : 1.101 MB/s
    Sequential Write (Q= 32,T= 1) : 1.101 MB/s
    Random Read 4KiB (Q= 32,T= 1) : 0.346 MB/s [ 84.5 IOPS]
    Random Write 4KiB (Q= 32,T= 1) : 0.681 MB/s [ 166.3 IOPS]
    Sequential Read (T= 1) : 1.048 MB/s
    Sequential Write (T= 1) : 1.048 MB/s
    Random Read 4KiB (Q= 1,T= 1) : 0.303 MB/s [ 74.0 IOPS]
    Random Write 4KiB (Q= 1,T= 1) : 0.681 MB/s [ 166.3 IOPS]

    Test : 1024 MiB [N: 52.7% (3928.8/7452.0 GiB)] (x5) [Interval=5 sec]
    Date : 2017/05/14 15:58:53
    OS : Windows 7 Enterprise SP1 [6.1 Build 7601] (x86)

Plugging the same drive into a different USB port on the motherboard and running CDM again, the sequential read speeds came out much better:

CrystalDiskMark 5.2.1 © 2007-2017 hiyohiyo
Crystal Dew World : http://crystalmark.info/

  • MB/s = 1,000,000 bytes/s [SATA/600 = 600,000,000 bytes/s]

  • KB = 1000 bytes, KiB = 1024 bytes

    Sequential Read (Q= 32,T= 1) : 16.543 MB/s
    Sequential Write (Q= 32,T= 1) : 15.966 MB/s
    Random Read 4KiB (Q= 32,T= 1) : 0.586 MB/s [ 143.1 IOPS]
    Random Write 4KiB (Q= 32,T= 1) : 4.450 MB/s [ 1086.4 IOPS]
    Sequential Read (T= 1) : 16.360 MB/s
    Sequential Write (T= 1) : 15.519 MB/s
    Random Read 4KiB (Q= 1,T= 1) : 0.448 MB/s [ 109.4 IOPS]
    Random Write 4KiB (Q= 1,T= 1) : 3.878 MB/s [ 946.8 IOPS]

    Test : 1024 MiB [N: 52.7% (3928.8/7452.0 GiB)] (x5) [Interval=5 sec]
    Date : 2017/05/14 16:17:31
    OS : Windows 7 Enterprise SP1 [6.1 Build 7601] (x86)

All USB ports on the motherboard are supposed to be 2.0 so I don’t know what’s going on with the super slow speeds we were getting on the first port, however plugged into the second port we’re direct streaming a movie now on the Roku and 20+ minutes in it appears it’s going to play through fine (before, all movies that required transcoding were crashing in the first 5-10 min tops). So I’ll wait to hear if you guys see any red flags in even the faster speeds for the port we’re using now, but if not and we don’t run into any more problems playing movies tonight then I’m going to assume this is sorted now and mark my question as answered. Thanks again.