Recording fails upon restart after hicup

[Lone_Stranger]

I routinely suffer loss of recordings after some glitch interrupts the initial one. This current example was when recording Varney&Co which was working fine for 45 minutes. Something then caused a restart of the recording. When it attempted to restart, it failed, resulting in only the first 45 minutes being saved. Note that NPVR states that the recording is still currently active, but I can't see how.

This happens with some frequency, with the following messages:

2016-02-12 09:49:15.192 [DEBUG][14] Asking NCableCardHost to start: E:\Recorded TV\Varney & Company\Varney & Company_20160212_09001200-0.ts
2016-02-12 09:49:15.318 [DEBUG][14] Failed to start recording on backup device too: ''
2016-02-12 09:49:15.324 [DEBUG][14] Temp at 2/12/2016 9:49:25 AM
2016-02-12 09:49:15.324 [DEBUG][14] Failed to start recording... (30097:E:\Recorded TV\Varney & Company\Varney & Company_20160212_09001200-0.ts): ''
2016-02-12 09:49:15.328 [ERROR][14] Unexpected error saving scheduled recording: System.Data.SQLite.SQLiteException (0x80004005): constraint failed
SCHEDULED_RECORDING.failure_reason may not be NULL
at System.Data.SQLite.SQLite3.Reset(SQLiteStatement stmt)
at System.Data.SQLite.SQLite3.Step(SQLiteStatement stmt)
at System.Data.SQLite.SQLiteDataReader.NextResult()
at System.Data.SQLite.SQLiteDataReader..ctor(SQLiteCommand cmd, CommandBehavior behave)
at System.Data.SQLite.SQLiteCommand.ExecuteReader(CommandBehavior behavior)
at System.Data.SQLite.SQLiteCommand.ExecuteNonQuery()
at NUtility.ScheduledRecording.Save()


At a loss...

[Lone_Stranger]

Bump....

[sub]

The cablecard hosts processes are a little slow to startup, since they have to wait for UPNP discovery to complete. This can take 15-20 seconds. If you try to start a recording before that completes, you could potential have a problem.

So, you could avoid restarting the machine while recording, or when recordings are going to be due to start, to give the recording service and cablecard hosts a chance to start properly.

Alternatively you could look at creating a PostStartup.bat, and put a delay of 30 seconds or so in it.

[Lone_Stranger]

Sub, I don't think I've explained my issue correctly. Let me try a different approach...

9:00am Recording starts automatically for Varney&Co as it's scheduled daily.

9:49.02am The active recording of Varney&Co fails for some reason with Recording service restarted during recording.

9:49.03am NPVR attempts to automatically restart, as there's 2.5hrs left to record. But I see there's a message in the logs indicating failure
Unexpected error saving scheduled recording: System.Data.SQLite.SQLiteException (0x80004005): constraint failed.

I see that nrecord attempts to restart the recording, but it can't use the tuners for some reason. It appears that nrecord goes after re-discovering all of the tuners (I'm out of my league here). ncchost (all 4 of them) attempt to restart the recording, but they each claim they have no DRI.

9:49.20am It would appear externally, that the recording has been restarted and is functioning normally. NPVR status indicates it is recording. But, it is not actually recording. Recording service is verified as active.

12:00pm The recording finishes, and it is marked complete, but with message
Recording service was stopped during recording.
As stated above, the recording service was verified as active throughout the problem. I don't believe it was stopped at all, but I wasn't watching it the full 3 hours.

At this point I captured the logs and the above snippet.

What results is a partial recording of the first 45 minutes, and then nothing, even though the status record indicates that it restarted and completed normally - except for the time it takes to restart. I've seen quite a few of these occur now, usually one or two per day (I record about 20 hrs per day).

I checked the Ceton log, and could not find any error for any reason at all.

I'm not concerned at this point about the reason for initial failure, as I can pursue that later. What I'm after is correction to the restart issue.

Thanks.....

[Lone_Stranger]

Bump.....

[sub]

9:49.02am The active recording of Varney&Co fails for some reason with Recording service restarted during recording.

What restarted it though? ie, NextPVR doesn't restart the recording service if it crashes. Did your machine reboot or something?

9:49.02am The active recording of Varney&Co fails for some reason with Recording service restarted during recording.

9:49.03am NPVR attempts to automatically restart, as there's 2.5hrs left to record. But I see there's a message in the logs indicating failure
Unexpected error saving scheduled recording: System.Data.SQLite.SQLiteException (0x80004005): constraint failed.

For whatever reason your recoridng service was restarted, you're now into the situation I described earlier, where it's attempting to start a recording before the cablecard hosts are in a ready state. (the SQLiteException is a flow on effect of this)

[Lone_Stranger]

Thank you very much,Sub. You are right again. I was unaware that the machine re-booted at about 9:48am. It was unattended at the time, and I didn't notice it - I hate it when Micro$oft automatically reboots when it wants.

But, it appears that upon system restart, that NPVR attempted to restart the recording, as it documented the abrupt ending of the recording at 9:48am, and created a new status record at 9:49am.

I guess what I'm asking, is if NPVR is supposed to attempt restart of the failed recording, as it's still within the scheduled recording window.

[ACTCMS]

I guess what I'm asking, is if NPVR is supposed to attempt restart of the failed recording, as it's still within the scheduled recording window.

From my experience, when NPVR starts it will honour any recording requests active at that time (as it should), so if ms or any other agency decides to reboot your machine while a recording is in progress, when NPVR restarts it will resume any recordings which are still within the scheduled window...

Alex

[Lone_Stranger]

Thank you Alex. That's what I thought it should do, and what I thought I'd seen in the past.

So, the question with this post, is then: Why did NPVR not restart the scheduled program? As stated earlier, it appears that an attempt was made to restart the scheduled recording. But, it failed while generating the original error messages, as documented above.

If there's no interest in pursuing this issue, I understand. I'll try to duplicate the situation again, when it next occurs.

[ACTCMS]

For whatever reason your recoridng service was restarted, you're now into the situation I described earlier, where it's attempting to start a recording before the cablecard hosts are in a ready state. (the SQLiteException is a flow on effect of this)

See above...

Alex