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)