PMS - Win10 - issues

General Discussions
1

Long story short, I’ve been on Win10 now for months. PMS has always worked great and I have never had a reason to complain, until now.

I have 2 issues mainly.

  1. I get the error “There was an unexpected error loading libraries”
  2. If Plex can fetch a show/movie via the Roku 3, it takes a long time, whereas it used to take seconds. When I say a long time, I mean 20+ seconds.

These symptoms are using the Plex app on Roku 3. I can play anything locally without a single issue and the content will load almost instantly.

You’re probably wondering about the hardware, right?

Win10
16gb RAM
i5 - 4690k

RAID 10 array (5.x TB formatted)
Connected to PC above with USB 3.0

I’ve optimized, repaired and ran the sqlite3 tools. I’ve installed, reinstalled, removed, installed, reinstalled PMS countless times to no avail.

As a test, I shutdown PMS, installed Emby server and installed the Emby app for Roku and it works flawlessly. My content loads in the usual 4-6sec that it used to load with the Plex app.

Here are my Roku logs. If anyone needs anything else, please let me know. I would much rather keep using Plex but god, is it frustrating right now.

2

It’s also worthy to note that I turned on remote debugging last night between 9-10p EST, so you should have logs on the issues I am talking about.

3

@jdstarns said:
Long story short, I’ve been on Win10 now for months. PMS has always worked great and I have never had a reason to complain, until now.

I have 2 issues mainly.

  1. I get the error “There was an unexpected error loading libraries”
  2. If Plex can fetch a show/movie via the Roku 3, it takes a long time, whereas it used to take seconds. When I say a long time, I mean 20+ seconds.

These symptoms are using the Plex app on Roku 3. I can play anything locally without a single issue and the content will load almost instantly.

You’re probably wondering about the hardware, right?

Win10
16gb RAM
i5 - 4690k

RAID 10 array (5.x TB formatted)
Connected to PC above with USB 3.0

I’ve optimized, repaired and ran the sqlite3 tools. I’ve installed, reinstalled, removed, installed, reinstalled PMS countless times to no avail.

As a test, I shutdown PMS, installed Emby server and installed the Emby app for Roku and it works flawlessly. My content loads in the usual 4-6sec that it used to load with the Plex app.

Here are my Roku logs. If anyone needs anything else, please let me know. I would much rather keep using Plex but god, is it frustrating right now.

Normally it would be database corruption or database fragmentation that would give rise to such symptoms.
Could you repeat the test but please provide both Plex Media Server.log and the roku log for the same periodrestart the server
Wait for it to get established (5 minutes)
Re launch the Plex for Roku app
When the problem arises, note down the time and collect the roku debug log and copy out the Plex Media Server.log
Attach both with info on time when the problem was noticed
https://support.plex.tv/hc/en-us/articles/200250417-Plex-Media-Server-Log-Files

4

Here is the PMS log from last night.

5

@jdstarns said:
Here is the PMS log from last night.

Can’t see slow loading or slow requests in the logs you attached.

I can see you have DNS Rebinding protection which is making the roku use your public IP and public port to get to the local server but that should not cause any serious issues and I have been running this way for a while. See section on DNS Rebinding on this support page https://support.plex.tv/hc/en-us/articles/206225077-How-to-Use-Secure-Server-Connections

I also see you have setup a Manual Connection to the server on the roku app. There is no need for that and I suggest you remove it as the roku app is discovering the server through GDM…

Could you tell me what port number you have in the settings / manual connections entry for 192.168.1.108.
I need to double check why the roku is trying out the public port for the local IP in some of the connection tests - extra to the correct ones being tried - so please could you get the xml from this request and save it to text file and send it to me by private message https://plex.tv/pms/resources?includeHttps=1

The only errors in the roku log for this server relate to DNS Rebinding and all the requests from the roku app to the server during the periods of time covered by the logs completed in under 1 second.

I need to know exactly what time the issue was and what was not loading or if it was buffering on video streaming
Also need confirmation of any time difference between the server and the roku and the time displayed in the roku logs. You can establish that by exiting the roku app and then restarting it and noting the time and then accessing the roku plex log and see what the start time in the log is.

The logs provided cover these times
Server logs Aug 11 from 21:53 to 02:14am Aug 12
roku log Aug 11 from 10:02:03 to 10:02:25 - that is only 20+ seconds worth so does not sound that you took it at the right time.

Looking at the server log - I can see some issues - transcoding is taking along time. Movie was
F:\My Media\TV Shows\The Strain\The Strain - 1x01 - Night Zero.mkv

You have Plex Media Server also on the F: Drive. I presume this is your RAID. May be you have a performance / setup issue with this.

These are a few examples of transcode actions taking too long. See the number of milliseconds eg 15,889 ms. One need to know what else was going on within the system at the time.

Aug 11, 2016 22:10:44.638 [10164] DEBUG - Completed: [127.0.0.1:63432] 206 PUT /video/:/transcode/session/Plex1GJ375010570/progress?progress=88.7&size=11274343&speed=0.0&remaining=20362 (32 live) 8970ms 289 bytes

Aug 11, 2016 22:10:44.638 [9188] DEBUG - Completed: [127.0.0.1:63417] 206 PUT /video/:/transcode/session/Plex1GJ375010570/progress?progress=88.7&size=11227320&speed=0.0&remaining=-1 (32 live) 15889ms 289 bytes

Aug 11, 2016 22:10:44.638 [10164] DEBUG - Completed: [127.0.0.1:63420] 206 PUT /video/:/transcode/session/Plex1GJ375010570/progress?progress=88.7&size=11274343&speed=0.0&remaining=286488 (32 live) 12426ms 289 bytes

Aug 11, 2016 22:10:44.638 [9188] DEBUG - Completed: [127.0.0.1:63422] 206 PUT /video/:/transcode/session/Plex1GJ375010570/progress?progress=88.7&size=11274343&speed=0.0&remaining=20471 (32 live) 11266ms 289 bytes

The log also shows a transcode job being initiated at 2016 22:09:57 but the transcode actions did not start till 22:10:20. And these requests once they started they did not complete till long time time later.
I would suggest first eliminating the system issues
The requests at this time - completed in times shown below instead of usual 1ms earlier

8970ms	22:10:44.638
15889ms	22:10:44.638
12426ms	22:10:44.638
11266ms	22:10:44.638
942ms	22:10:44.638
14738ms	22:10:44.638
10121ms	22:10:44.638
19357ms	22:10:44.638
6660ms	22:10:44.638
17053ms	22:10:44.638
5505ms	22:10:44.638
7816ms	22:10:44.638
13578ms	22:10:44.638
2046ms	22:10:44.638
4349ms	22:10:44.638
18197ms	22:10:44.638
3190ms	22:10:44.638
20510ms	22:10:44.638
21668ms	22:10:44.638
22819ms	22:10:44.638

So suggest looking at the windows logs. Try and do tests with local HDD instead of the RAID setup for the transcode area / media and plex media server.

Also would probably be easier to concentrate first on slow loading of the library rather than transcoding delays.

6

@sa2000 said:

@jdstarns said:
Here is the PMS log from last night.

Can’t see slow loading or slow requests in the logs you attached.

I can see you have DNS Rebinding protection which is making the roku use your public IP and public port to get to the local server but that should not cause any serious issues and I have been running this way for a while. See section on DNS Rebinding on this support page https://support.plex.tv/hc/en-us/articles/206225077-How-to-Use-Secure-Server-Connections

I also see you have setup a Manual Connection to the server on the roku app. There is no need for that and I suggest you remove it as the roku app is discovering the server through GDM…

Could you tell me what port number you have in the settings / manual connections entry for 192.168.1.108.
I need to double check why the roku is trying out the public port for the local IP in some of the connection tests - extra to the correct ones being tried - so please could you get the xml from this request and save it to text file and send it to me by private message https://plex.tv/pms/resources?includeHttps=1

The only errors in the roku log for this server relate to DNS Rebinding and all the requests from the roku app to the server during the periods of time covered by the logs completed in under 1 second.

I need to know exactly what time the issue was and what was not loading or if it was buffering on video streaming
Also need confirmation of any time difference between the server and the roku and the time displayed in the roku logs. You can establish that by exiting the roku app and then restarting it and noting the time and then accessing the roku plex log and see what the start time in the log is.

The logs provided cover these times
Server logs Aug 11 from 21:53 to 02:14am Aug 12
roku log Aug 11 from 10:02:03 to 10:02:25 - that is only 20+ seconds worth so does not sound that you took it at the right time.

Looking at the server log - I can see some issues - transcoding is taking along time. Movie was
F:\My Media\TV Shows\The Strain\The Strain - 1x01 - Night Zero.mkv

You have Plex Media Server also on the F: Drive. I presume this is your RAID. May be you have a performance / setup issue with this.

These are a few examples of transcode actions taking too long. See the number of milliseconds eg 15,889 ms. One need to know what else was going on within the system at the time.

Aug 11, 2016 22:10:44.638 [10164] DEBUG - Completed: [127.0.0.1:63432] 206 PUT /video/:/transcode/session/Plex1GJ375010570/progress?progress=88.7&size=11274343&speed=0.0&remaining=20362 (32 live) 8970ms 289 bytes

Aug 11, 2016 22:10:44.638 [9188] DEBUG - Completed: [127.0.0.1:63417] 206 PUT /video/:/transcode/session/Plex1GJ375010570/progress?progress=88.7&size=11227320&speed=0.0&remaining=-1 (32 live) 15889ms 289 bytes

Aug 11, 2016 22:10:44.638 [10164] DEBUG - Completed: [127.0.0.1:63420] 206 PUT /video/:/transcode/session/Plex1GJ375010570/progress?progress=88.7&size=11274343&speed=0.0&remaining=286488 (32 live) 12426ms 289 bytes

Aug 11, 2016 22:10:44.638 [9188] DEBUG - Completed: [127.0.0.1:63422] 206 PUT /video/:/transcode/session/Plex1GJ375010570/progress?progress=88.7&size=11274343&speed=0.0&remaining=20471 (32 live) 11266ms 289 bytes

The log also shows a transcode job being initiated at 2016 22:09:57 but the transcode actions did not start till 22:10:20. And these requests once they started they did not complete till long time time later.
I would suggest first eliminating the system issues
The requests at this time - completed in times shown below instead of usual 1ms earlier

8970ms	22:10:44.638
15889ms	22:10:44.638
12426ms	22:10:44.638
11266ms	22:10:44.638
942ms	22:10:44.638
14738ms	22:10:44.638
10121ms	22:10:44.638
19357ms	22:10:44.638
6660ms	22:10:44.638
17053ms	22:10:44.638
5505ms	22:10:44.638
7816ms	22:10:44.638
13578ms	22:10:44.638
2046ms	22:10:44.638
4349ms	22:10:44.638
18197ms	22:10:44.638
3190ms	22:10:44.638
20510ms	22:10:44.638
21668ms	22:10:44.638
22819ms	22:10:44.638

So suggest looking at the windows logs. Try and do tests with local HDD instead of the RAID setup for the transcode area / media and plex media server.

Also would probably be easier to concentrate first on slow loading of the library rather than transcoding delays.

While I can certainly appreciate the in depth look, it’s not a hardware issue. I can load any media, locally (sitting at my pc) and it loads almost instantly.

The 20sec blip you saw was me simply testing the loading time of the episode of “The Strain”, that you also saw.

The RAID setup isn’t anything fancy. It’s a RAID10 setup. It IS a hardware raid and not a software raid.

I’ll double-check the Windows logs but I have looked at them and didn’t see anything revealing.

I have also tested 2 other ways:

  1. From the internet (wifi at work) - This loads any tv episode in 6-8sec.
  2. Files play damn near instantly if I am sitting at my pc.

I pm’d you the xml file you requested.

7

@jdstarns said:

@sa2000 said:

@jdstarns said:
Here is the PMS log from last night.

Can’t see slow loading or slow requests in the logs you attached.

I can see you have DNS Rebinding protection which is making the roku use your public IP and public port to get to the local server but that should not cause any serious issues and I have been running this way for a while. See section on DNS Rebinding on this support page https://support.plex.tv/hc/en-us/articles/206225077-How-to-Use-Secure-Server-Connections

I also see you have setup a Manual Connection to the server on the roku app. There is no need for that and I suggest you remove it as the roku app is discovering the server through GDM…

Could you tell me what port number you have in the settings / manual connections entry for 192.168.1.108.
I need to double check why the roku is trying out the public port for the local IP in some of the connection tests - extra to the correct ones being tried - so please could you get the xml from this request and save it to text file and send it to me by private message https://plex.tv/pms/resources?includeHttps=1

The only errors in the roku log for this server relate to DNS Rebinding and all the requests from the roku app to the server during the periods of time covered by the logs completed in under 1 second.

I need to know exactly what time the issue was and what was not loading or if it was buffering on video streaming
Also need confirmation of any time difference between the server and the roku and the time displayed in the roku logs. You can establish that by exiting the roku app and then restarting it and noting the time and then accessing the roku plex log and see what the start time in the log is.

The logs provided cover these times
Server logs Aug 11 from 21:53 to 02:14am Aug 12
roku log Aug 11 from 10:02:03 to 10:02:25 - that is only 20+ seconds worth so does not sound that you took it at the right time.

Looking at the server log - I can see some issues - transcoding is taking along time. Movie was
F:\My Media\TV Shows\The Strain\The Strain - 1x01 - Night Zero.mkv

You have Plex Media Server also on the F: Drive. I presume this is your RAID. May be you have a performance / setup issue with this.

These are a few examples of transcode actions taking too long. See the number of milliseconds eg 15,889 ms. One need to know what else was going on within the system at the time.

Aug 11, 2016 22:10:44.638 [10164] DEBUG - Completed: [127.0.0.1:63432] 206 PUT /video/:/transcode/session/Plex1GJ375010570/progress?progress=88.7&size=11274343&speed=0.0&remaining=20362 (32 live) 8970ms 289 bytes

Aug 11, 2016 22:10:44.638 [9188] DEBUG - Completed: [127.0.0.1:63417] 206 PUT /video/:/transcode/session/Plex1GJ375010570/progress?progress=88.7&size=11227320&speed=0.0&remaining=-1 (32 live) 15889ms 289 bytes

Aug 11, 2016 22:10:44.638 [10164] DEBUG - Completed: [127.0.0.1:63420] 206 PUT /video/:/transcode/session/Plex1GJ375010570/progress?progress=88.7&size=11274343&speed=0.0&remaining=286488 (32 live) 12426ms 289 bytes

Aug 11, 2016 22:10:44.638 [9188] DEBUG - Completed: [127.0.0.1:63422] 206 PUT /video/:/transcode/session/Plex1GJ375010570/progress?progress=88.7&size=11274343&speed=0.0&remaining=20471 (32 live) 11266ms 289 bytes

The log also shows a transcode job being initiated at 2016 22:09:57 but the transcode actions did not start till 22:10:20. And these requests once they started they did not complete till long time time later.
I would suggest first eliminating the system issues
The requests at this time - completed in times shown below instead of usual 1ms earlier

8970ms	22:10:44.638
15889ms	22:10:44.638
12426ms	22:10:44.638
11266ms	22:10:44.638
942ms	22:10:44.638
14738ms	22:10:44.638
10121ms	22:10:44.638
19357ms	22:10:44.638
6660ms	22:10:44.638
17053ms	22:10:44.638
5505ms	22:10:44.638
7816ms	22:10:44.638
13578ms	22:10:44.638
2046ms	22:10:44.638
4349ms	22:10:44.638
18197ms	22:10:44.638
3190ms	22:10:44.638
20510ms	22:10:44.638
21668ms	22:10:44.638
22819ms	22:10:44.638

So suggest looking at the windows logs. Try and do tests with local HDD instead of the RAID setup for the transcode area / media and plex media server.

Also would probably be easier to concentrate first on slow loading of the library rather than transcoding delays.

While I can certainly appreciate the in depth look, it’s not a hardware issue. I can load any media, locally (sitting at my pc) and it loads almost instantly.

The 20sec blip you saw was me simply testing the loading time of the episode of “The Strain”, that you also saw.

The RAID setup isn’t anything fancy. It’s a RAID10 setup. It IS a hardware raid and not a software raid.

I’ll double-check the Windows logs but I have looked at them and didn’t see anything revealing.

I have also tested 2 other ways:

  1. From the internet (wifi at work) - This loads any tv episode in 6-8sec.
  2. Files play damn near instantly if I am sitting at my pc.

I pm’d you the xml file you requested.

Thanks for the pms/resources.xml

It is showing that you are switching from between manually specified port and automatically allocated port. The xml shows it is now public port 32400. Earlier logs showed it was public port 10499. I presume you just switched to manually specified port and a port forward in the router for 32400 to 32400 on 192.168.1.108

Anyway - this is not relevant although it would not help to switch back and forth
I will follow up with the devs why we had this in the roku log

8/12/2016 10:02:05 INFO Starting request: GET https://192-168-1-108.cc5f23938b1f4e38a7bd24775e34ed11.plex.direct:10499/ (async=true timeout=invalid)

It would not have worked anyway even with the right port because of DNS Rebinding which blocked the correct attempt

8/12/2016 10:02:05 INFO Starting request: GET https://192-168-1-108.cc5f23938b1f4e38a7bd24775e34ed11.plex.direct:32400/ (async=true timeout=invalid)
8/12/2016 10:02:05 INFO Got a -6 from https://192-168-1-108.cc5f23938b1f4e38a7bd24775e34ed11.plex.direct:32400/

Back to the actual issue -

Need to check out the windows event logs (System and Application) for time period 11 August, from 22:09:57 to 22:10:50 to look for any abnormal exceptions / errors

Also try and get clean logs - what I mean is to launch and then wait without stopping and restarting. The log showed attempt to play the video file and then cancelled and then re attempted immediately. This clouds the issue

So try once and when you notice the hang - wait a minute and then collect the diagnostics - server log and roku log and noting down the time the issue arose

Separately try and get evidence for library failing to load.

Best to always start with fresh logs after restarting the server and then waiting 5 minutes and then trying to reproduce the problem

8

Thanks for the help again,

I have checked the Windows logs (application and system) and there are no errors. Additionally, I decided to run a speed test on my raid array, those results are below:

CrystalDiskMark 5.1.2 x64 © 2007-2016 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) : 206.000 MB/s
    Sequential Write (Q= 32,T= 1) : 198.028 MB/s
    Random Read 4KiB (Q= 32,T= 1) : 0.370 MB/s [ 90.3 IOPS]
    Random Write 4KiB (Q= 32,T= 1) : 1.297 MB/s [ 316.7 IOPS]
    Sequential Read (T= 1) : 239.891 MB/s
    Sequential Write (T= 1) : 219.163 MB/s
    Random Read 4KiB (Q= 1,T= 1) : 0.365 MB/s [ 89.1 IOPS]
    Random Write 4KiB (Q= 1,T= 1) : 1.312 MB/s [ 320.3 IOPS]

    Test : 1024 MiB [F: 54.4% (3041.6/5588.8 GiB)] (x5) [Interval=5 sec]
    Date : 2016/08/12 12:51:09
    OS : Windows 10 Professional [10.0 Build 10586] (x64)

9

One more question - have you previously made use of the Custom Server Access URL setting?
in Settings / Server / Network / Show Advanced

I am trying to understand how we ended up with port 10499 with local IP 192.168.1.108 - it is not showing in the xml you sent me but does show in equivalent xml in the roku log

10

@sa2000 said:
One more question - have you previously made use of the Custom Server Access URL setting?
in Settings / Server / Network / Show Advanced

I am trying to understand how we ended up with port 10499 with local IP 192.168.1.108 - it is not showing in the xml you sent me but does show in equivalent xml in the roku log

I have. I added http://192.168.1.108 which is the ip address of my PMS. It didn’t seem to make a difference either way. As for port 10499, I don’t know. Last night, I also noticed in the logs that there were several get requests being made to 192.168.1.1, which is my router that has UPNP turned on.

I would think by ways of GDM discovery that the Plex app would know where the PMS server “lives”. In addition to that, I added the manual connection in the Roku app for 192.168.1.108. The port (32400) was already there.

11

@jdstarns said:

@sa2000 said:
One more question - have you previously made use of the Custom Server Access URL setting?
in Settings / Server / Network / Show Advanced

I am trying to understand how we ended up with port 10499 with local IP 192.168.1.108 - it is not showing in the xml you sent me but does show in equivalent xml in the roku log

I have. I added http://192.168.1.108 which is the ip address of my PMS. It didn’t seem to make a difference either way. As for port 10499, I don’t know. Last night, I also noticed in the logs that there were several get requests being made to 192.168.1.1, which is my router that has UPNP turned on.

I would think by ways of GDM discovery that the Plex app would know where the PMS server “lives”. In addition to that, I added the manual connection in the Roku app for 192.168.1.108. The port (32400) was already there.

The 192.168.1.1 in the log just means the requests were coming in to your router to your public IP Address and I presume because they are being received locally from the roku, the router is showing the source ip in the request as being its own IP. This is fine so long as 192.168.1.1 is only set the source IP for requests from within the local network -
The reason why the roku is using the public IP and not the local IP for the secure connections plex.direct url’s is because of DNS Rebinding protection - which you can look into and see if you can disable it. In my case my router does not allow me to change the behaviour so I live with DNS Rebinding.

You must have had port 10499 in the Custom Server Access URL - can’t see how else the roku would have used it

I presume you no longer have anything in the custom server access url as the xml you sent me did not show any

12

Wanted to update this.

I found the issue. It was my powerline adapters that were causing the issue. I ran a cat 6e cable from my plex server to my switch where the roku is and it now loads in 3-4 seconds.

I haven’t had an issue since I did this a couple of months ago.

13

I’m an IT consultant. I don’t recommend powerline adapters, and strongly advise against their use. Any network issue, and they (or wireless) are the very first thing you take out of the picture during troubleshooting.

14

I think there are probably more then a few techies here. Some of us probably even have a few acronyms behind our names.

While I acknowledge your comment, powerline adapters have their place in the home network world.

The problem is not with the powerline adapters but a problem with the house wiring.

They’ve been proven time and time again. They work.

15

@jdstarns said:
They’ve been proven time and time again. They work.

Not enough percent of the time or with enough consistency to make them a problem that should be recommended. Yes, there are a number of factors, including extremely common home wiring nuances (not “problems”, but just the normal way houses are wired) that interfere with them performing anywhere near like advertised on the box for most people.

16

Linking to an old post where I did some speed tests on Powerline which showed inadequate performance when the powerlines crossed from one electric circuit RCD (GFCI) to another - http://forums.plex.tv/discussion/comment/457054/#Comment_457054

They operated very well within the same RCD (GFCI) electric circuit in the house - but houses these days have loads of separate circuits

I have not revisited this since