PMS Crash but service looks running

Server Version#: 1.15.3.835
Player Version#: every kind of playerPlex Media Server Logs_2019-03-29_14-56-53.zip (805.8 KB)

hi!
from some while, even with earlier releases my PMS crashes. Seems like only one part of it, because if i try to run “/plex.sh start” it returns “Plex Media Server is currently running or hasn’t been shutdown properly. Please stop it from QNAP AppCenter and start it again.”

In some cases i just stop and restart the service from the appCenter. But more often i need to reboot my TS-453Pro QNAP (4.3.5.0883).

hope someone can help me, it crash even 2-3 times at day!!!

thanks!

Thanks for the logs

I can see several issues and need to see if you can remember what you did to recover from one of the failures

It was all for Friday March 29th

At 11:44 server was launched but the log shows it failing to start and a database locked error logged at 11:46:26. There is about 90 second gap in the log between 11:44:53 and 11:46:26

Mar 29, 2019 11:44:53.540 [0x7ffb385bd700] DEBUG - Jobs: '/share/CACHEDEV1_DATA/.qpkg/PlexMediaServer/CrashUploader' exit code for process 13080 is 0 (success)
Mar 29, 2019 11:46:26.532 [0x7ffb455c8740] ERROR - SQLITE3:(nil), 15, locking protocol in "PRAGMA cache_size=2000"
Mar 29, 2019 11:46:26.533 [0x7ffb455c8740] ERROR - Database corruption: sqlite3_statement_backend::prepare: locking protocol for SQL: PRAGMA cache_size=2000
Mar 29, 2019 11:46:26.533 [0x7ffb455c8740] ERROR - Error: Unable to set up server: sqlite3_statement_backend::prepare: locking protocol for SQL: PRAGMA cache_size=2000 (N4soci10soci_errorE)

Twenty minutes later, there was an attempt to launch the server again at 12:04 and again we have 90 second gap before logging same error at 12:05:42

Mar 29, 2019 12:04:09.158 [0x7f64ca509700] DEBUG - Jobs: '/share/CACHEDEV1_DATA/.qpkg/PlexMediaServer/CrashUploader' exit code for process 29321 is 0 (success)
Mar 29, 2019 12:05:42.152 [0x7f64d7514740] ERROR - SQLITE3:(nil), 15, locking protocol in "PRAGMA cache_size=2000"
Mar 29, 2019 12:05:42.152 [0x7f64d7514740] ERROR - Database corruption: sqlite3_statement_backend::prepare: locking protocol for SQL: PRAGMA cache_size=2000
Mar 29, 2019 12:05:42.152 [0x7f64d7514740] ERROR - Error: Unable to set up server: sqlite3_statement_backend::prepare: locking protocol for SQL: PRAGMA cache_size=2000 (N4soci10soci_errorE)

Next launch at 12:07:51 slightly different, in that we log a terminate action 60 seconds after possible hang and then hung again for 90 seconds during this sequence (as before)

Mar 29, 2019 12:07:53.519 [0x7f88de6bf700] DEBUG - Jobs: '/share/CACHEDEV1_DATA/.qpkg/PlexMediaServer/CrashUploader' exit code for process 32303 is 0 (success)
Mar 29, 2019 12:08:56.373 [0x7f88de6bf700] DEBUG - Shutting down with signal 15 (Terminated)
Mar 29, 2019 12:08:56.373 [0x7f88de6bf700] DEBUG - Ordered to stop server.
Mar 29, 2019 12:08:56.373 [0x7f88de6bf700] WARN - Timed out waiting for server to finish.
Mar 29, 2019 12:09:26.510 [0x7f88eb6ca740] ERROR - SQLITE3:(nil), 15, locking protocol in "PRAGMA cache_size=2000"
Mar 29, 2019 12:09:26.511 [0x7f88eb6ca740] ERROR - Database corruption: sqlite3_statement_backend::prepare: locking protocol for SQL: PRAGMA cache_size=2000
Mar 29, 2019 12:09:26.511 [0x7f88eb6ca740] ERROR - Error: Unable to set up server: sqlite3_statement_backend::prepare: locking protocol for SQL: PRAGMA cache_size=2000 (N4soci10soci_errorE)

The following launches did not have these issues. So would like to know if you remember what was being done in each case and if there was a real db corruption as suggested by the messages

The following launch that was ok was at 12:19

The db files concerned would be in
/share/CACHEDEV1_DATA/.qpkg/PlexMediaServer/Library/Plex Media Server/Plug-in Support/Databases/

The logs also show an actual crash at 14:28:55
I have located the uploaded crash report and this is being referred to the development team

The logs also show scanner crashes with one arising when scanning the CARTOON NETWORK library. I have a log for only one crash and it was when starting. Would be interested to see more and if it crashes each time this library is scanned

HI! first of all thank you for your reply!
it’s been a while, and i do not have a strong memory, but i can say for sure that i was adding movies. i’m pretty sure i’ve added 2 movies and some episodes.
i’m sure one of those was in the folder CARTOON NETWORK :“Ralph Breaks the Internet”, another one inthe folder MOVIES was “BUMBLEBEE”… i can’t tell you exactly about the episodes, maybe was “the good doctor”
anyway i’m pretty sure sometimes it crash searching for a movie’s association : it happend for sure for “bumblebee” , and maybe for “ralph…” too

but in the past it happens also without adding anything in any folder. last week it crashes playing a movie.

the boring is that the most of the times i need to reboot all, restart the service is not enough.

i don’t know if it can help but in the last 8 month i also have frequent warning from qnap about “file system check”. checking the fileystem everything looks fine, but looking at your answer it seems like i have some bad sector somewhere and maybe the db is affected. can be?
is there a way to check the integrity of that db? or maybe rebuild it?

thank you!

A scanner process crash should not affect the Plex Media Server process.
I would be interested to see logs after a restart following completion or failure of a library scan for CARTOON NETWORK library

The more important crashes are when the Plex Media Server process crashes and the logs show one such crash at 14:28:55 on 29th

The other Plex Media Server failures were failing to launch and that happened at 11:44, 12:04 and 12:08 - but the launch at 12:19 was ok and this was the bit i wanted to know if you did anything different between 11:44 - 12:08 and 12:19

The database file is
/share/CACHEDEV1_DATA/.qpkg/PlexMediaServer/Library/Plex Media Server/Plug-in Support/Databases/com.plexapp.plugins.library.db

We have instructions for checking the database integrity - see
https://support.plex.tv/articles/201100678-repair-a-corrupt-database/

Make sure you save copy in case of a problem with use of sqlite3

hi!
after the installation of the last release (ver. 1.15.3.858) are 2 days that i see no crashes. this morning i tried to add movies to different folders :
9:03 added “Tarzan” in “CARTOON NETWORK” associated correctly.
10:32 added “norm of the North” and “red & toby nemiciamici” in “CARTOON NETWORK”: for the second one i needed to associate it correctly.
10:41 added “Surf’s UP” in “CARTOON NETWORK” and “Macchine Mortali” in “Movies” , all went fine.
no crashes.
I attached the logs, only for info.

said that, looking at the db i’m thinking something is not working correctly.
reading your link about “checking the database integrity” i remember now some months ago (jannuary, the third) i recorded a failure of the db:
the web client showed me an error like “dashboard not available”. reading the forum i tried to fix the db file, but in the end i made a new one.
i’m sure about the date 'cause i made a copy of the db working on it.

this morning trying to download the file from the web client, and i get only and empty zip. what you find here, is a copy made with WinSCP directly from the path.

hope it helps.
thank you.
com.plexapp.plugins.library.zip (5.6 MB)
Plex Media Server Logs_2019-04-03_10-56-05.zip (2.7 MB)

Thanks for the logs and the database copy

There has not been a server crash since March 29th.

However, there are still scanner crashes during deep analysis. I have located the uploaded dmp files but would need logs of these scanner jobs that crash.

Because these crashes were happneing during scheduled tasks when a lot of analysis is done, the logs cycle round quickly and no longer available.

The two files that i can see got scanner crashes were these

/share/CACHEDEV1_DATA/Movies/Come.Ti.Divento.Bella.2018.FULL.HD.1080p.DTS+AC3.ITA.ENG.SUB.DDV.mkv

/share/external/DEV3302_1/Il miglio verde.mkv

The files are massive so i can’t ask for the files to repro the issue

The scanner crashes were at Apr 02, 2019 04:15 am and Apr 03, 2019 03:32 am

Initially i would just like to establish that we can get logs for the crashing deep analysis scans that crash, After we do that, then can explore if we can get a crash with short clips created from these mkv files, With that i can then reproduce the crash and pass to the development team

So first - lets see if the scanner can be run through the command line.

(The related article for running scanner in command line is https://support.plex.tv/articles/201242707-plex-media-scanner-via-command-line/ )

Try the following
export LD_LIBRARY_PATH=/share/CACHEDEV1_DATA/.qpkg/PlexMediaServer
and
export PLEX_MEDIA_SERVER_APPLICATION_SUPPORT_DIR=/share/CACHEDEV1_DATA/.qpkg/PlexMediaServer/Library

and then run these

./Plex\ Media\ Scanner --analyze-deeply --item 3274 --log-file-suffix Deep Analysis

and

./Plex\ Media\ Scanner --analyze-deeply --item 2434 --log-file-suffix Deep Analysis

And then get the logs to see if this works

(what i would be after is to see if a short clip eg 10 minute clip does crash the scanner in deep analysis)

hi!

i Did what you ask, but you need to know that saturday and sunday morning, before your email, i’ve re-organized the library to eliminate the external drive. I thought that it could be a source of issues.

for that i suggest to concentrate you on the first item :

/share/CACHEDEV1_DATA/Movies/Come.Ti.Divento.Bella.2018.FULL.HD.1080p.DTS+AC3.ITA.ENG.SUB.DDV.mkv

it never changed position.

the second one, “the green mile” is been moved to the internal partition… i supposed it changes item number maybe !!!

anyway here there is a copy of the logs (hope i did all correctly) and again a copy of the db updated.

tell me if you need anything else.

com.plexapp.plugins.library.zip (5.8 MB)
Plex Media Server Logs_2019-04-08_09-58-38.zip (2.9 MB)

May be the Plex Media Scanner Deep Analysis.log got written elsewhere in different path. Last one in the zip is from 3rd

Could you search for the file - timestamp should be about Apr 08, 2019 08:41

There appears to be a new database corruption

Apr 04, 2019 02:01:05.100 [0x7f8da1fc5700] DEBUG - Activity: updated activity f5df46a8-747b-4fbe-b0b6-1d96a58ce4ce - completed 40% - Optimizing database
Apr 04, 2019 02:01:05.427 [0x7f8da1fc5700] WARN - Held transaction for too long (../Library/FullTextSearch.cpp:27): 0.160000 seconds
Apr 04, 2019 02:01:05.534 [0x7f8da1fc5700] ERROR - SQLITE3:(nil), 11, database corruption at line 85694 of [bf8c1b2b7a]
Apr 04, 2019 02:01:05.535 [0x7f8da1fc5700] ERROR - SQLITE3:(nil), 11, statement aborts at 5: [SELECT rowid, x.'tag' FROM 'main'.'tags' AS x ORDER BY rowid ASC] database disk image is malformed
Apr 04, 2019 02:01:05.535 [0x7f8da1fc5700] ERROR - SQLITE3:(nil), 11, statement aborts at 8: [delete from fts4_tag_titles] database disk image is malformed
Apr 04, 2019 02:01:05.548 [0x7f8da1fc5700] ERROR - Exception inside transaction (inside=1) (../Library/FullTextSearch.cpp:38): sqlite3_statement_backend::loadOne: database disk image is malformed

It is an index so repairable

See
https://support.plex.tv/articles/201100678-repair-a-corrupt-database/

(i will send you the dump.sql file i created from the db you uploaded and you can restore from it (saving backup copy existing db) or you can go through the repair sequence

i suppose you meant these 2 files.

Plex Media ScannerDeep.1.log (923 Bytes)
Plex Media ScannerDeep.log (961 Bytes)

i also tried to repair the db from 2 different windows client. but in the end i always get an empty db:
image

copy all the files to windows. do the repair there and then copy back.
Make sure the plex media server service/process is not running during the time you repair/copy the db files

with the sql.dmp i sent you, all you need to do is
cd to the directory the files are in
execute
sqlite3 name-of-database-file.db < dump.sql

Then rename the restored db file name-of-database-file.db to be com.plexapp.plugins.library.db and copy it to the destination directory

hi!
i did what you said but i get a lot of error. The db also didn’t change sizes, looks like it does not affected.
i attached a part of the log (my cmd’s buffer wasn’t long enough), hope you can understand what’s wrong with it.

PS: my db is off course on the internal drive.

log.txt (704.2 KB)

Thank you. I see a problem.
The dump.sql although seemed to get generated - has the following as the last transaction

ROLLBACK; -- due to errors

I will have a look to see if it can be salvaged

Do you remember the actions taken for this database

Was there a repair before ? when?
A restore?
Recreate afresh?
What versions of Plex Media Server ran on this database ?

Edited: this statement is wrong - although the table looked ok, the db would not create a usable dump.sql file

Please ignore

The database you provided on the 3rd April here PMS Crash but service looks running does not have the corruption that appeared in the last set of logs - actually detected first at 02:01am on 4th April. So it happened between 3rd April 09:43 and 4rd April 02:01 am

i did something in january. the db was broken.
i tryied a restore without fortune. then if i well remember i replaced an older version (an automatic backup) instead of the original.
but nothing recently. I only moved items from the external disk to the internal volume.
i did nothing between 3rd and 4th of april.

A potential problem area. I can see that the 3rd April copy of the db was taken whilst Plex Media Server was actively updating the database and not after carefully shutting down Plex Media Server and making sure no Plex Media Server processes accessing the database.

I can see in the later database (8th April) entries added to the database a second after the copy that you took. So obviously PMS was active and running when the db file was copied out.

I do not know if this access to the db file impacted PMS or the database in any way

Well it is more complicated than it appeared. The 3rd April copy was also corrupt and would not create a usable dump.sql

Still trying to establish if it can be salvaged

What scheduled backup copies do you have in the Databases directory?

Here you can find all my databases in the directory.
MOD: Link removed for the sake of privacy

the .original is the one i used to try the recovery.
the one that starts with “vecchio” is one copy of the db i made on january when i have had the full corruption. i can’t remember if it is the corrupted one or the last known good copy of the db.
the others are the actually backups, off course.

Thanks - I have the download link for the databases

Will let you know what i find