Jump to content

Kodi hangs while adding new movies


booch
 Share

Recommended Posts

booch

After resolving problem from this thread - http://emby.media/community/index.php?/topic/35674-stuck-on-compressing-db-log-file-snippet/ I faced similar one. 

 

Each time when I start Kodi after Emby server got new movie(s) then sync process hangs with message about updating library with new movie(s) but actually they don't appear in Kodi library.

Kodi or PC restart does not help. Only force re-sync helps.

 

In the log I've found possible cause:

22:43:36 T:5320  NOTICE: VideoInfoScanner: Starting scan ..
22:43:36 T:5204  NOTICE: EMBY.kodimonitor -> Method: VideoLibrary.OnScanStarted Data: null
22:45:32 T:5772  NOTICE: EMBY.downloadutils -> Server unreachable at: http://192.168.0.101:8096/emby/Users/e03057b3b9414841ba1f0876ee5cd398/Items?format=json
22:45:32 T:5204  NOTICE: EMBY.service -> Server is online and ready.
22:46:32 T:5772  NOTICE: EMBY.downloadutils -> Server unreachable at: http://192.168.0.101:8096/emby/Users/e03057b3b9414841ba1f0876ee5cd398/Items?format=json
22:46:32 T:5204  NOTICE: EMBY.service -> Server is online and ready.

This URL returns next responce:

{"ResponseStatus":{"ErrorCode":"SecurityException","Message":"Access token is required.","StackTrace":" at MediaBrowser.Server.Implementations.HttpServer.Security.AuthService.ValidateSecurityToken (IServiceRequest request, System.String token) <0x40867160 + 0x00107> in <filename unknown>:0 \n at MediaBrowser.Server.Implementations.HttpServer.Security.AuthService.ValidateUser (IServiceRequest request, IAuthenticationAttributes authAttribtues) <0x4085d4d0 + 0x0007b> in <filename unknown>:0 \n at MediaBrowser.Server.Implementations.HttpServer.Security.AuthService.Authenticate (IServiceRequest request, IAuthenticationAttributes authAttribtues) <0x4085a670 + 0x00017> in <filename unknown>:0 \n at MediaBrowser.Controller.Net.AuthenticatedAttribute.RequestFilter (IRequest request, IResponse response, System.Object requestDto) <0x4085a510 + 0x0007a> in <filename unknown>:0 \n at ServiceStack.ServiceStackHost.ApplyRequestFiltersSingle (IRequest req, IResponse res, System.Object requestDto) <0x4083d240 + 0x0029e> in <filename unknown>:0 \n at ServiceStack.ServiceStackHost.ApplyRequestFilters (IRequest req, IResponse res, System.Object requestDto) <0x408362b0 + 0x000d5> in <filename unknown>:0 \n at ServiceStack.Host.RestHandler+<ProcessRequestAsync>d__13.MoveNext () <0x4082a650 + 0x00595> in <filename unknown>:0 "}}

Both HTPC with Kodi and Emby Server PC are located in local network. I can login to Emby from browser or app without problem with same user.

 

Kodi version: 16.1 installed on Windows 10 with Titan skin 3.6.71

Emby plugin version: 2.2.18

Emby Server version: 3.0.6000.0 installed on Ubuntu 14.04

Emby for Kodi Sync queue plugin version: 1.0.60.20.14567

 

I attached full Kodi log just in case

 

kodi.zip

server-63605088011.zip

Edited by booch
Link to comment
Share on other sites

Angelblue05

Can you also provide your server log from the same time frame? The response does not make sense - we always attach the token to the header as expected (if you look right before, everything was working correctly) :)

Edited by Angelblue05
Link to comment
Share on other sites

booch

Right now I've started Kodi and got same hanging sync with message "Processing added: 2 items"..

But now I decided to wait some time and sync gets done after about 20 minutes.

I believe it's not normal behavior for just 2 new movies.

Force resync takes approximately same time for all of my library..

 

So what's the problem could be with my setup?

Link to comment
Share on other sites

Angelblue05

In your server log, you got a lot of slow response. I am not sure why. I'm still looking into it.

 

 

Sent from my iPhone using Tapatalk

Link to comment
Share on other sites

booch

Another test.

I closed Kodi, then removed one movie from Emby server, then started Kodi and very long incremental sync gets started.

After about ~20 minutes movie disappears from Kodi's library but incremental sync stopped and started once again for some reason.. 10-20 minutes and again stop/start of sync. After 5th or 6th repeat sync finally gets finished.... but started again after some time (I didn't do anything with Emby library)

 

At this time on the Emby's server I see big performance overload with "mono-sgen" process (almost 100%):

booch    16137  137 25.1 3497960 1016380 ?     Ssl  июля25 5716:47 /usr/bin/mono-sgen --optimize=all /usr/lib/emby-server/bin/MediaBrowser.Server.Mono.exe -programdata /var/lib/emby-server -ffmpeg /usr/bin/ffmpeg -ffprobe /usr/bin/ffprobe -restartpath /usr/lib/emby-server/restart.sh

Probably slow sync occurs due to this bad performance.

My NAS with Emby server has these specs: Intel Atom D510, GeForce GT 630 and 4GB of RAM

I think it should be enough for much faster sync, isn't it?

Link to comment
Share on other sites

Angelblue05

If you are going to test, can you provide your Kodi log as well, thanks.

 

I don't think the issue is actually something add-on side, but you never know. I think something server side is causing this slowness and it's probably causing a delayed response when the add-on queries the server api. However, with your Kodi log, we'd be able to confirm, maybe find a solution to mitigate the effect it has in Kodi.

Edited by Angelblue05
Link to comment
Share on other sites

booch

Even after sync ends and closing Kodi, "mono-sgen" was loading system up to 90-95% of CPU. 

I restarted Emby server and it takes much less cpu usage now (about 20% overall). Even when I performed manual library sync it rises up to 50-60% only. Maybe memory leak on server side?

 

I'll do some tests after this restart and provide logs if problem reproduces

  • Like 1
Link to comment
Share on other sites

booch

New test

 

Steps:
1. Kodi is not running. CPU usage on server is about 10% in general while Emby is in idle state
2. New fake video is added to the Emby's library with "Suicide Squad (2016).mkv" filename. CPU usage rises up to 50% while scanning for about 1 minute and returns to the same low usage
3. Kodi is started, sync process begins with message about getting new movie. CPU usage on server rises up to 60-70%
4. After ~10 minutes sync spinner disappears in Kodi UI
5. Opened VIdeo section in Kodi to see whether new movie is added or not
 
====> Kodi crashes :(
 
I attached both Kodi and Emby logs

Kodi_crashed.zip

Link to comment
Share on other sites

booch
Test #2

Steps:

1. Kodi is not running. CPU usage on server is about 10% in general while Emby is in idle state

2. Kodi is started after previous crash, no sync process. New movie "Suicide Squad" exists in Kodi's librarry. Closed Kodi.

3. Removed "Suicide Squad (2016).mkv" from filesystem. Started Emby's library updatete. CPU rises up-to 95% for several minutes. Even after removing cpu was about 65-70%. After ~10 minutes cpu usage is low again.

4. Started Kodi, no sync process (or very fast?). There is no "Suicide Squad" movie in Kodi's library.

 

 


Test #3

Steps:

1. Kodi is not running. CPU usage on server is about 10% in general while Emby is in idle state

2. Added same "Suicide Squad (2016).mkv" to Emby's library. CPU rises up-to ~40% for several minutes.

3. Started Kodi, message appears about adding new movie. "Suicide Squad" is available after several seconds in Kodi's library.

 

Works great this time...

 

Edited by booch
Link to comment
Share on other sites

Angelblue05

I'm sorry @@booch

 

I've been trying to figure out something in your log. It seems your music library could be the problem. It took 4 mins to pull music updates from your server (a little more than 400 music items, albums, artists). Can you quickly disable your music library as a test (if you can't removed it from server, then simply disable music in the add-on settings > sync options)? Thanks.

Edited by Angelblue05
Link to comment
Share on other sites

booch

That's strange because music sync was always disabled in Emby's plugin for Kodi. I'm syncing only my video library

  • Like 1
Link to comment
Share on other sites

Angelblue05

@ @@xnappo @@Luke

 

We have a flaw with the fast sync. If music is disabled client side, the server plugin still records music events and sends them to the client when the client starts up. Unfortunately, I couldn't find a way to only retrieve the type for each item ids we have to process, before trying to add them to Kodi, to hopefully reduce the time wasted. This turns out to be very costly transaction when the item should not even be synced (logs provided by booch indicate almost 4 minutes to get the music items from the server ~430items, just to be skipped after the fact). Any solution?

 

Edit: I'm not sure if this is the issue, it should try to scan them in once, then move on... Unless something is causing the server to rescan those items every day?

Edited by Angelblue05
Link to comment
Share on other sites

xnappo

Adding @@jurmb84

 

But yes - I suspect this is actually the not identified/misidentified/reidentified bug

Edited by xnappo
Link to comment
Share on other sites

Angelblue05

It's a corner case. And I just meant a flaw when it comes to doing fast sync over manual sync :)

 

Indeed, nothing can be skipped in the server plugin, but even if we had a type param, the server would still need to be queried to find out the type because it's not included in server events, I think? 

Edited by Angelblue05
Link to comment
Share on other sites

Angelblue05

Yes I understood what you meant. The problem is the server plugin does not have that information because it's not included in server events that are being recorded. So the server plugin would still need to query the server itself for the type of item it is, which would slow things down server side making Luke dislike the fast sync even more, haha :)

 

Maybe we'll have no choice but to add the stuff to the emby database Kodi side, and mark it as skipped, this way it would avoid the situation the next time it happens? Hmm...

 

 

Sent from my iPhone using Tapatalk

Edited by Angelblue05
Link to comment
Share on other sites

Angelblue05

Yeah but considering how many times an unidentified item can be reprocessed... I'd be scare to add an extra verification step... :)

 

Hate is such a strong word... I'd say he dislikes it - because it can slows down the server itself (how or why, I can't tell you). He's been asking us for a while now, about what we need the server to provide to avoid needing the plugin. I told him we need a way to query by date modified,added,removed.

Edited by Angelblue05
Link to comment
Share on other sites

Angelblue05

Hehe, I hear you :)

 

What do you think of the following: we could add the items to the Emby database and mark them as skipped. Then, in the future, we can skip before pulling info from the server. I think it may also come in handy if one day we decide to skip import for more than just music. This would only really effect the scenario where item should be in database for update, but isn't. It will not be looked at for the manual sync.

Edited by Angelblue05
Link to comment
Share on other sites

xnappo

It really doesn't make sense to me that adding a 'modified' field and allowing queries against it in any way would slow down the server.  Can you guys think of why it would?  It is writing one more field, but it is opening the item to write anyway if it was modified.  It seems like an obvious DB feature to me.

Link to comment
Share on other sites

jurmb84

I am reading through this post as I was just about to post to ask ya'll to test a new version of the sync plugin which gets rid of SQLite... however... based on what I am seeing here, let me read this through and see if we want to add more functionality...

  • Like 1
Link to comment
Share on other sites

Angelblue05

Sounds good, let me know if you have any questions.

 

What we need is a way to filter some items from being returned if the user view is disabled Kodi side (for example, music). However how do we know what to skip since the server events are bare. I think marking items as skipped client side would be enough without adding complexity to the server plugin, but the downside is that we'd need to process the section at least once to tag them as skipped. If you think of something, I'm all ears.

Edited by Angelblue05
  • Like 1
Link to comment
Share on other sites

jurmb84

I am starting to dig a little and am already seeing that I have been tracking trailers as well... *sigh*... 
 

@@Luke - How can I tell what type of item I am looking at (movie, episode, song, album, etc) when the libraryManager_ItemAdded, libraryManager_ItemUpdated, libraryManager_ItemRemoved event handlers kick off?

 

I am seeing things like "ExtraType": "Trailer" when i serialize the object with IJsonSerializer but cannot find (or don't know where to look) that property in the object to check against... 

 

Cheers

Link to comment
Share on other sites

Guest
This topic is now closed to further replies.
 Share

×
×
  • Create New...