Database Issues: SQLiteException

[dcrdev 251]

So this is the second time this has happened to me now in the past couple of weeks. First time Emby stopped starting up, so I wiped the database and started again with a new install of the .NET core package.

 

Now the issue is back, but appears to be limited to TV Show suggestions, which just won't load. The server is still up and running and everything else appears to work.

 

On both occasions, it was a "SQLitePCL.pretty.SQLiteException" exception.

 

Here is the relevant part of the log:

2017-11-07 00:29:20.014 Error HttpServer: Error processing request
	*** Error Report ***
	Version: 3.2.36.0
	Command line: /opt/emby-server/system/EmbyServer.dll -programdata /var/lib/emby -ffmpeg /opt/emby-server/bin/ffmpeg -ffprobe /opt/emby-server/bin/ffprobe -updatepackage emby-server-rpm_{version}_x86_64.deb
	Operating system: Unix 3.10.0.693
	64-Bit OS: True
	64-Bit Process: True
	User Interactive: True
	Processor count: 8
	Program data path: /var/lib/emby
	Application directory: /opt/emby-server/system
	Corrupt: database disk image is malformed
	SQLitePCL.pretty.SQLiteException: Exception of type 'SQLitePCL.pretty.SQLiteException' was thrown.
	   at SQLitePCL.pretty.SQLiteException.CheckOk(sqlite3 db, Int32 rc)
	   at SQLitePCL.pretty.StatementImpl.MoveNext()
	   at Emby.Server.Implementations.Data.SqliteExtensions.<ExecuteQuery>d__36.MoveNext()
	   at Emby.Server.Implementations.Data.SqliteItemRepository.GetItemList(InternalItemsQuery query)
	   at Emby.Server.Implementations.Library.LibraryManager.GetItemList(InternalItemsQuery query, Boolean allowExternalContent)
	   at Emby.Server.Implementations.TV.TVSeriesManager.GetNextUp(String seriesKey, User user, DtoOptions dtoOptions)
	   at System.Linq.Utilities.<>c__DisplayClass2_0`3.<CombineSelectors>b__0(TSource x)
	   at System.Linq.Enumerable.SelectEnumerableIterator`2.MoveNext()
	   at System.Linq.Enumerable.WhereSelectEnumerableIterator`2.MoveNext()
	   at System.Linq.Enumerable.WhereEnumerableIterator`1.MoveNext()
	   at System.Linq.Enumerable.EnumerablePartition`1.ToArray()
	   at System.Linq.Enumerable.ToArray[TSource](IEnumerable`1 source)
	   at Emby.Server.Implementations.TV.TVSeriesManager.GetResult(IEnumerable`1 items, NextUpQuery query)
	   at Emby.Server.Implementations.TV.TVSeriesManager.GetNextUp(NextUpQuery request, List`1 parentsFolders, DtoOptions dtoOptions)
	   at Emby.Server.Implementations.TV.TVSeriesManager.GetNextUp(NextUpQuery request, DtoOptions dtoOptions)
	   at MediaBrowser.Api.TvShowsService.Get(GetNextUpEpisodes request)
	   at Emby.Server.Implementations.Services.ServiceExecGeneral.<Execute>d__2.MoveNext()
	--- End of stack trace from previous location where exception was thrown ---
	   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
	   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
	   at Emby.Server.Implementations.Services.ServiceHandler.<ProcessRequestAsync>d__15.MoveNext()
	--- End of stack trace from previous location where exception was thrown ---
	   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
	   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
	   at Emby.Server.Implementations.HttpServer.HttpListenerHost.<RequestHandler>d__72.MoveNext()
	SQLitePCL.pretty.SQLiteException
	   at SQLitePCL.pretty.SQLiteException.CheckOk(sqlite3 db, Int32 rc)
	   at SQLitePCL.pretty.StatementImpl.MoveNext()
	   at Emby.Server.Implementations.Data.SqliteExtensions.<ExecuteQuery>d__36.MoveNext()
	   at Emby.Server.Implementations.Data.SqliteItemRepository.GetItemList(InternalItemsQuery query)
	   at Emby.Server.Implementations.Library.LibraryManager.GetItemList(InternalItemsQuery query, Boolean allowExternalContent)
	   at Emby.Server.Implementations.TV.TVSeriesManager.GetNextUp(String seriesKey, User user, DtoOptions dtoOptions)
	   at System.Linq.Utilities.<>c__DisplayClass2_0`3.<CombineSelectors>b__0(TSource x)
	   at System.Linq.Enumerable.SelectEnumerableIterator`2.MoveNext()
	   at System.Linq.Enumerable.WhereSelectEnumerableIterator`2.MoveNext()
	   at System.Linq.Enumerable.WhereEnumerableIterator`1.MoveNext()
	   at System.Linq.Enumerable.EnumerablePartition`1.ToArray()
	   at System.Linq.Enumerable.ToArray[TSource](IEnumerable`1 source)
	   at Emby.Server.Implementations.TV.TVSeriesManager.GetResult(IEnumerable`1 items, NextUpQuery query)
	   at Emby.Server.Implementations.TV.TVSeriesManager.GetNextUp(NextUpQuery request, List`1 parentsFolders, DtoOptions dtoOptions)
	   at Emby.Server.Implementations.TV.TVSeriesManager.GetNextUp(NextUpQuery request, DtoOptions dtoOptions)
	   at MediaBrowser.Api.TvShowsService.Get(GetNextUpEpisodes request)
	   at Emby.Server.Implementations.Services.ServiceExecGeneral.<Execute>d__2.MoveNext()
	--- End of stack trace from previous location where exception was thrown ---
	   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
	   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
	   at Emby.Server.Implementations.Services.ServiceHandler.<ProcessRequestAsync>d__15.MoveNext()
	--- End of stack trace from previous location where exception was thrown ---
	   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
	   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
	   at Emby.Server.Implementations.HttpServer.HttpListenerHost.<RequestHandler>d__72.MoveNext()
	

Any help tracking down this issue would be appreciated.

[Luke 37107]

Somehow your database file has become corrupted.  You'll need to rename this file, restart the server and run a library scan:

/var/lib/emby/data/library.db

The most typical cause of this is abruptly terminating the server process in an ungraceful manner, e.g. a power loss, forcefully shutting down the machine, etc.

[dcrdev 251]

Somehow your database file has become corrupted.  You'll need to rename this file, restart the server and run a library scan:

/var/lib/emby/data/library.db

The most typical cause of this is abruptly terminating the server process in an ungraceful manner, e.g. a power loss, forcefully shutting down the machine, etc.

 

 

Yes @@Luke beginning to suspect these incidents (twice within a week) are related to shutdowns.

 

How are we supposed to be shutting down the server? On Linux when a shutdown is initiated systemd manages all the termination of services etc...

 

I'm really not sure why this happening all of a sudden, never has done before - there's certainly been no unexpected power loss; server is on a UPS.

[Luke 37107]

I would use the controls built into emby server to shut down. what might be happening is that it is abruptly stopping the server. i think we may need to look into how to get notified about that so that we can shut everything down gracefully.

[dcrdev 251]

Thanks @@Luke, can the server be shutdown via an API call?

 

I suppose if there was I could call that via cURL in the ShutdownPre systemd unit directive as a workaround for the time being.

[dcrdev 251]

@@Luke so can the server be shut down via an API call?

 

The thing is with using the default controls, is that the systemd service that's packaged has restart-always - so shutting down via the web interface will mean that it will start right back up again. Easy enough to override - if you drop a clone unit file into /etc/systemd/system - but still that's how it works by default.

 

Another thing I've been thinking about recently is the fragility of the database, for such an important part of the system I think there could be more safeguards inplace. For example Emby could always keep atleast one additional version of the database between reboots and then whenever the above exception is encountered, that gets swapped in.

 

Ofcourse people should also make their own backups (as I do) , but if something like this can happen from a simple restart then it's worth it.

[Luke 37107]

/system/shutdown

[dcrdev 251]

Thanks @@Luke

 

So for anyone else with similar troubles/concerns - here is a simple workaround:

 

Create this script somewhere - replacing the url and adding an api key:

#!/bin/bash
url="https://emby.server.location"
api_path="/emby/System/Shutdown"
api_key=""
data="True"

response=`curl -H "X-MediaBrowser-Token: $api_key" \
               -H "Content-Type: application/json" \
               -POST -d "$data" "$url$api_path" \
               -s -D /dev/null`

if [[ $response != *"ErrorCode"* ]]; then
    echo "Operation Completed Successfully! \n"
else
    echo "Received an Invalid Response from Server!" && \
    exit 1
fi

Then replace ExecStop with the path to the above script:

cat << EOF > /etc/systemd/system/emby-server.service
[Unit]
Description=Emby Server is a personal media server with apps on just about every device.
After=network.target

[Service]
EnvironmentFile=/etc/emby-server.conf
WorkingDirectory=/opt/emby-server
ExecStart=/opt/emby-server/bin/emby-server
ExecStop=/path/to/script/emby_shutdown.sh
Restart=always
User=emby

[Install]
WantedBy=multi-user.target
EOF

Then:

systemctl daemon-reload
chmod +x /path/to/script/emby_shutdown.sh
systemctl restart emby-server

Yes it would seem that the original unit is infact just killing the process as is.

[dcrdev 251]

Please can you do something about this -

 

Just happened to me again - updated to the latest release, got prompted to update the Reports plugin, did so and restarted emby; using the above API call I should mention. When emby was up again, I noticed the activity feed was blank so looked at the logs had a sqlite exception saying the database was malformed on disk.

 

About the 5th time within 2 months this has happened - fortunately I can restore from a zfs snapshot each time, but it's still a pain in the ass because I lose any metadata in between snapshots.

[Luke 37107]

Are you sure it actually shutdown gracefully via api? If I had to guess, you sent the api call but then some other part of your script actually terminated the server process abruptly. After you send that api call, you should then have some kind of pause in that script to not continue until you've verified that the server is no longer running.

[dcrdev 251]

Ok I'll add a check for the Emby process and see if that makes a difference, I thought the systemd unit wouldn't exit until the start process had exited - maybe not though.

 

In any case I want to highlight something very important that I think you should take note of here:

• In an unmodified installation of Emby the start/stop/restart controls in the web interface don't actually work as intended.
• When you initiate a shutdown in the web interface, the process goes into a failed state; it's not actually failed, it's just not being reported correctly.
• The systemd unit is configured to restart in this scenario.
• The end result is that as soon as Emby is stopped in the web interface, it begins starting right back up again. 

[dcrdev 251]

It happened again - I've been doing some digging with strace and wireshark...
 
So it would appear that Emby is making a request to mb3admin.com and this is taking a very long time for some reason, Emby even though receiving the shutdown call - doesn't appear to be auctioning this immediately. After 60 seconds systemd's timeout limit is exceeded and the process if forcefully killed by sending an un-catchable signal. 
 
So I have some questions that I'm not able to answer:

• Why is mb3admin.com taking so long to respond? I can send a request using cURL and receive a response immediately.
• Why is Emby refusing to shutdown, on what would seem to be a non critical action?
• Most importantly, what it is it that's making the sqlite database so fragile? I've used sqlite in many of my own projects and had always thought of it as extremely resilient. 

I guess the immediate workaround for me, is to increase the systemd unit timeout time - although that's going to slow down shutdown operations.

[Luke 37107]

 

 

• Why is Emby refusing to shutdown, on what would seem to be a non critical action?

Emby doesn't refuse to shutdown, rather something must be happening that is inhibiting a normal shutdown.

[dcrdev 251]

Emby doesn't refuse to shutdown, rather something must be happening that is inhibiting a normal shutdown.

 

That's what I meant - the extended request to mb3admin.com appears to be that factor, based on what's happening on my network.

 

The other questions still stand though - I don't get why the database appears to be so easily corruptible... 

Edited December 23, 2017 by dcrdev

[Luke 37107]

That should only happen if you abruptly terminate the server process.

[dcrdev 251]

That should only happen if you abruptly terminate the server process.

 

Yes but that's my point:

• The extended request appears to be prolonging shutdown.
• systemd has a timeout - if timeout is reached it send an uncatchable signal, the kernel kills the process and Emby doens't have the opportunity to catch the signal and handle it gracefully.
• sqlite shouldn't be so fragile in the first place...

I'm not terminating the process forcefully here, systemd is because it has a global timeout - this is not unique to my system.

 

Can anything be done on your end to improve resiliency to this kind of issue? I've noticed that 1 or 2 others in this forum section have had similar database issues recently.

 

I don't reboot the server often, but have to for kernel updates. 

Edited December 23, 2017 by dcrdev

[Luke 37107]

We'd have to look at the log of a specific example, thanks.