Database is Locked?

[zed]

A recording I had scheduled for this morning at 7:00AM did not record. The Pending screen still shows it (it's now 5:30PM). I looked at the logs but only one of them has any entries for today...GBPVRRecordingService.exe.log...and its timestamp is 1:02AM today. I looked in it and found the following:

6/26/2006 7:11:33 PM.553 INFO [4] GB-PVR Recording Service starting
6/26/2006 7:11:33 PM.616 VERBOSE [4] installDirectory is C:\Program Files\devnz\gbpvr\
6/26/2006 7:11:33 PM.632 VERBOSE [4] configurationFile is C:\Program Files\devnz\gbpvr\config.xml
6/26/2006 7:11:33 PM.632 VERBOSE [4] getValue() loading new key/value into cache: /settings/DatabaseConnectionString
6/26/2006 7:11:33 PM.632 VERBOSE [4] getValue: /settings/DatabaseConnectionString : Data Source=".\gbpvr.db3";Version=3;New=True;
6/26/2006 7:11:33 PM.632 VERBOSE [4] getValue() loading new key/value into cache: /settings/DatabaseIdentityQuery
6/26/2006 7:11:33 PM.632 VERBOSE [4] getValue: /settings/DatabaseIdentityQuery : select last_insert_rowid()
6/26/2006 7:11:33 PM.632 VERBOSE [4] databaseConnectionString is Data Source="C:\Program Files\devnz\gbpvr\\gbpvr.db3";Version=3;New=True;
6/26/2006 7:11:33 PM.632 VERBOSE [4] getValue() loading new key/value into cache: /settings/DatabaseProviderFactory
6/26/2006 7:11:33 PM.632 VERBOSE [4] getValue: /settings/DatabaseProviderFactory : System.Data.SQLite.SQLiteFactory
6/26/2006 7:11:33 PM.632 VERBOSE [4] ...using System.Data.SQLite.SQLiteFactory DB Provider Factory
6/26/2006 7:11:33 PM.632 VERBOSE [4] getValue() loading new key/value into cache: /settings/LoggingLevel
6/26/2006 7:11:33 PM.632 VERBOSE [4] getValue: /settings/LoggingLevel : Error
6/27/2006 1:01:08 AM.660 ERROR [15] Unexpected error removing recording from conversion queue: System.Data.SQLite.SQLiteException: The database file is locked
database is locked
at System.Data.SQLite.SQLite3.Reset(SQLiteStatement stmt)
at System.Data.SQLite.SQLite3.Step(SQLiteStatement stmt)
at System.Data.SQLite.SQLiteCommand.ExecuteNonQuery()
at GBPVR.RecordingService.x92f6085038c83bb7.x4fa2bfc067e20d05(Int32 x0f7b9658643bceb7)
6/27/2006 1:01:38 AM.738 ERROR [15] Unexpected error removing recording from conversion queue: System.Data.SQLite.SQLiteException: The database file is locked
database is locked
at System.Data.SQLite.SQLite3.Reset(SQLiteStatement stmt)
at System.Data.SQLite.SQLite3.Step(SQLiteStatement stmt)
at System.Data.SQLite.SQLiteCommand.ExecuteNonQuery()
at GBPVR.RecordingService.x92f6085038c83bb7.x4fa2bfc067e20d05(Int32 x0f7b9658643bceb7)
6/27/2006 1:02:08 AM.770 ERROR [15] Unexpected error removing recording from conversion queue: System.Data.SQLite.SQLiteException: The database file is locked
database is locked
at System.Data.SQLite.SQLite3.Reset(SQLiteStatement stmt)
at System.Data.SQLite.SQLite3.Step(SQLiteStatement stmt)
at System.Data.SQLite.SQLiteCommand.ExecuteNonQuery()
at GBPVR.RecordingService.x92f6085038c83bb7.x4fa2bfc067e20d05(Int32 x0f7b9658643bceb7)
6/27/2006 1:02:38 AM.832 ERROR [15] Unexpected error removing recording from conversion queue: System.Data.SQLite.SQLiteException: The database file is locked
database is locked
at System.Data.SQLite.SQLite3.Reset(SQLiteStatement stmt)
at System.Data.SQLite.SQLite3.Step(SQLiteStatement stmt)
at System.Data.SQLite.SQLiteCommand.ExecuteNonQuery()
at GBPVR.RecordingService.x92f6085038c83bb7.x4fa2bfc067e20d05(Int32 x0f7b9658643bceb7)

I have it set to start conversions at 1:00AM so I assume that's what triggered the errors. There were three files scheduled for conversion and none of them were converted.

I had restarted the recording service last night at 7:11 as indicated in the log and watched several recorded shows after that. The three recordings that were scheduled for conversion were all recorded between 9:00PM and 11:00PM.

My guess is that the database being locked is why the one scheduled for this morning was not recorded but there are no other entires in any of the log files for today.

Any idea why the database would be locked?


It just occurred to me that I have the epg update (zap2it) set to run at 7:00AM. Would that prevent the recording from being made?

Hmmm...doesn't look like the epg has been updated either...timestamp on the zap2it.xml file is 7:11AM on 6/25...???

[sub]

Its probably the EPG update getting in the way. I'll have to think about that some more.

[zed]

Just for grins, I scheduled a recording for shortly after I posted that question. It didn't start either. And nothing was written to any of the log files. Then I did a restart recording services and it all started up again. I'm curious about the database locked error and what would cause it (and what it would cause).

One more detail...I had recorded four programs but then deleted one of them before the conversion ran. It looks like it tried to do four conversions. Would my having deleted one of the files caused it any grief?

Also, I think the same thing happened yesterday...one of my recordings didn't record. I didn't think much of it at the time but I wonder if it was the same problem?

At any rate, certainly not life or death but if you think of anything, please let me know...

Thanks...

[hkdl]

I had this happen to me too once, I set some things to record before I headed off to work. Once I got home and saw what happened I restarted the recording service and never really thought about it again. It hasn't happened anymore though.

[zed]

It appears to have happened again. Log shows database locked, the conversions did not happen, and the epg update did not happen this morning (nothing scheduled to record at that time this morning). Recordings scheduled last night before 1:00AM were all successful. When I just now tried to schedule a new recording, I got the "No connection could be made because the target machine actively refused it" error. I'll attach the logs.

The last epg update appears to have been on 25June at about 7:00AM so this all started some time after that. I don't think I've changed anything in GBPVR or the computer.

Anyway, if you have time to take a look, I'd appreciate it.

[zed]

Just a follow-up on this...I turned off the auto-conversion that kicks off at 01:00AM and everything seems to be working OK now. No database locks and the epg update ran just fine. I guess sub's warning about it being 'very experimental' is valid .

No biggie, I guess, I can run it manually for the stuff I want converted...