Optimize database not working after upgrade to 1.40.0.7996-4956e330f

Plex Media Server Plex Pass Betas
1

Server Version#: 1.40.0.7996-4956e330f
I am getting the error about the database and it has been 24 hours since 1.40.0.7996 was installed.
How can I go about fixing the database?

Feb 08, 2024 10:31:49.458 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.461 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.464 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.467 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.473 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.475 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.477 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.480 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.483 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.486 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.489 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.493 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.496 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.499 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.502 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.506 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.509 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.513 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 10:31:49.516 [139963157056312] INFO - [Req#265c2/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed

2

It says Info, not Error.
These messages are normal at the first start after a server version upgrade.

3

How long will I see the message for after the upgrade. It has been over 24 hours since the upgrade and I still can’t optimize the database.

4

These logs might also be relevant as well.
Feb 08, 2024 15:38:40.132 [139861146823480] WARN - [Req#4a1] QueryParser: Invalid field ‘contentDirectoryID’ found, ignoring.
Feb 08, 2024 15:38:40.140 [139861158001464] WARN - [Req#4a0] QueryParser: Invalid field ‘sectionID’ found, ignoring.
Feb 08, 2024 15:38:40.140 [139861158001464] WARN - [Req#4a0] QueryParser: Invalid field ‘contentDirectoryID’ found, ignoring.
Feb 08, 2024 15:38:40.208 [139861146823480] WARN - [Req#4a1] SLOW QUERY: It took 390.000000 ms to retrieve 24 items.
Feb 08, 2024 15:38:40.210 [139861182745400] WARN - [Req#4a8] QueryParser: Invalid field ‘contentDirectoryID’ found, ignoring.
Feb 08, 2024 15:38:40.623 [139861182745400] WARN - [Req#4b7] QueryParser: Invalid field ‘contentDirectoryID’ found, ignoring.
Feb 08, 2024 15:38:40.686 [139861182745400] WARN - [Req#4b7] SLOW QUERY: It took 260.000000 ms to retrieve 66 items.
Feb 08, 2024 15:38:41.879 [139861127744312] WARN - [Req#4cd] QueryParser: Invalid field ‘sectionID’ found, ignoring.
Feb 08, 2024 15:38:41.879 [139861127744312] WARN - [Req#4cd] QueryParser: Invalid field ‘contentDirectoryID’ found, ignoring.

5

What happens when you try to optimize the database?

6

According to the logs it doesn’t say it completed. I am experiencing log load times when I click on a library so I started looking into the logs and found these errors.
Feb 08, 2024 16:19:52.505 [139861093010232] WARN - [Req#411b8] QueryParser: Invalid field ‘contentDirectoryID’ found, ignoring.
Feb 08, 2024 16:19:52.505 [139861093010232] WARN - [Req#411b8] QueryParser: Invalid field ‘pinnedContentDirectoryID’ found, ignoring.
Feb 08, 2024 16:19:52.510 [139861115132728] WARN - [Req#411b3] QueryParser: Invalid field ‘pinnedContentDirectoryID’ found, ignoring.
Feb 08, 2024 16:19:52.510 [139861115132728] WARN - [Req#411b3] QueryParser: Invalid field ‘pinnedContentDirectoryID’ found, ignoring.
Feb 08, 2024 16:19:52.510 [139861101447992] ERROR - [Req#411ba] Unknown metadata type: folder
Feb 08, 2024 16:19:52.510 [139861115132728] WARN - [Req#411b3] QueryParser: Invalid field ‘contentDirectoryID’ found, ignoring.
Feb 08, 2024 16:19:52.511 [139861101447992] WARN - [Req#411ba] QueryParser: Invalid field ‘contentDirectoryID’ found, ignoring.
Feb 08, 2024 16:19:52.511 [139861101447992] WARN - [Req#411ba] QueryParser: Invalid field ‘pinnedContentDirectoryID’ found, ignoring.
Feb 08, 2024 16:19:52.514 [139861099338552] ERROR - [Req#411b9] Unknown metadata type: folder
Feb 08, 2024 16:19:52.515 [139861099338552] WARN - [Req#411b9] QueryParser: Invalid field ‘contentDirectoryID’ found, ignoring.
Feb 08, 2024 16:19:52.515 [139861099338552] WARN - [Req#411b9] QueryParser: Invalid field ‘pinnedContentDirectoryID’ found, ignoring.
Feb 08, 2024 16:19:52.630 [139861115132728] WARN - [Req#411b3] SLOW QUERY: It took 360.000000 ms to retrieve 50 items.
Feb 08, 2024 16:19:52.632 [139861103557432] ERROR - [Req#411be] Unknown metadata type: folder
Feb 08, 2024 16:19:52.632 [139861103557432] WARN - [Req#411be] QueryParser: Invalid field ‘contentDirectoryID’ found, ignoring.
Feb 08, 2024 16:19:52.632 [139861103557432] WARN - [Req#411be] QueryParser: Invalid field ‘pinnedContentDirectoryID’ found, ignoring.
Feb 08, 2024 16:19:52.747 [139861119351608] ERROR - [Req#411c1] Unknown metadata type: folder
Feb 08, 2024 16:19:52.747 [139861119351608] WARN - [Req#411c1] QueryParser: Invalid field ‘contentDirectoryID’ found, ignoring.
Feb 08, 2024 16:19:52.748 [139861119351608] WARN - [Req#411c1] QueryParser: Invalid field ‘pinnedContentDirectoryID’ found, ignoring.
Feb 08, 2024 16:19:53.381 [139861101447992] ERROR - [Req#411cb] Unknown metadata type: folder
Feb 08, 2024 16:19:53.381 [139861101447992] WARN - [Req#411cb] QueryParser: Invalid field ‘contentDirectoryID’ found, ignoring.
Feb 08, 2024 16:19:53.382 [139861101447992] WARN - [Req#411cb] QueryParser: Invalid field ‘pinnedContentDirectoryID’ found, ignoring.
Feb 08, 2024 16:20:02.470 [139861167569720] WARN - [Req#4123f/Database optimization/com.plexapp.plugins.library.db/DatabaseFixups] Held transaction for too long (/home/runner/actions-runner/_work/plex-media-server/plex-media-server/Library/DatabaseFixups.cpp:222): 9.070000 seconds
Feb 08, 2024 16:20:03.599 [139861167569720] WARN - [Req#4123f/Database optimization/com.plexapp.plugins.library.db/DatabaseFixups] Held transaction for too long (/home/runner/actions-runner/_work/plex-media-server/plex-media-server/Library/DatabaseFixups.cpp:357): 1.200000 seconds
Feb 08, 2024 16:20:04.363 [139861167569720] WARN - [Req#4123f/Database optimization/com.plexapp.plugins.library.db/DatabaseFixups] Held transaction for too long (/home/runner/actions-runner/_work/plex-media-server/plex-media-server/Library/DatabaseFixups.cpp:390): 0.770000 seconds
Feb 08, 2024 16:20:19.456 [139861167569720] WARN - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] Held transaction for too long (/home/runner/actions-runner/_work/plex-media-server/plex-media-server/Library/FullTextSearch.cpp:58): 15.810000 seconds
Feb 08, 2024 16:20:23.701 [139861167569720] WARN - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] Held transaction for too long (/home/runner/actions-runner/_work/plex-media-server/plex-media-server/Library/FullTextSearch.cpp:71): 3.760000 seconds
Feb 08, 2024 16:21:01.994 [139861167569720] WARN - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] Held transaction for too long (/home/runner/actions-runner/_work/plex-media-server/plex-media-server/Library/FullTextSearch.cpp:81): 38.340000 seconds
Feb 08, 2024 16:21:16.702 [139861167569720] WARN - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] Held transaction for too long (/home/runner/actions-runner/_work/plex-media-server/plex-media-server/Library/FullTextSearch.cpp:94): 14.560000 seconds
Feb 08, 2024 16:21:37.059 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.061 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.064 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.067 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.069 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.071 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.074 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.076 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.078 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.080 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.082 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.084 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.086 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.088 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.090 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.093 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.095 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.097 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.099 [139861167569720] INFO - [Req#4123f/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 59: [select * from metadata_items limit 1] database schema has changed
Feb 08, 2024 16:21:37.109 [139861270936376] ERROR - WebSocket: closing connection due to fragmentation
Feb 08, 2024 16:21:37.111 [139861270936376] ERROR - WebSocket: closing connection due to fragmentation
Feb 08, 2024 16:21:37.111 [139861270936376] WARN - WebSocket: Ignoring message since we’re closing the connection
Feb 08, 2024 16:21:37.115 [139861270936376] ERROR - [EventSourceClient/pubsub/45.33.125.156:443] Retrying in 15 seconds.
Feb 08, 2024 16:21:37.171 [139861270936376] ERROR - WebSocket: closing connection due to fragmentation
Feb 08, 2024 16:21:37.171 [139861270936376] WARN - WebSocket: Ignoring message since we’re closing the connection
Feb 08, 2024 16:21:37.178 [139861270936376] ERROR - WebSocket: closing connection due to fragmentation
Feb 08, 2024 16:21:37.178 [139861270936376] WARN - WebSocket: Ignoring message since we’re closing the connection
Feb 08, 2024 16:21:37.178 [139861270936376] ERROR - WebSocket: closing connection due to fragmentation
Feb 08, 2024 16:21:37.178 [139861270936376] WARN - WebSocket: Ignoring message since we’re closing the connection
Feb 08, 2024 16:21:37.185 [139861215710008] WARN - Held transaction for too long (/home/runner/actions-runner/_work/plex-media-server/plex-media-server/Statistics/StatisticsManager.cpp:301): 0.370000 seconds
Feb 08, 2024 16:21:37.190 [139861119351608] WARN - [Req#412f0] WebSocket: Ignoring message since we’re closing the connection
Feb 08, 2024 16:21:37.210 [139861213600568] WARN - [Req#412aa] WebSocket: Ignoring message since we’re closing the connection
Feb 08, 2024 16:21:37.557 [139861197441848] WARN - [Req#41357] WebSocket: Ignoring message since we’re closing the connection

7

Any 3rd party tools accessing the database? There were a couple of threads a few weeks ago regarding Plex Meta Manager. It would sometimes cause slow query warnings when accessing the Plex database.

Try the Plex DBRepair Utility: GitHub - ChuckPa/PlexDBRepair: Database repair utility for Plex Media Server databases

8

Thanks, I have tried that that utility but there was no change. I also used the official Plex guide to repair a corrupt database. Both of the result in the same. I do have a couple applications integrated into plex. I will disable them to see if it fixes the slowness.

9

I just updated PMS on my Synology NAS and then manually optimized the database.

The database optimization completed.
Feb 08, 2024 10:44:04.996 [140482405448504] DEBUG - [Req#a255/Database optimization/com.plexapp.plugins.library.db] Database optimization: complete.

There were several INFO “statement aborts” messages as well, but as Otto previously mentioned, those are normal and can be ignored.

The Plex DBRepair Utility AUTO option will do a better job of optimizing the database than manually optimizing it via Settings → Troubleshooting or using the steps in Repair a Corrupt Database.

If the server is running normally, there are no SQLITE3 ERROR messages, and the DBRepair Utility runs successfully, then you should be OK.

10

If I may add ?

One of the options available to you REPLACE.
This is where you use one of the PMS-generated backups.
(It is the same procedure as documented on the Plex support pages)

Please read through the documentation provided for DBRepair and consider if you want to let it do the manual work for you

11

All the log extracts you pasted suggest you have disabled Debug Logging

To investigate and see what is happening to the db optimization thread, debug logging is needed

The warnings / errors you pasted are all normal - even the “Held transaction for too long” warning is normal when an optimize is in progress

Suggest you enable server debug logging, restart the server, perform an optimize and if it hangs collect the server logs and attach the logs zip - optimize may take a while on a large database

12

I rolled back the update and the datebase to one from Feb 2nd. I am still seeing the issues with the DB hanging. I will do the Debug logs as suggested below.

Thanks for all the help

13

Debug Logs will indicate if there is a permanent hang or just slow processing of requests, May need to increase the number of log files - depends on how soon after launch the problem arises as ideally would be good if possible to have debug logs covering from time of launch of Plex Media Server up to time of the issue arising.

If there is a permanent hang, one would then need to get other diagnostics - similar to what we normally ask for when investigating deadlocks which would require a process dump and a request to get a list of connections - but this can be decided once the initial set of logs are looked into.

14

Thanks everyone for the recommendations. Looks like my issue is related to the new version as pointed out here.

This can be closed.

15

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