booch 32 Posted July 26, 2016 Share Posted July 26, 2016 (edited) 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 July 26, 2016 by booch Link to comment Share on other sites More sharing options...
Angelblue05 4130 Posted July 26, 2016 Share Posted July 26, 2016 (edited) 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 July 26, 2016 by Angelblue05 Link to comment Share on other sites More sharing options...
booch 32 Posted July 26, 2016 Author Share Posted July 26, 2016 sure server-63605088011.zip Link to comment Share on other sites More sharing options...
booch 32 Posted July 27, 2016 Author Share Posted July 27, 2016 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 More sharing options...
Angelblue05 4130 Posted July 27, 2016 Share Posted July 27, 2016 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 More sharing options...
booch 32 Posted July 27, 2016 Author Share Posted July 27, 2016 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 More sharing options...
Angelblue05 4130 Posted July 27, 2016 Share Posted July 27, 2016 (edited) 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 July 27, 2016 by Angelblue05 Link to comment Share on other sites More sharing options...
booch 32 Posted July 27, 2016 Author Share Posted July 27, 2016 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 1 Link to comment Share on other sites More sharing options...
booch 32 Posted July 27, 2016 Author Share Posted July 27, 2016 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 More sharing options...
booch 32 Posted July 28, 2016 Author Share Posted July 28, 2016 (edited) 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 July 28, 2016 by booch Link to comment Share on other sites More sharing options...
booch 32 Posted July 29, 2016 Author Share Posted July 29, 2016 Any news about my problem? It constantly reproduces ( Link to comment Share on other sites More sharing options...
Angelblue05 4130 Posted July 29, 2016 Share Posted July 29, 2016 (edited) 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 July 29, 2016 by Angelblue05 Link to comment Share on other sites More sharing options...
booch 32 Posted July 29, 2016 Author Share Posted July 29, 2016 That's strange because music sync was always disabled in Emby's plugin for Kodi. I'm syncing only my video library 1 Link to comment Share on other sites More sharing options...
Angelblue05 4130 Posted July 29, 2016 Share Posted July 29, 2016 Interesting - the updates came from the fast sync. Ok, give me a few. Link to comment Share on other sites More sharing options...
Angelblue05 4130 Posted July 30, 2016 Share Posted July 30, 2016 (edited) @ @@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 July 30, 2016 by Angelblue05 Link to comment Share on other sites More sharing options...
xnappo 1592 Posted July 30, 2016 Share Posted July 30, 2016 (edited) Adding @@jurmb84 But yes - I suspect this is actually the not identified/misidentified/reidentified bug Edited July 30, 2016 by xnappo Link to comment Share on other sites More sharing options...
Angelblue05 4130 Posted July 30, 2016 Share Posted July 30, 2016 (edited) 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 July 30, 2016 by Angelblue05 Link to comment Share on other sites More sharing options...
Angelblue05 4130 Posted July 30, 2016 Share Posted July 30, 2016 (edited) 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 July 30, 2016 by Angelblue05 Link to comment Share on other sites More sharing options...
Angelblue05 4130 Posted July 30, 2016 Share Posted July 30, 2016 (edited) 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 July 30, 2016 by Angelblue05 Link to comment Share on other sites More sharing options...
Angelblue05 4130 Posted July 31, 2016 Share Posted July 31, 2016 (edited) 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 July 31, 2016 by Angelblue05 Link to comment Share on other sites More sharing options...
xnappo 1592 Posted July 31, 2016 Share Posted July 31, 2016 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 More sharing options...
Angelblue05 4130 Posted July 31, 2016 Share Posted July 31, 2016 It will have to be something @@Luke will need to chime in Sent from my iPhone using Tapatalk Link to comment Share on other sites More sharing options...
jurmb84 281 Posted August 3, 2016 Share Posted August 3, 2016 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... 1 Link to comment Share on other sites More sharing options...
Angelblue05 4130 Posted August 3, 2016 Share Posted August 3, 2016 (edited) 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 August 3, 2016 by Angelblue05 1 Link to comment Share on other sites More sharing options...
jurmb84 281 Posted August 3, 2016 Share Posted August 3, 2016 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 More sharing options...
Recommended Posts