SQLite Error 5: 'database is locked'

[BrettB]

I killed the NextPVRServer.exe which was running yesterday and started a new one.

I was then able to connect from knewc on the RPi, go into the Guide, select a show, and do a quick record. That seemed to work ok. Then I went in the guide to a show for tonight (Chicago Med) and tried to schedule a recurring all new recording rule. It seemed like it hung after I clicked OK. When I went to the server, I saw database is locked errors again and grabbed a copy of the log files to post here. In the meantime, it appears that the recurring recording scheduling did complete but the epsiode was not showing as red in the guide. I then also did a the same thing for Chicago Fire and got the same result.

Fresh logs attached.
  logs-20191009-0753.zip (Size: 1.51 MB / Downloads: 1)

Is it possible that this problem is somehow related to the fact that my database currently has 2 sets of all my cable card channels with the same numbers (1 set on the 1st Prime's 3 tuners and a 2nd set on the 2nd Prime's 3 tuners)? As I posted before the AutoMerge won't merge them because NextPVR pulled them in with different names.

[BrettB]

sub: Any ideas on this problem? Right now, I can't successfully record anything. It appears that recordings do get put in the table and the server seems to generate the file. But the table doesn't get updated to indicate that the recording ever began or completed. If I then stop and restart the server, the recording gets marked as failed because the recording service wasn't running at the scheduled recording time. (But it was, and there's even a file on the disk to show for it.)

[sub]

sub: Any ideas on this problem? Right now, I can't successfully record anything. It appears that recordings do get put in the table and the server seems to generate the file. But the table doesn't get updated to indicate that the recording ever began or completed. If I then stop and restart the server, the recording gets marked as failed because the recording service wasn't running at the scheduled recording time. (But it was, and there's even a file on the disk to show for it.)

I just took a good look through the logs, but it's not really clear what's happening.

If you just restart the recording service, schedule a recording of a show that starts soon. Does that recording happen, and the database get updated? or does it need to be running longer before the issue starts?

[sub]

Actually, be worth checking Martin's suggestion about trying without NTray.exe running to see if it makes a difference. I remember we did have an issue with this in pre-release testing. I'm not sure we found and fixed this.

[BrettB]

Actually, be worth checking Martin's suggestion about trying without NTray.exe running to see if it makes a difference. I remember we did have an issue with this in pre-release testing. I'm not sure we found and fixed this.

As I said above, NTray isn't running on that server at all. The /activity entries were coming from knewc running on an RPi.

[mvallevand]

You posted to that knewc couldn't connect do you have the Kodi log? I am wondering what error was coming back.

Martin

[BrettB]

You posted to that knewc couldn't connect do you have the Kodi log?  I am wondering what error was coming back.

When knewc couldn't connect, it was just timing out. The same as when I would try to open a browser window to the server. But that problem was apparently that the command window where NextPVRServer.exe was running was "paused" from me looking at the errors there (per sub's comment). Once I had hit ctrl-c, the window took off and then knewc and the web browser could connect to the server again.

So that's a different problem.

I just got home, so I can try doing a fresh start of the server. This time, I'll try it without knewc running on the client and see if recordings work.

[BrettB]

sub: Any ideas on this problem? Right now, I can't successfully record anything. It appears that recordings do get put in the table and the server seems to generate the file. But the table doesn't get updated to indicate that the recording ever began or completed. If I then stop and restart the server, the recording gets marked as failed because the recording service wasn't running at the scheduled recording time. (But it was, and there's even a file on the disk to show for it.)

I just took a good look through the logs, but it's not really clear what's happening.

If you just restart the recording service, schedule a recording of a show that starts soon. Does that recording happen, and the database get updated? or does it need to be running longer before the issue starts?

I just did a fresh start of the server. Didn't start knewc on the RPi. No NTray.exe running.

Chrisly Knows Best was scheduled to be recording at that time. The .ts file and a .map file are on the disk, but the .ts file isn't growing. Looking at Resource Monitor, it does appear that data is being written to the file.

I then went into the Guide (via the web app in Chrome on the same server) and selected A Million Little Things to record. It turned red in the guide, but the .ts file on the disk does not appear to be growing. However, looking at the resource monitor, it does appear to be getting written to. I then tried selecting Carol's Second Act in the guide and doing a quick record. That one didn't turn red. And that one did get a .ts file created.

I'm beginning to wonder if the problem is related to having more than 1 recording trying to go to the HDHR Prime. In all of my earlier testing, I only had 1 Prime tuner setup on the test server. I just added more over the weekend.

  logs-20191010-2044.zip (Size: 1.38 MB / Downloads: 2)

[mvallevand]

I wonder if this is somehow related to lengthy time getting art for display in the guide for "A Million Little Things" while the recording is being saved

Code:

2019-10-10 20:43:14.372    [DEBUG][22]    method=channel.show.artwork (9928532)
2019-10-10 20:43:18.080    [DEBUG][9]    Started recording (11474:2:E:\Recordings2\A Million Little Things\Season 02\A.Million.Little.Things.S02E03.Mixed.Signals.ts)
2019-10-10 20:43:17.392    [DEBUG][4]    method=recording.save (9928532)
2019-10-10 20:43:20.879    [DEBUG][4]    method=channel.show.artwork  (9928017)
2019-10-10 20:43:20.923    [DEBUG][4]    Downloading metadata and artwork took + 34.1107ms (too fast maybe some blocking here)
2019-10-10 20:43:20.924    [DEBUG][4]    No artwork found
2019-10-10 20:43:20.927    [DEBUG][4]    Returning 404
2019-10-10 20:43:21.238    [DEBUG][22]    Got landscape
2019-10-10 20:43:21.672    [DEBUG][20]    Got fanart
2019-10-10 20:43:22.163    [DEBUG][19]    method=recording.save (9928017)
2019-10-10 20:43:48.250    [ERROR][9]    Unexpected error saving scheduled recording: Microsoft.Data.Sqlite.SqliteException (0x80004005): SQLite Error 5: 'database is locked'.
2019-10-10 20:43:48.388    [DEBUG][20]    found match
2019-10-10 20:43:52.337    [ERROR][19]    Unexpected error saving scheduled recording: Microsoft.Data.Sqlite.SqliteException (0x80004005): SQLite Error 5: 'database is locked'.
2019-10-10 20:43:49.652    [DEBUG][35]    Done fanart.tv lookup

Martin

[BrettB]

Here are a few more sets of logs.

In the first one, I started the server just before The Late Show with Steven Colbert was scheduled. And apparently there was another chrisley know best. Both appeared to actually record and run the post-processing comskip. But the database locked errors cause the recordings to get flagged as bad, so not playable in NPVR.
  logs-20191010-2353.zip (Size: 1.14 MB / Downloads: 1)

The second was a clean start, then did a quick record on an epsiode of Mom. this time it was the only thing recording. Still got a database locked error right before the No ParallelProcessing.bat line.
  logs-20191010-2357.zip (Size: 817.98 KB / Downloads: 0)

The third was another clean start, then I started a quick record of the end of Nightline. But this time, I picked a channel on the Quatro (but still using the HDHR device type in NPVR) rather than the Prime tuner. And it seemed to work just fine. No database locks. The recording got marking in the Recordings list a "recording" and then "completed"!
  logs-20191011-0014.zip (Size: 694.11 KB / Downloads: 2)