Reland MSE: Verify MediaLog events created by existing WebM unit tests

Reland MSE: Verify MediaLog events created by existing WebM unit tests

Similar to previous SourceBufferStreamTests update in r342861, this
change updates media unit tests to provide a StrictMock<MockMediaLog> to
verify MediaLog events produced with existing MSE WebM unit tests. While
log message maintenance burden is increased, helpers are included to
reduce that burden while gaining improved resilience against logging
regression.

This CL does not verify all possible MSE WebM parser MEDIA_LOGs, just
those that are emitted by existing unit tests.

Versus previous land attempt (http://crrev.com/1300943002#ps40001), does
not verify sequence of MediaLogs in
WebMClusterParserTest.PreferOpusDurationsOverBlockDurations. This test
now only has about 3x execution time increase versus about 30x in prior
attempt.

BUG=524597
TEST=No regression locally on Linux.
R=xhwang@chromium.org,chcunningham@chromium.org

Committed: https://crrev.com/7305d9bf4014a3f75667d1e38123087a3229908b
Cr-Commit-Position: refs/heads/master@{#345634}

[wolenetz, 2015-08-25 19:29:43]

The CQ bit was checked by wolenetz@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2015-08-25 19:29:54]

Dry run: CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1306923004/1
View timeline at
 https://chromium-cq-status.appspot.com/patch-timeline/1306923004/1

[wolenetz, 2015-08-25 19:34:48]

Please take a look at patch set 1.
My current plan is to speculatively land this and watch the tree carefully for
any win7 dbg test problem like what occurred yesterday.
Do either of you know a better way than "speculatively landing" this CL to get a
bot to run this prior to landing? win7 dbg doesn't appear to be in the set of
Rietveld "try more bots".

https://codereview.chromium.org/1306923004/diff/1/media/formats/webm/webm_clu...
File media/formats/webm/webm_cluster_parser_unittest.cc (right):

https://codereview.chromium.org/1306923004/diff/1/media/formats/webm/webm_clu...
media/formats/webm/webm_cluster_parser_unittest.cc:1073: // Exhaustively testing
expected media logs' emission sequence in this test at
Compared to previously reverted CL http://crrev.com/1300943002#ps40001, this
patch set #1 differs only in this comment, which replaces "InSequence s;", and
in the CL description of same.

I think we don't actually lose much coverage by removing InSequence, because
OpusPacketDurationTooHigh is tested elsewhere in these unit tests, and
WebMBlockDurationMismatchesOpusDuration logs tested here (not in sequence) are
explicitly parameterized by both expected times, which ALWAYS in this test case
differ by 10ms.

[xhwang, 2015-08-25 20:07:31]

Agreed InSequence isn't helping a lot. But it would be interesting to understand
why it's failing on that bot.

With that lgtm :)

[commit-bot: I haz the power, 2015-08-25 20:36:54]

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

[commit-bot: I haz the power, 2015-08-25 20:36:55]

Dry run: This issue passed the CQ dry run.

[wolenetz, 2015-08-25 20:39:04]

On 2015/08/25 20:07:31, xhwang wrote:
> Agreed InSequence isn't helping a lot. But it would be interesting to
understand
> why it's failing on that bot.
> 
> With that lgtm :)

Paraphrasing from chat:
My speculation is win7 limited stack space/efficiency vs other platforms led to
the failure, though I have no specific data indicated it was stack space
exhaustion that was crashing the previous CL on the win7 dbg test bot.

If patch set 1 works, a subsequence speculative change to try out InSequence
again for the Prefer* test, yet with <expectation>.RetireOnSaturation() and
especially ASSERT_TRUE(Mock::VerifyAndClearExpectations(media_log_)) after each
loop iteration to reduce complexity. These ideas come from reading
https://code.google.com/p/googlemock/wiki/CookBook.

[chcunningham, 2015-08-25 20:51:17]

lgtm

[wolenetz, 2015-08-25 20:59:43]

Thanks for reviews. Landing this is currently pending go/no-go from
sheriffs/trooper on #chromium irc.

[iannucci1, 2015-08-25 20:59:47]

The CQ bit was checked by iannucci@google.com

[iannucci1, 2015-08-25 21:00:00]

The CQ bit was unchecked by iannucci@google.com

[wolenetz, 2015-08-26 00:11:28]

On 2015/08/25 20:39:04, wolenetz wrote:
> On 2015/08/25 20:07:31, xhwang wrote:
> > Agreed InSequence isn't helping a lot. But it would be interesting to
> understand
> > why it's failing on that bot.
> > 
> > With that lgtm :)
> 
> Paraphrasing from chat:
> My speculation is win7 limited stack space/efficiency vs other platforms led
to
> the failure, though I have no specific data indicated it was stack space
> exhaustion that was crashing the previous CL on the win7 dbg test bot.
> 
> If patch set 1 works, a subsequence speculative change to try out InSequence
> again for the Prefer* test, yet with <expectation>.RetireOnSaturation() and
> especially ASSERT_TRUE(Mock::VerifyAndClearExpectations(media_log_)) after
each
> loop iteration to reduce complexity. These ideas come from reading
> https://code.google.com/p/googlemock/wiki/CookBook.

While waiting for win dbg trybots, I tried locally a modified version of this
that did Mock::VerifyAndClearExpectations(...). It didn't change the execution
time in either InSequence s version (still ~7 seconds) or no InSequence version
(still ~600ms).

What did work was to move the InSequence s; inside the loop, and
ASSERT_TRUE(Mock::VerifyAndClearExpectations(...)) at the end of each iteration.
This keeps execution time low, while not drastically increasing execution time
if many of the iterations fail to meet logging expectations (because they're
asserted every iteration). I still don't trust InSequence, so will keep with the
current patch set if it passes the bots, and later may try this modification.

[wolenetz, 2015-08-26 00:31:38]

On 2015/08/26 00:11:28, wolenetz wrote:
> On 2015/08/25 20:39:04, wolenetz wrote:
> > On 2015/08/25 20:07:31, xhwang wrote:
> > > Agreed InSequence isn't helping a lot. But it would be interesting to
> > understand
> > > why it's failing on that bot.
> > > 
> > > With that lgtm :)
> > 
> > Paraphrasing from chat:
> > My speculation is win7 limited stack space/efficiency vs other platforms led
> to
> > the failure, though I have no specific data indicated it was stack space
> > exhaustion that was crashing the previous CL on the win7 dbg test bot.
> > 
> > If patch set 1 works, a subsequence speculative change to try out InSequence
> > again for the Prefer* test, yet with <expectation>.RetireOnSaturation() and
> > especially ASSERT_TRUE(Mock::VerifyAndClearExpectations(media_log_)) after
> each
> > loop iteration to reduce complexity. These ideas come from reading
> > https://code.google.com/p/googlemock/wiki/CookBook.
> 
> While waiting for win dbg trybots, I tried locally a modified version of this
> that did Mock::VerifyAndClearExpectations(...). It didn't change the execution
> time in either InSequence s version (still ~7 seconds) or no InSequence
version
> (still ~600ms).
> 
> What did work was to move the InSequence s; inside the loop, and
> ASSERT_TRUE(Mock::VerifyAndClearExpectations(...)) at the end of each
iteration.
> This keeps execution time low, while not drastically increasing execution time
> if many of the iterations fail to meet logging expectations (because they're
> asserted every iteration). I still don't trust InSequence, so will keep with
the
> current patch set if it passes the bots, and later may try this modification.

I've uploaded that refinement as a follow-up CL at
https://codereview.chromium.org/1316013002.

[wolenetz, 2015-08-26 17:43:41]

http://build.chromium.org/p/tryserver.chromium.win/builders/win_chromium_dbg_...
passed. Sending to CQ.

[wolenetz, 2015-08-26 17:43:47]

The CQ bit was checked by wolenetz@chromium.org

[commit-bot: I haz the power, 2015-08-26 17:44:20]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1306923004/1
View timeline at
 https://chromium-cq-status.appspot.com/patch-timeline/1306923004/1

[wolenetz, 2015-08-26 17:45:30]

The CQ bit was unchecked by wolenetz@chromium.org

[wolenetz, 2015-08-26 17:49:29]

I'll send to CQ once tree is open, so I can more closely watch this land and get
tested.

[wolenetz, 2015-08-26 19:10:38]

The CQ bit was checked by wolenetz@chromium.org

[commit-bot: I haz the power, 2015-08-26 19:10:50]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1306923004/1
View timeline at
 https://chromium-cq-status.appspot.com/patch-timeline/1306923004/1

[commit-bot: I haz the power, 2015-08-26 19:17:47]

Committed patchset #1 (id:1)

[commit-bot: I haz the power, 2015-08-26 19:18:23]

Patchset 1 (id:??) landed as
https://crrev.com/7305d9bf4014a3f75667d1e38123087a3229908b
Cr-Commit-Position: refs/heads/master@{#345634}

[wolenetz, 2015-08-26 20:28:12]

So far, it appears this version is not breaking the tree's win7 tests dbg(1) bot
like Monday's: the waterfall bot has passed media_unittests:
http://build.chromium.org/p/chromium.win/builders/Win7%20Tests%20%28dbg%29%28...