Jump to content

CoverArt - Huge performance impact

pclausen

By pclausen
in Plugins

 Share

Recommended Posts

pclausen

pclausen   41

Posted
Posted

I've been running the CoverArt plugin for ages and really love it.  However, I decided to dig into a performance issue I have been having for a long time.  Basically what happens in that there is a delay of about 10-15 seconds anytime I go into the main movie list from a client (Chrome or Edge browser) or from a HTPC running Emby theater.

 

I'm running Emby as a plugin under FreeNAS and I posted about it on their forum.  Here's a link:

 

https://forums.freenas.org/index.php?threads/emby-mono-only-running-single-threaded.39594/#post-246273

 

At first I thought the issues was due to Mono running single threaded, but that appears to not be the case.  As an experiment, I went ahead and removed the CoverArt plugin, and it made all the difference in the world.  Everything is coming up more or less instantly now on all my clients.

 

I do understand that when the plugin is first installed, it has to create all the treated thumbnails, and each time I have done a fresh install of Emby, and then added the CoverArt plugin, I have noticed this.  Like when I browse my movie collection the first, you can see the plugin creating the power thumbnails at a rate of perhaps 10 per second.  This continues as I go through each page of 100 movies until the end.  Then when I go out and come back in, after that 10-15 second delay, then all 100 thumbs on the first page pop in, and as I go to each subsequent page, they come up instantly.  However, if I change the sort order, the plugin appears to create the thumbs all over again at the 10 per second rate or so.

 

So it seems that the plugin is not properly caching the images that it creates, or at least not for all operations.  I have a large movie collection (2,400 titles) and a lot of TV episodes (9,500), so I wonder if I have exceeded some sort of limit?  My server hardware is pretty beefy (see sig), so I wouldn't think that is the issue.

 

Any thoughts on why I'm experiencing this slowness with the CoverArt plugin?

Link to comment
Share on other sites
ebr Emby Team

ebr   14929

Posted
Posted

The plug-in doesn't handle any of the caching the normal system does and I'm not convinced that it is a caching issue based on your description.   Does this only happen in the web client?  If so, my suspicion is that this is another manifestation of whatever is going on here.

Link to comment
Share on other sites
pclausen

pclausen   41

Posted
  • Author
Posted (edited)

The slowdown is also present in Emby Theater.  General navigation/browsing is much improved speed wise with CoverArt not installed.  On Roku, not so much, but then very little is shown on the screen at a given time.

 

I read through the other thread you linked to and I'm also running the Collections Plugin.  However, other than the 10-20 second delay in bringing up the movie list initially, and the delay when changing the sort order, I have no issues with my Emby server crashing or otherwise being unstable.

 

Joshua is going to enable openmp in his next release, so I'll try again once I get my hands on that to see if that makes a difference.

 

A friend of mine is running Emby on Windows server 2008 on a beefy dual Xeon server with 48G RAM and an Areca raid 6 controller.  He has a mirror copy of my collection (he acts as my remote backup), and he too is seeing the 10-20 second delay when going into the movie listing.  So perhaps it has something to do with the size of the collection?

 

I might try removing some of my media folders temporarily to see if that makes a difference, like maybe drop back to only include my ~700 DVD titles and not the Blu-Ray or HD-DVD ones.

Edited by pclausen
Link to comment
Share on other sites
pclausen

pclausen   41

Posted
  • Author
Posted

So created a new Emby jail for testing and imported just a single one of my media folder (DVD movies with ~500 movies).  Once the scan of the folder completed, I installed just the CoverArt plugin and configured the default profile to my preference.

 

After the initial browse through the 500 titles, it is now very fast.  I'll continue loading my other media folder, all just using the default profile for now, and test speed after each one.  Assuming I don't experience any slowdowns, even when I get to 2,400 titles, I'll then setup my custom profiles (i.e. Blu-Ray, HD-DVD, etc).  Test again, then add my TV library, retest.   Then add the Collections Plugin, etc, etc. 

  • Like 1
Link to comment
Share on other sites
pclausen

pclausen   41

Posted
  • Author
Posted

I added my main Blu-Ray media folder back in, which brought the movie count to 2,000.  And the slowness issue is back.

 

So CoverArt with 500 titles is nice and snappy, but with 2,000 titles it bogs down to the point of it taking 10-15 seconds to pull up the first page of 100 thumbs and sorting causes a similar delay.  Again, with 500 titles, these actions complete within 1 second.  So it's not like it went from 1 second with 500 titles to 4 seconds with 2,000 titles.  Some limit is reached it appears, which causes a non linear increase in the time it takes to "paint" the thumbs.

Link to comment
Share on other sites
pclausen

pclausen   41

Posted
  • Author
Posted (edited)

Here you go:

root@emby_2:/var/db/emby-server/logs # more server-63584918978.txt
2015-12-05 18:01:09.1191 Info - App: ActivityLogWebSocketListener stop transmitting over websocket to 10.0.1.53:55115
2015-12-05 18:01:09.1191 Info - App: ActivityLogWebSocketListener Begin transmitting over websocket to 10.0.1.53:55115
2015-12-05 18:01:09.1191 Info - App: SessionInfoWebSocketListener stop transmitting over websocket to 10.0.1.53:55115
2015-12-05 18:01:09.1191 Info - App: ScheduledTasksWebSocketListener stop transmitting over websocket to 10.0.1.53:55115
2015-12-05 18:01:09.4363 Info - HttpServer: HTTP GET http://10.0.1.105:8096/emby/DisplayPreferences/home?userId=1586a15fe4284314b7f32cce512baed1&client=webclient. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/                                                                                                                                                                               46.0.2490.86 Safari/537.36
2015-12-05 18:01:09.4381 Info - HttpServer: HTTP Response 200 to 10.0.1.53. Time: 2ms. http://10.0.1.105:8096/emby/DisplayPreferences/home?userId=1586a15fe4284314b7f32cce512baed1&client=webclient
2015-12-05 18:01:09.4396 Info - HttpServer: HTTP GET http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Views. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2490.86 Safari/537.36
2015-12-05 18:01:09.4412 Info - HttpServer: HTTP GET http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items?SortBy=DatePlayed&SortOrder=Descending&MediaTypes=Video&Filters=IsResumable&Limit=10&Recursive=true&Fields=PrimaryImageAspectRatio%2CSyn                                                                                                                                                                               cInfo&CollapseBoxSetItems=false&ExcludeLocationTypes=Virtual&ImageTypeLimit=1&EnableImageTypes=Primary%2CBackdrop%2CBanner%2CThumb. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2490.86 Safari/537.36
2015-12-05 18:01:09.4412 Info - HttpServer: HTTP GET http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items/Latest?Limit=20&Fields=PrimaryImageAspectRatio%2CSyncInfo&ImageTypeLimit=1&EnableImageTypes=Primary%2CBackdrop%2CThumb. UserAgent: Mozil                                                                                                                                                                               la/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2490.86 Safari/537.36
2015-12-05 18:01:09.4416 Info - HttpServer: HTTP GET http://10.0.1.105:8096/emby/LiveTv/Recordings?userId=1586a15fe4284314b7f32cce512baed1&limit=5&IsInProgress=false. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chr                                                                                                                                                                               ome/46.0.2490.86 Safari/537.36
2015-12-05 18:01:09.4416 Info - HttpServer: HTTP Response 200 to 10.0.1.53. Time: 3ms. http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Views
2015-12-05 18:01:09.4533 Info - HttpServer: HTTP Response 200 to 10.0.1.53. Time: 12ms. http://10.0.1.105:8096/emby/LiveTv/Recordings?userId=1586a15fe4284314b7f32cce512baed1&limit=5&IsInProgress=false
2015-12-05 18:01:09.4900 Info - HttpServer: HTTP Response 200 to 10.0.1.53. Time: 49ms. http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items?SortBy=DatePlayed&SortOrder=Descending&MediaTypes=Video&Filters=IsResumable&Limit=10&Recursive=true&F                                                                                                                                                                               ields=PrimaryImageAspectRatio%2CSyncInfo&CollapseBoxSetItems=false&ExcludeLocationTypes=Virtual&ImageTypeLimit=1&EnableImageTypes=Primary%2CBackdrop%2CBanner%2CThumb
2015-12-05 18:01:09.5001 Info - HttpServer: HTTP Response 200 to 10.0.1.53. Time: 59ms. http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items/Latest?Limit=20&Fields=PrimaryImageAspectRatio%2CSyncInfo&ImageTypeLimit=1&EnableImageTypes=Primary%2                                                                                                                                                                               CBackdrop%2CThumb
2015-12-05 18:01:11.1783 Info - HttpServer: HTTP GET http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items/d417db23f477b3573331d2ef22d0935c. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.                                                                                                                                                                               0.2490.86 Safari/537.36
2015-12-05 18:01:11.1809 Info - HttpServer: HTTP Response 200 to 10.0.1.53. Time: 2ms. http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items/d417db23f477b3573331d2ef22d0935c
2015-12-05 18:01:11.4893 Info - HttpServer: HTTP GET http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items/Latest?IncludeItemTypes=Movie&Limit=18&Fields=PrimaryImageAspectRatio%2CMediaSourceCount%2CSyncInfo&ParentId=d417db23f477b3573331d2ef22d                                                                                                                                                                               0935c&ImageTypeLimit=1&EnableImageTypes=Primary%2CBackdrop%2CBanner%2CThumb. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2490.86 Safari/537.36
2015-12-05 18:01:11.4947 Info - HttpServer: HTTP GET http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items?SortBy=DatePlayed&SortOrder=Descending&IncludeItemTypes=Movie&Filters=IsResumable&Limit=6&Recursive=true&Fields=PrimaryImageAspectRatio%                                                                                                                                                                               2CMediaSourceCount%2CSyncInfo&CollapseBoxSetItems=false&ParentId=d417db23f477b3573331d2ef22d0935c&ImageTypeLimit=1&EnableImageTypes=Primary%2CBackdrop%2CBanner%2CThumb. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) C                                                                                                                                                                               hrome/46.0.2490.86 Safari/537.36
2015-12-05 18:01:11.4947 Info - HttpServer: HTTP GET http://10.0.1.105:8096/emby/Movies/Recommendations?userId=1586a15fe4284314b7f32cce512baed1&categoryLimit=4&ItemLimit=9&Fields=PrimaryImageAspectRatio%2CMediaSourceCount%2CSyncInfo&ImageTypeLimit=1&EnableImageT                                                                                                                                                                               ypes=Primary%2CBackdrop%2CBanner%2CThumb. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2490.86 Safari/537.36
2015-12-05 18:01:11.5713 Info - HttpServer: HTTP GET http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items/d417db23f477b3573331d2ef22d0935c. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.                                                                                                                                                                               0.2490.86 Safari/537.36
2015-12-05 18:01:11.5739 Info - HttpServer: HTTP Response 200 to 10.0.1.53. Time: 2ms. http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items/d417db23f477b3573331d2ef22d0935c
2015-12-05 18:01:11.5907 Info - HttpServer: HTTP Response 200 to 10.0.1.53. Time: 96ms. http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items?SortBy=DatePlayed&SortOrder=Descending&IncludeItemTypes=Movie&Filters=IsResumable&Limit=6&Recursive=t                                                                                                                                                                               rue&Fields=PrimaryImageAspectRatio%2CMediaSourceCount%2CSyncInfo&CollapseBoxSetItems=false&ParentId=d417db23f477b3573331d2ef22d0935c&ImageTypeLimit=1&EnableImageTypes=Primary%2CBackdrop%2CBanner%2CThumb
2015-12-05 18:01:11.7510 Info - HttpServer: HTTP Response 200 to 10.0.1.53. Time: 256ms. http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items/Latest?IncludeItemTypes=Movie&Limit=18&Fields=PrimaryImageAspectRatio%2CMediaSourceCount%2CSyncInfo&                                                                                                                                                                               ParentId=d417db23f477b3573331d2ef22d0935c&ImageTypeLimit=1&EnableImageTypes=Primary%2CBackdrop%2CBanner%2CThumb
2015-12-05 18:01:13.3246 Info - HttpServer: HTTP GET http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items/d417db23f477b3573331d2ef22d0935c. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.                                                                                                                                                                               0.2490.86 Safari/537.36
2015-12-05 18:01:13.3271 Info - HttpServer: HTTP Response 200 to 10.0.1.53. Time: 2ms. http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items/d417db23f477b3573331d2ef22d0935c
2015-12-05 18:01:13.6382 Info - HttpServer: HTTP GET http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items?SortBy=SortName&SortOrder=Descending&IncludeItemTypes=Movie&Recursive=true&Fields=PrimaryImageAspectRatio%2CSortName%2CMediaSourceCount%                                                                                                                                                                               2CSyncInfo&ImageTypeLimit=1&EnableImageTypes=Primary%2CBackdrop%2CBanner%2CThumb&StartIndex=0&Limit=100&ParentId=d417db23f477b3573331d2ef22d0935c. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2490.86 Saf                                                                                                                                                                               ari/537.36
2015-12-05 18:01:22.9069 Info - HttpServer: HTTP Response 200 to 10.0.1.53. Time: 9268ms (slow). http://10.0.1.105:8096/emby/Users/1586a15fe4284314b7f32cce512baed1/Items?SortBy=SortName&SortOrder=Descending&IncludeItemTypes=Movie&Recursive=true&Fields=PrimaryIma                                                                                                                                                                               geAspectRatio%2CSortName%2CMediaSourceCount%2CSyncInfo&ImageTypeLimit=1&EnableImageTypes=Primary%2CBackdrop%2CBanner%2CThumb&StartIndex=0&Limit=100&ParentId=d417db23f477b3573331d2ef22d0935c
2015-12-05 18:01:37.2719 Info - HttpServer: HTTP Response 200 to 10.0.1.53. Time: 25777ms (slow). http://10.0.1.105:8096/emby/Movies/Recommendations?userId=1586a15fe4284314b7f32cce512baed1&categoryLimit=4&ItemLimit=9&Fields=PrimaryImageAspectRatio%2CMediaSourceC                                                                                                                                                                               ount%2CSyncInfo&ImageTypeLimit=1&EnableImageTypes=Primary%2CBackdrop%2CBanner%2CThumb

Note the response time on those last 2 entries.

Edited by pclausen
Link to comment
Share on other sites
pclausen

pclausen   41

Posted
  • Author
Posted (edited)

That was the complete log file.  I blew away the old one just before doing the action causing the delay.

root@emby_2:/var/db/emby-server/logs # ls -l
total 10
-rw-r--r--  1 emby  emby  9553 Dec  5 13:01 server-63584918978.txt
root@emby_2:/var/db/emby-server/logs #

Should I enable verbose and try again?

Edited by pclausen
Link to comment
Share on other sites
ebr Emby Team

ebr   14929

Posted
Posted

You do need to put your logging level to Debug though because I can't see if CA is even being called on to process anything in those logs.

Link to comment
Share on other sites
Luke Emby Team

Luke   37112

Posted
Posted

Ah gotcha.  I deleted the existing log after starting but before performing the action with the slowness.  Complete logs attached from turning on the plugin from the FreeNAS GUI up through the delay in showing the movie thumbs.

 

In this log, image requests are very fast, and all of the slow requests are data-related. The next major server release will have a lot of database performance improvements.

 

In the meantime, the current server release does use a fair amount of caching so subsequent requests of the same content should be a little faster.

Link to comment
Share on other sites
ebr Emby Team

ebr   14929

Posted
Posted

You do need to put your logging level to Debug though because I can't see if CA is even being called on to process anything in those logs.

 

Could you also please post your CoverArt.xml file from within plugins/configurations.  Thx.

Link to comment
Share on other sites
ebr Emby Team

ebr   14929

Posted
Posted

Thanks.  As I had suspected, CA isn't even being called.  So this is more than likely something at a deeper level in the environment.  Perhaps memory swapping to disc once a certain library size is achieved?

 

What is the memory consumption of the server process when it bogs down like this?

Link to comment
Share on other sites
pclausen

pclausen   41

Posted
  • Author
Posted (edited)

Here's what top shows during that 10-15 second period where I wait for the movie thumbs to pop in:

 

embytest10.PNG

Edited by pclausen
Link to comment
Share on other sites
Deathsquirrel

Deathsquirrel   741

Posted
Posted

Actually after upgrading to the latest coverart beta from the release version things seem to be working well aside from the initial page load in my movies.  That's still slow to start but fine once it begins.

Link to comment
Share on other sites
pclausen

pclausen   41

Posted
  • Author
Posted (edited)

I also upgraded to the latest coverart beta, but it didn't make a difference for me.

 

Video showing the issue:

 

 

Uninstalled CoverArt plugin and the issue goes away:

 

 

The ONLY change between the 1st and 2nd video was the removal of the CoverArt plugin and doing the required shutdown and restart of the Emby jail.

 

I rebooted my entire FreeNAS server to apply an update prior to running the above tests.  You will notice that there's PLENTY of free memory as the ARC hasn't filled up yet.

Edited by pclausen
Link to comment
Share on other sites
Happy2Play

Happy2Play   8296

Posted
Posted

I have one server that does this and another that doesn't, both server are running WHS 2011. And the odd thing is the server that does this has 2000+ movies and the one that doesn't has 5000+ movies.  Removing CA gets your same results.

Link to comment
Share on other sites
ebr Emby Team

ebr   14929

Posted
Posted

I don't think there was anything in the last Beta CA that would have had an impact but Luke did make a change yesterday that might so I've put up a new beta today.

Link to comment
Share on other sites
Swynol

Swynol   375

Posted
Posted

i'm also experiencing this. i thought it was just a perk of using coverart. mine is no where near as slow as yours in the video above but having covertart on slows it down by 4-5 seconds on Emby theatre, not so noticable on the web client. but my movie collection is only around 1500 movies but alot of TV series. 

 

updated to the Beta 4.0.9.5 so will see if that is any different.

Link to comment
Share on other sites

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now
 Share
Go to topic listing
×
×
  • Create New...