Log FilterHost events in PipelineImpl to MediaLog.

Log FilterHost events in PipelineImpl to MediaLog.

BUG=
TEST=


Committed: http://src.chromium.org/viewvc/chrome?view=rev&revision=97073

[Scott Franklin, 2011-08-10 23:05:56]

Adds logging calls to everything in the FilterHost implementation section of
PipelineImpl.

[scherkus (not reviewing), 2011-08-10 23:14:42]

http://codereview.chromium.org/7587007/diff/1/media/base/media_log_event.h
File media/base/media_log_event.h (right):

http://codereview.chromium.org/7587007/diff/1/media/base/media_log_event.h#ne...
media/base/media_log_event.h:55: TIME_SET,
a few these events fire like... A LOT (esp. time)

are you aware of some of the perf impact of some of these changes?

[Scott Franklin, 2011-08-11 21:29:14]

http://codereview.chromium.org/7587007/diff/1/media/base/media_log_event.h
File media/base/media_log_event.h (right):

http://codereview.chromium.org/7587007/diff/1/media/base/media_log_event.h#ne...
media/base/media_log_event.h:55: TIME_SET,
On 2011/08/10 23:14:42, scherkus wrote:
> a few these events fire like... A LOT (esp. time)
> 
> are you aware of some of the perf impact of some of these changes?

The ones that get set a lot are time, buffered time, current read position, and
buffered bytes. The rest combined all fit nicely on a single screen on the
webpage, so I'm assuming their performance impact is minimal.

I previously filtered those four out in javascript to prevent them from
overflowing the page, and I didn't realize they got called as astoundingly often
as they do.

Fortunately, those were also the least useful of the bunch; current playback
time is interesting, but likely not something that provides much value. The rest
all reveal something interesting about the video encoding or media pipeline (for
instance, loaded appears to only ever be set to true for file:// urls? weird).

[scherkus (not reviewing), 2011-08-11 23:09:00]

http://codereview.chromium.org/7587007/diff/1/media/base/media_log_event.h
File media/base/media_log_event.h (right):

http://codereview.chromium.org/7587007/diff/1/media/base/media_log_event.h#ne...
media/base/media_log_event.h:55: TIME_SET,
On 2011/08/11 21:29:14, Scott Franklin wrote:
> On 2011/08/10 23:14:42, scherkus wrote:
> > a few these events fire like... A LOT (esp. time)
> > 
> > are you aware of some of the perf impact of some of these changes?
> 
> The ones that get set a lot are time, buffered time, current read position,
and
> buffered bytes. The rest combined all fit nicely on a single screen on the
> webpage, so I'm assuming their performance impact is minimal.
> 
> I previously filtered those four out in javascript to prevent them from
> overflowing the page, and I didn't realize they got called as astoundingly
often
> as they do.
> 
> Fortunately, those were also the least useful of the bunch; current playback
> time is interesting, but likely not something that provides much value. The
rest
> all reveal something interesting about the video encoding or media pipeline
(for
> instance, loaded appears to only ever be set to true for file:// urls? weird).

I was referring to the performance impact of constantly IPC'ing this information
even though media-internals isn't open

[Scott Franklin, 2011-08-12 01:35:33]

http://codereview.chromium.org/7587007/diff/1/media/base/media_log_event.h
File media/base/media_log_event.h (right):

http://codereview.chromium.org/7587007/diff/1/media/base/media_log_event.h#ne...
media/base/media_log_event.h:55: TIME_SET,
On 2011/08/11 23:09:00, scherkus wrote:
> On 2011/08/11 21:29:14, Scott Franklin wrote:
> > On 2011/08/10 23:14:42, scherkus wrote:
> > > a few these events fire like... A LOT (esp. time)
> > > 
> > > are you aware of some of the perf impact of some of these changes?
> > 
> > The ones that get set a lot are time, buffered time, current read position,
> and
> > buffered bytes. The rest combined all fit nicely on a single screen on the
> > webpage, so I'm assuming their performance impact is minimal.
> > 
> > I previously filtered those four out in javascript to prevent them from
> > overflowing the page, and I didn't realize they got called as astoundingly
> often
> > as they do.
> > 
> > Fortunately, those were also the least useful of the bunch; current playback
> > time is interesting, but likely not something that provides much value. The
> rest
> > all reveal something interesting about the video encoding or media pipeline
> (for
> > instance, loaded appears to only ever be set to true for file:// urls?
weird).
> 
> I was referring to the performance impact of constantly IPC'ing this
information
> even though media-internals isn't open

Ah. I did look into it a bit.
A system could exist wherein new MediaLogs notify MediaInternals of their
existence and only IPC data if there's a tab open. New tabs likewise notify
MediaInternals of _their_ existence as usual, at which point MediaInternals can
tell existing and new MediaLogs to send their data.

Two things would need to happen.
1. MediaInternals needs a way to send IPC messages. I'm... not sure how to do
this one.

2. MediaLog needs a way to receive them. Simply adding another message filter to
content/renderer/media will do the trick. MediaLogs can then just blindly send
their messages through the filter, which can, well, filter them out if there's
no one on the other end who wants them.

The question is, is it worth it for the number of messages being sent?
Without the 4 big ones, this set will amount to < 100 messages over the lifetime
of a video, which I'm assuming is a drop in the bucket. BUFFERED_EXTENTS_CHANGED
is much more common (perhaps several per second), but that could be rate-limited
to 1-2Hz or something.
On the other hand, only sending in the presence of a media-internals tab has the
benefit that people can add whatever logging calls they want with little to no
regard for performance.

So basically, I don't know if it's a good idea to do it or not.

[scherkus (not reviewing), 2011-08-16 18:15:13]

cool -- LGTM!

[commit-bot: I haz the power, 2011-08-17 01:00:42]

Change committed as 97073