UpdateTool breaks Plex database

[crafty35a]

I love this tool, but for some time it has been breaking my Plex database any time I attempt to run it (all libraries show as unavailable immediately after running UpdateTool).

This could be coincidental, but the issues started immediately after I moved from Windows to UnRAID, and I did see mention in another issue of potential database corruption on UnRAID (#97 (comment))

I am happy to provide any data/log info that would be helpful to getting this issue resolved, but I don't know what you need. So please let me know what info I can provide.

Thank you!

[mynttt]

Yeah, it is a very annoying issue - the problem is that the tool requires write access to the DB. Normally you can just do it programmatically from Java with the correct JDBC driver, but Plex has diverged their flavor of SQLite from the default version, so the standard JDBC implementation that exists fails here.

To circumvent it, I've tried using the SQLite binary that Plex supplies with their distribution. I might need to update that one, as an older version could cause the issues. It works on a lot of systems but on some it causes trouble which I've not been able to diagnose yet :/

• What kind of Plex container are you running, and what is the version of Plex at the moment?

• Does the corruption always happen instantaneously?

[mynttt]

So I've updated the local binary that is supplied by Plex itself to interact with their flavour of SQLite for the Docker containers now. Could you test and see if the issue persists?

And are you on amd64 or arm64 architecture?

[mynttt]

@crafty35a Another thing that you could try is setting the Docker variable USE_PLEX_SQLITE_BINARY_FOR_WRITE_ACCESS to false to check if the default JDBC driver works on your database without corruptions.

[crafty35a]

• What kind of Plex container are you running, and what is the version of Plex at the moment?

I am using lscr.io/linuxserver/plex

• Does the corruption always happen instantaneously?

I don't think it was instantaneous back when I first moved to unRAID, but it does seem to be now.

So I've updated the local binary that is supplied by Plex itself to interact with their flavour of SQLite for the Docker containers now. Could you test and see if the issue persists?

No luck - same issue after updating

And are you on amd64 or arm64 architecture?

amd64

@crafty35a Another thing that you could try is setting the Docker variable USE_PLEX_SQLITE_BINARY_FOR_WRITE_ACCESS to false to check if the default JDBC driver works on your database without corruptions.

So far, this seems to have worked! I will keep an eye on it and let you know if that changes. If I can help with anything else, let me know as well. Thanks!

[mynttt]

@crafty35a Glad it works now! I can't explain why the Plex SQLite binary usage from the docker causes issues (because it never did on my unraid) but my guess is that it has something to do with the inter-docker sharing of the database and two potential different containers. Might have to investigate that in the future..

In case it does not brick, it would be nice to get an update in a few days again whether it still works well.

[crafty35a]

In case it does not brick, it would be nice to get an update in a few days again whether it still works well.

Bad news, I woke up today to Plex not working and my Plex container is just spamming these messages non-stop:

Starting Plex Media Server. . . (you can ignore the libusb_init error) Error: Unable to set up server: sqlite3_statement_backend::loadOne: database disk image is malformed (N4soci10soci_errorE) Starting Plex Media Server. . . (you can ignore the libusb_init error) Error: Unable to set up server: sqlite3_statement_backend::loadOne: database disk image is malformed (N4soci10soci_errorE)

Looks like UpdateTool has some similar errors in it's logs from last night:

02/12/2023 10:50:54 PM [INFO ] - 2023-02-12 22:50:54 @ TaskWrapper.run: ================================================ 02/12/2023 10:50:54 PM [INFO ] - 2023-02-12 22:50:54 @ TaskWrapper.run: Starting task: imdb-docker | Execution count: 3 02/12/2023 10:50:54 PM [INFO ] - 2023-02-12 22:50:54 @ TaskWrapper.run: ================================================ 02/12/2023 10:50:54 PM [INFO ] - 2023-02-12 22:50:54 @ ImdbDockerImplementation$ImdbBatchJob.run: LIBRARIES => PRE LIBRARY FILTERING 02/12/2023 10:50:54 PM [INFO ] - 2023-02-12 22:50:54 @ ImdbDockerImplementation$ImdbBatchJob.lambda$run$0: Found library [MOVIE] UFC (ID=5) with agent: tv.plex.agents.movie and 16 item(s). 02/12/2023 10:50:54 PM [INFO ] - 2023-02-12 22:50:54 @ ImdbDockerImplementation$ImdbBatchJob.lambda$run$0: Found library [MOVIE] Movies (ID=12) with agent: tv.plex.agents.movie and 1592 item(s). 02/12/2023 10:50:54 PM [INFO ] - 2023-02-12 22:50:54 @ ImdbDockerImplementation$ImdbBatchJob.lambda$run$0: Found library [MOVIE] Movies 4k (ID=21) with agent: tv.plex.agents.movie and 32 item(s). 02/12/2023 10:50:54 PM [INFO ] - 2023-02-12 22:50:54 @ ImdbDockerImplementation$ImdbBatchJob.lambda$run$0: Found library [SERIES] TV Shows (ID=2) with agent: tv.plex.agents.series and 8779 item(s). 02/12/2023 10:50:54 PM [INFO ] - 2023-02-12 22:50:54 @ ImdbDockerImplementation$ImdbBatchJob.lambda$run$0: Found library [SERIES] TV Shows 4k (ID=22) with agent: tv.plex.agents.series and 42 item(s). 02/12/2023 10:50:54 PM [INFO ] - 2023-02-12 22:50:54 @ ImdbDockerImplementation$ImdbBatchJob.run: LIBRARIES => POST LIBRARY FILTERING 02/12/2023 10:50:54 PM [INFO ] - 2023-02-12 22:50:54 @ ImdbDockerImplementation$ImdbBatchJob.lambda$run$3: Will process library UFC (ID=5) with agent: tv.plex.agents.movie and 16 item(s). 02/12/2023 10:50:54 PM [INFO ] - 2023-02-12 22:50:54 @ ImdbDockerImplementation$ImdbBatchJob.lambda$run$3: Will process library Movies (ID=12) with agent: tv.plex.agents.movie and 1592 item(s). 02/12/2023 10:50:54 PM [INFO ] - 2023-02-12 22:50:54 @ ImdbDockerImplementation$ImdbBatchJob.lambda$run$3: Will process library Movies 4k (ID=21) with agent: tv.plex.agents.movie and 32 item(s). 02/12/2023 10:50:54 PM [INFO ] - 2023-02-12 22:50:54 @ ImdbDockerImplementation$ImdbBatchJob.lambda$run$3: Will process library TV Shows (ID=2) with agent: tv.plex.agents.series and 8779 item(s). 02/12/2023 10:50:54 PM [INFO ] - 2023-02-12 22:50:54 @ ImdbDockerImplementation$ImdbBatchJob.lambda$run$3: Will process library TV Shows 4k (ID=22) with agent: tv.plex.agents.series and 42 item(s). 02/12/2023 10:50:55 PM [ERROR] - 2023-02-12 22:50:55 @ ImdbDockerImplementation$ImdbBatchJob.run: SQLiteException exception encountered... 02/12/2023 10:50:55 PM [ERROR] - 2023-02-12 22:50:55 @ ImdbDockerImplementation$ImdbBatchJob.run: Please contact the maintainer of the application with the stacktrace below if you think this is unwanted behavior. 02/12/2023 10:50:55 PM [ERROR] - 2023-02-12 22:50:55 @ ImdbDockerImplementation$ImdbBatchJob.run: ======================================== 02/12/2023 10:50:55 PM [ERROR] - 2023-02-12 22:50:55 @ ImdbDockerImplementation$ImdbBatchJob.run: org.sqlite.SQLiteException: [SQLITE_CORRUPT] The database disk image is malformed (database disk image is malformed) 02/12/2023 10:50:55 PM at org.sqlite.core.DB.newSQLException(DB.java:1012) 02/12/2023 10:50:55 PM at org.sqlite.core.DB.newSQLException(DB.java:1024) 02/12/2023 10:50:55 PM at org.sqlite.core.DB.execute(DB.java:866) 02/12/2023 10:50:55 PM at org.sqlite.core.CoreStatement.exec(CoreStatement.java:80) 02/12/2023 10:50:55 PM at org.sqlite.jdbc3.JDBC3Statement.executeQuery(JDBC3Statement.java:68) 02/12/2023 10:50:55 PM at updatetool.common.SqliteDatabaseProvider.queryFor(SqliteDatabaseProvider.java:39) 02/12/2023 10:50:55 PM at updatetool.imdb.ImdbDatabaseSupport.updateNewAgentMetadataMapping(ImdbDatabaseSupport.java:204) 02/12/2023 10:50:55 PM at updatetool.imdb.ImdbDatabaseSupport.requestMetadata(ImdbDatabaseSupport.java:178) 02/12/2023 10:50:55 PM at updatetool.imdb.ImdbDatabaseSupport.requestEntries(ImdbDatabaseSupport.java:160) 02/12/2023 10:50:55 PM at updatetool.imdb.ImdbLibraryMetadata.fetchAll(ImdbLibraryMetadata.java:18) 02/12/2023 10:50:55 PM at updatetool.imdb.ImdbDockerImplementation$ImdbBatchJob.run(ImdbDockerImplementation.java:254) 02/12/2023 10:50:55 PM at updatetool.TaskWrapper.run(Main.java:252) 02/12/2023 10:50:55 PM at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) 02/12/2023 10:50:55 PM at java.base/java.util.concurrent.FutureTask.runAndReset(Unknown Source) 02/12/2023 10:50:55 PM at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) 02/12/2023 10:50:55 PM at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) 02/12/2023 10:50:55 PM at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) 02/12/2023 10:50:55 PM at java.base/java.lang.Thread.run(Unknown Source) 02/12/2023 10:50:55 PM [ERROR] - 2023-02-12 22:50:55 @ ImdbDockerImplementation$ImdbBatchJob.run: ======================================== 02/12/2023 10:50:55 PM [ERROR] - 2023-02-12 22:50:55 @ ImdbDockerImplementation$ImdbBatchJob.run: The application will terminate now.

I am going to have to restore a backup to before I started using UpdateTool again, but let me know if I can test anything for you.

[mynttt]

@crafty35a I knew it was too good to be true lol

Yeah, using JDBC to write on the database caused tons of issues after Plex changed their SQLite3 flavour from vanilla to something customized.

That is why I include their own SQLite3 binary in my container to interact with it that way for write operations in order to not corrupt the database.

What suprises me is that in some cases (like yours) this still causes issues - it is a hard to diagnose problem for sure as it does not make a lot of sense.

What I've done now is compare the SQLite3 binary used by my container with the one supplied with the linuxserver/plex version.

It is exactly the same binary even with the same md5 hash:

0ae8569d986dbddff25a246d9a220925  Plex SQLite

SQLite version 3.35.5 2021-04-19 18:32:05
Enter ".help" for usage hints.
Connected to a transient in-memory database.
Use ".open FILENAME" to reopen on a persistent database.
sqlite> 

0ae8569d986dbddff25a246d9a220925  Plex SQLite

SQLite version 3.35.5 2021-04-19 18:32:05
Enter ".help" for usage hints.
Connected to a transient in-memory database.
Use ".open FILENAME" to reopen on a persistent database.
sqlite> 

Sadly the API that Plex uses to update writes done by the user in the web ui is not advanced enough to write into the fields required for UpdateTool to work properly, else I would not even do writes directly to the database. So now it has shown again that the only realistic way to update anything is over their binary.

I've looked in the code again and one of the ideas I have is that the use of transactions could cause these issues.

So I would suggest the following to diagnose this, since your system already has shown that the corruption is replicable:

First I would try out leaving the transaction away and then push an update to another tag that you could try out.

If that causes the same corruption I'd say the following:

1.) I would compile a special docker container that writes the queries that are applied to the binary to a text file instead of applying them.

2.) You send me that text file over so I can analyse it.

3.) We would then try applying the queries from within the linuxserver and updatetool container to see if corruption still happens that way.

[crafty35a]

Sounds good to me, I am more than happy to help test. Let me know what tag to update to and I will report back ASAP. Should I set USE_PLEX_SQLITE_BINARY_FOR_WRITE_ACCESS back to true?

[mynttt]

@crafty35a Can you try out this container? Instead of mynttt/updatetool:latest change it to mynttt/updatetool:test

I'm curious if the issue is now fixed! And yes, for the test please set it to true - else right now it does not really matter as both options cause corruptions for you!

[mynttt]

@crafty35a And if you can recover the log for me (and remove your API keys!)

[crafty35a]

So far, nothing has broken after running with the :test tag

Here is my log (link expires in 1 hour, let me know if you don't get it in time): https://ctxt.io/2/AAAQF6PcFQ

[mynttt]

Very nice! Let's see how it goes over the next days.. Don't want to celebrate preliminary again.. I've looked at the log and it looks promising.

In case it works well on your side now I would definitly push an update so the :latest tag also profits from this.

[crafty35a]

In case it works well on your side now I would definitly push an update so the :latest tag also profits from this.

I will keep you posted!