Bug #3822
Incomplete Recordings
0%
Description
I have a number of incidents recently where recordings have been cut short - the status is shown to be "Completed OK". An example tonight was a recording with an expected duration of 100 mins but the actual recording was only 53 mins 55 secs.
I'm using Tvheadend on a Synology Diskstation DS214Play running DSM 6.0-7321 Update 6. I'm using the Dierkse tvheadend-testing package. I have plenty of disk space available for my recording so it's not clear what causing this.
Is there any particular debugging or logging I can turn on to help investigate the issue further?
Thanks,
Mark
History
Updated by Jaroslav Kysela over 8 years ago
Updated by You may try to provide log for '--trace dvr' - https://tvheadend.org/projects/tvheadend/wiki/Traces .
Updated by Robin Mitra over 8 years ago
Updated by same here
last Time I checked, the recording stopped 5 mins too early.
5 mins happens to be the padding time (both for start an stop).
I retested this, and again 5 mins early stop. However, it stopped exactly where the actual show ended and commercial started. This might be a coincidence.
I then remebered that there is this feature that starts/stops with eit running flag.
Since I consider this highly unreliable (at least for my set of providers), I tried to disble this wherever I encountered it. There seem to be multiple places....
I did find another flag for 'skip commercials' where this is also used, and that one was still set. So I disabled it, and maybe now it works as it should.
Updated by Mark Siddons-Smith over 8 years ago
Updated by Thanks Jaroslav ... I'll capture and provide the log for '--trace dvr'.
Good point Robin ... most of my recordings have had no issues until recently so I didn't expect the eit running flag to be the cause although it could well be.
I'll provide the logs shortly.
Updated by Mark Siddons-Smith over 8 years ago
Typical that it decides to work when I'm capturing a trace log. 
I'll keep the trace log enabled whilst I try to capture an event where the timing is off. I do have the eit flag enabled so expect the issue to be related to that.
Will keep you posted.
Updated by Robin Mitra over 8 years ago
I tried this again today, and yes, the recording stops, when the 'it' thinks the program has stopped.
I.e. the The last one (GoT according to GUI, and as intended: from 29.05 13:55 to 15:05 local time stopped at 14:47 local time)
I did make sure that both "use running flag" and "skip commercials" is unchecked in the dvr config GUI ( is there a way to log that info too?)
Note that I do prefer that the dvr is 'intelligent', but I would prefer it to be based only on more reliable info. I am thinking here especially of programmes that last longer than planned (sports events, typically). IMHO the Eit current/next schedule is more reliable there.
In the log excerpt below, all the programmes were scheduled to record until xx:05 , and they all stopped earlier, i.e xx-1:57:yy
May 28 15:25:04 tvheadend tvheadend3042: dvr: entry 2122a01974a75bf5b368e6c7d7b946a2 "Billions" on "Sky Atlantic HD" starting at 2016-05-28 19:54:30, scheduled for recording by "192.168.1.21"
May 28 15:25:04 tvheadend tvheadend3042: dvr: entry b8f9907feee796f6a9754f4fa60cd928 "Game of Thrones" on "Sky Atlantic HD" starting at 2016-05-28 18:54:30, scheduled for recording by "192.168.1.21"
May 28 15:25:04 tvheadend tvheadend3042: dvr: entry dd45fb93651fe3201e63165fcd21f7e7 "Vinyl" on "Sky Atlantic HD" starting at 2016-05-28 17:54:30, scheduled for recording by "192.168.1.21"
May 28 15:25:05 tvheadend tvheadend3042: dvr: entry 31eb6a8e14050fe01c84023f382b4856 "Vinyl" on "Sky Atlantic HD" starting at 2016-05-29 07:54:30, scheduled for recording by "192.168.1.21"
May 28 15:25:06 tvheadend tvheadend3042: dvr: entry 5e7e731e7b7f905f0b439980176c2b65 "Game of Thrones" on "Sky Atlantic HD" starting at 2016-05-29 13:54:30, scheduled for recording by "192.168.1.21"
May 28 15:25:06 tvheadend tvheadend3042: dvr: entry 63b9d8dfb90e2b95644bcd4e7d0fc33f "Game of Thrones" on "Sky Atlantic HD" starting at 2016-05-29 19:54:30, scheduled for recording by "192.168.1.21"
May 28 15:25:09 tvheadend tvheadend3042: dvr: entry 3a50c6a1cff11e409963b85139cbd66b "Billions" on "Sky Atlantic HD" starting at 2016-05-30 21:54:30, scheduled for recording by "192.168.1.21"
May 28 15:25:09 tvheadend tvheadend3042: dvr: entry 40761a28ec39a3cfd673e7af2462ff5c "Game of Thrones" on "Sky Atlantic HD" starting at 2016-05-30 20:54:30, scheduled for recording by "192.168.1.21"
May 28 15:25:10 tvheadend tvheadend3042: dvr: entry a5db027b0e9d262cf3e7eaaebbf1fad2 "Billions" on "Sky Atlantic HD" starting at 2016-05-31 03:54:30, scheduled for recording by "192.168.1.21"
May 28 15:25:10 tvheadend tvheadend3042: dvr: entry 2a021776814d9dc7ec543558f9889510 "Game of Thrones" on "Sky Atlantic HD" starting at 2016-05-31 02:54:30, scheduled for recording by "192.168.1.21"
May 28 17:54:30 tvheadend tvheadend3042: dvr: "Vinyl" on "Sky Atlantic HD" recorder starting
May 28 17:56:16 tvheadend tvheadend3042: dvr: /hts-recordings/Vinyl/Vinyl.E.A.H.mkv from adapter: "DD4", network: "ASTRA 192", mux: "11992H", provider: "SKY", service: "Sky Atlantic HD"
May 28 17:56:16 tvheadend tvheadend3042: dvr: # type lang resolution aspect ratio sample rate channels
May 28 17:56:16 tvheadend tvheadend3042: dvr: 2 H264 1920x1080 16:9
May 28 17:56:16 tvheadend tvheadend3042: dvr: 3 AC3 ger 48000 2
May 28 17:56:16 tvheadend tvheadend3042: dvr: 4 AC3 eng 48000 2
May 28 18:54:30 tvheadend tvheadend3042: dvr: "Game of Thrones" on "Sky Atlantic HD" recorder starting
May 28 18:57:28 tvheadend tvheadend3042: dvr: "Vinyl" on "Sky Atlantic HD": End of program: Completed OK
May 28 18:57:28 tvheadend tvheadend3042: dvr: /hts-recordings/Game of Thrones/Game of Thrones.Das Tor.mkv from adapter: "DD4", network: "ASTRA 192", mux: "11992H", provider: "SKY", service: "Sky Atlantic HD"
May 28 18:57:28 tvheadend tvheadend3042: dvr: # type lang resolution aspect ratio sample rate channels
May 28 18:57:28 tvheadend tvheadend3042: dvr: 2 H264 1920x1080 16:9
May 28 18:57:28 tvheadend tvheadend3042: dvr: 3 AC3 ger 48000 5.1
May 28 18:57:28 tvheadend tvheadend3042: dvr: 4 AC3 eng 48000 2
May 28 19:54:30 tvheadend tvheadend3042: dvr: "Billions" on "Sky Atlantic HD" recorder starting
May 28 19:57:08 tvheadend tvheadend3042: dvr: "Game of Thrones" on "Sky Atlantic HD": End of program: Completed OK
May 28 19:57:08 tvheadend tvheadend3042: dvr: /hts-recordings/Billions/Billions.Die Spur nach Iowa.mkv from adapter: "DD4", network: "ASTRA 192", mux: "11992H", provider: "SKY", service: "Sky Atlantic HD"
May 28 19:57:08 tvheadend tvheadend3042: dvr: # type lang resolution aspect ratio sample rate channels
May 28 19:57:08 tvheadend tvheadend3042: dvr: 2 H264 1920x1080 16:9
May 28 19:57:08 tvheadend tvheadend3042: dvr: 3 AC3 ger 48000 5.1
May 28 19:57:08 tvheadend tvheadend3042: dvr: 4 AC3 eng 48000 2
May 28 20:59:25 tvheadend tvheadend3042: dvr: "Billions" on "Sky Atlantic HD": End of program: Completed OK
May 29 13:54:30 tvheadend tvheadend981: dvr: "Game of Thrones" on "Sky Atlantic HD" recorder starting
May 29 13:57:30 tvheadend tvheadend981: dvr: /hts-recordings/Game of Thrones/Game of Thrones.Das Tor-1.mkv from adapter: "DD2", network: "ASTRA 192", mux: "11992H", provider: "SKY", service: "Sky Atlantic HD"
May 29 13:57:30 tvheadend tvheadend981: dvr: # type lang resolution aspect ratio sample rate channels
May 29 13:57:30 tvheadend tvheadend981: dvr: 2 H264 1920x1080 16:9
May 29 13:57:30 tvheadend tvheadend981: dvr: 3 AC3 ger 48000 5.1
May 29 13:57:30 tvheadend tvheadend981: dvr: 4 AC3 eng 48000 2
May 29 14:57:09 tvheadend tvheadend981: dvr: "Game of Thrones" on "Sky Atlantic HD": End of program: Completed OK