Open Bug 1477342 Opened Last year Updated Last month

Intermittent /fetch/http-cache/304-update.html | HTTP cache updates stored headers from a Last-Modified 304 - assert_less_than: Response 3 does not come from cache expected a number less than 3 but got 3

Categories

(Core :: DOM: Networking, defect, P3)

defect

Tracking

()

Tracking Status
firefox70 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: kershaw)

Details

(Keywords: intermittent-failure, leave-open, Whiteboard: [stockwell disabled][stockwell needswork][necko-triaged])

Attachments

(2 files, 1 obsolete file)

Filed by: nerli [at] mozilla.com

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

https://queue.taskcluster.net/v1/task/AatYug7pSXC3wRZ-22pjbw/runs/0/artifacts/public/logs/live_backing.log

17:12:28     INFO - TEST-START | /fetch/http-cache/304-update.html
17:12:28     INFO - Setting pref network.http.rcwn.enabled (false)
17:12:28     INFO - PID 7996 | ++DOCSHELL 000002B70CB0D800 == 2 [pid = 1312] [id = {906d431e-1458-4130-b44a-5c2b575b0a9b}]
17:12:28     INFO - PID 7996 | ++DOMWINDOW == 5 (000002B70BBFA400) [pid = 1312] [serial = 5] [outer = 0000000000000000]
17:12:28     INFO - PID 7996 | ++DOMWINDOW == 6 (000002B70C09E400) [pid = 1312] [serial = 6] [outer = 000002B70BBFA400]
17:12:28     INFO - PID 7996 | 1532106748313	Marionette	DEBUG	[4294967301] Frame script loaded
17:12:28     INFO - PID 7996 | 1532106748341	Marionette	DEBUG	[4294967301] Frame script registered
17:12:28     INFO - PID 7996 | ++DOMWINDOW == 7 (000002B70C09E000) [pid = 1312] [serial = 7] [outer = 000002B70BBFA400]
17:12:28     INFO - PID 7996 | ++DOCSHELL 000002B70CB16800 == 3 [pid = 1312] [id = {c33565c4-fdf2-43c4-877b-26d396ce8888}]
17:12:28     INFO - PID 7996 | ++DOMWINDOW == 8 (000002B70C0EEC00) [pid = 1312] [serial = 8] [outer = 0000000000000000]
17:12:28     INFO - PID 7996 | ++DOMWINDOW == 9 (000002B70C0A5C00) [pid = 1312] [serial = 9] [outer = 000002B70C0EEC00]
17:12:28     INFO - PID 7996 | 1532106748451	Marionette	DEBUG	[4294967304] Frame script loaded
17:12:28     INFO - PID 7996 | 1532106748504	Marionette	DEBUG	[4294967304] Frame script registered
17:12:28     INFO - PID 7996 | ++DOMWINDOW == 10 (000002B70CBC9800) [pid = 1312] [serial = 10] [outer = 000002B70C0EEC00]
17:12:33     INFO - PID 7996 | --DOCSHELL 000002A6E8144000 == 5 [pid = 7996] [id = {4c7e85d0-0ab8-4fc5-aa06-06fd518f626b}]
17:12:33     INFO - PID 7996 | --DOCSHELL 000002A6EC92F000 == 4 [pid = 7996] [id = {bcad65cc-feaa-463f-a9ed-08b04b66df02}]
17:12:35     INFO - PID 7996 | --DOCSHELL 000001ACEC445000 == 0 [pid = 8124] [id = {e724f940-d835-46f2-9213-bd81ee095589}]
17:12:38     INFO - PID 7996 | --DOMWINDOW == 14 (000002A6E8257800) [pid = 7996] [serial = 4] [outer = 0000000000000000] [url = about:blank]
17:12:38     INFO - PID 7996 | --DOMWINDOW == 13 (000002A6EE511C00) [pid = 7996] [serial = 13] [outer = 0000000000000000] [url = about:blank]
17:12:38     INFO - PID 7996 | --DOMWINDOW == 12 (000002A6EE512C00) [pid = 7996] [serial = 14] [outer = 0000000000000000] [url = about:blank]
17:12:40     INFO - PID 7996 | --DOMWINDOW == 11 (000002A6ECA43200) [pid = 7996] [serial = 9] [outer = 0000000000000000] [url = about:blank]
17:12:40     INFO - PID 7996 | --DOMWINDOW == 9 (000002B70BB1B400) [pid = 1312] [serial = 2] [outer = 0000000000000000] [url = about:blank]
17:12:40     INFO - PID 7996 | --DOMWINDOW == 8 (000002B7045AEC00) [pid = 1312] [serial = 3] [outer = 0000000000000000] [url = about:blank]
17:12:40     INFO - PID 7996 | --DOMWINDOW == 7 (000002B70C0A5C00) [pid = 1312] [serial = 9] [outer = 0000000000000000] [url = about:blank]
17:12:40     INFO - PID 7996 | --DOMWINDOW == 6 (000002B70C09E400) [pid = 1312] [serial = 6] [outer = 0000000000000000] [url = about:blank]
17:12:44     INFO - PID 7996 | --DOMWINDOW == 10 (000002A6EDC1E400) [pid = 7996] [serial = 10] [outer = 0000000000000000] [url = about:blank]
17:12:45     INFO - PID 7996 | --DOMWINDOW == 2 (000001ACF3A0D800) [pid = 8124] [serial = 2] [outer = 0000000000000000] [url = about:blank]
17:12:45     INFO - PID 7996 | --DOMWINDOW == 1 (000001ACEC413E00) [pid = 8124] [serial = 1] [outer = 0000000000000000] [url = chrome://gfxsanity/content/sanitytest.html]
17:12:45     INFO - PID 7996 | [Parent 7996, StreamTrans #58] WARNING: 'NS_FAILED(rv)', file z:/build/build/src/modules/libjar/nsJARChannel.cpp, line 417
17:12:46     INFO - PID 7996 | --DOMWINDOW == 2 (000002240A50CC00) [pid = 1940] [serial = 2] [outer = 0000000000000000] [url = about:blank]
17:12:47     INFO - 
17:12:47     INFO - TEST-PASS | /fetch/http-cache/304-update.html | HTTP cache updates returned headers from a Last-Modified 304 
17:12:47     INFO - TEST-UNEXPECTED-FAIL | /fetch/http-cache/304-update.html | HTTP cache updates stored headers from a Last-Modified 304 - assert_less_than: Response 3 does not come from cache expected a number less than 3 but got 3
17:12:47     INFO - checkResponse@http://web-platform.test:8000/fetch/http-cache/http-cache.js:136:9
17:12:47     INFO - promise callback*code@http://web-platform.test:8000/fetch/http-cache/http-cache.js:52:18
17:12:47     INFO - runNextStep@http://web-platform.test:8000/fetch/http-cache/http-cache.js:74:18
17:12:47     INFO - promise callback*runNextStep@http://web-platform.test:8000/fetch/http-cache/http-cache.js:70:18
17:12:47     INFO - promise callback*runNextStep@http://web-platform.test:8000/fetch/http-cache/http-cache.js:74:18
17:12:47     INFO - makeTest/<@http://web-platform.test:8000/fetch/http-cache/http-cache.js:82:12
17:12:47     INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:1538:20
17:12:47     INFO - promise_test/tests.promise_tests<@http://web-platform.test:8000/resources/testharness.js:577:27
17:12:47     INFO - promise callback*promise_test@http://web-platform.test:8000/resources/testharness.js:573:31
17:12:47     INFO - run_tests/<@http://web-platform.test:8000/fetch/http-cache/http-cache.js:246:5
17:12:47     INFO - run_tests@http://web-platform.test:8000/fetch/http-cache/http-cache.js:245:3
17:12:47     INFO - @http://web-platform.test:8000/fetch/http-cache/304-update.html:124:5
:jlast could you please take a look?
Flags: needinfo?(jlaster)
Hi! I made a patch to disable this. Please have a look and see if it's ok to disable this. Thank you.
Assignee: nobody → csabou
Attachment #8995692 - Flags: review?(gbrown)
Dear Reader,

We are a joint research team from the University of Zurich, Switzerland* and Mozilla** and are building a tool to automatically recognize the type of an intermittent-failure, such as the one here.

By automatically recognizing the type of failure, the tool should provide a starting point for the bug fixing process. To evaluate and improve the tool, we kindly ask your feedback.
    
Tool Result - this intermittent-failure is most likely affected by a:
Concurrency Issue: This includes tests in which failures occur due to thread management issues (different threads or their outcomes depending on an implicit ordering), race conditions and/or deadlocks, and issues related to an asynchronous waits (e.g. a process trying to access an external resource or continuing before the external resource is available).

Feedback: 
1. Did the tool correctly recognize the type of intermittent-failure? (please also explain why or why not)
2. Did the information from the tool help your analysis, the bug fixing process, or anything in the process? (please also let us know how the tool was useful and/or what would improve the tool's usefulness for you)

Thank you very much for your help! 
*Moritz, Fabio and Alberto (http://www.ifi.uzh.ch/en/zest/team.html)
**Marco Castellucio (https://marco-c.github.io/)
Comment on attachment 8995692 [details] [diff] [review]
Disable on Linux64, OSX and Windows10

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

::: testing/web-platform/meta/fetch/http-cache/304-update.html.ini
@@ +1,3 @@
>  [304-update.html]
>    disabled:
> +    if (os == "linux") and (bits == 64) :https://bugzilla.mozilla.org/show_bug.cgi?id=1477342

There are recent linux32 failures also, so I would suggest simply (os == "linux") here.
Attachment #8995692 - Flags: review?(gbrown) → review+
Pushed by csabou@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/ca58c0290774
Disable /fetch/http-cache/304-update.html for frequent failures on Linux64, OSX, Windows10. r=gbrown
Keywords: leave-open
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
:ccoroiu, i'm not sure what information i'd have here?
Flags: needinfo?(jlaster)
Priority: -- → P3
Over the last 7 days there are 33 failures on this bug. These happen on windows7-32-msvc, windows7-32, windows10-64-ccov, windows10-64, 

Here is the most recent log example: https://treeherder.mozilla.org/logviewer.html#?job_id=195394104&repo=autoland&lineNumber=2947


23:20:15     INFO - TEST-UNEXPECTED-FAIL | /fetch/http-cache/304-update.html | HTTP cache updates stored headers from a Last-Modified 304 - assert_less_than: Response 3 does not come from cache expected a number less than 3 but got 3
Flags: needinfo?(overholt)
The Necko team is going to look at Fetch issues.
Component: DOM → DOM: Networking
Flags: needinfo?(overholt) → needinfo?(jduell.mcbugs)
There have been 33 failures in the last week, on Windows 7 32 and Windows 10 64, Debug, Opt and Pgo.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=197522236&repo=mozilla-central&lineNumber=920
Whiteboard: [stockwell disabled] → [stockwell disabled][stockwell needswork]
Any updates on this? 35 failures in the last week on Windows 7 and Windows 10, Debug, Pgo and Opt.
Comment 14 intended to disable this test on windows10, but contained a typo: 10.0.15603 should be 10.0.15063. Given the on-going failures on windows7 and windows10, perhaps that condition should be expanded to all windows (all platforms).
Flags: needinfo?(csabou)
Attachment #8995692 - Attachment is obsolete: true
Attachment #9010749 - Flags: review?(gbrown)
Flags: needinfo?(csabou)
Attachment #9010749 - Flags: review?(gbrown) → review+
Pushed by rgurzau@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/82558985e880
Disable /fetch/http-cache/304-update.html for frequent failures on Linux64, OSX, Windows r=gbrown
Assignee: csabou → nobody
Flags: needinfo?(jduell.mcbugs) → needinfo?(dd.mozilla)
I suspect this is because of network.http.rcwn.enabled.
(In reply to Mark Nottingham from comment #43)
> I suspect this is because of network.http.rcwn.enabled.

Isn't that disabled at https://searchfox.org/mozilla-central/source/testing/web-platform/meta/fetch/http-cache/__dir__.ini#1 ?
Ah - never mind then. Thanks.

There are 29 total failures in the last 7 days: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-07-10&endday=2019-07-17&tree=trunk&bug=1477342

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=257004562&repo=autoland&lineNumber=3548

[task 2019-07-17T19:06:41.337Z] 19:06:41 INFO - TEST-START | /fetch/http-cache/304-update.html
[task 2019-07-17T19:06:41.361Z] 19:06:41 INFO - Setting pref network.http.rcwn.enabled (false)
[task 2019-07-17T19:07:09.461Z] 19:07:09 INFO -
[task 2019-07-17T19:07:09.461Z] 19:07:09 INFO - TEST-PASS | /fetch/http-cache/304-update.html | HTTP cache updates returned headers from a Last-Modified 304
[task 2019-07-17T19:07:09.461Z] 19:07:09 INFO - TEST-UNEXPECTED-FAIL | /fetch/http-cache/304-update.html | HTTP cache updates stored headers from a Last-Modified 304 - assert_less_than: Response 3 does not come from cache expected a number less than 3 but got 3
[task 2019-07-17T19:07:09.461Z] 19:07:09 INFO - checkResponse@http://web-platform.test:8000/fetch/http-cache/http-cache.js:136:9
[task 2019-07-17T19:07:09.678Z] 19:07:09 INFO - ...
[task 2019-07-17T19:07:09.678Z] 19:07:09 INFO - TEST-OK | /fetch/http-cache/304-update.html | took 28339ms
[task 2019-07-17T19:07:10.317Z] 19:07:10 INFO - Closing logging queue
[task 2019-07-17T19:07:10.317Z] 19:07:10 INFO - queue closed
[task 2019-07-17T19:07:10.333Z] 19:07:10 INFO - Setting up ssl
[task 2019-07-17T19:07:10.348Z] 19:07:10 INFO - certutil |
[task 2019-07-17T19:07:10.369Z] 19:07:10 INFO - certutil |
[task 2019-07-17T19:07:10.384Z] 19:07:10 INFO - certutil |
[task 2019-07-17T19:07:10.384Z] 19:07:10 INFO - Certificate Nickname Trust Attributes
[task 2019-07-17T19:07:10.384Z] 19:07:10 INFO - SSL,S/MIME,JAR/XPI
[task 2019-07-17T19:07:10.384Z] 19:07:10 INFO -
[task 2019-07-17T19:07:10.384Z] 19:07:10 INFO - web-platform-tests CT,,
[task 2019-07-17T19:07:10.385Z] 19:07:10 INFO -
[task 2019-07-17T19:07:12.116Z] 19:07:12 INFO - adb Granting important runtime permissions to org.mozilla.geckoview.test
[task 2019-07-17T19:07:13.568Z] 19:07:13 INFO - adb launch_application: am start -W -n org.mozilla.geckoview.test/org.mozilla.geckoview.test.TestRunnerActivity -a android.intent.action.MAIN --es env9 MOZ_CRASHREPORTER_NO_REPORT=1 --es env8 MOZ_DISABLE_NONLOCAL_CONNECTIONS=1 --es args "-no-remote -profile /sdcard/tests/profile --marionette about:blank" --es env3 MOZ_HIDE_RESULTS_TABLE=1 --es env2 R_LOG_VERBOSE=1 --es env1 MOZ_WEBRENDER=0 --es env0 MOZ_CRASHREPORTER=1 --es env7 R_LOG_DESTINATION=stderr --es env6 MOZ_CRASHREPORTER_SHUTDOWN=1 --es env5 MOZ_LOG=signaling:3,mtransport:4,DataChannel:4,jsep:4 --es env4 STYLO_THREADS=4 --ez use_multiprocess True --es env11 R_LOG_LEVEL=6 --es env10 MOZ_PROCESS_LOG=/tmp/tmp5HmKJrpidlog
[task 2019-07-17T19:07:14.710Z] 19:07:14 INFO - Starting runner

:nhi, could you take a look at this?

Flags: needinfo?(nhnguyen)
Flags: needinfo?(nhnguyen)
Flags: needinfo?(kershaw)
Flags: needinfo?(dd.mozilla)
Assignee: nobody → kershaw
Flags: needinfo?(kershaw)
Whiteboard: [stockwell disabled][stockwell needswork] → [stockwell disabled][stockwell needswork][necko-triaged]

Kershaw, this is failing regularly also on android-em-7-0-x86_64 opt & debug and it's disabled on win, linux and mac. Can we disable this everywhere or do you want to fix it?
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-07-28&endday=2019-08-27&tree=trunk&bug=1477342

Flags: needinfo?(kershaw)
Pushed by rmaries@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/3d205e901e3a
Disabled 304-update.html on Android. r=egao

(In reply to Cosmin Sabou [:CosminS] from comment #81)

Kershaw, this is failing regularly also on android-em-7-0-x86_64 opt & debug and it's disabled on win, linux and mac. Can we disable this everywhere or do you want to fix it?
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-07-28&endday=2019-08-27&tree=trunk&bug=1477342

Sorry that I didn't manage to fix this.

Flags: needinfo?(kershaw)
You need to log in before you can comment on or make changes to this bug.