Log out-of-order frames in chrome://media-internals.

Log out-of-order frames in chrome://media-internals.

BUG=703019
Review-Url: https://codereview.chromium.org/2770253004
Cr-Commit-Position: refs/heads/master@{#459871}
Committed: https://chromium.googlesource.com/chromium/src/+/44cce866bb03e9424ac86ac4cdff8500fd906567

[sandersd (OOO until July 31), 2017-03-24 23:00:23]

sandersd@chromium.org changed reviewers:
+ dalecurtis@chromium.org, wolenetz@chromium.org

[sandersd (OOO until July 31), 2017-03-24 23:00:23]

sandersd@chromium.org changed required reviewers:
+ dalecurtis@chromium.org

[sandersd (OOO until July 31), 2017-03-24 23:00:23]

Excerpt of the new log, as produced from the sample in the bug report:

00:00:00 322	event	PLAY
00:00:00 462	info	Decoded frame is out of timestamp order.
00:00:00 529	info	Decoded frame is out of timestamp order.
00:00:00 598	info	Decoded frame is out of timestamp order.
00:00:00 664	info	Decoded frame is out of timestamp order.
00:00:00 746	info	Decoded frame is out of timestamp order.
00:00:00 828	info	Decoded frame is out of timestamp order.
00:00:00 898	info	Decoded frame is out of timestamp order.
00:00:00 965	info	Decoded frame is out of timestamp order.
00:00:00 276	duration	30.950967
00:00:01 28	info	(Log limit reached. Further similar entries may be suppressed):
Decoded frame is out of timestamp order.
00:00:02 609	info	Selected video track: []

[DaleCurtis, 2017-03-24 23:19:18]

https://codereview.chromium.org/2770253004/diff/1/media/filters/video_rendere...
File media/filters/video_renderer_algorithm.cc (right):

https://codereview.chromium.org/2770253004/diff/1/media/filters/video_rendere...
media/filters/video_renderer_algorithm.cc:363: << "Dropping frame with timestamp
before the last rendered frame.";
Include timestamps?

https://codereview.chromium.org/2770253004/diff/1/media/filters/video_rendere...
media/filters/video_renderer_algorithm.cc:402: << "Decoded frame is out of
timestamp order.";
Include timestamp?

https://codereview.chromium.org/2770253004/diff/1/media/filters/video_rendere...
File media/filters/video_renderer_algorithm.h (right):

https://codereview.chromium.org/2770253004/diff/1/media/filters/video_rendere...
media/filters/video_renderer_algorithm.h:271: int out_of_order_frame_logs_ = 0;
Clear on Reset()?

[sandersd (OOO until July 31), 2017-03-24 23:50:59]

Example of the modified format:

00:00:00 654	event	PLAY
00:00:00 787	info	Decoded frame with timestamp 0.1326 s is out of order.
00:00:00 852	info	Decoded frame with timestamp 0.2 s is out of order.
00:00:00 918	info	Decoded frame with timestamp 0.266 s is out of order.
00:00:00 589	duration	30.950967
00:00:01 09	info	Decoded frame with timestamp 0.333 s is out of order.
00:00:01 92	info	Decoded frame with timestamp 0.4327 s is out of order.
00:00:01 151	info	Decoded frame with timestamp 0.4997 s is out of order.
00:00:01 220	info	Decoded frame with timestamp 0.5657 s is out of order.
00:00:01 306	info	Decoded frame with timestamp 0.6327 s is out of order.
00:00:01 353	info	(Log limit reached. Further similar entries may be
suppressed): Decoded frame with timestamp 0.6997 s is out of order.
00:00:01 605	info	Selected video track: []
00:00:01 607	video_buffering_state	BUFFERING_HAVE_NOTHING
00:00:01 608	video_buffering_state	BUFFERING_HAVE_ENOUGH
00:00:22 681	info	Selected video track: [1]
00:00:22 681	video_buffering_state	BUFFERING_HAVE_NOTHING
00:00:22 886	info	Dropping frame with timestamp 24.3683 s, which is earlier than
the last rendered frame (24.403 s).
00:00:23 535	video_buffering_state	BUFFERING_HAVE_ENOUGH
00:00:28 300	info	Selected video track: []

https://codereview.chromium.org/2770253004/diff/1/media/filters/video_rendere...
File media/filters/video_renderer_algorithm.cc (right):

https://codereview.chromium.org/2770253004/diff/1/media/filters/video_rendere...
media/filters/video_renderer_algorithm.cc:363: << "Dropping frame with timestamp
before the last rendered frame.";
On 2017/03/24 23:19:17, DaleCurtis wrote:
> Include timestamps?

Done.

https://codereview.chromium.org/2770253004/diff/1/media/filters/video_rendere...
media/filters/video_renderer_algorithm.cc:402: << "Decoded frame is out of
timestamp order.";
On 2017/03/24 23:19:17, DaleCurtis wrote:
> Include timestamp?

Done.

https://codereview.chromium.org/2770253004/diff/1/media/filters/video_rendere...
File media/filters/video_renderer_algorithm.h (right):

https://codereview.chromium.org/2770253004/diff/1/media/filters/video_rendere...
media/filters/video_renderer_algorithm.h:271: int out_of_order_frame_logs_ = 0;
On 2017/03/24 23:19:17, DaleCurtis wrote:
> Clear on Reset()?

Done.

[DaleCurtis, 2017-03-24 23:54:40]

lgtm

[sandersd (OOO until July 31), 2017-03-24 23:57:21]

sandersd@chromium.org changed reviewers:
+ emircan@chromium.org

[sandersd (OOO until July 31), 2017-03-24 23:57:21]

emircan@chromium.org: Please review changes in
content/renderer/media/webmediaplayer_ms*

[emircan, 2017-03-25 00:03:39]

lgtm

[sandersd (OOO until July 31), 2017-03-25 00:32:21]

The CQ bit was checked by sandersd@chromium.org

[commit-bot: I haz the power, 2017-03-25 00:33:04]

CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-03-25 02:33:33]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-03-25 02:33:34]

Try jobs failed on following builders:
  linux_chromium_chromeos_rel_ng on master.tryserver.chromium.linux (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.linux/builders/linux_chromium_...)

[sandersd (OOO until July 31), 2017-03-27 18:02:40]

The CQ bit was checked by sandersd@chromium.org

[commit-bot: I haz the power, 2017-03-27 18:04:20]

CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-03-27 20:51:20]

CQ is committing da patch.

Bot data: {"patchset_id": 20001, "attempt_start_ts": 1490637760360460,
"parent_rev": "1107d5c0934dadf9013fcc5fb7217001d543b122", "commit_rev":
"44cce866bb03e9424ac86ac4cdff8500fd906567"}

[commit-bot: I haz the power, 2017-03-27 20:52:10]

Description was changed from

==========
Log out-of-order frames in chrome://media-internals.

BUG=703019
==========

to

==========
Log out-of-order frames in chrome://media-internals.

BUG=703019

Review-Url: https://codereview.chromium.org/2770253004
Cr-Commit-Position: refs/heads/master@{#459871}
Committed:
https://chromium.googlesource.com/chromium/src/+/44cce866bb03e9424ac86ac4cdff...
==========

[commit-bot: I haz the power, 2017-03-27 20:52:12]

Committed patchset #2 (id:20001) as
https://chromium.googlesource.com/chromium/src/+/44cce866bb03e9424ac86ac4cdff...

[wolenetz, 2017-03-29 22:34:32]

post-landing lgtm with note:

https://codereview.chromium.org/2770253004/diff/20001/media/filters/video_ren...
File media/filters/video_renderer_algorithm.cc (right):

https://codereview.chromium.org/2770253004/diff/20001/media/filters/video_ren...
media/filters/video_renderer_algorithm.cc:318: frames_dropped_during_enqueue_ =
0;
post-review note: Clear on reset here could cause spamminess in media-internals
log easily exceeding the per-player / global log entry limit. sandersd@ ack'ed
offline and mentioned that isolating such overflow to be per-player, not against
global, is upcoming work.