Thanks for those logs.
- I see 6 log files full of it scanning only music. It’s as if
– The server has a substantial music library
– Something changed dates/times somewhere on files/directories and caused it to trigger a full music library rescans like this.
Nov 01, 2022 02:03:13.026 [0x7f42822b3700] DEBUG - Activity: updated activity e9cb9d89-0b70-4b71-8fd6-aa7e00b403ca - completed 39.1% - Scanning Music
Nov 01, 2022 02:03:13.026 [0x7f42822b3700] DEBUG - Scanner: Processing directory /volume1/Music/Music/iTunes/Album Artwork/Cloud Purchases/495984AA4C58E457/04/14/11 (parent: yes)
Nov 01, 2022 02:03:13.026 [0x7f42822b3700] DEBUG - Skipping over directory 'Music/iTunes/Album Artwork/Cloud Purchases/495984AA4C58E457/04/14/11', as nothing has changed; removing 0 media items from map.
-
I do not see any other activity (communicating with Plex.tv, attempts to play anything, etc) which I would expect however that may have rolled off the logs buffer (common when a machine has a lot of music)
-
I noticed, which isn’t important right now, there is a bunch of junk in the Music shared folder which shouldn’t be there. It looks like other apps store their Settings info in the Music shared folder. This should be addressed at some point.
Nov 01, 2022 06:23:13.333 [0x7f42825a1700] DEBUG - Skipping over directory 'Music/GarageBand', as nothing has changed; removing 0 media items from map.
Nov 01, 2022 06:23:13.333 [0x7f42825a1700] DEBUG - Activity: updated activity 6c9d8bb9-e8d6-495f-a329-710deae5c98a - completed 59.4% - Scanning Music
Nov 01, 2022 06:23:13.333 [0x7f42825a1700] DEBUG - Scanner: Processing directory /volume1/Music/Music/Audio Music Apps (parent: yes)
Nov 01, 2022 06:23:13.334 [0x7f42825a1700] DEBUG - Skipping over directory 'Music/Audio Music Apps', as nothing has changed; removing 0 media items from map.
Nov 01, 2022 06:23:13.334 [0x7f42825a1700] DEBUG - Scanner: Processing directory /volume1/Music/Music/Audio Music Apps/Plug-In Settings (parent: yes)
Nov 01, 2022 06:23:13.334 [0x7f42825a1700] DEBUG - Skipping over directory 'Music/Audio Music Apps/Plug-In Settings', as nothing has changed; removing 0 media items from map.
Nov 01, 2022 06:23:13.334 [0x7f42825a1700] DEBUG - Scanner: Processing directory /volume1/Music/Music/Audio Music Apps/Plug-In Settings/Alchemy (parent: yes)
Nov 01, 2022 06:23:13.334 [0x7f42825a1700] DEBUG - Skipping over directory 'Music/Audio Music Apps/Plug-In Settings/Alchemy', as nothing has changed; removing 0 media items from map.
Nov 01, 2022 06:23:13.335 [0x7f42825a1700] DEBUG - Scanner: Processing directory /volume1/Music/Music/Audio Music Apps/Plug-In Settings/Alchemy/Libraries (parent: yes)
Nov 01, 2022 06:23:13.335 [0x7f42825a1700] DEBUG - Skipping over directory 'Music/Audio Music Apps/Plug-In Settings/Alchemy/Libraries', as nothing has changed; removing 0 media items from map.
Nov 01, 2022 06:23:13.335 [0x7f42825a1700] DEBUG - Scanner: Processing directory /volume1/Music/Music/Audio Music Apps/Plug-In Settings/Alchemy/Libraries/ImportBrowser (parent: yes)
Nov 01, 2022 06:23:13.335 [0x7f42825a1700] DEBUG - Skipping over directory 'Music/Audio Music Apps/Plug-In Settings/Alchemy/Libraries/ImportBrowser', as nothing has changed; removing 0 media items from map.
Nov 01, 2022 06:23:13.335 [0x7f42825a1700] DEBUG - Activity: updated activity 6c9d8bb9-e8d6-495f-a329-710deae5c98a - completed 64.4% - Scanning Music
Nov 01, 2022 06:23:13.335 [0x7f42825a1700] DEBUG - Scanner: Processing directory /volume1/Music/Music/Audio Music Apps/Sampler Instruments (parent: yes)
Nov 01, 2022 06:23:13.335 [0x7f42825a1700] DEBUG - Skipping over directory 'Music/Audio Music Apps/Sampler Instruments', as nothing has changed; removing 0 media items from map.
Nov 01, 2022 06:23:13.335 [0x7f42825a1700] DEBUG - Activity: updated activity 6c9d8bb9-e8d6-495f-a329-710deae5c98a - completed 69.3% - Scanning Music
Nov 01, 2022 06:23:13.335 [0x7f42825a1700] DEBUG - Scanner: Processing directory /volume1/Music/Music/Audio Music Apps/Databases (parent: yes)
Nov 01, 2022 06:23:13.336 [0x7f42825a1700] DEBUG - Skipping over directory 'Music/Audio Music Apps/Databases', as nothing has changed; removing 0 media items from map.
Nov 01, 2022 06:23:13.336 [0x7f42825a1700] DEBUG - Scanner: Processing directory /volume1/Music/Music/Audio Music Apps/Databases/Tags (parent: yes)
Nov 01, 2022 06:23:13.340 [0x7f42825a1700] DEBUG - Skipping over directory 'Music/Audio Music Apps/Databases/Tags', as nothing has changed; removing 0 media items from map.
Nov 01, 2022 06:23:13.340 [0x7f42825a1700] DEBUG - Activity: updated activity 6c9d8bb9-e8d6-495f-a329-710deae5c98a - completed 74.3% - Scanning Music
Nov 01, 2022 06:23:13.340 [0x7f42825a1700] DEBUG - Scanner: Processing directory /volume1/Music/Music/Audio Music Apps/Custom Icons (parent: yes)
- Someone set the periodic library scan interval to a ridiculously low number. Observe here how the music scanner finishes. It calculates just under 20 minutes has elapsed which is apparently longer than the scan interval — so off it goes again.
This can only be corrected by regaining owner control of the server.
Nov 01, 2022 06:23:13.341 [0x7f42825a1700] DEBUG - Skipping over directory 'Music/Amazon Music/Esther Williams', as nothing has changed; removing 0 media items from map.
Nov 01, 2022 06:23:13.341 [0x7f42825a1700] DEBUG - Activity: updated activity 6c9d8bb9-e8d6-495f-a329-710deae5c98a - completed 99.0% - Scanning Music
Nov 01, 2022 06:23:13.341 [0x7f42825a1700] DEBUG - Music Scanner: Idle and left with 3675 media items.
Nov 01, 2022 06:23:13.342 [0x7f42825a1700] DEBUG - Activity: updated activity 6c9d8bb9-e8d6-495f-a329-710deae5c98a - completed 99.0% - Scanning Music
Nov 01, 2022 06:23:13.342 [0x7f42825a1700] DEBUG - Removing 0 media items that were left.
Nov 01, 2022 06:23:13.342 [0x7f42825a1700] DEBUG - Removing 0 directories that were left.
Nov 01, 2022 06:23:13.658 [0x7f42825a1700] DEBUG - Activity: updated activity 6c9d8bb9-e8d6-495f-a329-710deae5c98a - completed 100.0% - Scanning Music
Nov 01, 2022 06:23:13.660 [0x7f42825a1700] DEBUG - Refreshing section 4 of type: 8
Nov 01, 2022 06:23:13.875 [0x7f42822b3700] DEBUG - Refreshing 0 IDs.
Nov 01, 2022 06:23:13.875 [0x7f42825a1700] DEBUG - Activity: registered new activity 05fa1c28-cbf5-45a4-a503-c21d3f7540c1 - Processing subscriptions
Nov 01, 2022 06:23:13.875 [0x7f42825a1700] DEBUG - Activity: Ended activity 6c9d8bb9-e8d6-495f-a329-710deae5c98a.
Nov 01, 2022 06:23:13.875 [0x7f4283159700] DEBUG - Grabber: Cleaning up orphaned grabs.
Nov 01, 2022 06:23:13.875 [0x7f4283159700] DEBUG - Grabber: Cleaned up 0 decrepit directories in 0.0 sec.
Nov 01, 2022 06:23:13.875 [0x7f4283159700] DEBUG - Activity: registered new activity c15691e1-9665-4089-9bf9-fa62035674c8 - Processing subscriptions
Nov 01, 2022 06:23:13.875 [0x7f4283159700] DEBUG - Subscription: Scheduling subscriptions.
Nov 01, 2022 06:23:13.875 [0x7f4283159700] DEBUG - Subscription: Initialized 0 schedulers.
Nov 01, 2022 06:23:13.875 [0x7f4283159700] DEBUG - Subscription: Starting with 0 grabs, scheduled 0 active ones preemptively.
Nov 01, 2022 06:23:13.875 [0x7f4283159700] DEBUG - Subscription: Scheduled all subscriptions in 0 ms.
Nov 01, 2022 06:23:13.875 [0x7f4283159700] DEBUG - Activity: Ended activity c15691e1-9665-4089-9bf9-fa62035674c8.
Nov 01, 2022 06:23:13.875 [0x7f4283159700] DEBUG - Subscription: There are 0 active grabs at the end.
Nov 01, 2022 06:23:13.875 [0x7f4283159700] DEBUG - Activity: Ended activity 05fa1c28-cbf5-45a4-a503-c21d3f7540c1.
Nov 01, 2022 06:23:13.875 [0x7f4283159700] DEBUG - Subscription: Refreshed all content in 0 ms.
Nov 01, 2022 06:28:10.721 [0x7f429943d700] DEBUG - Checking if time for scheduled update
Nov 01, 2022 06:33:10.721 [0x7f4283159700] DEBUG - Checking if time for scheduled update
Nov 01, 2022 06:38:10.722 [0x7f4283159700] DEBUG - Checking if time for scheduled update
Nov 01, 2022 06:43:10.723 [0x7f429943d700] DEBUG - Checking if time for scheduled update
Nov 01, 2022 06:43:10.723 [0x7f429943d700] INFO - It's been 1197 seconds, so we're starting scheduled library update for section 4 (Music)
Nov 01, 2022 06:43:10.723 [0x7f429943d700] DEBUG - Library Updater: Requested that section 4 be updated, force=0, deep=0, subdir= iTunes=0
Nov 01, 2022 06:43:10.723 [0x7f429943d700] DEBUG - Library Updater: Queueing section 4
Nov 01, 2022 06:43:10.723 [0x7f42822b3700] DEBUG - Activity: registered new activity 90262f65-1720-4a3d-ad10-b39d12a73e5c - Scanning
Nov 01, 2022 06:43:10.723 [0x7f42822b3700] DEBUG - Scanning section 4
Nov 01, 2022 06:43:10.723 [0x7f42822b3700] DEBUG - Activity: updated activity 90262f65-1720-4a3d-ad10-b39d12a73e5c - completed 0.0% - Scanning Music
Nov 01, 2022 06:43:10.723 [0x7f42822b3700] DEBUG - Job was already killed, not killing again.
Nov 01, 2022 06:43:10.733 [0x7f42822b3700] DEBUG - Asked to cull library timeline before time 1667301790, we're starting with 0 items.
Nov 01, 2022 06:43:10.733 [0x7f42822b3700] DEBUG - Library timeline cull complete with 0 items left.
Nov 01, 2022 06:43:10.733 [0x7f42822b3700] DEBUG - Scanning Music using en(Plex Music) with 3675 current media items and 1 section locations in the database...
Nov 01, 2022 06:43:10.733 [0x7f42822b3700] DEBUG - Performing a scan with 'Plex Music' (language: en virtual: 0).
Nov 01, 2022 06:43:10.734 [0x7f42822b3700] DEBUG - * Scanning /volume1/Music
Nov 01, 2022 06:43:10.734 [0x7f42822b3700] DEBUG - Scanner: Processing directory /volume1/Music (parent: no)
Nov 01, 2022 06:43:10.734 [0x7f42822b3700] DEBUG - Skipping over directory '', as nothing has changed; removing 0 media items from map.
Nov 01, 2022 06:43:10.734 [0x7f42822b3700] DEBUG - Scanner: Processing directory /volume1/Music/Music (parent: yes)
Nov 01, 2022 06:43:10.735 [0x7f42822b3700] DEBUG - Skipping over directory 'Music', as nothing has changed; removing 0 media items from map.
Nov 01, 2022 06:43:10.735 [0x7f42822b3700] DEBUG - Scanner: Processing directory /volume1/Music/Music/Music (parent: yes)
Nov 01, 2022 06:43:10.736 [0x7f42822b3700] DEBUG - Skipping over directory 'Music/Music', as nothing has changed; removing 0 media items from map.
Nov 01, 2022 06:43:10.736 [0x7f42822b3700] DEBUG - Scanner: Processing directory /volume1/Music/Music/Music/Music Library.musiclibrary (parent: yes)
Nov 01, 2022 06:43:10.736 [0x7f42822b3700] DEBUG - Skipping over directory 'Music/Music/Music Library.musiclibrary', as nothing has changed; removing 0 media items from map.
Nov 01, 2022 06:43:10.736 [0x7f42822b3700] DEBUG - Activity: updated activity 90262f65-1720-4a3d-ad10-b39d12a73e5c - completed 9.9% - Scanning Music
Nov 01, 2022 06:43:10.736 [0x7f42822b3700] DEBUG - Scanner: Processing directory /volume1/Music/Music/Music/Previous Libraries.localized (parent: yes)
Nov 01, 2022 06:43:10.737 [0x7f42822b3700] DEBUG - Skipping over directory 'Music/Music/Previous Libraries.localized', as nothing has changed; removing 0 medi
-
Speaking to the admin control, the next step is to verify if PMS can actually communicate with Plex.tv (the server is signed in). I suspect the problem here is that something signed the server out of its account. Now let’s make the server confirm it is or isn’t still attached to an account. I suspect it’s not attached. These next steps will show us the current server state.
– Restart PMS
– Allow it to run , completely idle, for 4 minutes.
– Stop PMS
– Make a new ZIP file of the Logs directory (repeating what was done above)
– Again download and attach here.
-
While in the “Plex Media Server” shared folder,
– make certain “Preferences.xml” is not zero-length.
– make certain the length is more than 200-300 bytes. A signed-in server, with music, should have a size of about 1 - 1.5 KBytes