1538933 - Intermittent VideoFrameConverterTest.Duplication | Expected: (frames[1].second()) > (now + TimeDuration::FromMilliseconds(1100)), actual: 24-byte object <69-8E 86-9A DA-02 00-00 D0-58 22-B9 DA-02 00-00 00-00 01-E4 FF-7F 00-00> vs 24-byte object

Status: RESOLVED DUPLICATE of bug 1660174

(Core :: WebRTC: Audio/Video, defect, P5)

Description

[Treeherder Bug Filer]

#[markdown(off)]
Filed by: cbrindusan [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=235905939&repo=mozilla-central

https://queue.taskcluster.net/v1/task/DFM32D_bTbyMK_G3F0WeLw/runs/0/artifacts/public/logs/live_backing.log

17:42:43 INFO - TEST-START | VideoFrameConverterTest.Duplication
17:42:45 WARNING - TEST-UNEXPECTED-FAIL | VideoFrameConverterTest.Duplication | Expected: (frames[1].second()) > (now + TimeDuration::FromMilliseconds(1100)), actual: 24-byte object <69-8E 86-9A DA-02 00-00 D0-58 22-B9 DA-02 00-00 00-00 01-E4 FF-7F 00-00> vs 24-byte object <6F-5C 64-98 DA-02 00-00 04-7A 22-B9 DA-02 00-00 00-00 01-33 F8-7F 00-00> @ z:/build/build/src/dom/media/gtest/TestVideoFrameConverter.cpp:137
17:42:45 WARNING - TEST-UNEXPECTED-FAIL | VideoFrameConverterTest.Duplication | test completed (time: 1102ms)

Comment 1

[Intermittent Failures Robot]

1 failures in 3910 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• windows10-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1538933&startday=2019-03-25&endday=2019-03-31&tree=all

Comment 2

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 3

[Intermittent Failures Robot]

1 failures in 4730 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1538933&startday=2019-05-20&endday=2019-05-26&tree=all

Comment 4

[Cristina Coroiu [:ccoroiu]]

Recent failure log:
task 2019-07-11T11:25:28.111Z] 11:25:28 INFO - TEST-PASS | testAssistIntentNewIntent | The toolbar is in the editing state -
[task 2019-07-11T11:25:28.111Z] 11:25:28 INFO - Buffered messages finished
[task 2019-07-11T11:25:28.111Z] 11:25:28 WARNING - TEST-UNEXPECTED-FAIL | testAssistIntentNewIntent | Waiting for Toolbar to exit editing mode. -
[task 2019-07-11T11:25:28.111Z] 11:25:28 INFO - 0 ERROR Exception caught during test! - junit.framework.AssertionFailedError: TEST-UNEXPECTED-FAIL | testAssistIntentNewIntent | Waiting for Toolbar to exit editing mode. -
[task 2019-07-11T11:25:28.111Z] 11:25:28 INFO - at junit.framework.Assert.fail(Assert.java:50)
[task 2019-07-11T11:25:28.112Z] 11:25:28 INFO - at org.mozilla.gecko.FennecMochitestAssert._logMochitestResult(FennecMochitestAssert.java:124)
[task 2019-07-11T11:25:28.112Z] 11:25:28 INFO - at org.mozilla.gecko.FennecMochitestAssert.ok(FennecMochitestAssert.java:145)
[task 2019-07-11T11:25:28.113Z] 11:25:28 INFO - at org.mozilla.gecko.tests.helpers.AssertionHelper.fAssertTrue(AssertionHelper.java:98)
[task 2019-07-11T11:25:28.113Z] 11:25:28 INFO - at org.mozilla.gecko.tests.helpers.WaitHelper.waitFor(WaitHelper.java:63)
[task 2019-07-11T11:25:28.114Z] 11:25:28 INFO - at org.mozilla.gecko.tests.components.ToolbarComponent.waitForNotEditing(ToolbarComponent.java:319)
[task 2019-07-11T11:25:28.115Z] 11:25:28 INFO - at org.mozilla.gecko.tests.components.ToolbarComponent.dismissEditingMode(ToolbarComponent.java:247)
[task 2019-07-11T11:25:28.115Z] 11:25:28 INFO - at org.mozilla.gecko.tests.AssistIntentTest.verifyAssistIntentHandling(AssistIntentTest.java:26)
[task 2019-07-11T11:25:28.116Z] 11:25:28 INFO - at org.mozilla.gecko.tests.testAssistIntentNewIntent.testAssistIntentNewIntent(testAssistIntentNewIntent.java:26)
[task 2019-07-11T11:25:28.116Z] 11:25:28 INFO - at java.lang.reflect.Method.invokeNative(Native Method)
[task 2019-07-11T11:25:28.116Z] 11:25:28 INFO - at java.lang.reflect.Method.invoke(Method.java:525)
[task 2019-07-11T11:25:28.117Z] 11:25:28 INFO - at android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:214)
[task 2019-07-11T11:25:28.117Z] 11:25:28 INFO - at android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:199)
[task 2019-07-11T11:25:28.118Z] 11:25:28 INFO - at android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:192)
[task 2019-07-11T11:25:28.119Z] 11:25:28 INFO - at org.mozilla.gecko.tests.BaseRobocopTest.runTest(BaseRobocopTest.java:188)
[task 2019-07-11T11:25:28.119Z] 11:25:28 INFO - at junit.framework.TestCase.runBare(TestCase.java:134)
[task 2019-07-11T11:25:28.119Z] 11:25:28 INFO - at junit.framework.TestResult$1.protect(TestResult.java:115)
[task 2019-07-11T11:25:28.120Z] 11:25:28 INFO - at junit.framework.TestResult.runProtected(TestResult.java:133)
[task 2019-07-11T11:25:28.120Z] 11:25:28 INFO - at junit.framework.TestResult.run(TestResult.java:118)
[task 2019-07-11T11:25:28.121Z] 11:25:28 INFO - at junit.framework.TestCase.run(TestCase.java:124)
[task 2019-07-11T11:25:28.121Z] 11:25:28 INFO - at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:191)
[task 2019-07-11T11:25:28.121Z] 11:25:28 INFO - at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:176)
[task 2019-07-11T11:25:28.122Z] 11:25:28 INFO - at android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:554)
[task 2019-07-11T11:25:28.122Z] 11:25:28 INFO - at org.mozilla.gecko.FennecInstrumentationTestRunner.onStart(FennecInstrumentationTestRunner.java:66)
[task 2019-07-11T11:25:28.123Z] 11:25:28 INFO - at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1701)
[task 2019-07-11T11:25:28.123Z] 11:25:28 WARNING - TEST-UNEXPECTED-FAIL | testAssistIntentNewIntent | Exception caught - junit.framework.AssertionFailedError: TEST-UNEXPECTED-FAIL | testAssistIntentNewIntent | Waiting for Toolbar to exit editing mode. -
[task 2019-07-11T11:25:28.123Z] 11:25:28 INFO - TEST-OK | testAssistIntentNewIntent | took 73782ms

Comment 5

[Intermittent Failures Robot]

1 failures in 4710 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-release: 1

Platform breakdown:

• windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1538933&startday=2019-07-08&endday=2019-07-14&tree=all

Comment 6

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1538933 - Compare TimeDuration instead of TimeStamp in TestVideoFrameConverter for sensible logs. r?bwc

Depends on D40599

Comment 7

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/9f6cb22cf3e2
Compare TimeDuration instead of TimeStamp in TestVideoFrameConverter for sensible logs. r=bwc

Comment 8

[Stefan Hindli [:stefan_hindli]]

https://hg.mozilla.org/mozilla-central/rev/9f6cb22cf3e2

Comment 9

[Intermittent Failures Robot]

2 failures in 4666 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1
• autoland: 1

Platform breakdown:

• windows7-32: 1
• windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1538933&startday=2019-08-05&endday=2019-08-11&tree=all

Comment 10

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1538933 - Convert remaining TimeStamp checks to use TimeDuration. r?bwc

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/c7035d0cf37c
Convert remaining TimeStamp checks to use TimeDuration. r=bwc

Comment 12

[Bogdan Tara[:bogdan_tara | bogdant]]

https://hg.mozilla.org/mozilla-central/rev/c7035d0cf37c

Comment 13

[Intermittent Failures Robot]

1 failures in 4182 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1538933&startday=2019-10-21&endday=2019-10-27&tree=all

Comment 14

[Andreas Pehrson [:pehrsons]]

That last failure's log says:

[task 2019-10-21T07:44:11.473Z] 07:44:11 WARNING - TEST-UNEXPECTED-FAIL | VideoFrameConverterTest.Duplication | Expected: (TimeStamp::Now() - now) > (TimeDuration::FromMilliseconds(1100)), actual: 1099.98 ms vs 1100 ms @ z:/build/build/src/dom/media/gtest/TestVideoFrameConverter.cpp:135
[task 2019-10-21T07:44:11.473Z] 07:44:11 WARNING - TEST-UNEXPECTED-FAIL | VideoFrameConverterTest.Duplication | Expected: (frames[1].second() - now) > (TimeDuration::FromMilliseconds(1100)), actual: 1099.95 ms vs 1100 ms @ z:/build/build/src/dom/media/gtest/TestVideoFrameConverter.cpp:142
[task 2019-10-21T07:44:11.473Z] 07:44:11 WARNING - TEST-UNEXPECTED-FAIL | VideoFrameConverterTest.Duplication | test completed (time: 1104ms)

The only fuzziness I found in the same-frame 1s timer (i.e., nsTimer) was this: https://searchfox.org/mozilla-central/rev/6566d92dd46417a2f57e75c515135ebe84c9cef5/xpcom/threads/TimerThread.cpp#381-383

I wonder how many microseconds we're talking about for various platforms here.

Comment 15

[Intermittent Failures Robot]

1 failures in 4867 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-esr68: 1

Platform breakdown:

• windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1538933&startday=2019-12-09&endday=2019-12-15&tree=all

Comment 16

[Intermittent Failures Robot]

1 failures in 4727 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1538933&startday=2020-05-18&endday=2020-05-24&tree=all

Comment 17

[Andreas Pehrson [:pehrsons]]

This is getting fixed in bug 1660174.