problem with graph stopping killed wrong recording

[johnsonx42]

Last night at 8pm NPVR started recording the Grammys and also Dateline NBC. At 9pm when it went to stop Dateline NBC, it got the infamous "Async stop taking way too long" error and then died. In the process it also killed the Grammys recording at 9pm, even though that recording was to have continued until 11:30pm. After this both recordings continued to show as "Recording" until I restarted the recording service at around 10:30pm.

Both files were perfectly watchable.

I know the root cause of this error remains a mystery, but can you make sure it doesn't go tearing down the wrong graph (or all graphs?) when it's trying to recover from this?

Code:

2011-02-13 20:00:00.447 [DEBUG][7] About to start recording (52573): F:\Recordings\The 53rd Annual Grammy Awards\The 53rd Annual Grammy Awards_20110213_20002330.ts 2011-02-13 20:00:00.447 [INFO][7] DigitalRecorder.StartStream(F:\Recordings\The 53rd Annual Grammy Awards\The 53rd Annual Grammy Awards_20110213_20002330.ts) 2011-02-13 20:00:00.447 [INFO][7] Creating BDA graph 2011-02-13 20:00:00.457 [DEBUG][7] Using tuner WinTV HVR-950 BDA Tuner (1) 2011-02-13 20:00:00.470 [DEBUG][7] About to auto detect capture filter 2011-02-13 20:00:00.474 [DEBUG][7] Got capture filter: 'WinTV HVR-950 BDA Capture' 2011-02-13 20:00:00.475 [DEBUG][7] Added capture filter 2011-02-13 20:00:00.477 [DEBUG][7] Connected Tuner to Capture 2011-02-13 20:00:00.501 [DEBUG][7] Graph filter list: 2011-02-13 20:00:00.501 [DEBUG][7] - MPEG-2 Sections and Tables 2011-02-13 20:00:00.501 [DEBUG][7] - BDA MPEG2 Transport Information Filter 2011-02-13 20:00:00.501 [DEBUG][7] - MPEG-2 Demultiplexer 2011-02-13 20:00:00.501 [DEBUG][7] - NPVR TS Mon 2011-02-13 20:00:00.501 [DEBUG][7] - Capture 2011-02-13 20:00:00.501 [DEBUG][7] - Tuner 2011-02-13 20:00:00.501 [DEBUG][7] - Network Provider 2011-02-13 20:00:00.501 [INFO][7] About to start BDA graph 2011-02-13 20:00:00.501 [DEBUG][7] Starting graph... 2011-02-13 20:00:00.957 [DEBUG][7] About to tune BDA graph: <tuning> <type>ATSC</type> <locator> <physical_channel>43</physical_channel> </locator> <service_id>1</service_id> <tsid>289</tsid> <service_type>1</service_type> </tuning> 2011-02-13 20:00:01.193 [DEBUG][7] Calling LockChannel() 2011-02-13 20:00:01.256 [DEBUG][7] locked=1, present=1, strength=-28, quality=78 (took 63ms to check) 2011-02-13 20:00:01.258 [INFO][7] DigitalRecorder.StartStream() allocated handle: 0x147 2011-02-13 20:00:01.258 [DEBUG][7] Temp at 2/13/2011 8:00:11 PM 2011-02-13 20:00:01.258 [DEBUG][7] Started recording (52573:F:\Recordings\The 53rd Annual Grammy Awards\The 53rd Annual Grammy Awards_20110213_20002330.ts) 2011-02-13 20:00:01.393 [DEBUG][7] Starting: C:\Users\Public\NPVR\Scripts\ParallelProcessing.bat "F:\Recordings\The 53rd Annual Grammy Awards\The 53rd Annual Grammy Awards_20110213_20002330.ts" 2 52573 2011-02-13 20:00:01.417 [DEBUG][7] About to start recording (53634): F:\Recordings\Dateline NBC\Dateline NBC_20110213_20002100.ts 2011-02-13 20:00:01.417 [INFO][7] DigitalRecorder.StartStream(F:\Recordings\Dateline NBC\Dateline NBC_20110213_20002100.ts) 2011-02-13 20:00:01.417 [INFO][7] Creating BDA graph 2011-02-13 20:00:01.424 [DEBUG][7] Using tuner Hauppauge WinTV 885 BDA Tuner/Demod (1) 2011-02-13 20:00:01.436 [DEBUG][7] About to auto detect capture filter 2011-02-13 20:00:01.440 [DEBUG][7] Got capture filter: 'Hauppauge WinTV 885 TS Capture' 2011-02-13 20:00:01.441 [DEBUG][7] Added capture filter 2011-02-13 20:00:01.443 [DEBUG][7] Connected Tuner to Capture 2011-02-13 20:00:01.465 [DEBUG][7] Graph filter list: 2011-02-13 20:00:01.465 [DEBUG][7] - MPEG-2 Sections and Tables 2011-02-13 20:00:01.465 [DEBUG][7] - BDA MPEG2 Transport Information Filter 2011-02-13 20:00:01.465 [DEBUG][7] - MPEG-2 Demultiplexer 2011-02-13 20:00:01.465 [DEBUG][7] - NPVR TS Mon 2011-02-13 20:00:01.465 [DEBUG][7] - Capture 2011-02-13 20:00:01.465 [DEBUG][7] - Tuner 2011-02-13 20:00:01.465 [DEBUG][7] - Network Provider 2011-02-13 20:00:01.465 [INFO][7] About to start BDA graph 2011-02-13 20:00:01.465 [DEBUG][7] Starting graph... 2011-02-13 20:00:01.559 [DEBUG][7] About to tune BDA graph: <tuning> <type>ATSC</type> <locator> <physical_channel>36</physical_channel> </locator> <service_id>3</service_id> <tsid>291</tsid> <service_type>1</service_type> </tuning> 2011-02-13 20:00:02.261 [DEBUG][7] Calling LockChannel() 2011-02-13 20:00:02.278 [DEBUG][7] locked=1, present=1, strength=-9000, quality=99 (took 15ms to check) 2011-02-13 20:00:02.279 [INFO][7] DigitalRecorder.StartStream() allocated handle: 0x148 2011-02-13 20:00:02.279 [DEBUG][7] Temp at 2/13/2011 8:00:12 PM 2011-02-13 20:00:02.279 [DEBUG][7] Started recording (53634:F:\Recordings\Dateline NBC\Dateline NBC_20110213_20002100.ts) 2011-02-13 20:00:02.475 [DEBUG][7] Starting: C:\Users\Public\NPVR\Scripts\ParallelProcessing.bat "F:\Recordings\Dateline NBC\Dateline NBC_20110213_20002100.ts" 4 53634 2011-02-13 20:00:03.057 [DEBUG][7] - deleting extra recording: F:\Recordings\Dateline NBC\Dateline NBC_20110206_21002308.ts (2/7/2011 5:00:00 AM) 2011-02-13 20:00:03.207 [DEBUG][7] -removing: F:\Recordings\Dateline NBC\Dateline NBC_20110206_21002308.txt 2011-02-13 20:00:03.207 [DEBUG][7] -removing: F:\Recordings\Dateline NBC\Dateline NBC_20110206_21002308.log 2011-02-13 20:00:03.207 [DEBUG][7] -removing: F:\Recordings\Dateline NBC\Dateline NBC_20110206_21002308.edl 2011-02-13 20:00:03.208 [DEBUG][7] -removing: F:\Recordings\Dateline NBC\Dateline NBC_20110206_21002308.logo.txt 2011-02-13 21:00:00.023 [DEBUG][7] Stopping recording (53634). Past end time of recording. 2011-02-13 21:00:00.023 [INFO][7] DigitalRecorder.StopStream() handle: 148 2011-02-13 21:00:00.023 [INFO][7] No more streams active. Stopping device. 2011-02-13 21:00:00.023 [DEBUG][7] About to request async graph stop 2011-02-13 21:00:00.023 [DEBUG][16] Graph stopping... (async) 2011-02-13 21:00:08.023 [DEBUG][7] Async stop taking way too long 2011-02-13 21:00:08.023 [DEBUG][7] Removing filter MPEG-2 Sections and Tables 2011-02-13 21:00:08.023 [DEBUG][7] Removing filter BDA MPEG2 Transport Information Filter 2011-02-13 21:00:08.023 [DEBUG][7] Removing filter MPEG-2 Demultiplexer

(that is the end of the log)