Something has changed in the scanning logic

Reed97123 · June 6, 2017, 9:37pm

@ChuckPA said:
When I saw your logs, the very first thing that went through my mind was a functionally corrupted database. The EPG errors are outrageous.
The other Plex components ‘held transaction too long’ are another sign of things being fouled up badly either at the machine or within PMS itself.
What is a functionally corrupted database and how does this normally happen? What about are the EPG errors are abnormal?

Is the purpose of the experiment to see if it can be recreated? What are you hoping to find?

In your instructions above could you clarify:

Add in one section containing the primary media and one section containing the links
Add a library with the actual data and a different library with the hard links? I’m not sure if you are using ‘section’ to denote library. Also, I’m not sure the difference you are trying to highlight. Hard links are indistinguishable once created, they aren’t like symbolic links, they behave the same as all other hard links.

As metadata is coming down, complete making Settings tweaks per your normal operating state
Make all my other settings identical to my original server?

Now test and see what you get from it.
‘test’ it meaning, see if I still get the same errors?

This is a lot of work to recreate an identical new server database. If the purpose is to see if this is reproducible, wouldn’t it be equivalent if I just rebuild my database in the original location and see if it happens again? There has to be an easier way to have Plex recreate my database, correct? Something like just erasing the database and having it re-generate it?

ChuckPa · June 6, 2017, 9:46pm

A “functionally corrupt” database is one where the tables themselves are intact but the data in them is gibberish.
At no point in time should the EPG be complaining the errors it is.

Regarding test construction:

Library refers to the parent directory path for all PMS metadata . This includes Library.SAVE (containing your existing metadata which we will hold safe)
I ask you create a new PMS Library in /var/lib/plexmediaserver (PMS will do this automatically after we rename your existing one)
I then ask you to create a section which contains known REAL media… not where you created your hard links.
Lastly, I ask you to create a section which contains the Hardlinks only. (where you created the hardlinks to the original files).

Reed97123 · June 6, 2017, 9:51pm

@ChuckPA said:
When I saw your logs, the very first thing that went through my mind was a functionally corrupted database. The EPG errors are outrageous.
The other Plex components ‘held transaction too long’ are another sign of things being fouled up badly either at the machine or within PMS itself.
I searched through my logs and didn’t see any of the errors you mentioned. I searched specifically for the ‘held transaction too long’ and didn’t find it in any of the files. The Plex Tuner Service.*.log didn’t show any EPG issues. Where are you seeing this, did I miss it somehow?

ChuckPa · June 6, 2017, 9:55pm

May 24, 2017 06:26:09.995 [0x7f9db47ff700] INFO - SQLITE3:0x10, 283, recovered 709 frames from WAL file /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Plug-in Support/Databases/tv.plex.providers.epg.onconnect-4a4b452e-4e9e-43f3-9c2f-430c87595bd5.db-wal
May 24, 2017 06:26:10.325 [0x7f9daf7ff700] ERROR - downloadContainer: expected MediaContainer element, found html
May 24, 2017 06:26:10.325 [0x7f9daf7ff700] WARN - DVR:Subscription: No container available for /tv.plex.providers.epg.onconnect:2/metadata/com%2Egracenote%2Eonconnect%3A%2F%2Fshow%2F11770080
May 24, 2017 06:26:10.391 [0x7f9daf7ff700] ERROR - downloadContainer: expected MediaContainer element, found html
May 24, 2017 06:26:10.392 [0x7f9daf7ff700] WARN - DVR:Subscription: No container available for /tv.plex.providers.epg.onconnect:2/metadata/com%2Egracenote%2Eonconnect%3A%2F%2Fshow%2F13810522
May 24, 2017 06:26:10.922 [0x7f9daf7ff700] ERROR - downloadContainer: expected MediaContainer element, found html
May 24, 2017 06:26:10.922 [0x7f9daf7ff700] WARN - DVR:Subscription: No container available for /tv.plex.providers.epg.onconnect:2/metadata/com%2Egracenote%2Eonconnect%3A%2F%2Fshow%2F12900185

Reed97123 · June 6, 2017, 9:59pm

@ChuckPA said:
3. I then ask you to create a section which contains known REAL media… not where you created your hard links.
Hard links are no different (or less real) than ‘real media’. There is no functional way to discriminate between two different hard links pointing to the same file. What you term ‘real media’ is a file with one hard link pointing to it. A second hard link to the file isn’t any less real than the first.

Reed97123 · June 6, 2017, 10:01pm

Where are the ‘held transaction too long’ issues you mentioned?

ChuckPa · June 6, 2017, 10:02pm

Didn’t you keep your media ‘partitioned’ at the directory level?

A “Master” directory
A “His” directory (which contains hardlinks to Master)
A “Her” directory (which contains hardlinks to Master)

All this to operate under the rule of " Delete the file when done watching " ??

Reed97123 · June 6, 2017, 10:06pm

@ChuckPA said:
Didn’t you keep your media ‘partitioned’ at the directory level?

A “Master” directory
A “His” directory (which contains hardlinks to Master)
A “Her” directory (which contains hardlinks to Master)

All this to operate under the rule of " Delete the file when done watching " ??

No, not really. I record it to a ‘Shared’ folder then I re-encode it on the tmp drive, move it back, create hard link #2 from my directory, create hard link #3 from my wife’s directory, then erase hard link #1 (the original hard link).

(Create a file, hard link to the new file from another location, erase the original file (hard link), is equivalent to the move command.)

No “Delete the file when done watching” is used. Each person manually deletes when they want (not automatic).

ChuckPa · June 6, 2017, 10:07pm

Here…

FROM THE TOP:

Plex Media Server.2 log

Slow database (needs optimizing)

May 23, 2017 21:02:39.663 [0x7ffb52bfb700] WARN - SLOW QUERY: It took 290.000000 ms to retrieve 28 items.
May 23, 2017 21:02:40.982 [0x7ffb3e7f4700] WARN - SLOW QUERY: It took 260.000000 ms to retrieve 28 items.

Corrupt Photo Cache

May 23, 2017 21:48:02.258 [0x7ffb543fe700] WARN - Range could not be satisfied 841182458 - 0 (total size=841182458)
May 23, 2017 21:52:25.223 [0x7ffb473fb700] ERROR - Error resizing an image, we don't trust what we cached [/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/PhotoTranscoder/d2/d20b7b66066a5a4d761da85716b01b338102986b.jpg]
May 23, 2017 21:52:35.036 [0x7ffb47bfc700] ERROR - Error resizing an image, we don't trust what we cached [/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/PhotoTranscoder/d2/d20b7b66066a5a4d761da85716b01b338102986b.jpg]
May 23, 2017 21:52:36.466 [0x7ffb503ff700] ERROR - Error resizing an image, we don't trust what we cached [/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/PhotoTranscoder/d2/d20b7b66066a5a4d761da85716b01b338102986b.jpg]
May 23, 2017 21:52:36.485 [0x7ffb47bfc700] ERROR - Error resizing an image, we don't trust what we cached [/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/PhotoTranscoder/d2/d20b7b66066a5a4d761da85716b01b338102986b.jpg]
May 23, 2017 21:52:56.958 [0x7ffb4f7fb700] ERROR - Error resizing an image, we don't trust what we cached [/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/PhotoTranscoder/d2/d20b7b66066a5a4d761da85716b01b338102986b.jpg]
May 23, 2017 21:53:01.788 [0x7ffb503ff700] ERROR - Error resizing an image, we don't trust what we cached [/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/PhotoTranscoder/d2/d20b7b66066a5a4d761da85716b01b338102986b.jpg]
May 23, 2017 21:53:01.819 [0x7ffb52bff700] ERROR - Error resizing an image, we don't trust what we cached [/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/PhotoTranscoder/d2/d20b7b66066a5a4d761da85716b01b338102986b.jpg]
May 23, 2017 21:53:02.865 [0x7ffb52bff700] WARN - Range could not be satisfied 595497011 - 0 (total size=595497011)
May 23, 2017 21:53:02.915 [0x7ffb54bff700] WARN - Range could not be satisfied 595497011 - 0 (total size=595497011)

The above are trivial to resolve.

Lastly, the DVR EPG

May 24, 2017 02:04:08.780 [0x7ffb53bfd700] INFO - SQLITE3:0x10, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
May 24, 2017 02:04:08.790 [0x7ffb53bfd700] INFO - SQLITE3:0x10, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
May 24, 2017 02:04:08.800 [0x7ffb53bfd700] INFO - SQLITE3:0x10, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
May 24, 2017 02:05:05.125 [0x7ffb42ffd700] WARN - PubSub: Received notifyConnectivity event with incorrect async identifier (b959e570-ee68-47e4-ab65-37ed5d389ac7, expected b2220983-0947-46bb-bc97-38eb1e7e1776)
May 24, 2017 02:19:45.444 [0x7ffb53bfd700] INFO - SQLITE3:0x10, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
May 24, 2017 02:19:45.457 [0x7ffb53bfd700] INFO - SQLITE3:0x10, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
May 24, 2017 02:19:45.468 [0x7ffb53bfd700] INFO - SQLITE3:0x10, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
May 24, 2017 02:19:45.478 [0x7ffb53bfd700] INFO - SQLITE3:0x10, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
May 24, 2017 02:19:46.810 [0x7ffb52bff700] ERROR - downloadContainer: expected MediaContainer element, found html
May 24, 2017 02:19:46.811 [0x7ffb52bff700] WARN - DVR:Subscription: No container available for /tv.plex.providers.epg.onconnect:2/metadata/com%2Egracenote%2Eonconnect%3A%2F%2Fshow%2F11770080
May 24, 2017 02:19:46.878 [0x7ffb52bff700] ERROR - downloadContainer: expected MediaContainer element, found html
May 24, 2017 02:19:46.878 [0x7ffb52bff700] WARN - DVR:Subscription: No container available for /tv.plex.providers.epg.onconnect:2/metadata/com%2Egracenote%2Eonconnect%3A%2F%2Fshow%2F13810522
May 24, 2017 02:19:47.194 [0x7ffb52bff700] ERROR - downloadContainer: expected MediaContainer element, found html
May 24, 2017 02:19:47.194 [0x7ffb52bff700] WARN - DVR:Subscription: No container available for /tv.plex.providers.epg.onconnect:2/metadata/com%2Egracenote%2Eonconnect%3A%2F%2Fshow%2F12900185

Reed97123 · June 6, 2017, 10:15pm

I see that there are issues, but I don’t see how they are affecting the Movies being detected and metadata being downloaded for them.

Errors:

Database optimization needed.
Pictures issues - Would this affect movies?
EPG issues - This affects movies?

I can just remove pictures altogether, I don’t really use Plex for pictures. As for the EPG issues, I just recreated the database about half a year ago because of database issues. I guess I can just do it again.

ChuckPa · June 6, 2017, 10:41pm

Database issues:
Affects all of PMS.
When PMS and its internal agents (like metadata, the scanner, etc) cannot talk to each other, it falls apart. EPG mis

Remedy
Optimize the database
Enable the Scheduled task to automatically optimize weekly.

If the database is still slow, Perform a fully manual, offline, optimization ( I will gladly help with this procedure )

Photo cache affects all the thumbnails. It is the whole photo cache.

Remedy
Stop PMS.
Delete everything in /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Caches
Start PMS
Update Library

EPG issues are not related but their presence in the logs tells me there is garbage in there somewhere. Why and how it got there is unknown without doing a full postmortem

Reed97123 · June 8, 2017, 3:49pm

I completely uninstalled Plex and then re-installed it. I’m still seeing some errors in the newly recreated library.

Are any of these serious? Attaching the full logs as well.

root@NAS:/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Logs# fgrep ERROR *
Plex DLNA Server.log:Jun 07, 2017 08:44:06.860 [0x7fb386643800] ERROR - Couldn't rename file /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Plug-in Support/Databases/com.plexapp.dlna-new.db-shm to /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Plug-in Support/Databases/com.plexapp.dlna.db-shm: No such file or directory
Plex DLNA Server.log:Jun 07, 2017 08:44:06.860 [0x7fb386643800] ERROR - Couldn't rename file /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Plug-in Support/Databases/com.plexapp.dlna-new.db-wal to /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Plug-in Support/Databases/com.plexapp.dlna.db-wal: No such file or directory
Plex Media Server.1.log:Jun 07, 2017 08:52:44.924 [0x7ff2ad2ce800] ERROR - Transcoder: Error cleaning old transcode sessions: boost::filesystem::directory_iterator::construct: No such file or directory: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions"
Plex Media Server.1.log:Jun 07, 2017 08:52:52.848 [0x7ff2a03ff700] ERROR - Error issuing curl_easy_perform(handle): 7
Plex Media Server.1.log:Jun 07, 2017 08:53:05.044 [0x7ff28bffe700] ERROR - [PlexRelay] kex protocol error: type 7 seq 11
Plex Media Server.2.log:Jun 07, 2017 08:49:02.786 [0x7f413584b800] ERROR - Transcoder: Error cleaning old transcode sessions: boost::filesystem::directory_iterator::construct: No such file or directory: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions"
Plex Media Server.2.log:Jun 07, 2017 08:49:18.628 [0x7f41187fa700] ERROR - Error issuing curl_easy_perform(handle): 28
Plex Media Server.2.log:Jun 07, 2017 08:51:13.655 [0x7f4126ffe700] ERROR - EventSource: Retrying in 15 seconds.
Plex Media Server.2.log:Jun 07, 2017 08:51:13.669 [0x7f4126ffe700] ERROR - CERT: Error in TLS handshake: short read
Plex Media Server.2.log:Jun 07, 2017 08:51:13.692 [0x7f41277ff700] ERROR - CERT: Error in TLS handshake: short read
Plex Media Server.2.log:Jun 07, 2017 08:51:13.706 [0x7f4126ffe700] ERROR - CERT: Error in TLS handshake: short read
Plex Media Server.2.log:Jun 07, 2017 08:51:13.706 [0x7f4126ffe700] ERROR - CERT: Error in TLS handshake: short read
Plex Media Server.2.log:Jun 07, 2017 08:51:13.706 [0x7f4126ffe700] ERROR - CERT: Error in TLS handshake: short read
Plex Media Server.2.log:Jun 07, 2017 08:51:15.042 [0x7f41147f9700] ERROR - [PlexRelay] kex protocol error: type 7 seq 11
Plex Media Server.2.log:Jun 07, 2017 08:52:36.951 [0x7f411d3ff700] ERROR - Plex Tuner Service failed to start
Plex Media Server.3.log:Jun 07, 2017 08:43:57.507 [0x7fa92a47f800] ERROR - SQLITE3:0x10, 1, duplicate column name: grandparent_guid
Plex Media Server.3.log:Jun 07, 2017 08:43:57.510 [0x7fa92a47f800] ERROR - SQLITE3:0x10, 1, duplicate column name: originally_available_at
Plex Media Server.3.log:Jun 07, 2017 08:43:58.778 [0x7fa91bbff700] ERROR - JobManager: child process returned: 1 (Operation not permitted)
Plex Media Server.3.log:Jun 07, 2017 08:44:06.543 [0x7fa92a47f800] ERROR - Transcoder: Error cleaning old transcode sessions: boost::filesystem::directory_iterator::construct: No such file or directory: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions"
Plex Media Server.3.log:Jun 07, 2017 08:44:06.689 [0x7fa9183fc700] ERROR - SQLITE3:0x10, 14, cannot open file at line 34876 of [fc49f556e4]
Plex Media Server.3.log:Jun 07, 2017 08:44:06.689 [0x7fa9183fc700] ERROR - SQLITE3:0x10, 14, os_unix.c:34876: (2) open(/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/gn_lists.gdb) - No such file or directory
Plex Media Server.3.log:Jun 07, 2017 08:44:06.904 [0x7fa9183fc700] ERROR - SQLITE3:0x10, 14, cannot open file at line 34876 of [fc49f556e4]
Plex Media Server.3.log:Jun 07, 2017 08:44:06.904 [0x7fa9183fc700] ERROR - SQLITE3:0x10, 14, os_unix.c:34876: (2) open(/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/gn_lists.gdb) - No such file or directory
Plex Media Server.3.log:Jun 07, 2017 08:44:41.584 [0x7fa90d7fc700] ERROR - Error issuing curl_easy_perform(handle): 28
Plex Media Server.3.log:Jun 07, 2017 08:46:59.445 [0x7fa9193fe700] ERROR - EventSource: Retrying in 15 seconds.
Plex Media Server.3.log:Jun 07, 2017 08:48:41.109 [0x7fa911fff700] ERROR - Plex Tuner Service failed to start
Plex Media Server.log:Jun 07, 2017 08:55:31.300 [0x7ffbe855e800] ERROR - Transcoder: Error cleaning old transcode sessions: boost::filesystem::directory_iterator::construct: No such file or directory: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions"
Plex Media Server.log:Jun 07, 2017 08:55:56.356 [0x7ffbce3ff700] ERROR - Error issuing curl_easy_perform(handle): 28
Plex Media Server.log:Jun 07, 2017 08:57:54.994 [0x7ffbcc7fe700] ERROR - [PlexRelay] kex protocol error: type 7 seq 11
Plex Media Server.log:Jun 07, 2017 08:57:55.017 [0x7ffbcb7fc700] ERROR - [PlexRelay] kex protocol error: type 7 seq 11
Plex Media Server.log:Jun 07, 2017 09:20:36.542 [0x7ffbce3ff700] ERROR - SQLITE3:0x10, 1, duplicate column name: grandparent_guid
Plex Media Server.log:Jun 07, 2017 09:20:36.542 [0x7ffbce3ff700] ERROR - SQLITE3:0x10, 1, duplicate column name: originally_available_at
Plex Media Server.log:Jun 07, 2017 09:20:38.173 [0x7ffbc0ffe700] ERROR - Uncaught exception running threadpool task: Null value fetched and no indicator defined.
Plex Media Server.log:Jun 08, 2017 02:38:36.465 [0x7ffbb83fa700] ERROR - SQLITE3:0x10, 1, duplicate column name: grandparent_guid
Plex Media Server.log:Jun 08, 2017 02:38:36.469 [0x7ffbb83fa700] ERROR - SQLITE3:0x10, 1, duplicate column name: originally_available_at
Plex Media Server.log:Jun 08, 2017 02:39:03.066 [0x7ffbc87fb700] ERROR - XML: Entity: line 1:
Plex Media Server.log:Jun 08, 2017 02:39:03.066 [0x7ffbc87fb700] ERROR - XML: parser
Plex Media Server.log:Jun 08, 2017 02:39:03.066 [0x7ffbc87fb700] ERROR - XML: error :
Plex Media Server.log:Jun 08, 2017 02:39:03.066 [0x7ffbc87fb700] ERROR - XML: Start tag expected, '<' not found
Plex Media Server.log:Jun 08, 2017 02:39:03.066 [0x7ffbc87fb700] ERROR - XML:
Plex Media Server.log:Jun 08, 2017 02:39:03.066 [0x7ffbc87fb700] ERROR - XML:  ^
Plex Media Server.log:Jun 08, 2017 02:39:03.066 [0x7ffbc87fb700] ERROR - Error parsing content.
Plex Media Server.log:Jun 08, 2017 02:39:03.068 [0x7ffbc87fb700] ERROR - MyPlex: Error parsing XML:
Plex Media Server.log:Jun 08, 2017 02:39:03.913 [0x7ffbbabff700] ERROR - XML: Entity: line 1:
Plex Media Server.log:Jun 08, 2017 02:39:03.913 [0x7ffbbabff700] ERROR - XML: parser
Plex Media Server.log:Jun 08, 2017 02:39:03.913 [0x7ffbbabff700] ERROR - XML: error :
Plex Media Server.log:Jun 08, 2017 02:39:03.914 [0x7ffbbabff700] ERROR - XML: Start tag expected, '<' not found
Plex Media Server.log:Jun 08, 2017 02:39:03.914 [0x7ffbbabff700] ERROR - XML:
Plex Media Server.log:Jun 08, 2017 02:39:03.914 [0x7ffbbabff700] ERROR - XML:  ^
Plex Media Server.log:Jun 08, 2017 02:39:03.914 [0x7ffbbabff700] ERROR - Error parsing content.
Plex Media Server.log:Jun 08, 2017 02:39:03.914 [0x7ffbbabff700] ERROR - MyPlex: Error parsing XML:
Plex Media Server.log:Jun 08, 2017 02:39:07.654 [0x7ffbc87fb700] ERROR - XML: Entity: line 1:
Plex Media Server.log:Jun 08, 2017 02:39:07.654 [0x7ffbc87fb700] ERROR - XML: parser
Plex Media Server.log:Jun 08, 2017 02:39:07.654 [0x7ffbc87fb700] ERROR - XML: error :
Plex Media Server.log:Jun 08, 2017 02:39:07.654 [0x7ffbc87fb700] ERROR - XML: Start tag expected, '<' not found
Plex Media Server.log:Jun 08, 2017 02:39:07.654 [0x7ffbc87fb700] ERROR - XML:
Plex Media Server.log:Jun 08, 2017 02:39:07.654 [0x7ffbc87fb700] ERROR - XML:  ^
Plex Media Server.log:Jun 08, 2017 02:39:07.654 [0x7ffbc87fb700] ERROR - Error parsing content.
Plex Media Server.log:Jun 08, 2017 02:39:07.654 [0x7ffbc87fb700] ERROR - MyPlex: Error parsing XML:
Plex Media Server.log:Jun 08, 2017 02:40:24.764 [0x7ffbbabff700] ERROR - XML: Entity: line 1:
Plex Media Server.log:Jun 08, 2017 02:40:24.764 [0x7ffbbabff700] ERROR - XML: parser
Plex Media Server.log:Jun 08, 2017 02:40:24.764 [0x7ffbbabff700] ERROR - XML: error :
Plex Media Server.log:Jun 08, 2017 02:40:24.764 [0x7ffbbabff700] ERROR - XML: Start tag expected, '<' not found
Plex Media Server.log:Jun 08, 2017 02:40:24.764 [0x7ffbbabff700] ERROR - XML:
Plex Media Server.log:Jun 08, 2017 02:40:24.764 [0x7ffbbabff700] ERROR - XML:  ^
Plex Media Server.log:Jun 08, 2017 02:40:24.764 [0x7ffbbabff700] ERROR - Error parsing content.
Plex Media Server.log:Jun 08, 2017 02:40:24.764 [0x7ffbbabff700] ERROR - MyPlex: Error parsing XML:

ChuckPa · June 8, 2017, 4:07pm

Reed,
Please look at Plex Media Server.log lines 976 -> 1031. The database is in serious trouble again. Did you build all sections at once without optimizing between sections?

As example:

Jun 07, 2017 09:13:08.081 [0x7ffbc87fb700] WARN - SLOW QUERY: It took 280.000000 ms to retrieve 0 items.
Jun 07, 2017 09:13:08.313 [0x7ffbc87fb700] WARN - SLOW QUERY: It took 230.000000 ms to retrieve 0 items.
Jun 07, 2017 09:13:12.125 [0x7ffbccbfe700] WARN - SLOW QUERY: It took 250.000000 ms to retrieve 0 items.
Jun 07, 2017 09:13:12.368 [0x7ffbccbfe700] WARN - SLOW QUERY: It took 260.000000 ms to retrieve 0 items.
Jun 07, 2017 09:13:15.128 [0x7ffbc87fb700] WARN - SLOW QUERY: It took 230.000000 ms to retrieve 0 items.
Jun 07, 2017 09:13:15.338 [0x7ffbc87fb700] WARN - SLOW QUERY: It took 220.000000 ms to retrieve 0 items.
Jun 07, 2017 09:13:18.525 [0x7ffbccbfe700] WARN - SLOW QUERY: It took 230.000000 ms to retrieve 0 items.
Jun 07, 2017 09:13:18.751 [0x7ffbccbfe700] WARN - SLOW QUERY: It took 220.000000 ms to retrieve 0 items.
Jun 07, 2017 09:13:22.197 [0x7ffbc87fb700] WARN - SLOW QUERY: It took 210.000000 ms to retrieve 0 items.
Jun 07, 2017 09:13:22.408 [0x7ffbc87fb700] WARN - SLOW QUERY: It took 210.000000 ms to retrieve 0 items.

Reed97123 · June 8, 2017, 4:17pm

Yes, I entered them as fast as I could navigate the GUI to create them.

ChuckPa · June 8, 2017, 4:19pm

Please optimize the DB, restart PMS, and continue with your testing.

Reed97123 · June 8, 2017, 4:26pm

What about the other voluminous errors? In the past I thought a certain number of errors were the norm, but you had seemed very concerned about many of the errors prior to my clean installation.

Are the remainder of the errors benign?

ChuckPa · June 8, 2017, 4:40pm

Reed, some errors are the norm (the XML parsing from some devices is normal).
I am looking at the errors in your most recent log file only.

I cannot over emphasize enough, when the database is slow / problematic, everything has problems. Those errors are all cascaded off the main issue.

Reed97123 · June 8, 2017, 4:46pm

@ChuckPA said:
Reed, some errors are the norm (the XML parsing from some devices is normal).
I’m not sure how I can personally determine the severity except dealing with it every day as you are. There are a ton of error messages listed, which I focused on but you from your experience dismissed. Meanwhile you focused in on the WARN messages, which I had ignored.

@ChuckPA said:
I cannot over emphasize enough, when the database is slow / problematic, everything has problems. Those errors are all cascaded off the main issue.
I’m not dismissing your warnings, I just have no idea how to personally determine the severity of issues when the ERROR/WARN do not correlate to their level of severity.

ChuckPa · June 8, 2017, 6:08pm

The database “Warning” is one of those which probably should be an error. The database is still functioning so it’s not an ERROR. The down stream affects of it being slow are the manifestations. e.g. Non-responsive Dashboard, unable to match content or download metadata, and even slow to start playback to name but a few.

Reed97123 · June 21, 2017, 3:03pm

I’m still getting the database warn message about slow access:

Plex Media Server.1.log:Jun 18, 2017 17:38:28.319 [0x7f04763ff700] WARN - SLOW QUERY: It took 1060.000000 ms to retrieve 50 items.
Plex Media Server.2.log:Jun 11, 2017 23:56:52.492 [0x7facc17fc700] WARN - SLOW QUERY: It took 210.000000 ms to retrieve 48 items.
Plex Media Server.log:Jun 19, 2017 20:24:31.633 [0x7ff6003fe700] WARN - SLOW QUERY: It took 230.000000 ms to retrieve 48 items.
Plex Media Server.log:Jun 19, 2017 20:24:34.205 [0x7ff5f9ffd700] WARN - SLOW QUERY: It took 220.000000 ms to retrieve 48 items.
Plex Media Server.log:Jun 19, 2017 20:24:35.389 [0x7ff5f9ffd700] WARN - SLOW QUERY: It took 260.000000 ms to retrieve 48 items.

Attached the recent logs.

Topic		Replies	Views
Metadata Scanning stops working after sometime (only reboot) resolves Metadata & Adding Files server-linux	48	1004	January 31, 2020
Plex being really unreliable and slow... General Discussions	31	834	January 7, 2020
Plex server loses connection when scanning any library Desktops & Laptops server-linux	15	978	December 26, 2019
Scan issue on Plex Media Server Ubuntu Desktops & Laptops server-linux	30	1661	June 22, 2019
Plex Media Scanner - Run through Command Line Very slow (Log Included) Desktops & Laptops server-windows	15	450	January 8, 2020

Something has changed in the scanning logic

Related topics