Slow or unresponsive Plex Debian Server

andouk · December 30, 2021, 4:00pm

For about the past 2 weeks now I’ve been met with either a slow or unresponsive Plex server, content just stops playing and when I check the main web interface it just won’t load at all, restarting the container seems to fix it but a lot of the time it’s only temporary for maybe 10 minutes or so, If I leave it alone it eventually comes back online and is accessible again.

I got the logs today which do contain errors about the database being slow or unresponsive.

Specs
Xeon E3-1245
8GB RAM
250GB SSD as boot and used for the library database etc.

Could this just be a bug or something as that plex version is about 9 months old now, I’ve just upgraded it via docker today to 1.25.2.5319, I’ll admit the server again was unresponsive for a good 5-10 minutes when it upgraded, but did come back online, haven’t had a chance to test any further as of yet.

I’ve attached the log below

Dec 30, 2021 04:57:00.243 [0x7f132fc73700] INFO - Plex Media Server v1.22.0.4163-d8c4875dd - Docker Docker Container (LinuxServer.io) x86_64 - build: linux-x86_64 debian - GMT 00:00
Dec 30, 2021 04:57:00.243 [0x7f132fc73700] INFO - Linux version: 5.7.0-0.bpo.2-amd64, language: en-US
Dec 30, 2021 04:57:00.243 [0x7f132fc73700] INFO - Processor           Intel(R) Xeon(R) CPU E31245 @ 3.30GHz
Dec 30, 2021 04:57:00.243 [0x7f132fc73700] INFO - /usr/lib/plexmediaserver/Plex Media Server
Dec 30, 2021 04:57:00.250 [0x7f1330765100] INFO - SQLITE3:(nil), 283, recovered 11 frames from WAL file /config/Library/Application Support/Plex Media Server/Plug-in Support/Databases/com.plexapp.plugins.library.db-wal
Dec 30, 2021 04:57:00.441 [0x7f1330765100] INFO - SQLITE3:(nil), 283, recovered 438 frames from WAL file /config/Library/Application Support/Plex Media Server/Plug-in Support/Databases/com.plexapp.plugins.library.blobs.db-wal
Dec 30, 2021 04:57:00.690 [0x7f1330765100] INFO - [CERT/OCSP] Successfully retrieved response from cache.
Dec 30, 2021 04:57:01.270 [0x7f1317fff700] WARN - Unrecognized MediaProvider feature: collection
Dec 30, 2021 04:57:01.270 [0x7f1317fff700] WARN - Unrecognized MediaProvider feature: availability
Dec 30, 2021 04:57:01.270 [0x7f1317fff700] WARN - Unrecognized MediaProvider feature: availability-platforms
Dec 30, 2021 04:57:01.270 [0x7f1317fff700] WARN - Unrecognized MediaProvider feature: universalsearch
Dec 30, 2021 04:57:01.271 [0x7f13253e7700] WARN - Unrecognized MediaProvider feature: collection
Dec 30, 2021 04:57:01.271 [0x7f13253e7700] WARN - Unrecognized MediaProvider feature: availability
Dec 30, 2021 04:57:01.271 [0x7f13253e7700] WARN - Unrecognized MediaProvider feature: availability-platforms
Dec 30, 2021 04:57:01.271 [0x7f13253e7700] WARN - Unrecognized MediaProvider feature: universalsearch
Dec 30, 2021 04:57:02.240 [0x7f13253e7700] WARN - Crash: Crash reporting disabled
Dec 30, 2021 04:57:02.709 [0x7f1314ff9700] INFO - LibraryUpdateManager path watching is disabled
Dec 30, 2021 04:57:02.894 [0x7f13157fa700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 04:57:03.121 [0x7f1324be6700] INFO - Sync: downloaded 0 sync list(s) with 0 sync items(s): 0 new, 0 updated, 0 deleted
Dec 30, 2021 04:57:03.121 [0x7f12d67fc700] WARN - Sync: local sync directory "/config/Library/Application Support/Plex Media Server/Cache/Transcode/Sync+" does not exist
Dec 30, 2021 04:57:03.452 [0x7f12b4ff9700] WARN - MyPlex: attempted a reachability check but we're not yet online.
Dec 30, 2021 04:57:05.439 [0x7f13253e7700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 04:57:06.246 [0x7f12af7fe700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 04:57:12.308 [0x7f12d77fe700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 04:57:12.320 [0x7f12d77fe700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 04:57:13.436 [0x7f12d7fff700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 04:57:13.452 [0x7f12d7fff700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 04:57:13.504 [0x7f12b57fa700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 04:57:13.512 [0x7f12b57fa700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 04:57:14.394 [0x7f12b4ff9700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 04:57:14.409 [0x7f12b4ff9700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 04:58:20.460 [0x7f12f4ff9700] WARN - MyPlex: we have an existing connectivity refresh request for async identifier 9bbe8961-15ee-402e-887d-264a9655018b, but it has expired so we will try again.
Dec 30, 2021 04:58:44.010 [0x7f13167fc700] INFO - Sync: downloaded 0 sync list(s) with 0 sync items(s): 0 new, 0 updated, 0 deleted
Dec 30, 2021 04:58:44.010 [0x7f12d4ff9700] WARN - Sync: local sync directory "/config/Library/Application Support/Plex Media Server/Cache/Transcode/Sync+" does not exist
Dec 30, 2021 05:00:51.368 [0x7f12b77fe700] WARN - NAT: PMP, got an error: Not Supported by gateway.
Dec 30, 2021 05:00:51.533 [0x7f12b77fe700] WARN - MyPlex: we have an existing connectivity refresh request for async identifier 8e6ff5d6-8c96-480e-a06c-5c51694b53d5, but it has expired so we will try again.
Dec 30, 2021 05:00:51.915 [0x7f1325be8700] WARN - PubSub: Received notifyConnectivity event with incorrect async identifier (8e6ff5d6-8c96-480e-a06c-5c51694b53d5, expected e2c4f7e4-86ac-4d53-a413-bc4bf4d82d4c)
Dec 30, 2021 05:01:18.001 [0x7f1315ffb700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 05:01:18.022 [0x7f1315ffb700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 05:01:18.089 [0x7f13253e7700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 05:02:02.408 [0x7f12b77fe700] ERROR - [Time] Failed to convert '1970-01-01 00:00:01' to epoch.
Dec 30, 2021 05:02:02.408 [0x7f12b77fe700] ERROR - [Time] Failed to convert '1970-01-01 00:00:01' to epoch.
Dec 30, 2021 05:02:02.725 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Held transaction for too long (../Library/DatabaseFixups.cpp:211): 0.510000 seconds
Dec 30, 2021 05:02:02.725 [0x7f12b77fe700] WARN - Took too long (0.310000 seconds) to start a transaction on ../Library/MediaItem.cpp:1453
Dec 30, 2021 05:02:02.725 [0x7f12b77fe700] WARN - Transaction that was running was started on thread 0x7f12d4ff9700 at ../Library/DatabaseFixups.cpp:200
Dec 30, 2021 05:02:03.742 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Waited one whole second for a busy database.
Dec 30, 2021 05:02:04.933 [0x7f12d7fff700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 05:02:04.946 [0x7f12d7fff700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 05:02:04.987 [0x7f13177fe700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 05:02:05.965 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Waited one whole second for a busy database.
Dec 30, 2021 05:02:08.189 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Waited one whole second for a busy database.
Dec 30, 2021 05:02:08.312 [0x7f13167fc700] WARN - Waited one whole second for a busy database.
Dec 30, 2021 05:02:10.412 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Waited one whole second for a busy database.
Dec 30, 2021 05:02:10.535 [0x7f13167fc700] WARN - Waited one whole second for a busy database.
Dec 30, 2021 05:02:12.635 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Waited one whole second for a busy database.
Dec 30, 2021 05:02:12.758 [0x7f13167fc700] WARN - Waited one whole second for a busy database.
Dec 30, 2021 05:02:14.858 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Waited one whole second for a busy database.
Dec 30, 2021 05:02:14.981 [0x7f13167fc700] WARN - Waited one whole second for a busy database.
Dec 30, 2021 05:02:17.081 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Waited one whole second for a busy database.
Dec 30, 2021 05:02:17.205 [0x7f13167fc700] WARN - Waited one whole second for a busy database.
Dec 30, 2021 05:02:19.305 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Waited one whole second for a busy database.
Dec 30, 2021 05:02:19.428 [0x7f13167fc700] WARN - Waited one whole second for a busy database.
Dec 30, 2021 05:02:21.528 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Waited one whole second for a busy database.
Dec 30, 2021 05:02:21.651 [0x7f13167fc700] WARN - Waited one whole second for a busy database.
Dec 30, 2021 05:02:23.751 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Waited one whole second for a busy database.
Dec 30, 2021 05:02:23.875 [0x7f13167fc700] WARN - Waited one whole second for a busy database.
Dec 30, 2021 05:02:25.975 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Waited one whole second for a busy database.
Dec 30, 2021 05:02:26.098 [0x7f13167fc700] WARN - Waited one whole second for a busy database.
Dec 30, 2021 05:02:28.199 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Waited one whole second for a busy database.
Dec 30, 2021 05:02:28.322 [0x7f13167fc700] WARN - Waited one whole second for a busy database.
Dec 30, 2021 05:02:30.422 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Waited one whole second for a busy database.
Dec 30, 2021 05:02:30.545 [0x7f13167fc700] WARN - Waited one whole second for a busy database.
Dec 30, 2021 05:02:31.803 [0x7f12b77fe700] WARN - Waited one whole second for a busy database.
Dec 30, 2021 05:02:32.646 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Waited one whole second for a busy database.
Dec 30, 2021 05:02:32.769 [0x7f13167fc700] WARN - Waited one whole second for a busy database.
Dec 30, 2021 05:02:32.827 [0x7f12b77fe700] ERROR - Failed to begin transaction (../Statistics/StatisticsManager.cpp:245) (tries=1): Cannot begin transaction. database is locked
Dec 30, 2021 05:02:34.126 [0x7f12b77fe700] WARN - Took too long (3.190000 seconds) to start a transaction on ../Statistics/StatisticsManager.cpp:245
Dec 30, 2021 05:02:34.126 [0x7f12b77fe700] WARN - Transaction that was running was started on thread 0x7f1316ffd700 at ../Library/MetadataItem.cpp:1081
Dec 30, 2021 05:02:36.445 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Held transaction for too long (../Library/FullTextSearch.cpp:54): 2.310000 seconds
Dec 30, 2021 05:02:37.851 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Held transaction for too long (../Library/FullTextSearch.cpp:64): 1.060000 seconds
Dec 30, 2021 05:02:39.254 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Held transaction for too long (../Library/FullTextSearch.cpp:75): 1.350000 seconds
Dec 30, 2021 05:02:40.062 [0x7f12d4ff9700] WARN - [Database optimization/com.plexapp.plugins.library.db] Held transaction for too long (../Library/FullTextSearch.cpp:85): 0.690000 seconds
Dec 30, 2021 05:06:02.433 [0x7f13157fa700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 05:06:02.433 [0x7f1326bea700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 05:25:41.178 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.205 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.209 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.212 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.214 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.217 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.219 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.221 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.223 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.224 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.226 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.227 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.228 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.230 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.231 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.233 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.234 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.235 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:41.237 [0x7f12d4ff9700] INFO - [Database optimization/com.plexapp.plugins.library.db] SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:25:42.013 [0x7f1325be8700] ERROR - EventSource: Retrying in 15 seconds.
Dec 30, 2021 05:25:45.889 [0x7f12b6ffd700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 05:26:12.186 [0x7f12b67fc700] WARN - NAT: PMP, got an error: Not Supported by gateway.
Dec 30, 2021 05:26:12.700 [0x7f13253e7700] WARN - Held transaction for too long (../Statistics/StatisticsManager.cpp:245): 0.540000 seconds
Dec 30, 2021 05:26:41.381 [0x7f12d4ff9700] INFO - SQLITE3:(nil), 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Dec 30, 2021 05:27:11.826 [0x7f132f472700] WARN - JobManager: Could not find job for handle 414
Dec 30, 2021 05:47:34.706 [0x7f12d77fe700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 05:47:34.707 [0x7f13253e7700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 05:47:34.823 [0x7f12b67fc700] WARN - Got a request to stop a transcode session without a session GUID (or with an invalid one).
Dec 30, 2021 05:47:35.255 [0x7f12b6ffd700] ERROR - Unknown metadata type: folder
Dec 30, 2021 05:47:35.255 [0x7f12b67fc700] ERROR - Unknown metadata type: folder
Dec 30, 2021 05:47:35.276 [0x7f12b6ffd700] WARN - QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Dec 30, 2021 05:47:35.276 [0x7f12b67fc700] WARN - QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Dec 30, 2021 05:47:35.626 [0x7f12af7fe700] WARN - SLOW QUERY: It took 230.000000 ms to retrieve 24 items.
Dec 30, 2021 05:57:16.738 [0x7f12d7fff700] WARN - NAT: PMP, got an error: Not Supported by gateway.
Dec 30, 2021 06:36:04.555 [0x7f12b6ffd700] ERROR - Unable to find client profile for device; platform=PlayStation, platformVersion=4.50, device=PlayStation 5, model=PlayStation 5
Dec 30, 2021 06:36:04.559 [0x7f13253e7700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 06:39:32.541 [0x7f12d77fe700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 06:39:32.544 [0x7f12d7fff700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 06:57:17.109 [0x7f12d77fe700] WARN - NAT: PMP, got an error: Not Supported by gateway.
Dec 30, 2021 07:57:17.584 [0x7f13253e7700] WARN - NAT: PMP, got an error: Not Supported by gateway.
Dec 30, 2021 08:57:18.466 [0x7f13157fb700] WARN - NAT: PMP, got an error: Not Supported by gateway.
Dec 30, 2021 09:57:18.961 [0x7f12d7fff700] WARN - NAT: PMP, got an error: Not Supported by gateway.
Dec 30, 2021 10:57:18.513 [0x7f12d7fff700] WARN - NAT: PMP, got an error: Not Supported by gateway.
Dec 30, 2021 11:38:26.054 [0x7f12b6ffd700] ERROR - Unable to find client profile for device; platform=PlayStation, platformVersion=4.50, device=PlayStation 5, model=PlayStation 5
Dec 30, 2021 11:38:26.059 [0x7f13157fb700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 11:41:32.622 [0x7f13253e7700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 11:41:32.624 [0x7f12b67fc700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 11:57:18.923 [0x7f13253e7700] WARN - NAT: PMP, got an error: Not Supported by gateway.
Dec 30, 2021 12:57:18.591 [0x7f13157fb700] WARN - NAT: PMP, got an error: Not Supported by gateway.
Dec 30, 2021 13:28:50.135 [0x7f12b6ffd700] ERROR - Unable to find client profile for device; platform=PlayStation, platformVersion=4.50, device=PlayStation 5, model=PlayStation 5
Dec 30, 2021 13:28:50.139 [0x7f12adffb700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 13:28:50.141 [0x7f13157fb700] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 30, 2021 13:57:18.508 [0x7f13157fb700] WARN - NAT: PMP, got an error: Not Supported by gateway.
Dec 30, 2021 14:57:18.126 [0x7f12adffb700] WARN - NAT: PMP, got an error: Not Supported by gateway.
Dec 30, 2021 15:52:06.473 [0x7f12acff9700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 15:52:06.492 [0x7f12acff9700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 15:52:06.607 [0x7f128d7fa700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 15:52:06.625 [0x7f128d7fa700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 15:52:06.832 [0x7f128cff9700] WARN - SLOW QUERY: It took 470.000000 ms to retrieve 1 items.
Dec 30, 2021 15:52:07.240 [0x7f128d7fa700] WARN - SLOW QUERY: It took 890.000000 ms to retrieve 50 items.
Dec 30, 2021 15:52:07.240 [0x7f12acff9700] WARN - SLOW QUERY: It took 1280.000000 ms to retrieve 50 items.
Dec 30, 2021 15:52:07.553 [0x7f128dffb700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Dec 30, 2021 15:52:07.569 [0x7f128dffb700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.

ChuckPa · December 31, 2021, 2:17pm

Please do the following

Please turn DEBUG logging back on. (the default). Can’t see anything in INFO/ERROR mode.
Restart Plex
Wait 3 minutes
Download Logs ZIP file
Attach the ZIP file

andouk · December 31, 2021, 5:43pm

Plex Media Server Logs_2021-12-31_17-39-47.zip (6.1 MB)

Attached, thanks

ChuckPa · December 31, 2021, 6:14pm

Is there a VM involved here?

I am seeing playback

Dec 31, 2021 17:38:09.160 [0x7fa47c4c5b38] DEBUG - Play progress on 224458 'Sleepless in Peckham' - got played 2306090 ms by account 19110763!

andouk · December 31, 2021, 6:28pm

No, somebody was just watching something when I pulled the log after the restart

I can pull it again if you need me to with nobody watching, they must have just reconnected after it was restarted

ChuckPa · December 31, 2021, 6:41pm

my concern is the “slow or unresponsive” as compared to someone getting actual playback.

May I ask what constitutes “Slow or Unresponsive” ?

andouk · December 31, 2021, 8:02pm

As I said in the OP, the server stops playing randomly and the web interface no longer loads, meaning it’s unresponsive, but it does come back online eventually meaning it’s slow to respond.

The Database being slow to be read in the original log and the SQlite and the Unrecognised MediaProvider Feature: errors would also indicate there’s a problem somewhere?

But I guess from your response you don’t see it as a concern if somebody is able to connect to the server 3 minutes later after a restart.

Looking at the new log provided it seems the errors have disappeared and I haven’t had the symptom’s I mentioned since the update a hour or so after I made this post.

Is this just a case of the version I was running being old/buggy and unoptimized or?

Updated version is v1.25.2.5319-c43dc0277 the previous version with the errors and unresponsiveness v1.22.0.4163-d8c4875dd

ChuckPa · December 31, 2021, 8:24pm

what I’m not yet understanding is what the system, itself, is doing.

Is the CPU usage High?
Is the disk I/O high?

I believe you there is a problem as evidenced by

Dec 30, 2021 05:02:30.545 [0x7f13167fc700] WARN - Waited one whole second for a busy database.
Dec 30, 2021 05:02:31.803 [0x7f12b77fe700] WARN - Waited one whole second for a busy database.

the challenge is:

How big is the database?
Is it fragmented?
– Even a 7000 passmark quad core Xeon will have trouble getting in and out in time if the DB is big or fragmented (SQL has internal links it must follow when tables are not contiguous)… SSD helps by reducing I/O latency but not CPU time to walk the links)
How many media files are indexed in Plex?

andouk · December 31, 2021, 8:43pm

I can’t see the disk I/O but I did notice when it does go offline the CPU usage does peg itself at around 90%+ and dropping frequently then going back again, after a while it settles.

The databases folder shows as 8GB on the SSD
Unsure if it’s fragmented, filesystem is EXT4
Unsure on the exact number of media files, but TV shows has 450 shows, Movies has 3,138, Music has 32,000 tracks and Photos has about 60,000, all in all totalling about 12TB, photos and music are rarely ever accessed.

Previous to this before Feb/March this year I was running a E8400 for about 4-5 years, but I did have the whole plex databases etc on a hard drive and not a SSD and never really had any issues like this other than a actual drive beginning to fail.

I’m wondering if this is just the cheap SSD being at fault now, unsure whether it has a RAM cache or not, could that be causing database issues?

ChuckPa · December 31, 2021, 10:15pm

When is the last time you ran Optimize Database ?

EXT4 doesn’t impact performance. Optimizing the DB is what defragments it.

if you ls -lah com.plexapp.plugins.library* , what does it show?

Your .db file should only be a few hundred MB.

If it’s larger then that’s where we look.

SSD doesn’t need a RAM cache. SATA-3 SSD is capable of saturating the SATA bus all by itself. RAM cache would buy you nothing.

andouk · December 31, 2021, 11:26pm

The last time I ran that was probably a few years ago, but I do have these set in the schedule tasks tab

Optimize database every week
Remove old bundles every week
Remove old cache files every week

That file the .db is just under 6gb, unless I’m looking at the wrong one.

I should probably note at this point that this was a previously plex library copied from other drives when I upgraded, rather than lose the ordering I had I just copied everything needed and pointed plex to the new drives.

I’ve attached a screenshot as I couldn’t get that command to work via ssh for some reason, I mainly manage the drives via smb shares on a windows machine.

ChuckPa · December 31, 2021, 11:52pm

That’s bad and explains the slowness.
Executing a SQL query against a file that size will take time and cause the timeouts (locked database).

There is already a fix being circulated (in test) to remedy the problem.

I would like you to do the following:

make certain sqlite3 is installed on the linux host.
stop plex
On the Linux host side of the container

cd '/path/to/container/Library/Application Support/Plex Media Server/Plug-in Support/Databases'

echo 'select count(metadata_item_id),metadata_item_id from metadata_relations group by metadata_item_id order by count(metadata_item_id) desc limit 20' | sqlite3 com.plexapp.plug-ins.library.db

This will take a moment to run.
It will generate a report.

The report (query results) will be of the form ‘Count | Media_Item_Id’

If you have any media item IDs where the count > 50-60 (50-60 extras) then you are experiencing the known database problem.

A corrected version of Plex exists for the native host app but I don’t know if a docker container version exists. it’s not likely to exist.

We can fake out a native installation to use your existing docker container if you wish.

Please let me know your query results and how you wish to proceed

andouk · January 1, 2022, 1:17am

It seems sqlite3 is missing from my install

With sqlite3 installed I now get this error “Error: near line 1: no such table: metadata_relations”

More info , probably irrelevant now but, the previous install was not using a docker container, just a straight deb file installed and then edited the config to point the database and config to a hdd and not the boot drive.

ChuckPa · January 1, 2022, 2:21am

Which version of PMS are you using? Th table should exist.

andouk · January 1, 2022, 10:41am

v1.25.2.5319-c43dc0277 the latest I believe

Is there context missing from what you asked me to do?

ChuckPa · January 3, 2022, 1:39pm

I opened my database in sqlite3

chuck@plexinc:/home/plex/Library/Application Support/Plex Media Server/Plug-in Support/Databases$ echo .schema | sqlite3 com.plexapp.plugins.library.db | grep metadata_relations
CREATE TABLE IF NOT EXISTS "metadata_relations" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "metadata_item_id" integer, "related_metadata_item_id" integer, "relation_type" integer, "created_at" datetime, "updated_at" datetime);
CREATE INDEX "index_metadata_relations_on_metadata_item_id" ON "metadata_relations" ("metadata_item_id" );
CREATE INDEX "index_metadata_relations_on_related_metadata_item_id" ON "metadata_relations" ("related_metadata_item_id" );
CREATE INDEX "index_metadata_relations_on_relation_type" ON "metadata_relations" ("relation_type" );
chuck@plexinc:/home/plex/Library/Application Support/Plex Media Server/Plug-in Support/Databases$

andouk · January 3, 2022, 8:04pm

No Idea where I’m going wrong here

root@OMV:/config/plex/Library/Application Support/Plex Media Server/Plug-in Support/Databases#

root@OMV:/config/plex/Library/Application Support/Plex Media Server/Plug-in Support/Databases# echo .schema | sqlite3 com.plexapp.plugins.library.db | grep metadata_relations
CREATE TABLE IF NOT EXISTS "metadata_relations" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "metadata_item_id" integer, "related_metadata_item_id" integer, "relation_type" integer, "created_at" datetime, "updated_at" datetime);
CREATE INDEX "index_metadata_relations_on_metadata_item_id" ON "metadata_relations" ("metadata_item_id" );
CREATE INDEX "index_metadata_relations_on_related_metadata_item_id" ON "metadata_relations" ("related_metadata_item_id" );
CREATE INDEX "index_metadata_relations_on_relation_type" ON "metadata_relations" ("relation_type" );
root@OMV:/config/plex/Library/Application Support/Plex Media Server/Plug-in Support/Databases# echo 'select count(metadata_item_id),metadata_item_id from metadata_relations group by metadata_item_id order by count(metadata_item_id) desc limit 20' | sqlite3 com.plexapp.plug-ins.library.db
Error: near line 1: no such table: metadata_relations
root@OMV:/config/plex/Library/Application Support/Plex Media Server/Plug-in Support/Databases#

I’ve also tried running sqlite3 and then opening the database with .open then running the command you asked

SQLite version 3.27.2 2019-02-25 16:06:06
Enter ".help" for usage hints.
Connected to a transient in-memory database.
Use ".open FILENAME" to reopen on a persistent database.
sqlite> .open com.plexapp.plugins.library.db
sqlite> 'select count(metadata_item_id),metadata_item_id from metadata_relations group by metadata_item_id order by count(metadata_item_id) desc limit 20'
   ...>

Since the update after I created this post the errors seem to have gone and I’ve yet to have it drop or slow down at all either. Still if there is a bug with the database I’d like to fix it if possible.

ChuckPa · January 3, 2022, 8:26pm

in that last select statement, interactive sqlite3 statements need the closing ;

andouk · January 3, 2022, 8:32pm

Thanks, I’d just been reading about that but couldn’t really make much sense of what it was telling me to do.

Anyway I’m guessing these are the numbers

ChuckPa · January 3, 2022, 8:47pm

@andouk

Those values are Count_of_extras | Media_item

that tells me your media item #61752 (whatever it is) has 36 extras.

If you had a bloated database, you would see something above 100,000 (typically)

Topic		Replies	Views
Plex Media Server: Ongoing Network Issue Desktops & Laptops server-linux	64	1466	February 21, 2019
Plex being really unreliable and slow... General Discussions	31	828	January 7, 2020
Unresponsive Interface - FREQUENT issue Desktops & Laptops server-linux	36	609	September 3, 2019
I think something may be wrong with my Plex database, how can I be sure? Metadata & Adding Files server-mac	10	1315	November 14, 2020
DB locks and wait times Desktops & Laptops server-linux , server-docker	56	990	March 13, 2022

Slow or unresponsive Plex Debian Server

Related topics