Opened 12 years ago

Last modified 8 years ago

#935 new defect

mplayer video encoding does not use kernel-supplied v4l2 frame timestamp

Reported by: mplayer@… Owned by: reimar
Priority: important Component: ve
Version: 1.0rc2 Severity: major
Keywords: Cc: reimar
Blocked By: Blocking:
Reproduced by developer: Analyzed by developer:

Description

Encoding TV/PAL signal captured by bttv 878 card does not rely on precise kernel-supplied frame timestamps (buf.timestamp.tv_sec and buf.timestamp.tv_usec fields of the structure received from VIDIOC_DQBUF V4L2 ioctl).

This results in quickly floating timestamp error up to 0.45s observed range (-250ms..+200ms) on a pretty powerful Intel Pentium D 3GHz (2 cores) with 1Gb RAM, and as a consequense frame skip/duplicate frame messages forth and back approximately every dozen of frames; almost every frame if system has heavy disk I/O load.

Such frequent skipping/duplicating of frames results in noticeably jerky playback of recordeded AVI file. Also the resulting AVI file exposes A/V sync drift of roughly 10 seconds per 24 hours of recording.

As a workaround, -noskip parameter turns off the frame timestamp skipping/duplicating logic; the resulting AVI feels fine then. But as -noskip is not default, I feel the bug deserves fix before upcoming 1.0 release.

The kernel-supplied frame timestamps are very precise: they are at most few dozens microseconds(!) off even values - observed float is roughly 1000x larger proving the kernel-supplied timestamps are not being used (at least correctly).

Historically, the bug is there since at least 1.0-pre versions; but some mplayer version dated 1.5-2 years ago did not have tv->avi jerking problems. Unfortunatelly the well-working exact version is unknown (it is not even certain if v4l2 driver was used back then, not v4l(1) - alas).

Also, doing the tv->avi capture (of 768x288 YUV videostream) with mplayer-1.0-rc2 cvs 24929 major memory leak experienced: on mostly idle system it is roughly 5Mb per hour (which can be explained by in-memory AVI index, for example); but putting noticeable disk I/O load on the system (leading to the more frequent skip/duplicate problem) the leak speed noticeably grows to 10-50Mb per hour. A major disk I/O activity spike almost always leads to terrible paging activity for a minute or two, and when the trashing ceases the mencoder process is found to occupy 500-1500Mb of virtual memory (versus ~70Mb right after startup) having swapped out almost everything else; in roughtly 10% cases mencoder then hangs consuming no CPU (with log ending by a horde of messages 'video buffer full - dropping frame'), in other 90% cases it recovers and continues writing with greatly reduced framerate (hmm?), or with up-to-a-couple-of minutes A/V desync in resulting AVI (with totally continuous and quality sound but extremely poor video framerate during the pagetrashing period). Obviously, stopping such mencoder instance also triggers major paging activity: up to 1-2 minutes to write out AVI index and exit on otherwise idle system, that's frustrating.

I have no proof (or even certainity) that the memory leakage results because of wrongly timestamped frames; additional doubts are raised by the fact that even with -noskip option mencoder still exposes the major memory leak (but does -noskip make interframe durations really even?); as both problems occurs under the same conditions they well might be interlinked - maybe lavc leaks memory if presented with uneven interframe timings? Any way, it worth rechecking after the frame timestamp problem patch becomes available, unless someone experienced spots a leak source before that.

Attachments (3)

mplayer-framestamp-float (56.4 KB) - added by mplayer@… 12 years ago.
The sample frame timestamp floating log fragment
mencoder-output.gz (14.7 KB) - added by mplayer@… 12 years ago.
unpatched mencoder output
mencoder-valgrind (7.1 KB) - added by mplayer@… 12 years ago.
some memory leaks found by valgrind

Download all attachments as: .zip

Change History (11)

Changed 12 years ago by mplayer@…

The sample frame timestamp floating log fragment

comment:1 Changed 12 years ago by mplayer@…

This log is taken by uncommenting and slightly extending the debug print at mencoder.c line 1277, and rasing predicates on the following dozen lines to use mux_frametime*10 as cutoff, not mux_frametime - to make it obvious that captures frames are not really get lost or duplicated, as v_timer_corr keeps floating around zero.

comment:2 Changed 12 years ago by mplayer@…

BTW that's the options mencoder get started with:

nice -n0 mencoder -tv driver=v4l2:alsa:width=768:height=288:immediatemode=0:volume=50:normid=0:channels=$CHANLIST -ovc lavc -lavcopts vcodec=mpeg4:vbitrate=1750 -oac mp3lame -lameopts abr:br=96 tv://1

Changed 12 years ago by mplayer@…

unpatched mencoder output

comment:3 Changed 12 years ago by mplayer@…

Here is the log of unmodified mencoder, run under moderate disk I/O load and at least 40% CPU (P4 3Ghz 2-core) idle all the time. Exposes all the startup details, as well as the frequent skip/duplicate frame problem.

Changed 12 years ago by mplayer@…

some memory leaks found by valgrind

comment:4 Changed 12 years ago by mplayer@…

Here is some leaks valgrind detects with mplayer. Performance under valgrind is not perfect at all, so it is difficult to run even 96x72 pixels capture (anyone running AMD high-GHz system? you might have better luck with valgrind than on HT or 2-core Intel). But still, the 150Kb of definitelly lost memory in roughly 40 seconds is roughly 10Mb/per hour, approximatelly the amount of leak factually observed so hopefully the real leak (versus 'incomplete shutdown' leaks - freeing a structure but not a memory block pointed from within the structure) is in the list.

Hmm, probably the memory leaking issue deserves a separate bug already?

comment:5 Changed 12 years ago by reimar

The huge memleak you describe has been found by someone else as well and went completely away by using a different kernel (IIRC both newer and older versions work).

comment:6 Changed 12 years ago by mplayer@…

The huge memory leak currently occurs with linux 2.6.23.1; previously it was persisting with 2.6.20.6, 2.6.17.11, and even before that - with kernels 2.6.16, 2.6.15, etc. Kernel replacement never lead to memory leak speed change here.

comment:7 Changed 12 years ago by reimar

  • Cc Reimar.Doeffinger@… added

As to the memleak: Sorry, the other one was more like 10 MB/min, I misread.
Better try with -noidx to make sure, those skipped frames might simply bloat the index greatly, which is not _really_ a bug.

Encoding TV/PAL signal captured by bttv 878 card does not rely on precise
kernel-supplied frame timestamps (buf.timestamp.tv_sec and
buf.timestamp.tv_usec fields of the structure received from VIDIOC_DQBUF V4L2
ioctl).

Actually it does, but it adjusts it to keep A-V sync (tvi_v4l2.c, line 1724). Possibly the algorithm to do that adjustment is buggy, or the quartz on either the soundcard or the TV card is very much off the correct frequency.
Unfortunately I do not have the hardware to test.

comment:8 Changed 8 years ago by compn

  • Owner changed from r_togni@… to reimar
Note: See TracTickets for help on using tickets.