Closed Bug 1433617 Opened 2 years ago Closed 2 years ago

Very frequent TEST-UNEXPECTED-TIMEOUT | /content-security-policy/prefetch-src/prefetch-allowed.html | Prefetch succeeds when allowed by prefetch-src - Test timed out

Categories

(Core :: DOM: Security, defect, P5)

defect

Tracking

()

RESOLVED FIXED
mozilla61
Tracking Status
firefox60 --- fixed
firefox61 --- fixed

People

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

References

Details

(Keywords: intermittent-failure, Whiteboard: [domsecurity-active][stockwell fixed:other][wptsync upstream])

Attachments

(1 file, 1 obsolete file)

Assignee: nobody → james
Blocks: 1433144
Summary: Very frequent Win7 debug TEST-UNEXPECTED-TIMEOUT | /content-security-policy/prefetch-src/prefetch-allowed.html | Prefetch succeeds when allowed by prefetch-src - Test timed out → Very frequent TEST-UNEXPECTED-TIMEOUT | /content-security-policy/prefetch-src/prefetch-allowed.html | Prefetch succeeds when allowed by prefetch-src - Test timed out
There have been 40 failures in the last week.

Occurrences per platform:
- Linux x64: 14
- linux64-stylo-disabled: 8
- Linux: 8
- linux32-stylo-disabled: 6
- OS X 10.10: 3
- windows10-64: 1

Occurrences per build type:
- opt: 32
- pgo: 7
- debug: 1

Here is a recent relevant log file and a snippet with the failure:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=160956801&lineNumber=1591

[task 2018-02-07T23:25:30.186Z] 23:25:30     INFO - TEST-PASS | /content-security-policy/prefetch-src/prefetch-allowed.html | Browser supports prefetch. 
[task 2018-02-07T23:25:30.186Z] 23:25:30     INFO - TEST-PASS | /content-security-policy/prefetch-src/prefetch-allowed.html | Browser supports performance APIs. 
[task 2018-02-07T23:25:30.186Z] 23:25:30     INFO - TEST-UNEXPECTED-TIMEOUT | /content-security-policy/prefetch-src/prefetch-allowed.html | Prefetch succeeds when allowed by prefetch-src - Test timed out
[task 2018-02-07T23:25:30.186Z] 23:25:30     INFO - TEST-INFO | expected FAIL
[task 2018-02-07T23:25:30.187Z] 23:25:30     INFO - TEST-UNEXPECTED-TIMEOUT | /content-security-policy/prefetch-src/prefetch-allowed.html | expected OK
[task 2018-02-07T23:25:30.187Z] 23:25:30     INFO - TEST-INFO took 10188ms
Flags: needinfo?(james)
Whiteboard: [stockwell needswork]
Component: web-platform-tests → DOM: Security
Product: Testing → Core
Version: Version 3 → unspecified
:ckerschb, this was filed in the wrong component- moving to your area to get the right people looking at it.
Flags: needinfo?(james) → needinfo?(ckerschb)
Vino, can you also have a look at this one please!
Assignee: james → cegvinoth
Status: NEW → ASSIGNED
Flags: needinfo?(ckerschb) → needinfo?(cegvinoth)
Whiteboard: [stockwell needswork] → [stockwell needswork][domsecurity-active]
In the last 7 days, there have been 34 failures.

For the failure pattern see Comment 4

An example of a recent log file:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-central&job_id=162979819&lineNumber=1565

:ckerschb, :vinoth are there any updates here?
Flags: needinfo?(ckerschb)
(In reply to Cristina Coroiu [:ccoroiu] from comment #9)
> In the last 7 days, there have been 34 failures.

:ccoroiu, how much of a problem is 34 failures? Does that put this bug in the bucket with the most intermittent failures? I think we can prioritize this intermittent over others if needed. Please let me know.
Flags: needinfo?(ckerschb) → needinfo?(ccoroiu)
:ckerschb the issue here is that every week there are ~30/40/50 failures (i checked this month only), which means that this failure is a priority. If you have other failures or more important tasks, feel free to postpone this, but it still needs a fix sooner, rather than later. 

Thanks.
Flags: needinfo?(ccoroiu)
(In reply to Andreea Pavel [:apavel] from comment #11)
> :ckerschb the issue here is that every week there are ~30/40/50 failures (i
> checked this month only), which means that this failure is a priority. If
> you have other failures or more important tasks, feel free to postpone this,
> but it still needs a fix sooner, rather than later. 


kk - thanks for the info. I'll make sure we look into that rather sooner than later then - thanks!
:ckerschb great! thank you!
I will look into it.
Flags: needinfo?(cegvinoth)
(In reply to Phabricator Automation from comment #15)
> Created attachment 8953470 [details]
> Bug 1433617 - sleep function added to waitUntilResourceDownloaded method

Tested it in Try server,
https://treeherder.mozilla.org/#/jobs?repo=try&revision=11c56d996ad8c43ecfa0ed9eefc9ba28eb235383

Now the test is getting PASSED. I think because of continuous failure, test is now expecting TIMEOUT itseems,
https://treeherder.mozilla.org/logviewer.html#?job_id=163948458&repo=try&lineNumber=1601

Prefetch-helper.js file,
https://dxr.mozilla.org/mozilla-central/source/testing/web-platform/tests/content-security-policy/support/prefetch-helper.js#11

Main reason for the timeout error is, performance.getEntriesByName() is getting the Prefetched Image in few seconds delay. And the function waitUntilResourceDownloaded returns before the image is added to the performance.getEntriesByName() list. 
Hence I added 500ms delay.
Attachment #8953470 - Flags: review?(ckerschb)
Comment on attachment 8953470 [details]
Bug 1433617 - sleep function added to waitUntilResourceDownloaded method

Still the issue exists.So marking as Obsolete
Attachment #8953470 - Attachment is obsolete: true
Attachment #8953470 - Flags: review?(ckerschb)
Update:
There have been 44 failures in the last week and 105 failures in the last 21 days.

Failures per platforms in the last 7 days:
- Linux x64: 17
- linux64-stylo-disabled: 9
- linux32-stylo-disabled: 6
- OS X 10.10: 6
- Linux: 6

Failures per build type in the last 7 days:
- opt: 38
- pgo: 6

Here is a recent log file and a snippet with the failure:
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=166013057&lineNumber=1557

[task 2018-03-05T16:26:30.061Z] 16:26:30     INFO - TEST-START | /content-security-policy/prefetch-src/prefetch-allowed.html
[task 2018-03-05T16:26:30.086Z] 16:26:30     INFO - Setting pref security.mixed_content.upgrade_display_content (false)
[task 2018-03-05T16:26:30.134Z] 16:26:30     INFO - Setting pref security.csp.enable_violation_events (true)
[task 2018-03-05T16:26:40.372Z] 16:26:40     INFO - 
[task 2018-03-05T16:26:40.372Z] 16:26:40     INFO - TEST-PASS | /content-security-policy/prefetch-src/prefetch-allowed.html | Browser supports prefetch. 
[task 2018-03-05T16:26:40.373Z] 16:26:40     INFO - TEST-PASS | /content-security-policy/prefetch-src/prefetch-allowed.html | Browser supports performance APIs. 
[task 2018-03-05T16:26:40.373Z] 16:26:40     INFO - TEST-UNEXPECTED-TIMEOUT | /content-security-policy/prefetch-src/prefetch-allowed.html | Prefetch succeeds when allowed by prefetch-src - Test timed out
[task 2018-03-05T16:26:40.373Z] 16:26:40     INFO - TEST-INFO | expected FAIL
[task 2018-03-05T16:26:40.374Z] 16:26:40     INFO - TEST-UNEXPECTED-TIMEOUT | /content-security-policy/prefetch-src/prefetch-allowed.html | expected OK
[task 2018-03-05T16:26:40.374Z] 16:26:40     INFO - TEST-INFO took 10316ms
[task 2018-03-05T16:26:40.536Z] 16:26:40     INFO - PID 2072 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping
[task 2018-03-05T16:26:40.839Z] 16:26:40     INFO - Browser exited with return code 0

:ckerschb is there somebody that can take another look at this?
I see that :vinoth tried to make a patch, but the issue still exists.
Flags: needinfo?(ckerschb)
:jkt, any chance you could take a quick look and see if you can identify the problem?
Flags: needinfo?(ckerschb) → needinfo?(jkt)
(In reply to Phabricator Automation from comment #22)
> Created attachment 8957087 [details]
> Bug 1433617 - Cache control headers added to png image

Main problem is, Cache control header need to be set for the resources from the server side to enable prefetching. 

Cache control check is done here,
https://dxr.mozilla.org/mozilla-central/rev/a859a4b2257e6c61f7c2aab456cf551df856bd95/uriloader/prefetch/nsPrefetchService.cpp#260

It was missing previously in the test, hence added it.

Now I will push these changes to try server and figure out if the tests are passing. I will update the results.
Patch from :vinoth works for me :)
Flags: needinfo?(jkt)
Update:
There have been 32 failures in the last week and they are occurring on Linux platforms.

:ckerschb :jkt any updates on this one?
Flags: needinfo?(ckerschb)
(In reply to Andrei Ciure[:andrei_ciure_] from comment #28)
> Update:
> There have been 32 failures in the last week and they are occurring on Linux
> platforms.
> 
> :ckerschb :jkt any updates on this one?

New patch works locally for myself and jkt.
But on linux 64 platform alone it throws timeout error, in try server[1]
Hence working on finding the cause.

[1] https://treeherder.mozilla.org/#/jobs?repo=try&revision=22101f28d89f5788e488117fe3568617d803f321&selectedJob=166990950
(In reply to Andrei Ciure[:andrei_ciure_] from comment #28)
> Update:
> There have been 32 failures in the last week and they are occurring on Linux
> platforms.
> 
> :ckerschb :jkt any updates on this one?

:vino is on it!
Flags: needinfo?(ckerschb)
Comment on attachment 8957087 [details]
Bug 1433617 - Cache control headers added to png image

Main problem before is, Cache control header need to be set for the resources from the server side to enable prefetching. It was missing previously, hence added it.
Reason for using a new window for prefetch is, because prefetch is of low priority and it is being interrupted by the test runner in the same file.
These issues are fixed in the patch.

Tested it in try server,
https://treeherder.mozilla.org/#/jobs?repo=try&revision=b927ed56be7529becfdaba0d102c0d0e9ce5e76c
Attachment #8957087 - Flags: review?(ckerschb)
Comment on attachment 8957087 [details]
Bug 1433617 - Cache control headers added to png image

Christoph Kerschbaumer [:ckerschb] has approved the revision.

https://phabricator.services.mozilla.com/D697
Attachment #8957087 - Flags: review+
Attachment #8957087 - Flags: review?(ckerschb)
Keywords: checkin-needed
Pushed by ryanvm@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/e84c93b3a8ab
Cache control headers added to png image. r=ckerschb
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/e84c93b3a8ab
Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla61
Created web-platform-tests PR https://github.com/w3c/web-platform-tests/pull/10306 for changes under testing/web-platform/tests
Whiteboard: [domsecurity-active][stockwell disable-recommended] → [domsecurity-active][stockwell disable-recommended][wptsync upstream]
Whiteboard: [domsecurity-active][stockwell disable-recommended][wptsync upstream] → [domsecurity-active][stockwell disable-recommended][wptsync upstream error]
Whiteboard: [domsecurity-active][stockwell disable-recommended][wptsync upstream error] → [domsecurity-active][stockwell disable-recommended][wptsync upstream]
Whiteboard: [domsecurity-active][stockwell disable-recommended][wptsync upstream] → [domsecurity-active][stockwell fixed:other][wptsync upstream]
You need to log in before you can comment on or make changes to this bug.