Partial Scan Slow

Plex Media Server Metadata & Adding Files
1

Server Version#: 1.15.4.919
Player Version#:

Hi,

My partial scans are taking ages to complete. (often longer than full scans).

The problem has existed for months, across a variety of server versions.

here’s a log example of a single folder - containing a single file, taking 21 minutes.

All advice much appreciated.

-M.

May 21, 2019 20:36:25.390 [13608] INFO - Plex Media Scanner v1.15.4.919-8e2884e4b - Microsoft PC x64 - build: windows-x86 - GMT 01:00
May 21, 2019 20:36:25.390 [13608] INFO - Windows version: 6.2 (Build 9200), language en-GB
May 21, 2019 20:36:25.390 [13608] INFO - 6 3600 MHz processor(s): Architecture=0, Level=6, Revision=40458 Processor Identifier=Intel64 Family 6 Model 158 Stepping 10, GenuineIntel
May 21, 2019 20:36:25.390 [13608] DEBUG - “C:\Program Files (x86)\Plex\Plex Media Server\Plex Media Scanner.exe” --scan --refresh --section 5 --directory "W:\TV Shows\The Big Bang Theory\Specials\The_Big_Bang_Theory_-00x06-_Unraveling_the_Mystery-A_Big_Bang_Farewell"
May 21, 2019 20:36:25.390 [7544] DEBUG - Opening 20 database sessions to library (com.plexapp.plugins.library), SQLite 3.26.0, threadsafe=1
May 21, 2019 20:36:25.578 [7544] DEBUG - It took 15.625000 ms to retrieve 671 items.
May 21, 2019 20:40:01.539 [7544] DEBUG - It took 15.625000 ms to retrieve 671 items.
May 21, 2019 20:43:34.755 [7544] DEBUG - It took 15.625000 ms to retrieve 671 items.
May 21, 2019 20:47:03.064 [7544] DEBUG - It took 15.625000 ms to retrieve 671 items.
May 21, 2019 20:50:38.819 [7544] DEBUG - It took 0.000000 ms to retrieve 671 items.
May 21, 2019 20:54:05.203 [7544] DEBUG - It took 15.625000 ms to retrieve 671 items.
May 21, 2019 20:57:31.183 [7544] DEBUG - Scanning TV Shows using en(Plex Series Scanner) with 1 current media items and 1 section locations in the database…
May 21, 2019 20:57:31.183 [5088] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/cullTimeline?librarySectionID=5&sinceTime=1558467451
May 21, 2019 20:57:31.183 [5088] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/cullTimeline?librarySectionID=5&sinceTime=1558467451
May 21, 2019 20:57:31.230 [7544] DEBUG - Performing a scan with ‘Plex Series Scanner’ (language: en virtual: 0).
May 21, 2019 20:57:31.230 [7544] DEBUG - * Scanning W:\TV Shows\The Big Bang Theory\Specials\The_Big_Bang_Theory-00x06-_Unraveling_the_Mystery-A_Big_Bang_Farewell
May 21, 2019 20:57:31.230 [7544] DEBUG - * Scanning directory W:\TV Shows\The Big Bang Theory\Specials\The_Big_Bang_Theory-00x06-_Unraveling_the_Mystery-A_Big_Bang_Farewell (parent: yes)
May 21, 2019 20:57:31.230 [7544] DEBUG - Removing 1 media items that were left.
May 21, 2019 20:57:31.230 [7544] DEBUG - Deleting media item 317418.
May 21, 2019 20:57:31.230 [7544] DEBUG - Was connected to metadata item 184045, count is now 0.
May 21, 2019 20:57:31.230 [7544] DEBUG - Destroying metadata item 184045 (Unraveling the Mystery: A Big Bang Farewell)
May 21, 2019 20:57:31.230 [7544] DEBUG - Destroying metadata item 184044 (Specials)
May 21, 2019 20:57:31.230 [7544] DEBUG - Updating deletion state for metadata item 165610, is has a dead item count of 0.
May 21, 2019 20:57:31.230 [5088] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/flushMetadataCounterCache
May 21, 2019 20:57:31.230 [7544] DEBUG - Removing 1 directories that were left.
May 21, 2019 20:57:31.230 [7544] DEBUG - Deleting directory [The Big Bang Theory/Specials/The_Big_Bang_Theory-00x06-_Unraveling_the_Mystery-_A_Big_Bang_Farewell] (81077)
May 21, 2019 20:57:31.246 [5088] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/flushMetadataCounterCache
May 21, 2019 20:57:31.246 [5088] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/flushMetadataCounterCache
May 21, 2019 20:57:31.261 [5088] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/flushMetadataCounterCache
May 21, 2019 20:57:31.308 [7544] DEBUG - Refreshing section 5 of type: 2
May 21, 2019 20:57:31.308 [5088] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/destroy?librarySectionID=5&ids=184044,184045&types=3,4&parentIDs=165610,184044&rootIDs=-1,165610
May 21, 2019 20:57:31.324 [5088] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/destroy?librarySectionID=5&ids=184044,184045&types=3,4&parentIDs=165610,184044&rootIDs=-1,165610
May 21, 2019 20:57:31.777 [7544] DEBUG - The show ‘Legacies’ has unmatched leaves, and show was matched, so we’ll refresh.
May 21, 2019 20:57:31.855 [7544] DEBUG - The show ‘Narcos: Mexico’ has unmatched leaves, and show was matched, so we’ll refresh.
May 21, 2019 20:57:32.019 [4844] DEBUG - Refreshing 2 IDs.
May 21, 2019 20:57:32.019 [4844] DEBUG - Refreshing metadata for ‘Legacies’ (agent: com.plexapp.agents.thetvdb)
May 21, 2019 20:57:32.019 [5088] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=5&metadataItemID=176848&metadataType=2&state=3&metadataState=queued
May 21, 2019 20:57:32.019 [4844] DEBUG - Refreshing GUID: ‘com.plexapp.agents.thetvdb://347521?lang=en’
May 21, 2019 20:57:32.019 [4844] DEBUG - HTTP requesting GET http://127.0.0.1:32400/system/agents/update?mediaType=2&force=1&guid=com.plexapp.agents.thetvdb%3A%2F%2F347521%3Flang%3Den&id=176848
May 21, 2019 20:57:32.019 [5088] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=5&metadataItemID=176848&metadataType=2&state=3&metadataState=queued
May 21, 2019 20:57:32.035 [4844] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/system/agents/update?mediaType=2&force=1&guid=com.plexapp.agents.thetvdb%3A%2F%2F347521%3Flang%3Den&id=176848
May 21, 2019 20:57:32.035 [4844] DEBUG - Refreshing metadata for ‘Narcos: Mexico’ (agent: com.plexapp.agents.thetvdb)
May 21, 2019 20:57:32.035 [4844] DEBUG - Refreshing GUID: ‘com.plexapp.agents.thetvdb://350458?lang=en’
May 21, 2019 20:57:32.035 [5088] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=5&metadataItemID=177345&metadataType=2&state=3&metadataState=queued
May 21, 2019 20:57:32.035 [4844] DEBUG - HTTP requesting GET http://127.0.0.1:32400/system/agents/update?mediaType=2&force=1&guid=com.plexapp.agents.thetvdb%3A%2F%2F350458%3Flang%3Den&id=177345
May 21, 2019 20:57:32.035 [5088] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/changeItemState?librarySectionID=5&metadataItemID=177345&metadataType=2&state=3&metadataState=queued
May 21, 2019 20:57:32.050 [4844] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/system/agents/update?mediaType=2&force=1&guid=com.plexapp.agents.thetvdb%3A%2F%2F350458%3Flang%3Den&id=177345

2

Looks like you’ve got something tying up your database so the scanner is waiting for it to be ready before it does the actual scan. Scanning appears to only take a few seconds. It’s just waiting for 21 minutes for the database.

Try optimizing the database and see if that helps. Also look to see if you have other things that could slow down your database. A backup or virus program scanning anything Plex related. If you have Tautulli or other 3rd party Plex related things installed, maybe try turning those off and see if that makes a difference.

3

have just completed a move of my plex installation onto a new (much higher spec) windows machine, and while everything is working ok, I’m still getting this same behaviour with slow partial scans.

The delays are all on the few lines which read “It took XX.625000 ms to retrieve XXX items.”, similiar to below.

I’m happy there is no other load etc on my machine that is causing the slowdown, but annt sure where to look next.

Any ideas?

If i switch on verbose logging, will that effect the output in the plex scanner logs?

Jun 21, 2019 10:13:10.705 [11840] DEBUG - “C:\Program Files (x86)\Plex\Plex Media Server\Plex Media Scanner.exe” --scan --refresh --section 5 --directory “V:\TV Shows\MasterChef (US)\Season 10”
Jun 21, 2019 10:13:10.705 [15900] DEBUG - Opening 20 database sessions to library (com.plexapp.plugins.library), SQLite 3.26.0, threadsafe=1
Jun 21, 2019 10:13:10.861 [15900] DEBUG - It took 15.625000 ms to retrieve 674 items.
Jun 21, 2019 10:17:04.015 [15900] DEBUG - It took 15.625000 ms to retrieve 674 items.
Jun 21, 2019 10:20:57.250 [15900] DEBUG - It took 0.000000 ms to retrieve 674 items.

PS: have optimised the database a bunch of times, and switched off anything else that I can think of that could potentially interfere (but on the basis that its a clean build of windows, there’s actually very little)

4

This might already be solved. The fix should land in one of the next updates.

5

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.