search

jellyfin / jellyfin-kodi

Jellyfin Plugin for Kodi
https://jellyfin.org
GNU General Public License v3.0
856 stars 113 forks source link

Refuses to Sync Extremely Large Shows #454

Open alpaca1thunder opened 3 years ago

alpaca1thunder commented 3 years ago

Describe the bug So I have a very long series with 300+ seasons and a very large amount of episodes that Jellyfin-Kodi will "get stuck" on, and sync indefinitely. The webui will also become unresponsive, which makes me think this might be a Jellyfin thing, but I'm not sure.

To Reproduce

  1. Start fresh installation of LibreELEC
  2. Install Jellyfin-Kodi
  3. Add Server Info
  4. Sync
  5. It gets stuck with the said show in the corner and the ball spinning

Expected behavior For it to successfully sync.

System (please complete the following information):

Additional context I had previously thought this was an Nginx thing for me, but after just exposing the port and going around Nginx the problem still persists. It seemed to fail and crash when it was behind nginx after an hour or so, and without it it just syncs indefinitely.

I have libraries/Kodi setups that are working with it because the episodes were added gradually, and I've been able to mitigate it by migrating by database to a new machine and resetting the add-on ID in the client. But some of my posters are messed up, and I'd like to be able to do a clean installation.

I don't mind posting logs, if someone could let me know what information I could provide for it to be useful.

Thanks for reading! :)

mcarlton00 commented 3 years ago

You can grab logs with this method. However, instead of enabling Kodi's debug logging, enable our addon's debug logs (Addons -> Jellyfin -> Settings -> Advanced -> Log Level). https://kodi.wiki/view/Log_file/Easy

I have a hunch that this might be a followup of #350 where the device is running out of memory, but the logs should give us a better idea. How long have you let it sit spinning before giving up on the sync?

alpaca1thunder commented 3 years ago

You can grab logs with this method. However, instead of enabling Kodi's debug logging, enable our addon's debug logs (Addons -> Jellyfin -> Settings -> Advanced -> Log Level). https://kodi.wiki/view/Log_file/Easy

I have a hunch that this might be a followup of #350 where the device is running out of memory, but the logs should give us a better idea. How long have you let it sit spinning before giving up on the sync?

Thanks for the prompt reply!

Here's the relevant log info from a clean installation:

2020-12-27 11:29:57.113 T:2862465904  NOTICE: JELLYFIN.jellyfin.http -> DEBUG::jellyfin_kodi/jellyfin/http.py:84 --->[ http ] {
                                                "url": "http://[REDACTED]:8096/Shows/ad0875ac13c3e1ef50e533bd3861d7d0/Seasons", 
                                                "verify": true, 
                                                "headers": {
                                                    "Accept-Charset": "UTF-8,*", 
                                                    "Accept-encoding": "gzip", 
                                                    "X-MediaBrowser-Token": "3cb56a23452b4fbbac60aae9ecf20294", 
                                                    "Content-type": "application/json", 
                                                    "x-emby-authorization": "MediaBrowser Client=Kodi, Device=Kodi (neetpi2), DeviceId=212724e4-9d06-4718-9ee0-ba633406111d, Version=0.6.5+py2, UserId=8b07e5e25ee34e01935b60258992c780", 
                                                    "User-Agent": "Jellyfin-Kodi/0.6.5+py2"
                                                }, 
                                                "params": {
                                                    "Fields": "Path,Genres,SortName,Studios,Writer,Taglines,LocalTrailerCount,OfficialRating,CumulativeRunTimeTicks,ItemCounts,Metascore,AirTime,DateCreated,People,Overview,CriticRating,CriticRatingSummary,Etag,ShortOverview,ProductionLocations,Tags,ProviderIds,ParentId,RemoteTrailers,SpecialEpisodeNumbers,MediaSources,VoteCount,RecursiveItemCount,PrimaryImageAspectRatio", 
                                                    "EnableImages": true, 
                                                    "UserId": "8b07e5e25ee34e01935b60258992c780"
                                                }, 
                                                "timeout": 30, 
                                                "type": "GET"
                                            }
2020-12-27 11:42:03.163 T:2862465904  NOTICE: JELLYFIN.jellyfin.http -> ERROR::jellyfin_kodi/jellyfin/http.py:106 HTTPConnectionPool(host='[REDACTED]', port=8096): Max retries exceeded with url: /Shows/ad0875ac13c3e1ef50e533bd3861d7d0/Seasons?Fields=Path%2CGenres%2CSortName%2CStudios%2CWriter%2CTaglines%2CLocalTrailerCount%2COfficialRating%2CCumulativeRunTimeTicks%2CItemCounts%2CMetascore%2CAirTime%2CDateCreated%2CPeople%2COverview%2CCriticRating%2CCriticRatingSummary%2CEtag%2CShortOverview%2CProductionLocations%2CTags%2CProviderIds%2CParentId%2CRemoteTrailers%2CSpecialEpisodeNumbers%2CMediaSources%2CVoteCount%2CRecursiveItemCount%2CPrimaryImageAspectRatio&EnableImages=True&UserId=8b07e5e25ee34e01935b60258992c780 (Caused by ReadTimeoutError("HTTPConnectionPool(host='[REDACTED]', port=8096): Read timed out. (read timeout=30)",))
2020-12-27 11:42:03.174 T:2862465904  NOTICE: JELLYFIN.database -> ERROR::jellyfin_kodi/database/__init__.py:163 type: <type 'exceptions.KeyError'> value: u'auth.server-id'
2020-12-27 11:42:03.186 T:2862465904  NOTICE: JELLYFIN.database -> DEBUG::jellyfin_kodi/database/__init__.py:167 [jellyfin] 645 rows updated.
2020-12-27 11:42:03.365 T:2862465904  NOTICE: JELLYFIN.database -> DEBUG::jellyfin_kodi/database/__init__.py:170 ---<[ database: jellyfin ] 2592304832
2020-12-27 11:42:03.759 T:2862465904  NOTICE: JELLYFIN.database -> ERROR::jellyfin_kodi/database/__init__.py:163 type: <type 'exceptions.KeyError'> value: u'auth.server-id'
2020-12-27 11:42:03.765 T:2862465904  NOTICE: JELLYFIN.database -> DEBUG::jellyfin_kodi/database/__init__.py:167 [video] 8718 rows updated.
2020-12-27 11:42:04.021 T:2862465904  NOTICE: JELLYFIN.database -> DEBUG::jellyfin_kodi/database/__init__.py:170 ---<[ database: video ] 2592304688

This came a little bit after, but it could just be other things in my library updating:

2020-12-27 12:06:02.341 T:2881561456  NOTICE: JELLYFIN.helper.utils -> DEBUG::jellyfin_kodi/helper/utils.py:145 ---[ event: plugin.video.jellyfin/LibraryChanged ] "[{\"FoldersAddedTo\": [\"e675012a1892a87530d2c0b0d14a9026\"], \"CollectionFolders\": [\"f137a2dd21bbc1b99aa5c0f6bf02a805\", \"09790ec4c9712e6dfb0961f34680b352\", \"767bffe4f11c93ef34b805451a696a4e\"], \"ItemsRemoved\": [], \"ItemsUpdated\": [], \"FoldersRemovedFrom\": [], \"ItemsAdded\": [\"999f18f489950a5a534145fde501a23d\"], \"IsEmpty\": false}]"
2020-12-27 12:06:02.353 T:2881561456  NOTICE: JELLYFIN.helper.utils -> DEBUG::jellyfin_kodi/helper/utils.py:145 ---[ event: plugin.video.jellyfin/LibraryChanged ] "[{\"FoldersAddedTo\": [], \"CollectionFolders\": [], \"ItemsRemoved\": [], \"ItemsUpdated\": [\"999f18f489950a5a534145fde501a23d\"], \"FoldersRemovedFrom\": [], \"ItemsAdded\": [], \"IsEmpty\": false}]"
2020-12-27 12:06:02.373 T:2682864496  NOTICE: JELLYFIN.entrypoint.service -> DEBUG::jellyfin_kodi/entrypoint/service.py:167 [ plugin.video.jellyfin: LibraryChanged ] {
                                                "FoldersAddedTo": [
                                                    "e675012a1892a87530d2c0b0d14a9026"
                                                ],
                                                "CollectionFolders": [
                                                    "f137a2dd21bbc1b99aa5c0f6bf02a805",
                                                    "09790ec4c9712e6dfb0961f34680b352",
                                                    "767bffe4f11c93ef34b805451a696a4e"
                                                ],
                                                "ItemsRemoved": [],
                                                "ItemsUpdated": [],
                                                "FoldersRemovedFrom": [],
                                                "ItemsAdded": [
                                                    "999f18f489950a5a534145fde501a23d"
                                                ],
                                                "IsEmpty": false
                                            }
2020-12-27 12:06:02.385 T:2682864496  NOTICE: JELLYFIN.entrypoint.service -> DEBUG::jellyfin_kodi/entrypoint/service.py:167 [ plugin.video.jellyfin: LibraryChanged ] {
                                                "FoldersAddedTo": [],
                                                "CollectionFolders": [],
                                                "ItemsRemoved": [],
                                                "ItemsUpdated": [
                                                    "999f18f489950a5a534145fde501a23d"
                                                ],
                                                "FoldersRemovedFrom": [],
                                                "ItemsAdded": [],
                                                "IsEmpty": false
                                            }

The rest of the logs seem to just be successful syncs from the shows before it. The sync has been hung on the one show for about 45~ Minutes now.

I'm not sure how much help this is, but I've had the same result on 3 different machines before with a variety of different specs. One had 16GB of ram and a pretty speedy processor, the machine I'm testing it on now is just an RPi4B. So tl;dr, I don't think it has anything to do with the specs of any of the client machines.

I've got the Pi set aside for figuring this out, so let me know if you need me to test anything.

mcarlton00 commented 3 years ago

Nope, it's definitely not an issue with memory like I initially thought. It seems as though the server is taking too long to respond when trying to get a season list for that show, causing us to timeout locally. That shouldn't be hanging the whole sync though, ideally it should just log an error and move on.

I may need to set up a dummy show on my server and simulate a bunch of seasons to try to replicate this before we can try to find a way around it.

mcarlton00 commented 3 years ago

Actually, if you can would you be able to increase the timeout on this line on one of your installs and see if that has any effect? I would start with 30 and increase from there if needed.

https://github.com/jellyfin/jellyfin-kodi/blob/d59c4fc18a426eb7f6602473b81d4914570da4a4/jellyfin_kodi/jellyfin/api.py#L50

alpaca1thunder commented 3 years ago

Actually, if you can would you be able to increase the timeout on this line on one of your installs and see if that has any effect? I would start with 30 and increase from there if needed.

https://github.com/jellyfin/jellyfin-kodi/blob/d59c4fc18a426eb7f6602473b81d4914570da4a4/jellyfin_kodi/jellyfin/api.py#L50

Done, tried it with 30 and 60. Still no luck, same issues.

What's weird is that this really slows down the web interlace to my Jellyfin instance (when it gets to syncing the show), even afterwards sometimes. I've had to restart the docker container after each attempt.

For some reason it disconnected from the Wifi at the end of the previous sync attempt (after logging the same error) so I'm going to bump it up to 120 and use an Ethernet cable just to be sure. Will report back after that's done.

alpaca1thunder commented 3 years ago

Nope with 120 as well ): Same issue, final log says:

2020-12-28 12:51:41.997 T:2747659120  NOTICE: JELLYFIN.jellyfin.http -> ERROR::jellyfin_kodi/jellyfin/http.py:106 HTTPConnectionPool(host='[REDACTED]', port=8096): Max retries exceeded with url: /Shows/ad0875ac13c3e1ef50e533bd3861d7d0/Seasons?Fields=Path%2CGenres%2CSortName%2CStudios%2CWriter%2CTaglines%2CLocalTrailerCount%2COfficialRating%2CCumulativeRunTimeTicks%2CItemCounts%2CMetascore%2CAirTime%2CDateCreated%2CPeople%2COverview%2CCriticRating%2CCriticRatingSummary%2CEtag%2CShortOverview%2CProductionLocations%2CTags%2CProviderIds%2CParentId%2CRemoteTrailers%2CSpecialEpisodeNumbers%2CMediaSources%2CVoteCount%2CRecursiveItemCount%2CPrimaryImageAspectRatio&EnableImages=True&UserId=8b07e5e25ee34e01935b60258992c780 (Caused by ReadTimeoutError("HTTPConnectionPool(host='[REDACTED]', port=8096): Read timed out. (read timeout=30)",))
alpaca1thunder commented 3 years ago

Tried this with Kodi Matrix and the latest add-on version as well, still no luck. Will give it a go with 10.7 server stable when that's available to see if that changes anything.

Sorry, don't mean to spam this post. Just updating it in case anyone is running into similar issues and wants to debug.

mcarlton00 commented 3 years ago

Not being spammy, this has been idle for a while. Activity kinda spikes and ebbs and it's been pretty quiet lately.

At this moment I'm assuming it's a server issue, but haven't been able to confirm that yet. Given the messages you've posted, it seems like the server takes too long to respond to that API call when it has to load so much data. I need to write a script to spoof a file directory that looks like something with a ton of seasons and try to load that into the server. For reference, what show is this so I can try to replicate it?

GRMrGecko commented 3 years ago

Hello,

The problem is indeed something to do with the interaction between Jellyfin Kodi and Jellyfin server. During my testing, a task started and did something, after which the issue went away. But with the information I have, I can provide the following details.

  1. I ran the same query that Kodi does for 1 page using an API key and it took about 6-9 seconds to return a result.
  2. After running the kodi sync, and waiting for Kodi to reach the TV series with a lot of episodes, I ran the same query at the same time as Kodi and it took 4 and a half minutes to execute.
  3. I then enabled debug in Jellyfin server (https://jellyfin.org/docs/general/administration/troubleshooting.html) and got some log output during both my query and the kodi query. Logs are attached here.
  4. From reviewing the logs, I see a main difference in calls in that Kodi is requesting 3 different pages at the same time. I haven't been able to try running the 3 calls manually myself, and with Jellyfin being fixed now I have no idea if I can even try to reproduce it again... But below are the 3 queries I would run to test.
curl --request GET \
  --url 'http://10.0.0.5:8096/Shows/d3834d20****0a4aea1afa/Episodes?api_key=5882a707b****09aceafe&userId=63d90de****e121bcb9&EnableUserData=True&EnableImages=True&Fields=Path%2CGenres%2CSortName%2CStudios%2CWriter%2CTaglines%2CLocalTrailerCount%2COfficialRating%2CCumulativeRunTimeTicks%2CItemCounts%2CMetascore%2CAirTime%2CDateCreated%2CPeople%2COverview%2CCriticRating%2CCriticRatingSummary%2CEtag%2CShortOverview%2CProductionLocations%2CTags%2CProviderIds%2CParentId%2CRemoteTrailers%2CSpecialEpisodeNumbers%2CMediaSources%2CVoteCount%2CRecursiveItemCount%2CPrimaryImageAspectRatio&StartIndex=0&Limit=15' \
  --header 'Accept: application/json' \
& curl --request GET \
  --url 'http://10.0.0.5:8096/Shows/d3834d20****0a4aea1afa/Episodes?api_key=5882a707b****09aceafe&userId=63d90de****e121bcb9&EnableUserData=True&EnableImages=True&Fields=Path%2CGenres%2CSortName%2CStudios%2CWriter%2CTaglines%2CLocalTrailerCount%2COfficialRating%2CCumulativeRunTimeTicks%2CItemCounts%2CMetascore%2CAirTime%2CDateCreated%2CPeople%2COverview%2CCriticRating%2CCriticRatingSummary%2CEtag%2CShortOverview%2CProductionLocations%2CTags%2CProviderIds%2CParentId%2CRemoteTrailers%2CSpecialEpisodeNumbers%2CMediaSources%2CVoteCount%2CRecursiveItemCount%2CPrimaryImageAspectRatio&StartIndex=15&Limit=15' \
  --header 'Accept: application/json' \
& curl --request GET \
  --url 'http://10.0.0.5:8096/Shows/d3834d20****0a4aea1afa/Episodes?api_key=5882a707b****09aceafe&userId=63d90de****e121bcb9&EnableUserData=True&EnableImages=True&Fields=Path%2CGenres%2CSortName%2CStudios%2CWriter%2CTaglines%2CLocalTrailerCount%2COfficialRating%2CCumulativeRunTimeTicks%2CItemCounts%2CMetascore%2CAirTime%2CDateCreated%2CPeople%2COverview%2CCriticRating%2CCriticRatingSummary%2CEtag%2CShortOverview%2CProductionLocations%2CTags%2CProviderIds%2CParentId%2CRemoteTrailers%2CSpecialEpisodeNumbers%2CMediaSources%2CVoteCount%2CRecursiveItemCount%2CPrimaryImageAspectRatio&StartIndex=30&Limit=15' \
  --header 'Accept: application/json'

Hope this information helps. call-from-kodi-sync.txt Manual-call.txt

ChojinDSL commented 3 years ago

Just wanted to add that I'm experiencing the same thing with a large show like SNL which has over 40 seasons.

kohsine commented 3 years ago

I think I've found a workaround for this. I reorganized the show into season folders and that seemed to work. I'm using Sonarr so this was pretty easy but I dont know how hard it would be to manually do it.