Errors during Startup (still starts), then Optimize causes malformed disk image

Plex Media Server
1

Server Version#: Plex Media Server v1.29.2.6364-6d72b0cf6 - Debian GNU/Linux PC x86_64 - build: linux-x86_64 debian - GMT -05:00

Been running Plex for a few years with very few issues, but this just started up recently. I noticed sometimes new shows wouldn’t be added, and I’d see things in the logs like:

Nov 13, 2022 21:35:41.370 [0x7f6268876b38] ERROR - Exception assimilating media item in Moonshiners (2011) [tvdb-253695]/Season 08: sqlite3_statement_backend::loadOne: database disk image is malformed
Nov 13, 2022 21:35:41.574 [0x7f6268876b38] ERROR - SQLITE3:0x80000001, 267, statement aborts at 178: [update metadata_items set updated_at=null,guid=?,hash=? where id=?] database disk image is malformed
Nov 13, 2022 21:35:41.574 [0x7f6268876b38] ERROR - Exception inside transaction (inside=1) (/data/jenkins/server/3537899744/Library/MetadataItem.cpp:4003): sqlite3_statement_backend::loadOne: database disk image is malformed
Nov 13, 2022 21:35:41.575 [0x7f6268876b38] ERROR - Exception assimilating media item in Moonshiners (2011) [tvdb-253695]/Season 08: sqlite3_statement_backend::loadOne: database disk image is malformed
Nov 13, 2022 21:35:41.779 [0x7f6268876b38] ERROR - SQLITE3:0x80000001, 267, statement aborts at 178: [update metadata_items set updated_at=null,guid=?,hash=? where id=?] database disk image is malformed
Nov 13, 2022 21:35:41.779 [0x7f6268876b38] ERROR - Exception inside transaction (inside=1) (/data/jenkins/server/3537899744/Library/MetadataItem.cpp:4003): sqlite3_statement_backend::loadOne: database disk image is malformed

So I went through the steps outlined here: https://support.plex.tv/articles/repair-a-corrupted-database/ (including the VACUUM and REINDEX commands, and the full recover).

Steps all work fine, PRAGMA integrity_check returns ok on the final database.

When I start the server up agan, I now see these errors:

tail -f -n 1500 /var/lib/plexmediaserver/Library/Application\ Support/Plex\ Media\ Server/Logs/Plex\ Media\ Server.log | grep ERR
Nov 14, 2022 09:18:00.753 [0x7f1a27b9f0d0] ERROR - SQLITE3:0x80000001, 1, table 'library_timeline_entries' already exists in "CREATE TABLE 'library_timeline_entries' ('id' INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, 'library_section_id' integer, 'metadata_item_id' integer, 'state' i
Nov 14, 2022 09:18:00.753 [0x7f1a27b9f0d0] ERROR - Exception inside transaction (inside=1) (/data/jenkins/server/3537899744/Library/DatabaseMigrations.cpp:289): sqlite3_statement_backend::prepare: table 'library_timeline_entries' already exists for SQL: CREATE TABLE 'library_timeline_entries' ('id' INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, 'library_section_id' integer, 'metadata_item_id' integer, 'state' integer, 'updated_at' datetime)
Nov 14, 2022 09:18:00.755 [0x7f1a27b9f0d0] ERROR - Exception thrown during migrations, aborting: sqlite3_statement_backend::prepare: table 'library_timeline_entries' already exists for SQL: CREATE TABLE 'library_timeline_entries' ('id' INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, 'library_section_id' integer, 'metadata_item_id' integer, 'state' integer, 'updated_at' datetime)

But, the server seems to start up fine and everything seems to be working more or less OK (at least in the short run). However, if I run the Optimize Database command from Settings → Manage → Troubleshooting, I get the below error in my logs (although UI has a checkmark and says all is good):

Nov 14, 2022 09:27:00.517 [0x7f1a224a4b38] ERROR - [Req#1b5/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 267, statement aborts at 4: [insert into fts4_metadata_titles_icu(fts4_metadata_titles_icu) VALUES('optimize')] database disk image is malformed
Nov 14, 2022 09:27:00.536 [0x7f1a224a4b38] ERROR - Thread: Uncaught exception running async task which was spawned by thread 0x7f1a20da4b38: sqlite3_statement_backend::loadOne: database disk image is malformed
Nov 14, 2022 09:27:00.536 [0x7f1a224a4b38] DEBUG - Activity: Ended activity 52175569-4d20-4b8d-b185-281a679333dd.

If I run it again:

Nov 14, 2022 09:28:32.556 [0x7f1a21ebdb38] DEBUG - [Req#1e7/Database optimization/com.plexapp.plugins.library.db] Activity: updated activity ceab93a8-a0cf-435a-aa9f-163eb4f50dbb - completed 40.0% - Optimizing database
Nov 14, 2022 09:28:36.311 [0x7f1a21ebdb38] ERROR - [Req#1e7/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 267, statement aborts at 35: [insert into fts4_metadata_titles_icu(rowid, title, title_sort, original_title) select metadata_items.id,  metadata_items.title || ' ' || artists.title,  metadata_items.title_sort || '
Nov 14, 2022 09:28:36.311 [0x7f1a21ebdb38] ERROR - [Req#1e7/Database optimization/com.plexapp.plugins.library.db] Exception inside transaction (inside=1) (/data/jenkins/server/3537899744/Library/FullTextSearch.cpp:58): sqlite3_statement_backend::loadOne: database disk image is malformed
Nov 14, 2022 09:28:36.315 [0x7f1a21ebdb38] ERROR - Thread: Uncaught exception running async task which was spawned by thread 0x7f1a20da4b38: sqlite3_statement_backend::loadOne: database disk image is malformed
Nov 14, 2022 09:28:36.315 [0x7f1a21ebdb38] DEBUG - Activity: Ended activity ceab93a8-a0cf-435a-aa9f-163eb4f50dbb.

(Note: this consistently happens around 40%).

My last backup DB is from a week ago, I don’t have any older than that unfortunately, and it gives me the same error on startup :frowning:

Here are my logs:
Plex Media Server Logs_2022-11-14_09-38-47.zip (616.8 KB)

And a link to the DB (1.6 GB):

2

Your DB might be beyond repair but may I suggest –

3

Thanks @ChuckPa

I ran the utility (1, 2, 3, 4) and restarted the server, unfortunately same issue at startup:

Nov 14, 2022 11:43:03.204 [0x7f988ad480d0] ERROR - SQLITE3:0x80000001, 1, table 'library_timeline_entries' already exists in "CREATE TABLE 'library_timeline_entries' ('id' INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, 'library_section_id' integer, 'metadata_item_id' integer, 'state' i
Nov 14, 2022 11:43:03.205 [0x7f988ad480d0] ERROR - Exception inside transaction (inside=1) (/data/jenkins/server/3537899744/Library/DatabaseMigrations.cpp:289): sqlite3_statement_backend::prepare: table 'library_timeline_entries' already exists for SQL: CREATE TABLE 'library_timeline_entries' ('id' INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, 'library_section_id' integer, 'metadata_item_id' integer, 'state' integer, 'updated_at' datetime)
Nov 14, 2022 11:43:03.206 [0x7f988ad480d0] ERROR - Exception thrown during migrations, aborting: sqlite3_statement_backend::prepare: table 'library_timeline_entries' already exists for SQL: CREATE TABLE 'library_timeline_entries' ('id' INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, 'library_section_id' integer, 'metadata_item_id' integer, 'state' integer, 'updated_at' datetime)

And when I do the scan, a lot of:

Nov 14, 2022 11:43:55.439 [0x7f987fc53b38] ERROR - [Req#5d] Unknown metadata type: folder
Nov 14, 2022 11:43:55.465 [0x7f98850c6b38] ERROR - [Req#6b] Unknown metadata type: folder
Nov 14, 2022 11:43:57.103 [0x7f98850c6b38] ERROR - [Req#6f] Unknown metadata type: folder

Logs from the DBRepair utility look good:

2022-11-14 11.37.57 - Session start: Host is Debian GNU/Linux 9 (stretch)
2022-11-14 11.38.17 - Check   - Check com.plexapp.plugins.library.db - PASS
2022-11-14 11.38.17 - Check   - Check com.plexapp.plugins.library.blobs.db - PASS
2022-11-14 11.38.17 - Check   - PASS
2022-11-14 11.38.24 - Vacuum  - MakeBackup com.plexapp.plugins.library.db - PASS
2022-11-14 11.38.24 - Vacuum  - MakeBackup com.plexapp.plugins.library.blobs.db - PASS
2022-11-14 11.38.24 - Vacuum  - MakeBackups - PASS
2022-11-14 11.38.33 - Vacuum  - Vacuum main database - PASS (Size: 1602MB/1597MB).
2022-11-14 11.38.33 - Vacuum  - Vacuum blobs database - PASS (Size: 44MB/44MB).
2022-11-14 11.38.33 - Vacuum  - PASS
2022-11-14 11.38.45 - Reindex - MakeBackup com.plexapp.plugins.library.db - PASS
2022-11-14 11.38.45 - Reindex - MakeBackup com.plexapp.plugins.library.blobs.db - PASS
2022-11-14 11.38.45 - Reindex - MakeBackup - PASS
2022-11-14 11.38.59 - Reindex - Reindex: com.plexapp.plugins.library.db - PASS
2022-11-14 11.38.59 - Reindex - Reindex: com.plexapp.plugins.library.blobs.db - PASS
2022-11-14 11.38.59 - Reindex - PASS
2022-11-14 11.39.59 - Repair  - Export databases - PASS
2022-11-14 11.41.21 - Repair  - Import - PASS
2022-11-14 11.41.35 - Repair  - Verify main database - PASS (Size: 1597MB/1597MB).
2022-11-14 11.41.35 - Repair  - Verify blobs database - PASS (Size: 44MB/44MB).
2022-11-14 11.41.35 - Repair  - Move files - PASS
2022-11-14 11.41.35 - Repair  - PASS

Unfortunately, Optimization returned the same error I was getting before:

Nov 14, 2022 11:49:56.284 [0x7f9880c22b38] DEBUG - [Req#41407/Database optimization/com.plexapp.plugins.library.db] Rebuilding full text search tables.
Nov 14, 2022 11:49:56.285 [0x7f9880c22b38] DEBUG - [Req#41407/Database optimization/com.plexapp.plugins.library.db] Activity: updated activity 6e3e54f2-110c-4e73-8bcc-1cc94943bf13 - completed 40.0% - Optimizing database
Nov 14, 2022 11:50:00.061 [0x7f98849b5b38] DEBUG - Request: [127.0.0.1:49458 (Loopback)] GET /library/sections (6 live) #413fd Signed-in Token (TheYGC) (Chrome)
Nov 14, 2022 11:50:04.589 [0x7f9880c22b38] WARN - [Req#41407/Database optimization/com.plexapp.plugins.library.db] Held transaction for too long (/data/jenkins/server/3537899744/Library/FullTextSearch.cpp:58): 8.310000 seconds
Nov 14, 2022 11:50:04.815 [0x7f9880c22b38] ERROR - [Req#41407/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 267, statement aborts at 4: [insert into fts4_metadata_titles_icu(fts4_metadata_titles_icu) VALUES('optimize')] database disk image is malformed
Nov 14, 2022 11:50:04.820 [0x7f9880c22b38] ERROR - Thread: Uncaught exception running async task which was spawned by thread 0x7f98849b5b38: sqlite3_statement_backend::loadOne: database disk image is malformed

But, re-running the utility tells me everything is fine. I am really at a loss here :confused:

4

You didn’t read my documentation?

1-2-3-4 wasn’t the right sequence but , in this case, it won’t matter.

The sequence 1-4-3 is what you needed

  1. 1 - Confirm which DB is damaged/malformed
  2. 4 - Attempt repair
  3. 3 - Reindex after the repair

If you’ve done those steps, seeing the errors you do on both databases , you are probably, and unfortunately, stuck.

Translation – full cold rebuild.

5

I did read it – I didn’t see any errors from Step 1 (ie: neither database was malformed), so I thought Case C would be the best to try. Probably should’ve gone with Case B, that’s my fault.

Full rebuild meaning, delete Plex and do a library scan? Unfortunately I have a ton of media and custom Metadata, plus most of the storage is on the cloud so I will likely get API banned… Last time I did a little change to my folder structure, took about 3 days to do a scan and it didn’t even need to download any metadata :frowning:

Are there no clues as to what could be breaking in the Optimization step that might be possible to repair this existing one? It has the same problem every time, so at least it’s repeatable…

Ugh, I wish I had a slightly older backup — scheduled tasks only keeps the 3 most recent, huh? 11-06 unfortunately still has this problem :frowning:

6

Restored a database from September, still getting the same issue when running “Optimize Database” even though I don’t think I had any problems at all at that time :confused:

Nov 15, 2022 00:41:38.318 [0x7f2492f24b38] ERROR - [Req#133/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 267, statement aborts at 46: [insert into fts4_tag_titles_icu(rowid, tag) select id, tag from tags where tag_type in (1,2,4,6,0,207,400)] database disk image is malformed
7

The utility I wrote does basic database export, import, vacuum, and reindex.

Most database errors are corrected by exporting and reimporting.

Given you’e done the “Repair” (export + import + check), this tells me PMS is looking for the schema to be different than what it’s finding.

These schema changes are “database migrations” which are applied incrementally as you install successive updates to PMS.

What you’re showing here looks like a single malformed record (bad data in the record) which a migration (update) would have updated to an expected value.

I don’t know the database internals that well but there are a few folks who do.

I did help a user today with a malformed blobs DB. He had two damaged records and we were able to export+import manually. The two bad records fell out. A fresh of his metadata got PMS to rewrite the missing records.

I would like to ask our DB guy (here in support) what he thinks the next best step is.

He might know how to fix this manually / directly with SQLite (but no promises).

1 Like
9

Thanks so much for the follow-up. If there’s anything else you guys might need, please let me know. I can share backups of my regular and blobs DBs, or whatever else you/the DB team may need.

I’m all ears. Really desperate to get this back up and running smoothly without doing a full library scan, I have so much custom metadata from running this server over the years.

10

I’m trying every combination of versions and databases I can think of, but even 1.29.0 with my October 1st database gives me the below errors when I start it up, like something is totally busted with all attempts at DB migrations:

Nov 15, 2022 11:21:56.027 [0x7fca2185eb00] DEBUG - HttpServer: Set up a thread pool with 2 threads.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] INFO - Running migrations. (EPG 0)
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 0.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 1.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 2.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 3.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 4.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 5.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 6.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 7.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 8.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 9.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 10.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 11.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 12.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 13.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 14.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 15.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 16.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 17.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 18.
Nov 15, 2022 11:21:56.052 [0x7fca25f671c0] DEBUG - Captured session 19.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] INFO - Running forward migration 20101001034731.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 0.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 1.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 2.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 3.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 4.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 5.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 6.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 7.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 8.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 9.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 10.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 11.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 12.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 13.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 14.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 15.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 16.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 17.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 18.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] DEBUG - Captured session 19.
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] ERROR - SQLITE3:0x80000001, 1, table 'library_timeline_entries' already exists in "CREATE TABLE 'library_timeline_entries' ('id' INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, 'library_section_id' integer, 'metadata_item_id' integer, 'state' i
Nov 15, 2022 11:21:56.054 [0x7fca25f671c0] ERROR - Exception inside transaction (inside=1) (/data/jenkins/server/3534295259/Library/DatabaseMigrations.cpp:295): sqlite3_statement_backend::prepare: table 'library_timeline_entries' already exists for SQL: CREATE TABLE 'library_timeline_entries' ('id' INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, 'library_section_id' integer, 'metadata_item_id' integer, 'state' integer, 'updated_at' datetime)
Nov 15, 2022 11:21:56.055 [0x7fca25f671c0] ERROR - Exception thrown during migrations, aborting: sqlite3_statement_backend::prepare: table 'library_timeline_entries' already exists for SQL: CREATE TABLE 'library_timeline_entries' ('id' INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, 'library_section_id' integer, 'metadata_item_id' integer, 'state' integer, 'updated_at' datetime)

Interestingly, when I run Optimize on this DB from 10/01, I don’t get any Errors in the log, but a bunch of (scary looking) INFOs saying the database schema has changed:

Nov 15, 2022 11:30:19.473 [0x7fca1fd09b00] DEBUG - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] Rebuilding full text search tables.
Nov 15, 2022 11:30:19.473 [0x7fca1fd09b00] DEBUG - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] Activity: updated activity 97ea0367-4632-459f-ae92-538364c89237 - completed 40.0% - Optimizing database
Nov 15, 2022 11:30:27.709 [0x7fca1fd09b00] WARN - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] Held transaction for too long (/data/jenkins/server/3534295259/Library/FullTextSearch.cpp:58): 8.240000 seconds
Nov 15, 2022 11:30:32.039 [0x7fca1fd09b00] WARN - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] Held transaction for too long (/data/jenkins/server/3534295259/Library/FullTextSearch.cpp:71): 4.080000 seconds
Nov 15, 2022 11:30:37.477 [0x7fca21b67b00] DEBUG - Using X-Forwarded-For: 64.111.71.131 as remote address
Nov 15, 2022 11:30:37.477 [0x7fca21b67b00] DEBUG - Auth: Refreshing tokens inside the token-based authentication filter.
Nov 15, 2022 11:30:37.477 [0x7fca21b67b00] DEBUG - [HCl#83] HTTP requesting GET https://plex.tv/api/v2/server/access_tokens?auth_token=xxxxxxxxxxxxxxxxxxxx&unknownToken=xxxxxxxxxxxxxxxxxxxx
Nov 15, 2022 11:30:37.547 [0x7fca20115b00] DEBUG - [HttpClient/HCl#83] HTTP/2.0 (0.1s) 200 response from GET https://plex.tv/api/v2/server/access_tokens?auth_token=xxxxxxxxxxxxxxxxxxxx&unknownToken=xxxxxxxxxxxxxxxxxxxx (reused)
Nov 15, 2022 11:30:37.547 [0x7fca21b67b00] DEBUG - MyPlex: updating with 17 access tokens
Nov 15, 2022 11:30:42.266 [0x7fca1fd09b00] WARN - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] Held transaction for too long (/data/jenkins/server/3534295259/Library/FullTextSearch.cpp:81): 10.220000 seconds
Nov 15, 2022 11:30:58.341 [0x7fca1fd09b00] WARN - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] Held transaction for too long (/data/jenkins/server/3534295259/Library/FullTextSearch.cpp:94): 15.960000 seconds
Nov 15, 2022 11:30:58.380 [0x7fca1fd09b00] DEBUG - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] Database optimization: starting.
Nov 15, 2022 11:30:58.380 [0x7fca1fd09b00] DEBUG - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] Activity: updated activity 97ea0367-4632-459f-ae92-538364c89237 - completed 60.0% - Optimizing database
Nov 15, 2022 11:31:13.667 [0x7fca1fd09b00] DEBUG - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] Database optimization: complete.
Nov 15, 2022 11:31:13.669 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.670 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.673 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.675 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.676 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.677 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.678 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.680 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.681 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.682 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.683 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.685 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.686 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.687 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.688 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.690 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.691 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.692 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed
Nov 15, 2022 11:31:13.693 [0x7fca1fd09b00] INFO - [Req#1f3/Database optimization/com.plexapp.plugins.library.db] SQLITE3:0x80000001, 17, statement aborts at 58: [select * from metadata_items limit 1] database schema has changed

And when I do a scan of this 10/01 library, I get tons of these:

Nov 15, 2022 11:35:20.628 [0x7fca1ac19b00] ERROR - Unknown metadata type:
Nov 15, 2022 11:35:22.480 [0x7fca1a518b00] ERROR - Unknown metadata type:
Nov 15, 2022 11:35:24.812 [0x7fca1ac19b00] ERROR - Unknown metadata type:
Nov 15, 2022 11:35:26.683 [0x7fca1a315b00] ERROR - Unknown metadata type:
Nov 15, 2022 11:35:28.731 [0x7fca1ac19b00] ERROR - Unknown metadata type:
Nov 15, 2022 11:35:30.877 [0x7fca1a315b00] ERROR - Unknown metadata type:
Nov 15, 2022 11:35:32.424 [0x7fca1a518b00] ERROR - Unknown metadata type:
Nov 15, 2022 11:35:38.000 [0x7fca1ac19b00] ERROR - Unknown metadata type:

Just for my own curiosity I tried dropping the library_timeline_entries from blobs and regular DB and restarting, but it seemed to just crash/hang in “Running database migrations” – tried leaving it overnight last night and no dice.

I’ve found backups from 09/31 - 11/12 so can try restoring any of those, but I worry it’ll be pretty much the identical result :frowning:

It’s so bizarre though, nothing was visibly broken, everything was running fine – Sonarr, Radarr, etc. until the other day.

12

@TheYGC

Would it be possible to get a zipped copy of the DB you wish to use?

I will work with the folks here and see if we can find what it’s barking at.
The current thinking is that PMS changed a string value to a numeric value in the schema

Regarding the other errors you posted.

  1. “unknown metadata type:” – Ignore please. That’s ongoing development
  2. Database optimization - schema has changed - common with the old schema. That specific message content changes in the future.

Please be VERY careful about taking error messages out of context like this.
They will run you down the wrong road in a hurry.

13

Of course, thank you so much. Here it is (both the db and the blobs): databases-2022.11.15.zip - Google Drive

This is from my October 1st backup, after completing a full scan and attempting to optimize. The only thing immediately wrong with this one is those error messages I shared on startup, but scans/adding content/everything except Optimization seems to be working fine.

I can also share the malformed DB from a few day ago (from before restoring this one from backup) if that would be helpful – just let me know.

Please let me know when it’s been downloaded so I can stop sharing it on Drive…

16

Just popping back by to see if there have been any updates here? Still getting the same errors every restart, but things generally seem to be working mostly OK, although full library scans are getting slower and Optimize doesn’t seem to be working :confused:

17

@TheYGC

YES. Thank you for pinging me. ( I lost the thread and couldn’t find it. :cry: )

I’m sending you a PM with all the info

18

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