Project

General

Profile

Bug #2838

Recording cuts short, when using webtv/vorbis/web

Added by Danni Finne over 9 years ago. Updated over 9 years ago.

Status:
New
Priority:
Normal
Category:
Transcoding
Target version:
-
Start date:
2015-05-11
Due date:
% Done:

0%

Estimated time:
Found in version:
3.9.2778~g130f413
Affected Versions:

Description

When I try to use transcoding (chosen webtv-vp8-vorbis-webm) the program I record ends way to soon.

Under "Finished Recordings" the duration is as expected. For example 10mins + 1min before + 1min after = 12mins. But when I watch the recording in VLC or XBMC, it is only 05:26mins long.

Everything works great when I don't transcode.


Files

tvh.log (58.3 KB) tvh.log debug logfile Danni Finne, 2015-05-17 06:12

History

#1

Updated by Danni Finne over 9 years ago

user@server:~/tvheadend-git$ ./configure --enable-libffmpeg_static
Checking support/features
checking for cc execinfo.h ... ok
checking for cc -mmmx ... ok
checking for cc -msse2 ... ok
checking for cc getloadavg ... ok
checking for cc atomic64 ... ok
checking for cc lockowner ... ok
checking for cc qsort_r ... ok
checking for cc stime ... ok
checking for cc recvmmsg ... ok
checking for cc sendmmsg ... ok
checking for cc libiconv ... fail
checking for cc libdvben50221 ... ok
checking for py module gzip ... ok
checking for bzip2 ... ok
checking for pkg openssl ... ok (detected 1.0.1)
checking for cc linux/dvb/version.h ... ok
checking for cc libhdhomerun/hdhomerun.h ... ok
checking for pkg zlib ... ok (detected 1.2.3.4)
checking for pkg liburiparser ... ok (detected 0.7.5)
checking for pkg avahi-client ... ok (detected 0.6.30)
checking for cc sys/inotify.h ... ok
fetching dvb-scan files ... ok
checking for pkg dbus-1 ... ok (detected 1.4.18)

Compiler:
Using C compiler: cc
Using LD flags: -lhdhomerun -ldvben50221 -ldvbapi -lucsi
Build for arch: i686

Binaries:
Using PYTHON: python

Options:
cwc yes
capmt yes
constcw yes
linuxdvb yes
satip_server yes
satip_client yes
hdhomerun_client yes
hdhomerun_static no
iptv yes
tsfile yes
dvbscan yes
timeshift yes
trace yes
imagecache yes
avahi yes
zlib yes
libav yes
libffmpeg_static yes
libffmpeg_static_x264 yes
inotify yes
epoll yes
uriparser yes
ccache no
tvhcsa yes
bundle no
dvbcsa no
dvben50221 yes
kqueue no
dbus_1 yes
android no
tsdebug no
gtimer_check no
execinfo yes
mmx yes
sse2 yes
getloadavg yes
atomic64 yes
lockowner yes
qsort_r yes
stime yes
recvmmsg yes
sendmmsg yes
libdvben50221 yes
py_gzip yes
bin_bzip2 yes
ssl yes
linuxdvbapi yes
libhdhomerun yes
upnp yes
inotify_h yes
linuxdvb_ca yes
mpegts yes
mpegts_dvb yes

Packages:
openssl 1.0.1
zlib 1.2.3.4
liburiparser 0.7.5
avahi-client 0.6.30
dbus-1 1.4.18

Installation paths:
Prefix: /usr/local
Binaries: ${prefix}/bin
Libraries: ${prefix}/lib
Data files: ${prefix}/share
Man pages: ${datadir}/man

Final Binary:
/home/danni/tvheadend-git/build.linux/tvheadend

Tvheadend Data Directory:
/usr/local/share/tvheadend

#2

Updated by Mark Clarkstone over 9 years ago

Danni Finne wrote:

Snip

Update to the latest [3.9.2825], there were some fixes relating to incorrect timings recently.

See commit:e1f9b29a

#3

Updated by Danni Finne over 9 years ago

Mark Clarkstone wrote:

Danni Finne wrote:

Snip

Update to the latest [3.9.2825], there were some fixes relating to incorrect timings recently.

See commit:e1f9b29a

Didn't help unfortunately. Seems like recordings are always little under half length of reported (and correct) duration.

#4

Updated by Jaroslav Kysela over 9 years ago

You should see the reason of the cut in logs...

#5

Updated by Danni Finne over 9 years ago

Jaroslav Kysela wrote:

You should see the reason of the cut in logs...

This is console output for a transcoded (vorbis) recording. Only thing I see is "8 frames left in queue on closing".

2015-05-13 06:00:38.596 [   INFO] dvr: entry 6b69aeec4993f1ff9f69e5b73323f14e "Godmorgen Sverige - sammendrag" on "SVT1HD" starting at 2015-05-13 06:03:30, scheduled for recording by "10.0.42.109" 
2015-05-13 06:03:30.000 [   INFO] dvr: "Godmorgen Sverige - sammendrag" on "SVT1HD" recorder starting
2015-05-13 06:03:30.001 [   INFO] mpegts: 474MHz in Yousee - tuning on HDHomeRun DVB-C Tuner #0 (10.0.42.125)
2015-05-13 06:03:30.001 [   INFO] tvhdhomerun: tuning to a8qam64-6875:474000000
2015-05-13 06:03:30.014 [   INFO] subscription: 04AB: "DVR: Godmorgen Sverige - sammendrag" subscribing on channel "SVT1HD", weight: 300, adapter: "HDHomeRun DVB-C Tuner #0 (10.0.42.125)", network: "Yousee", mux: "474MHz", provider: "YouSee", service: "SVT1HD", profile="webtv-vp8-vorbis-webm" 
2015-05-13 06:03:30.702 [   INFO] transcode: 0002: 1:H264 1280x720 ==> VP8 682x384 (libvpx)
2015-05-13 06:03:30.702 [   INFO] transcode: 0002: 2:TELETEXT ==> Filtered
2015-05-13 06:03:30.702 [   INFO] transcode: 0002: 3:AC3 ==> VORBIS (libvorbis)
2015-05-13 06:03:30.980 [   INFO] transcode: 0002: 1:H264 1280x720 ==> VP8 682x384 (libvpx)
2015-05-13 06:03:30.980 [   INFO] transcode: 0002: 2:TELETEXT ==> Filtered
2015-05-13 06:03:30.981 [   INFO] transcode: 0002: 3:AC3 ==> VORBIS (libvorbis)
2015-05-13 06:03:31.215 [   INFO] libav: Increasing reorder buffer to 1
2015-05-13 06:03:31.279 [ NOTICE] libav: v1.3.0
2015-05-13 06:03:39.677 [   INFO] dvr: /mnt/SeagateUSB/tv_recordings/SVT1HD-Godmorgen-Sverige---sammendrag.2015-05-13.06-05.mkv from adapter: "HDHomeRun DVB-C Tuner #0 (10.0.42.125)", network: "Yousee", mux: "474MHz", provider: "YouSee", service: "SVT1HD" 
2015-05-13 06:03:39.677 [   INFO] dvr:  #  type              lang  resolution  aspect ratio  sample rate  channels
2015-05-13 06:03:39.677 [   INFO] dvr:  1  VP8                     682x384     16:9
2015-05-13 06:03:39.677 [   INFO] dvr:  3  VORBIS            swe                             48000        2
2015-05-13 06:06:40.642 [   INFO] subscription: 04AE: "HTTP" unsubscribing, hostname="10.0.42.109", username="VLC/2.2.1 LibVLC/2.2.1" 
2015-05-13 06:06:49.101 [   INFO] subscription: 04AF: "HTTP" unsubscribing, hostname="10.0.42.109", username="VLC/2.2.1 LibVLC/2.2.1" 
2015-05-13 06:06:53.347 [   INFO] subscription: 04B0: "HTTP" unsubscribing, hostname="10.0.42.109", username="VLC/2.2.1 LibVLC/2.2.1" 
2015-05-13 06:06:53.878 [   INFO] subscription: 04B1: "HTTP" unsubscribing, hostname="10.0.42.109", username="VLC/2.2.1 LibVLC/2.2.1" 
2015-05-13 06:13:45.195 [WARNING] epggrab: EIT: DVB Grabber - data completion timeout for 474MHz in Yousee
2015-05-13 06:26:00.880 [   INFO] subscription: 04AB: "DVR: Godmorgen Sverige - sammendrag" unsubscribing from "SVT1HD" 
2015-05-13 06:26:00.946 [WARNING] libav: 8 frames left in the queue on closing
2015-05-13 06:26:00.983 [   INFO] dvr: "Godmorgen Sverige - sammendrag" on "SVT1HD": End of program: Completed OK

Can I see the command/parameters tvheadend uses? I'd like to "post-transcode" a recording with same parameters as tvheadend, to see if that also cuts the recording. If it does, it must be the libraries used on my system that are broken...

#6

Updated by Jaroslav Kysela over 9 years ago

Danni Finne wrote:

Jaroslav Kysela wrote:

You should see the reason of the cut in logs...

This is console output for a transcoded (vorbis) recording. Only thing I see is "8 frames left in queue on closing".

[...]

Can I see the command/parameters tvheadend uses? I'd like to "post-transcode" a recording with same parameters as tvheadend, to see if that also cuts the recording. If it does, it must be the libraries used on my system that are broken...

Sorry, it's not easy to correlate the cmd-line parameters with the direct ffmpeg-lib calls.

What does say 'mkvinfo -v -v' for this file, do you see frames up to the end of recordings (check timecodes) ?

#7

Updated by Danni Finne over 9 years ago

Jaroslav Kysela wrote:

What does say 'mkvinfo -v -v' for this file, do you see frames up to the end of recordings (check timecodes) ?

Last couple of timecode in mkvinfo -v -v output is:

| + SimpleBlock (key, track number 2, 1 frame(s), timecode 548.802s = 00:09:08.802) at 94632123
| + SimpleBlock (key, track number 2, 1 frame(s), timecode 548.805s = 00:09:08.805) at 94632183
| + SimpleBlock (key, track number 2, 1 frame(s), timecode 548.808s = 00:09:08.808) at 94632245
| + SimpleBlock (key, track number 2, 1 frame(s), timecode 548.810s = 00:09:08.810) at 94632305
| + SimpleBlock (key, track number 2, 1 frame(s), timecode 548.813s = 00:09:08.813) at 94632370
| + SimpleBlock (key, track number 2, 1 frame(s), timecode 548.816s = 00:09:08.816) at 94632438
| + SimpleBlock (key, track number 2, 1 frame(s), timecode 548.818s = 00:09:08.818) at 94632502

So (I think - not familiar with mkvinfo) I see frames up until the end of the file... Problem is the end of the file is too soon :-)

This is only 09:08 minutes long and it should be 22 minutes, which is also registered in tvheadend Duration.

#8

Updated by Jaroslav Kysela over 9 years ago

I did a quick test here (70 min recordings) without this issue - I have all frames in .mkv file correctly.

Could you compile tvh with --enable-trace (or use the debug package) and enable 'service,subscription,parsers,descrambler' subsystems to get a more complete log ?

#9

Updated by Danni Finne over 9 years ago

Jaroslav Kysela wrote:

Could you compile tvh with --enable-trace (or use the debug package) and enable 'service,subscription,parsers,descrambler' subsystems to get a more complete log ?

Sure, log is attached. Recorded something random called "Happy Endings (48)" that is 22mins long.

When I watch it it is 11mins long.

#10

Updated by Jaroslav Kysela over 9 years ago

I see only some epggrab activity at the "cut" time. Could you disable three tuners? (keep active only one)

Also available in: Atom PDF