1263428 - Intermittent test_resource_timing.html | PerformanceEntry has correct order of timing attributes (link) - assert_greater_than_equal: connectStart after domainLookupEnd expected a number greater than or equal to 482.3286635493814 but got 482.28181595114637

Status: RESOLVED FIXED

(Core :: Networking, defect)

Description

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

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

23:53:17     INFO - TEST-PASS | /resource-timing/test_resource_timing.html | PerformanceEntry has correct name, initiatorType, startTime, and duration (img) 
23:53:17     INFO - TEST-PASS | /resource-timing/test_resource_timing.html | PerformanceEntry has correct order of timing attributes (img) 
23:53:17     INFO - TEST-PASS | /resource-timing/test_resource_timing.html | window.performance.getEntriesByName() and window.performance.getEntriesByNameType() return same data (link) 
23:53:17     INFO - TEST-PASS | /resource-timing/test_resource_timing.html | PerformanceEntry has correct name, initiatorType, startTime, and duration (link) 
23:53:17     INFO - TEST-UNEXPECTED-FAIL | /resource-timing/test_resource_timing.html | PerformanceEntry has correct order of timing attributes (link) - assert_greater_than_equal: connectStart after domainLookupEnd expected a number greater than or equal to 482.3286635493814 but got 482.28181595114637
23:53:17     INFO - test@http://web-platform.test:8000/resource-timing/test_resource_timing.js:171:9
23:53:17     INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:1382:20
23:53:17     INFO - resource_load@http://web-platform.test:8000/resource-timing/test_resource_timing.js:162:5
23:53:17     INFO - inner/<@http://web-platform.test:8000/resource-timing/test_resource_timing.js:124:25
23:53:17     INFO - setTimeout handler*inner@http://web-platform.test:8000/resource-timing/test_resource_timing.js:123:21
23:53:17     INFO - setTimeout handler*inner@http://web-platform.test:8000/resource-timing/test_resource_timing.js:130:9
23:53:17     INFO - poll_for_stylesheet_load@http://web-platform.test:8000/resource-timing/test_resource_timing.js:132:5
23:53:17     INFO - onload@http://web-platform.test:8000/resource-timing/test_resource_timing.js:88:13
23:53:17     INFO - EventHandlerNonNull*@http://web-platform.test:8000/resource-timing/test_resource_timing.js:26:1
23:53:17     INFO - TEST-PASS | /resource-timing/test_resource_timing.html | window.performance.getEntriesByName() and window.performance.getEntriesByNameType() return same data (script)

Comment 1

[Intermittent Failures Robot]

5 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 2
* mozilla-central: 2
* ash: 1

Platform breakdown:
* windows7-32: 5

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-04&endday=2016-04-10&tree=all

Comment 2

[Valentin Gosu [:valentin]]

This is a regression - e10s only - caused by a push that occurred on April 1st or before.
Some of the orange failures were recorded in bug 1141370.
I've looked at the change log and I don't think the networking changes can account for this regressions. There were a couple of e10s patches, but I don't see how it would lead to this failure.

Comment 3

[Intermittent Failures Robot]

27 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 15
* fx-team: 10
* try: 1
* mozilla-central: 1

Platform breakdown:
* windows7-32: 16
* osx-10-10: 6
* linux64: 3
* windowsxp: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-13&endday=2016-04-13&tree=all

Comment 4

[Intermittent Failures Robot]

61 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 33
* fx-team: 12
* try: 9
* mozilla-central: 4
* ash: 3

Platform breakdown:
* windows7-32: 52
* osx-10-10: 5
* linux64: 2
* windows8-64: 1
* osx-10-6: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-14&endday=2016-04-14&tree=all

Comment 5

[Ben Kelly [:bkelly, not reviewing]]

Valentin, any ideas?  This seems to have gotten a lot worse recently:

  https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-03-28&endday=2016-04-15&tree=all

Comment 6

[Intermittent Failures Robot]

60 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 27
* fx-team: 20
* mozilla-central: 6
* try: 4
* ash: 3

Platform breakdown:
* windows7-32: 47
* osx-10-10: 11
* windowsxp: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-15&endday=2016-04-15&tree=all

Comment 7

[Valentin Gosu [:valentin]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/cd04bd37115c1eaba4fc53cf3cd62dd3167565f3
Bug 1263428 - Add temporary code to debug intermittent WPT failure a=testonly

Comment 8

[Intermittent Failures Robot]

241 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 101
* fx-team: 59
* try: 58
* mozilla-central: 15
* ash: 8

Platform breakdown:
* windows7-32: 194
* osx-10-10: 32
* linux64: 8
* windowsxp: 4
* windows8-64: 2
* osx-10-6: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-11&endday=2016-04-17&tree=all

Comment 9

[Carsten Book [:Tomcat]]

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

Comment 10

[Valentin Gosu [:valentin]]

This is not yet fixed. Still debugging. Setting leave-open flag.

Comment 11

[Intermittent Failures Robot]

50 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 24
* fx-team: 15
* mozilla-central: 10
* try: 1

Platform breakdown:
* windows7-32: 44
* osx-10-10: 6

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-18&endday=2016-04-18&tree=all

Comment 12

[Intermittent Failures Robot]

55 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 26
* fx-team: 20
* mozilla-central: 9

Platform breakdown:
* windows7-32: 40
* osx-10-10: 14
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-19&endday=2016-04-19&tree=all

Comment 13

[Intermittent Failures Robot]

75 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 38
* fx-team: 26
* mozilla-central: 6
* try: 3
* ash: 2

Platform breakdown:
* windows7-32: 59
* osx-10-10: 7
* windowsxp: 3
* linux64: 3
* linux32: 2
* windows8-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-20&endday=2016-04-20&tree=all

Comment 14

[Intermittent Failures Robot]

72 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 36
* fx-team: 22
* mozilla-central: 7
* ash: 6
* try: 1

Platform breakdown:
* windows7-32: 54
* osx-10-10: 11
* windowsxp: 3
* windows8-64: 3
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-21&endday=2016-04-21&tree=all

Comment 15

[Intermittent Failures Robot]

57 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 34
* fx-team: 17
* mozilla-central: 6

Platform breakdown:
* windows7-32: 47
* osx-10-10: 7
* linux64: 2
* windowsxp: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-22&endday=2016-04-22&tree=all

Comment 16

[Intermittent Failures Robot]

30 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 21
* try: 8
* fx-team: 1

Platform breakdown:
* windows7-32: 24
* osx-10-10: 5
* windowsxp: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-23&endday=2016-04-23&tree=all

Comment 17

[Intermittent Failures Robot]

448 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 216
* fx-team: 127
* mozilla-central: 52
* try: 43
* ash: 10

Platform breakdown:
* windows7-32: 345
* osx-10-10: 63
* linux64: 17
* windowsxp: 11
* linux32: 7
* windows8-64: 5

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-18&endday=2016-04-24&tree=all

Comment 18

[Intermittent Failures Robot]

69 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 29
* fx-team: 22
* mozilla-central: 13
* ash: 3
* mozilla-aurora: 2

Platform breakdown:
* windows7-32: 57
* osx-10-10: 9
* linux64: 2
* windowsxp: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-25&endday=2016-04-25&tree=all

Comment 19

[Intermittent Failures Robot]

81 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 44
* fx-team: 17
* mozilla-central: 8
* mozilla-aurora: 7
* ash: 3
* try: 2

Platform breakdown:
* windows7-32: 67
* osx-10-10: 12
* windowsxp: 1
* windows8-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-26&endday=2016-04-26&tree=all

Comment 20

[Valentin Gosu [:valentin]]

Attachment: Make sure we don't set the domainLookupEnd timestamp after connectStart for non-persistant connections

I actually think this should fix the issue. This was a racy condition, where we assumed that if requestStart is null, then this is not a persistant connection. The assumption was false, and when OnLookupComplete fired before had started sending the request, it would set a domainLookupEnd that was larger than connectStart.

Comment 21

[Patrick McManus [:mcmanus]]

Comment on attachment 8746115 [details] [diff] [review]
Make sure we don't set the domainLookupEnd timestamp after connectStart for non-persistant connections

Review of attachment 8746115 [details] [diff] [review]:
-----------------------------------------------------------------

::: netwerk/protocol/http/nsHttpChannel.cpp
@@ +6093,5 @@
>          mTransactionPump = nullptr;
>  
>          // We no longer need the dns prefetch object
>          if (mDNSPrefetch && mDNSPrefetch->TimingsValid()
>              && !mTransactionTimings.requestStart.IsNull()

do you still need the requestStart null check?

Comment 22

[Valentin Gosu [:valentin]]

(In reply to Patrick McManus [:mcmanus] from comment #21)
> >              && !mTransactionTimings.requestStart.IsNull()
> 
> do you still need the requestStart null check?

I left it in so we wouldn't change the behaviour - in case the connect fails.

Comment 23

[Valentin Gosu [:valentin]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/119f55446e975341b3d09cd4036dc39a3b59ec82
Bug 1263428 - Make sure we don't set the domainLookupEnd timestamp after connectStart for non-persistant connections r=mcmanus

Comment 24

[Intermittent Failures Robot]

63 automation job failures were associated with this bug yesterday.

Repository breakdown:
* mozilla-inbound: 29
* fx-team: 15
* mozilla-central: 9
* try: 7
* mozilla-aurora: 3

Platform breakdown:
* windows7-32: 54
* osx-10-10: 9

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-27&endday=2016-04-27&tree=all

Comment 25

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/119f55446e97

Comment 26

[Intermittent Failures Robot]

18 automation job failures were associated with this bug yesterday.

Repository breakdown:
* fx-team: 12
* try: 2
* mozilla-central: 2
* mozilla-aurora: 2

Platform breakdown:
* windows7-32: 16
* osx-10-10: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-28&endday=2016-04-28&tree=all

Comment 27

[Valentin Gosu [:valentin]]

No failures since it landed on central. I think we can mark this as fixed.

Comment 28

[Ryan VanderMeulen [:RyanVM]]

Thanks!

Comment 29

[Intermittent Failures Robot]

253 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 104
* fx-team: 70
* mozilla-central: 35
* try: 21
* mozilla-aurora: 17
* ash: 6

Platform breakdown:
* windows7-32: 215
* osx-10-10: 33
* windowsxp: 2
* linux64: 2
* windows8-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-04-25&endday=2016-05-01&tree=all

Comment 30

[Intermittent Failures Robot]

23 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-aurora: 23

Platform breakdown:
* windows7-32: 17
* osx-10-10: 5
* windowsxp: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-05-10&endday=2016-05-16&tree=all

Comment 31

[Ryan VanderMeulen [:RyanVM]]

Can you please request Aurora approval on this when you get a chance?

Comment 32

[Valentin Gosu [:valentin]]

Comment on attachment 8746115 [details] [diff] [review]
Make sure we don't set the domainLookupEnd timestamp after connectStart for non-persistant connections

Approval Request Comment
[Feature/regressing bug #]: Bug 1123920
[User impact if declined]: intermittent failures when DNS prefetch is involved.
[Describe test coverage new/current, TreeHerder]: both mochitests and WPT
[Risks and why]: low risk. Patch makes sure we only use DNS prefetch timings when they make sense.
[String/UUID change made/needed]: none.

Comment 33

[Intermittent Failures Robot]

26 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-aurora: 26

Platform breakdown:
* windows7-32: 23
* osx-10-10: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-05-16&endday=2016-05-22&tree=all

Comment 34

[Sylvestre Ledru [:Sylvestre]]

Comment on attachment 8746115 [details] [diff] [review]
Make sure we don't set the domainLookupEnd timestamp after connectStart for non-persistant connections

Fix an intermittent, taking it.

Comment 35

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/9d9a6bbe53f4

Comment 36

[Intermittent Failures Robot]

17 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-aurora: 17

Platform breakdown:
* windows7-32: 14
* osx-10-10: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1263428&startday=2016-05-23&endday=2016-05-29&tree=all