[mythtv] [mythtv-commits] Ticket #8367: Log storm from bad h264 decoded video

[Marc Randolph]

On Mon, Apr 19, 2010 at 11:55 AM, Michael T. Dean
<mtdean at thirdcontact.com> wrote:
> On 04/19/2010 12:45 AM, MythTV wrote:
>>
>> #8367: Log storm from bad h264 decoded video
>>
>> -------------------------------------------+--------------------------------
>>  Reporter:  Robin Gilks<g8ecj@…>           |       Owner:  janne
>>      Type:  defect                         |      Status:  new
>>  Priority:  minor                          |   Milestone:  unknown
>> Component:  MythTV - Video Playback        |     Version:  0.23rc2
>>  Severity:  medium                         |     Mlocked:  0
>>
>> -------------------------------------------+--------------------------------
>>  Unrelated to #7982, error messages swamp the nfs network connection which
>>  cause error messages that swamp the nfs network connection which
>>  cause......
>>
>>  Averaging 8 messages per millisecond to the log. Currently running with
>> no
>>  '-v' options at all (i.e. mythfrontend>  /home/mythtv/mythfrontend.log
>>  2>&1)
>>
>>  2010-04-19 08:14:39.440 [h264 @ 0x7f301f5da500]number of reference frames
>>  exceeds max (probably corrupt input), discarding one
>
> Robin,
>
> Those messages are considered errors by libav*, so they're reported (since
> changes for #6729) at the general level of verbosity.  The MythTV default
> verbosity is -v important,general .  Because errors should be reported in
> default verbosity, libav* errors will likely remain at general verbose
> level.  So, if you don't want to see them, you'll need to run at -v
> important (or, whatever verbosity that doesn't include general).

Howdy Mike and others,

I understand and agree with the general "keep the error message" idea,
but 8 per millisecond is at the opposite extreme and not helpful in
the general case.  Could this (and other... perhaps all?) repeating
messages be thresholded when default logging is enabled by storing the
last item that was logged and discarding all identical log messages
that occur within the next second?  After 1 second, the process could
start over, so at most, you'd get one per second of such messages.

Between "number of reference frames exceeds max (probably corrupt
input), discarding one" that Robin mentions, and that I've
encountered, plus separately running into
RingBuf(/var/lib/mythtv/recordings/2008_20100408174700.mpg) Error:
Invalid file descriptor in 'safe_read()'  [33 times per millisecond]
or
TV: Attempting to change from None to None [8 times a second, per
http://svn.mythtv.org/trac/ticket/8244]

the result is that my log file sizes, not to mention in some cases,
apparent lock-ups, have increased dramatically since moving to 0.23
(with a correspondingly lower WAF).

Have fun,

   Marc