Corruption of my database and inability to 'roll back' system

Plex Media Server
1

Whole system went into melt down the night of the login outage
After a system restart Plex would not start (same DB error at end of this log)

I have tried using TimeMachine to roll back all Plex files to a date before the issue, but after 1.19.5 didn’t run I tried 1.20 on the latest restore, it seems to start updating but then errored the same again. Please help. Years of work in this build :slight_smile:

Server Version#: 1.19.5 and 1.20.0
Player Version#:

Aug 09, 2020 09:39:36.768 [0x70000f0df000] INFO - Plex Media Server v1.20.0.3181-0800642ec - Apple Mac x86_64 - build: darwin-x86_64 macos - GMT 01:00
Aug 09, 2020 09:39:36.769 [0x70000f0df000] INFO - MacOSX version: 10.14.6, language: en-GB
Aug 09, 2020 09:39:36.769 [0x70000f0df000] INFO - Processor Intel(R) Xeon(R) CPU E5-1680 v2 @ 3.00GHz
Aug 09, 2020 09:39:36.769 [0x70000f0df000] INFO - /Applications/Plex Media Server.app/Contents/MacOS/Plex Media Server
Aug 09, 2020 09:39:36.934 [0x70000f2eb000] DEBUG - BPQ: [Idle] → [Starting]
Aug 09, 2020 09:39:36.937 [0x70000f2eb000] DEBUG - FeatureManager: Using cached data for features list
Aug 09, 2020 09:39:36.947 [0x70000f2eb000] DEBUG - Opening 20 database sessions to library (com.plexapp.plugins.library), SQLite 3.26.0, threadsafe=1
Aug 09, 2020 09:39:36.966 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 283, recovered 847 frames from WAL file /Users/plexserver/Library/Application Support/Plex Media Server/Plug-in Support/Databases/com.plexapp.plugins.library.db-wal
Aug 09, 2020 09:39:37.013 [0x70000f2eb000] DEBUG - Running migrations. (EPG 0)
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Running forward migration 20200615032400.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 0.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 1.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 2.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 3.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 4.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 5.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 6.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 7.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 8.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 9.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 10.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 11.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 12.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 13.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 14.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 15.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 16.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 17.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 18.
Aug 09, 2020 09:39:37.014 [0x70000f2eb000] DEBUG - Captured session 19.
Aug 09, 2020 09:39:38.711 [0x70000f2eb000] WARN - Held transaction for too long (…/Library/FullTextSearch.cpp:54): 1.120000 seconds
Aug 09, 2020 09:39:38.753 [0x70000f474000] DEBUG - Job running: ‘/Applications/Plex Media Server.app/Contents/MacOS/CrashUploader’ ‘–directory=/Users/plexserver/Library/Application Support/Plex Media Server/Crash Reports/1.20.0.3181-0800642ec’ ‘–version=1.20.0.3181-0800642ec’ ‘–platform=MacOSX’ ‘–platformVersion=10.14.6’ ‘–serverUuid=3a16bd158601021bfec31b1060b3dba47a03e8f7’ ‘–userId=anon@thedoor.co.uk’ ‘–sentryUrl=https://sentry.io/api/1233455/minidump’ ‘–sentryKey=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx’ ‘–vendor=Apple’ ‘–model=x86_64’ ‘–device=Mac’
Aug 09, 2020 09:39:38.769 [0x70000f474000] DEBUG - Jobs: Starting child process with pid 417
Aug 09, 2020 09:39:38.806 [0x70000f3f1000] DEBUG - Jobs: ‘/Applications/Plex Media Server.app/Contents/MacOS/CrashUploader’ exit code for process 417 is 0 (success)
Aug 09, 2020 09:39:39.313 [0x70000f2eb000] WARN - Held transaction for too long (…/Library/FullTextSearch.cpp:64): 0.590000 seconds
Aug 09, 2020 09:39:40.855 [0x70000f2eb000] WARN - Held transaction for too long (…/Library/FullTextSearch.cpp:75): 1.220000 seconds
Aug 09, 2020 09:39:41.608 [0x70000f2eb000] WARN - Held transaction for too long (…/Library/FullTextSearch.cpp:85): 0.700000 seconds
Aug 09, 2020 09:39:41.609 [0x70000f2eb000] WARN - Held transaction for too long (…/Library/DatabaseMigrations.cpp:209): 3.630000 seconds
Aug 09, 2020 09:39:41.860 [0x70000f2eb000] DEBUG - Analyzing database.
Aug 09, 2020 09:39:42.735 [0x70000f2eb000] DEBUG - Vacuuming database.
Aug 09, 2020 09:39:58.643 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.645 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.647 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.649 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.650 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.652 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.654 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.656 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.658 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.660 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.662 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.664 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.666 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.668 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.670 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.672 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.674 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.675 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.677 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 17, statement aborts at 57: [select * from metadata_items limit 1] database schema has changed
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Completed forward migration 20200615032400.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Running forward migration 20200701090000.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 0.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 1.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 2.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 3.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 4.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 5.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 6.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 7.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 8.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 9.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 10.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 11.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 12.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 13.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 14.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 15.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 16.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 17.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 18.
Aug 09, 2020 09:39:58.679 [0x70000f2eb000] DEBUG - Captured session 19.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Completed forward migration 20200701090000.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Running forward migration 20200728130000.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 0.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 1.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 2.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 3.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 4.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 5.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 6.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 7.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 8.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 9.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 10.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 11.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 12.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 13.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 14.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 15.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 16.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 17.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 18.
Aug 09, 2020 09:39:58.682 [0x70000f2eb000] DEBUG - Captured session 19.
Aug 09, 2020 09:39:58.685 [0x70000f2eb000] DEBUG - Completed forward migration 20200728130000.
Aug 09, 2020 09:39:58.731 [0x70000f2eb000] DEBUG - ChangestampAllocator: initialized to 33754155
Aug 09, 2020 09:39:58.731 [0x70000f2eb000] DEBUG - Opening 2 database sessions to library (com.plexapp.plugins.library.blobs), SQLite 3.26.0, threadsafe=1
Aug 09, 2020 09:39:58.734 [0x70000f2eb000] INFO - SQLITE3:0x10976ffe8, 283, recovered 86 frames from WAL file /Users/plexserver/Library/Application Support/Plex Media Server/Plug-in Support/Databases/com.plexapp.plugins.library.blobs.db-wal
Aug 09, 2020 09:39:58.743 [0x70000f2eb000] ERROR - SQLITE3:0x10976ffe8, 11, database corruption at line 65066 of [bf8c1b2b7a]
Aug 09, 2020 09:39:58.743 [0x70000f2eb000] ERROR - SQLITE3:0x10976ffe8, 11, statement aborts at 8: database disk image is malformed
Aug 09, 2020 09:39:58.743 [0x70000f2eb000] ERROR - SQLITE3:0x10976ffe8, 11, database disk image is malformed in “PRAGMA cache_size=2000”
Aug 09, 2020 09:39:58.746 [0x70000f2eb000] ERROR - Database corruption: sqlite3_statement_backend::prepare: database disk image is malformed for SQL: PRAGMA cache_size=2000

2

You’ve three options:

  1. Repair the corrupted database.
  2. Replace w/ a backup version.
  3. Delete & start over.

Replace is straightforward, as long as the backup is not corrupted.

If you delete, you’ll lose libraries, etc, but your media is not touched.

Details in support article:

3

Thanks, I tried that. To no avail. What’s odd is that the backups won’t work since it was working prior to the night in question wed/thurs I forget

4

Not sure about restoring with Time Machine (I run PMS on a Synology NAS).

Did you try using the backup Plex makes via Scheduled Tasks?

Related Page : Restore a Database Backed Up via ‘Scheduled Tasks’

1 Like
5

TimeMachine gives me (like most of em now) a view of every change going back in time each day at midnight.

Good thought, no I haven’t, i wil have a go.

6

Time Machine may not be able to make a valid backup of the database files while Plex Media Server is running and has them open/locked. That’s a common problem for backups and open files.

Your logs show problems with the .blobs. database as well. If restoring from a Plex backup doesn’t work, you might want to try the “Repair a Corrupt …” comments twice, once for each database.

The “Repair …” instructions are for ‘com.plexapp.plugins.library.db’, there’s also a file ‘com.plexapp.plugins.library.blobs.db’ that may need the same process.

7

Thanks all, restore from backup files, was easy and relaly quick - doh

1 Like
8

This is another reason why an alternative to SQLite is needed!

9

Again, this wasn’t an SQLite issue. The initial issue wasn’t caused by SQLite and the initial recovery attempt wasn’t hampered by SQLite.

Time Machine isn’t an appropriate tool for backing up databases.

OP already stated that the Plex-created database backup was restored successfully.

10

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