1522621 - Intermittent /resource-timing/buffer-full-inspect-buffer-during-callback.html | Test that entries in the secondary buffer are not exposed during the callback and before they are copied to the primary buffer - assert_equals: All 4 entries should be stored

Status: RESOLVED FIXED

(Core :: Performance, defect, P1)

Description

[Treeherder Bug Filer]

Filed by: nbeleuzu [at] mozilla.com

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

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

[task 2019-01-24T13:07:27.302Z] 13:07:27 INFO - PID 16658 | JavaScript error: http://web-platform.test:8000/resource-timing/resources/buffer-full-utilities.js, line 12: uncaught exception: Error: assert_equals: A sync request was not added to the primary buffer just yet, because it is full expected 1297 but got 1296
[task 2019-01-24T13:07:27.302Z] 13:07:27 INFO - PID 16658 | JavaScript error: http://web-platform.test:8000/resource-timing/resources/buffer-full-utilities.js, line 12: uncaught exception: Error: assert_equals: A sync request was not added to the primary buffer just yet, because it is full expected 1297 but got 1296
[task 2019-01-24T13:07:27.303Z] 13:07:27 INFO - PID 16658 | JavaScript error: http://web-platform.test:8000/resource-timing/resources/buffer-full-utilities.js, line 12: uncaught exception: Error: assert_equals: A sync request was not added to the primary buffer just yet, because it is full expected 1297 but got 1296
[task 2019-01-24T13:07:27.303Z] 13:07:27 INFO - PID 16658 | JavaScript error: , line 0: uncaught exception: Error: assert_equals: A sync request was not added to the primary buffer just yet, because it is full expected 1297 but got 1296
[task 2019-01-24T13:07:27.453Z] 13:07:27 INFO - Closing window 21474836481
[task 2019-01-24T13:07:27.503Z] 13:07:27 INFO -
[task 2019-01-24T13:07:27.504Z] 13:07:27 INFO - TEST-UNEXPECTED-FAIL | /resource-timing/buffer-full-inspect-buffer-during-callback.html | Test that entries in the secondary buffer are not exposed during the callback and before they are copied to the primary buffer - assert_equals: All 4 entries should be stored in resource timing buffer. expected 1298 but got 1297
[task 2019-01-24T13:07:27.504Z] 13:07:27 INFO - testThatBufferContainsTheRightResources@http://web-platform.test:8000/resource-timing/buffer-full-inspect-buffer-during-callback.html:40:5
[task 2019-01-24T13:07:27.504Z] 13:07:27 INFO - @http://web-platform.test:8000/resource-timing/buffer-full-inspect-buffer-during-callback.html:52:5
[task 2019-01-24T13:07:27.504Z] 13:07:27 INFO - asyncTest.prototype.step@http://web-platform.test:8000/resources/testharness.js:1566:20
[task 2019-01-24T13:07:27.505Z] 13:07:27 INFO - promise_test/tests.promise_tests</<@http://web-platform.test:8000/resources/testharness.js:591:31
[task 2019-01-24T13:07:27.505Z] 13:07:27 INFO - promise_test/tests.promise_tests<@http://web-platform.test:8000/resources/testharness.js:590:20
[task 2019-01-24T13:07:27.505Z] 13:07:27 INFO - promise callbackpromise_test@http://web-platform.test:8000/resources/testharness.js:589:31
[task 2019-01-24T13:07:27.505Z] 13:07:27 INFO - @http://web-platform.test:8000/resource-timing/buffer-full-inspect-buffer-during-callback.html:48:1
[task 2019-01-24T13:07:27.506Z] 13:07:27 INFO - TEST-INFO | expected TIMEOUT
[task 2019-01-24T13:07:27.507Z] 13:07:27 INFO - TEST-ERROR | /resource-timing/buffer-full-inspect-buffer-during-callback.html | took 7843ms
[task 2019-01-24T13:07:27.528Z] 13:07:27 INFO - PID 16658 | 1548335247522 Marionette INFO Stopped listening on port 2828
[task 2019-01-24T13:07:27.652Z] 13:07:27 INFO - PID 16658 | [Parent 16658, Gecko_IOThread] WARNING: pipe error (86): Connection reset by peer: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 357
[task 2019-01-24T13:07:27.652Z] 13:07:27 INFO - PID 16658 | [Parent 16658, Gecko_IOThread] WARNING: pipe error (87): Connection reset by peer: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 357
[task 2019-01-24T13:07:28.121Z] 13:07:28 INFO - Browser exited with return code 0
[task 2019-01-24T13:07:28.122Z] 13:07:28 INFO - PROCESS LEAKS None
[task 2019-01-24T13:07:28.124Z] 13:07:28 INFO - Closing logging queue
[task 2019-01-24T13:07:28.124Z] 13:07:28 INFO - queue closed
[task 2019-01-24T13:07:28.145Z] 13:07:28 INFO - Setting up ssl
[task 2019-01-24T13:07:28.182Z] 13:07:28 INFO - certutil |
[task 2019-01-24T13:07:28.210Z] 13:07:28 INFO - certutil |
[task 2019-01-24T13:07:28.234Z] 13:07:28 INFO - certutil |
[task 2019-01-24T13:07:28.234Z] 13:07:28 INFO - Certificate Nickname Trust Attributes
[task 2019-01-24T13:07:28.234Z] 13:07:28 INFO - SSL,S/MIME,JAR/XPI
[task 2019-01-24T13:07:28.234Z] 13:07:28 INFO -
[task 2019-01-24T13:07:28.235Z] 13:07:28 INFO - web-platform-tests CT,,
[task 2019-01-24T13:07:28.235Z] 13:07:28 INFO -
[task 2019-01-24T13:07:28.271Z] 13:07:28 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox --marionette about:blank -profile /tmp/tmpV7k6yn.mozrunner
[task 2019-01-24T13:07:28.292Z] 13:07:28 INFO - Starting runner
[task 2019-01-24T13:07:28.810Z] 13:07:28 INFO - PID 18444 | 1548335248800 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: mozillaAddons
[task 2019-01-24T13:07:28.811Z] 13:07:28 INFO - PID 18444 | 1548335248800 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: resource://pdf.js/
[task 2019-01-24T13:07:28.811Z] 13:07:28 INFO - PID 18444 | 1548335248800 [e-mail] WARN Loading extension '[e-mail]': Reading manifest: Invalid extension permission: about:reader*
[task 2019-01-24T13:07:31.668Z] 13:07:31 INFO - PID 18444 | 1548335251663 Marionette INFO Listening on port 2828

Comment 1

[Intermittent Failures Robot]

17 failures in 2383 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 15
• mozilla-central: 2

Platform breakdown:

• linux64-devedition: 6
• linux64-nightly: 6
• linux32: 2
• linux32-nightly: 2
• linux32-devedition: 1

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

Comment 2

[Intermittent Failures Robot]

27 failures in 517 pushes (0.052 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-beta: 17
• cedar: 1
• mozilla-inbound: 3
• autoland: 2
• try: 2
• mozilla-central: 2

Platform breakdown:

• linux32: 9
• linux64-nightly: 5
• linux64-devedition: 12
• linux32-devedition: 1

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

Comment 3

[Hsin-Yi Tsai (she/her) [:hsinyi]]

Hi James, I wonder if there are changes to WPT harness recently. There are several wpt intermittent failures whose failure rate increased these days.

Comment 4

[James Graham [:jgraham]]

Yeah, we changed from running the driver script (injected via marionette) in the test window instead of in the opener window. That's important for some kinds of tests since it allows the test window to be a true top level window with null opener, but does mean that we are getting different behaviour in edge conditions. I don't know if/how marionette-injected script will interfere with resource timing (it's basically running in a frame-script).

Comment 5

[Intermittent Failures Robot]

20 failures in 481 pushes (0.042 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-inbound: 4
• autoland: 12
• mozilla-central: 2
• try: 2

Platform breakdown:

• linux32: 18
• linux64-devedition: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1522621&startday=2019-02-01&endday=2019-02-01&tree=all

Comment 6

[Hsin-Yi Tsai (she/her) [:hsinyi]]

(In reply to James Graham [:jgraham] from comment #4)

Yeah, we changed from running the driver script (injected via marionette) in the test window instead of in the opener window. That's important for some kinds of tests since it allows the test window to be a true top level window with null opener, but does mean that we are getting different behaviour in edge conditions. I don't know if/how marionette-injected script will interfere with resource timing (it's basically running in a frame-script).

Thanks James!

Comment 7

[Andreea Pavel [:apavel]]

This should be fixed by https://hg.mozilla.org/mozilla-central/rev/26db1cffe8de98af57fabb6db36401cf5cb393b7

Turned perma when 1522837 landed, no other occurrences on integration branches since the backout landed.

Only occurrences are on mozilla-beta and beta sims

sim: https://treeherder.mozilla.org/#/jobs?repo=try&revision=d4da4e041cd615bd72e0f963a70752ef5bbb612a&searchStr=os%2Cx%2C10.10%2Cnightly%2Copt%2Cweb%2Cplatform%2Ctests%2Cwith%2Ce10s%2Ctest-macosx64-nightly%2Fopt-web-platform-tests-e10s-7%2Cw-e10s%28wpt7%29&selectedJob=225670969

beta: https://treeherder.mozilla.org/#/jobs?repo=mozilla-beta&resultStatus=testfailed%2Cbusted%2Cexception&classifiedState=unclassified&fromchange=69a3d7c8d04bb6959e105b0c46d0aed4dda85ad9&selectedJob=225684467

Comment 8

[Intermittent Failures Robot]

74 failures in 2628 pushes (0.028 failures/push) were associated with this bug in the last 7 days.

This is the #20 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• oak: 1
• try: 20
• mozilla-beta: 26
• autoland: 14
• mozilla-central: 5
• cedar: 1
• mozilla-inbound: 7

Platform breakdown:

• linux32: 31
• linux32-devedition: 2
• linux64-nightly: 11
• linux64-devedition: 24
• linux32-nightly: 2
• macosx64-nightly: 4

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

Comment 9

[Hsin-Yi Tsai (she/her) [:hsinyi]]

Thanks for the comment 7. My understanding is that this falls at Performance team's wheelhouse (as this is the test of performance API) so moving there to get proper attention. Feel free to reset if I got something wrong.

Comment 10

[Intermittent Failures Robot]

19 failures in 379 pushes (0.05 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-inbound: 1
• mozilla-beta: 16
• try: 2

Platform breakdown:

• linux32: 1
• macosx64-nightly: 2
• linux64-nightly: 8
• linux64-devedition: 8

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1522621&startday=2019-02-04&endday=2019-02-04&tree=all

Comment 11

[Intermittent Failures Robot]

62 failures in 2658 pushes (0.023 failures/push) were associated with this bug in the last 7 days.

This is the #33 most frequent failure this week.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• try: 4
• mozilla-beta: 57
• mozilla-inbound: 1

Platform breakdown:

• macosx64-nightly: 4
• linux32: 9
• linux64-nightly: 26
• linux64-devedition: 23

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

Comment 12

[Intermittent Failures Robot]

15 failures in 533 pushes (0.028 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-beta: 15

Platform breakdown:

• linux64-nightly: 7
• linux64-devedition: 7
• linux32: 1

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

Comment 13

[Intermittent Failures Robot]

19 failures in 471 pushes (0.04 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-beta: 19

Platform breakdown:

• linux32-devedition: 1
• linux64-devedition: 11
• linux64-nightly: 7

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

Comment 14

[Intermittent Failures Robot]

42 failures in 2832 pushes (0.015 failures/push) were associated with this bug in the last 7 days.

This is the #40 most frequent failure this week.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• mozilla-beta: 42

Platform breakdown:

• linux32: 1
• linux32-devedition: 1
• linux64-devedition: 22
• linux64-nightly: 18

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

Comment 15

[Bogdan Tara[:bogdan_tara | bogdant]]

This seems to perma fail on beta:

https://treeherder.mozilla.org/#/jobs?repo=mozilla-beta&fromchange=e0e4b872648840352e81400e823a8b146f8780e3&selectedJob=229199833&searchStr=Linux%2Cx64%2Copt%2Cwpt11

Comment 16

[Intermittent Failures Robot]

25 failures in 501 pushes (0.05 failures/push) were associated with this bug yesterday.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• mozilla-beta: 25

Platform breakdown:

• linux64-devedition: 13
• linux64-nightly: 12

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1522621&startday=2019-02-19&endday=2019-02-19&tree=all

Comment 17

[Intermittent Failures Robot]

57 failures in 2602 pushes (0.022 failures/push) were associated with this bug in the last 7 days.

This is the #21 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• mozilla-beta: 57

Platform breakdown:

• linux64-devedition: 28
• linux64-nightly: 27
• linux32-devedition: 2

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

Comment 18

[Intermittent Failures Robot]

48 failures in 2981 pushes (0.016 failures/push) were associated with this bug in the last 7 days.

This is the #28 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• mozilla-beta: 48

Platform breakdown:

• linux64-devedition: 23
• linux64-nightly: 24
• linux32-devedition: 1

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

Comment 19

[Intermittent Failures Robot]

34 failures in 2818 pushes (0.012 failures/push) were associated with this bug in the last 7 days.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• mozilla-beta: 34

Platform breakdown:

• linux64-devedition: 14
• linux64-nightly: 10
• linux32-devedition: 10

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

Comment 20

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-release: 1

Platform breakdown:

• linux32-nightly: 1

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

Comment 21

[Will Hawkins]

This should be solved thanks to the solution for 1539006 and 1525051.

If you can confirm, Mr. Graham, we can close this one!

Thanks,
Will

Comment 22

[James Graham [:jgraham]]

OK, so I reenabled some tests and scheduled a try push: https://treeherder.mozilla.org/#/jobs?repo=try&revision=006f408b7ba5d3a31472865fbabaa22bbbfece6b

Hopefully that shows stability. If it does you should be able to land the patch. Note that in general I can't/shouldn't be on the critical path here; I simply don't have the bandwidth to do the test work every time something is fixed. Generally it's the reposibility of the engineers working on the feature to ensure that we have the appropriate test coverage and wpt tests enabled. Obviously I'm very happy to help with that process in any way I can, though.

Comment 23

[Kim Moir [:kmoir] ET]

:jgraham Did that commit stick? I just checked the try push but the push has expired in th and I can't see the results. I'm just following up because I want to close this performance bug if it's not relevant anymore.

Comment 24

[James Graham [:jgraham]]

I also have no memory of what happened in that try push, but the test is still disabled: https://searchfox.org/mozilla-central/source/testing/web-platform/meta/resource-timing/buffer-full-inspect-buffer-during-callback.html.ini I'd say we need to repeat the experiment of re-enabling it and see what happens.

Comment 25

[Sean Feng [:sefeng]]

I've fixed some similar bugs for performance apis, and I'll take a look.

Comment 26

[Kim Moir [:kmoir] ET]

Thanks Sean I really appreciate it!

Comment 27

[Sean Feng [:sefeng]]

Attachment: Bug 1522621 - Enable buffer-full-inspect-buffer-during-callback.html r=smaug

This test has been fixed in bug 1525051. We should enable it.

Comment 28

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/d24060ec6ddf
Enable buffer-full-inspect-buffer-during-callback.html r=smaug

Comment 29

[Cristina Coroiu [:ccoroiu]]

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

Comment 30

[Sean Feng [:sefeng]]

It's fixed, removing my NI.