Opened 16 years ago

Last modified 13 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: no Analyzed by developer: no

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@… 16 years ago.
The sample frame timestamp floating log fragment
mencoder-output.gz (14.7 KB ) - added by mplayer@… 16 years ago.
unpatched mencoder output
mencoder-valgrind (7.1 KB ) - added by mplayer@… 16 years ago.
some memory leaks found by valgrind

Download all attachments as: .zip

Change History (11)

by mplayer@…, 16 years ago

Attachment: mplayer-framestamp-float added

The sample frame timestamp floating log fragment

comment:1 by mplayer@…, 16 years ago

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 by mplayer@…, 16 years ago

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

by mplayer@…, 16 years ago

Attachment: mencoder-output.gz added

unpatched mencoder output

comment:3 by mplayer@…, 16 years ago

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.

by mplayer@…, 16 years ago

Attachment: mencoder-valgrind added

some memory leaks found by valgrind

comment:4 by mplayer@…, 16 years ago

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 by reimar, 16 years ago

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 by mplayer@…, 16 years ago

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 by reimar, 16 years ago

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 by compn, 13 years ago

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