Plexmediaserver SQLite errors, won't scan

Plex Media Server Desktops & Laptops
1

Server Version#: 1.16.3.1402-22929c8a2 and 1.16.3.1433-359b06978
Player Version#: Version 3.104.2

Yesterday I couldn’t scan library files. I found these errors just after starting plexmediaserver, it happens withing 2 minutes of service start.

Jul 25, 2019 12:29:47.876 [0x7f0b367fc700] ERROR - SQLITE3:(nil), 1, statement aborts at 1: [COMMIT] cannot commit - no transaction is active
Jul 25, 2019 12:29:47.876 [0x7f0b367fc700] ERROR - Failed to commit transaction (…/Library/MetadataItem.cpp:958) (tries=9): Cannot commit transaction. cannot commit - no transaction is active
Jul 25, 2019 12:29:49.002 [0x7f0b367fc700] ERROR - SQLITE3:(nil), 1, statement aborts at 1: [COMMIT] cannot commit - no transaction is active
Jul 25, 2019 12:29:49.003 [0x7f0b367fc700] ERROR - Failed to commit transaction (…/Library/MetadataItem.cpp:958) (tries=10): Cannot commit transaction. cannot commit - no transaction is active
Jul 25, 2019 12:29:49.003 [0x7f0b367fc700] ERROR - Exception inside transaction (inside=1) (…/Library/MetadataItem.cpp:958): Cannot commit transaction. cannot commit - no transaction is active
Jul 25, 2019 12:29:49.003 [0x7f0b367fc700] ERROR - SQLITE3:(nil), 1, statement aborts at 1: [ROLLBACK] cannot rollback - no transaction is active
Jul 25, 2019 12:29:49.004 [0x7f0b367fc700] ERROR - Failed to roll back transaction (…/Library/MetadataItem.cpp:956): Cannot rollback transaction. cannot rollback - no transaction is active
Jul 25, 2019 12:29:49.004 [0x7f0b367fc700] ERROR - * Error loading episode.
Jul 25, 2019 12:29:49.036 [0x7f0b367fc700] ERROR - Failed to commit transaction (…/Library/MetadataItem.cpp:958) (tries=1): Cannot commit transaction. out of memory

Once this starts in the error logs, the media scanner will never finish or find new files. If I stop the server and restart it, it will find a file or two, then go back to this. Playback and other server functions aren’t apparently impacted, just this.

I am running on Ubuntu 18.04.2 LTS, Linux 4.15.0-55-generic, 12 CPU KVM VM with 16Gig of ram.

The “out of memory” seems especially odd, as I’m well under 50% system RAM utilization.

total used free shared buff/cache available
Mem: 15849 1276 6999 7 7573 14235
Swap: 30515 0 30515

I was running 1.16.3.1402-22929c8a2 when this started. I followed the “Repair a Corrupt Database” instructions, sqlite3 gave me “Error: database disk image is malformed”, so I did a dump and import, but aside from the integrity check coming back clean, it’s the exact same problem.
I upgraded to 1.16.3.1433-359b06978 just now, hoping it might have had a bug fix, but it’s exactly the same.

2

would you be kind enough to make a tar.gz of the Logs directory and attach it here with your next post?

Hopefully DEBUG logging is still enabled. If not, this will be extremely difficult to diagnose because DEBUG tells us what it’s about to do. DEBUG on occupies no more disk space than off (26 MB buffer). VERBOSE logging reduces our visibility window to about 2 minutes of elapsed time and therefore not used unless are are targeting a very specific operation.

3

Logs.tar.gz (58.4 KB)
I was able to get the errors in the logs with DEBUG and VERBOSE, and without running the media scanner, you can find the error on lines 2825, 2826, 2827, 2828, 2829, 2843, 2844, and 2845 of ‘Plex Media Server.log’.

Excerpt:

2821-Jul 25, 2019 15:39:23.438 [0x7f6ea67fc700] DEBUG - Running database fix-ups.
2822-Jul 25, 2019 15:39:23.439 [0x7f6ea67fc700] DEBUG - Deleting media item 1729713.
2823-Jul 25, 2019 15:39:23.440 [0x7f6ea67fc700] DEBUG - Was connected to metadata item 778246, count is now 0.
2824-Jul 25, 2019 15:39:23.440 [0x7f6ea67fc700] DEBUG - Destroying metadata item 778246 (com.plexapp.agents)
2825:Jul 25, 2019 15:39:23.443 [0x7f6ea67fc700] ERROR - SQLITE3:(nil), 7, statement aborts at 82: [delete from metadata_items where id=?] out of memory
2826:Jul 25, 2019 15:39:23.443 [0x7f6ea67fc700] ERROR - Exception inside transaction (inside=1) (../Library/MetadataItem.cpp:750): sqlite3_statement_backend::loadOne: out of memory
2827:Jul 25, 2019 15:39:23.443 [0x7f6ea67fc700] ERROR - Exception inside transaction (inside=1) (../Library/MediaItem.cpp:769): sqlite3_statement_backend::loadOne: out of memory
2828:Jul 25, 2019 15:39:23.443 [0x7f6ea67fc700] ERROR - Exception inside transaction (inside=1) (../Library/DatabaseFixups.cpp:185): sqlite3_statement_backend::loadOne: out of memory
2829:Jul 25, 2019 15:39:23.443 [0x7f6ea67fc700] ERROR - Fixup 42DatabaseFixupsGarbageCollectTransientItems threw an exception: sqlite3_statement_backend::loadOne: out of memory
2830-Jul 25, 2019 15:39:23.444 [0x7f6ea67fc700] DEBUG - Collections: Found 0 collections tags in section 1.
2831-Jul 25, 2019 15:39:23.444 [0x7f6ea67fc700] DEBUG - Collections: We had 0 collections in the library already.
2832-Jul 25, 2019 15:39:23.444 [0x7f6ea67fc700] DEBUG - Collections: Synced tags in section 1 in 0ms.
2833-Jul 25, 2019 15:39:23.444 [0x7f6ea67fc700] DEBUG - Collections: Refreshed attributes for 0 collections in section 1 in 0ms.
--
2839-Jul 25, 2019 15:39:23.446 [0x7f6ea67fc700] DEBUG - Collection: Refreshed visibility in section 2 in 0ms.
2840-Jul 25, 2019 15:39:23.446 [0x7f6ea67fc700] DEBUG - Collections: Found 1 collections tags in section 3.
2841-Jul 25, 2019 15:39:23.447 [0x7f6ea67fc700] DEBUG - Collections: We had 1 collections in the library already.
2842-Jul 25, 2019 15:39:23.447 [0x7f6ea67fc700] DEBUG - Collections: Synced tags in section 3 in 0ms.
2843:Jul 25, 2019 15:39:23.448 [0x7f6ea67fc700] ERROR - SQLITE3:(nil), 7, statement aborts at 171: [update metadata_items set extra_data=? where library_section_id=? and metadata_type=? and `index` not in (22861)] out of memory
2844:Jul 25, 2019 15:39:23.449 [0x7f6ea67fc700] ERROR - Exception inside transaction (inside=1) (../Library/MetadataCollection.cpp:236): sqlite3_statement_backend::loadOne: out of memory
2845:Jul 25, 2019 15:39:23.449 [0x7f6ea67fc700] ERROR - Fixup 29DatabaseFixupsSyncCollections threw an exception: sqlite3_statement_backend::loadOne: out of memory
2846-Jul 25, 2019 15:39:23.449 [0x7f6ea67fc700] DEBUG - Running database fix-ups completed in 0.0 seconds.
2847-Jul 25, 2019 15:39:23.449 [0x7f6ea67fc700] DEBUG - HTTP requesting GET https://plex.tv/api/v2/features?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
2848-Jul 25, 2019 15:39:23.449 [0x7f6edbfff700] VERBOSE - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
2849-Jul 25, 2019 15:39:23.449 [0x7f6edbfff700] VERBOSE - Auth: Came in with the master token, authorization succeeded.

Full logs attached.

4

Thanks for the logs. I suspect the out of memory errors are a consequence of having a corrupt database. Repair action would not remove bad data

Could you look in the directory /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Plug-in Support/Databases for any recent automatic backups that you can restore from. The backups that you would find there would be ones before the integrity check started to fail

The backup files would be named

com.plexapp.plugins.library.db-2019-mm-dd
com.plexapp.plugins.library.blobs.db-2019-mm-dd
5

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