Recording service not working

[dspdrew]

I have a problem that seems to happen about once a week. Ill come home and find that the "Whats New" screen showing the last recording at about 2AM that morning. I know there were quite a few shows that should have recorded, including one that should have been recording when I walked in. Again, nothing in the "What's New" screen shows that any recordings failed or anything, just shows the last recording at 2AM that morning. I try accessing the System plugin, and NPVR crashes. I try watching Live TV, and I get nothing, just "Please wait" until it finally crashes.

I checked services.msc, and it shows the NPVR Recording service in "Started" status. I also noticed that the computer has been waking up when it is supposed to record something and then goes back to sleep 10 minutes later with sleep reason: System Idle. I tried starting the recording service, but still the same. I tried Re-starting the recording service, and now everything seems to be working normal again, and 13 failed recordings are now showing in the "What's New" screen.

Anybody have any idea why this keeps happening? I posted the NPVR log from when I tried watching Live TV and it crashed, and I posted the NRecord log from before it stopped recording until now.

[dspdrew]

No idea?

[sub]

There is no sign of any error messages or other sign of problems in your logs.

What should it have recorded (name/time/channel) that it didnt, and was it previously listed in the pending recordings?

[dspdrew]

What is this? Because today's logs don't have anything like it after the EPG updated. I think each time it resumed it was supposed to be recording a show.

In today's logs at this point it has a whole bunch of "2010-11-19 02:10:16.609 [DEBUG][7] Requesting wake up for 'RecordingOID10718' at 12/3/2010 11:27 PM" entries, and then starts recording the next show in the schedule.

Code:

2010-11-18 03:02:16.807    [DEBUG][8]    Exported 284 recordings to 'C:\Users\Public\NPVR\recording-backup.xml'
2010-11-18 03:02:16.817    [DEBUG][8]    Requesting wake up for 'EPGWAKEUP' at 11/19/2010 2:00 AM
2010-11-18 03:27:31.752    [DEBUG][4]    Resuming...
2010-11-18 03:27:33.514    [DEBUG][5]    cycling MVP servers
2010-11-18 04:57:31.690    [DEBUG][4]    Resuming...
2010-11-18 04:57:33.507    [DEBUG][5]    cycling MVP servers
2010-11-18 05:27:31.715    [DEBUG][16]    Resuming...
2010-11-18 05:27:33.510    [DEBUG][5]    cycling MVP servers
2010-11-18 05:57:31.742    [DEBUG][17]    Resuming...
2010-11-18 05:57:33.512    [DEBUG][5]    cycling MVP servers
2010-11-18 06:23:55.717    [DEBUG][4]    Resuming...
2010-11-18 06:23:55.972    [DEBUG][4]    Resuming...
2010-11-18 06:23:57.507    [DEBUG][5]    cycling MVP servers
2010-11-18 11:57:34.692    [DEBUG][18]    Resuming...
2010-11-18 11:57:35.510    [DEBUG][5]    cycling MVP servers
2010-11-18 13:57:31.747    [DEBUG][4]    Resuming...
2010-11-18 13:57:33.512    [DEBUG][5]    cycling MVP servers
2010-11-18 15:57:31.742    [DEBUG][20]    Resuming...
2010-11-18 15:57:33.512    [DEBUG][5]    cycling MVP servers
2010-11-18 16:57:32.772    [DEBUG][4]    Resuming...
2010-11-18 16:57:34.512    [DEBUG][5]    cycling MVP servers
2010-11-18 17:57:32.702    [DEBUG][23]    Resuming...
2010-11-18 17:57:34.514    [DEBUG][5]    cycling MVP servers
2010-11-18 18:19:56.727    [DEBUG][4]    Resuming...
2010-11-18 18:19:56.977    [DEBUG][4]    Resuming...
2010-11-18 18:19:58.512    [DEBUG][5]    cycling MVP servers
2010-11-18 18:47:50.765    [DEBUG][25]    OnStop()
2010-11-18 18:47:50.765    [DEBUG][25]    About to stop webserver
2010-11-18 18:47:51.093    [DEBUG][25]    webserver stopped
2010-11-18 18:47:51.093    [DEBUG][25]    About to stop MVP servers
2010-11-18 18:47:51.093    [DEBUG][25]    MVPManager shutdown initiated
2010-11-18 18:47:51.093    [DEBUG][25]    MVPManager shutdown complete
2010-11-18 18:47:51.093    [DEBUG][25]    MVP servers stopped
2010-11-18 18:47:51.093    [DEBUG][25]    About to stop recording service
2010-11-18 18:47:51.093    [INFO][25]    RecordingService.Shutdown()
2010-11-18 18:47:53.105    [INFO][25]    Recording Service hadnt stopped after 2000ms, continuing anyway
2010-11-18 18:47:53.308    [DEBUG][25]    recording service stopped
2010-11-18 18:47:53.308    [DEBUG][25]    OnStop() complete...

[dspdrew]

To answer your question, here is the only way I could put all that info together. I grabbed these lines from today's log, and it should be pretty close to what should have recorded yesterday.

2010-11-19 02:10:18.374 [DEBUG][7] Started recording (10768:Z:\recordings\MANswers\MANswers_20101119_01550228-0.ts)
2010-11-19 02:59:01.198 [DEBUG][7] Started recording (10667:Z:\recordings\Family Guy\Family Guy_20101119_03000330.ts)
2010-11-19 03:30:00.509 [DEBUG][7] Started recording (10668:Z:\recordings\Family Guy\Family Guy_20101119_03300400.ts)
2010-11-19 05:29:01.464 [DEBUG][7] Started recording (10828:Z:\recordings\Married With Children\Married With Children_20101119_05300600.ts)
2010-11-19 06:30:00.393 [DEBUG][7] Started recording (10830:Z:\recordings\Married With Children\Married With Children_20101119_06300700.ts)
2010-11-19 09:59:01.606 [DEBUG][7] Started recording (10629:Z:\recordings\Modern Marvels\Modern Marvels_20101119_10001100.ts)
2010-11-19 11:59:01.271 [DEBUG][7] Started recording (10794:Z:\recordings\New York Undercover\New York Undercover_20101119_12001300.ts)
2010-11-19 13:59:01.661 [DEBUG][7] Started recording (10745:Z:\recordings\Glenn Beck\Glenn Beck_20101119_14001500.ts)
2010-11-19 15:59:01.121 [DEBUG][7] Started recording (10630:Z:\recordings\Modern Marvels\Modern Marvels_20101119_16001700.ts)
2010-11-19 15:59:02.726 [DEBUG][7] Started recording (10658:Z:\recordings\Attack of the Show!\Attack of the Show!_20101119_16001700.ts)
2010-11-19 16:59:00.732 [DEBUG][7] Started recording (10719:Z:\recordings\Family Guy\Family Guy_20101119_17001730.ts)
2010-11-19 17:00:00.896 [DEBUG][7] Started recording (10631:Z:\recordings\Modern Marvels\Modern Marvels_20101119_17001800.ts)
2010-11-19 17:00:01.391 [DEBUG][7] Started recording (10912:Z:\recordings\Freedom Watch with Judge Napolitano\Freedom Watch with Judge Napolitano_20101119_17001800.ts)
2010-11-19 17:59:01.047 [DEBUG][7] Started recording (10618:Z:\recordings\TMZ\TMZ_20101119_18001830.ts)

[dspdrew]

Can somebody tell me what "cycling MVP servers" is, because it obviously was doing that instead of recording like it was supposed to.

[sub]

It recycles the MVP servers each time the machine comes out of standby. This happens on it's own thread, and appears to be working fine. It isnt the source of your problem.

I'm pretty sure your problem occurred long before that, when log messages from one of the other threads stopped appearing in the logs. No sign of an error message to indicate why though.

[telii1]

Has anyone found a solution to this problem? I have the same problem.