1576039 - Perma [Tier 2] dom/security/test/general/test_cache_split.html | Test timed out.

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=263027971&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/KGEnBVefRRGIVdFKFMkonQ/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-08-22T23:57:35.141Z] 23:57:35 INFO - 191 INFO TEST-PASS | dom/security/test/general/test_cache_split.html | cookieBehavior interaction 2 req to: Same Origin expected 1 request to Server, got 1
[task 2019-08-22T23:57:35.141Z] 23:57:35 INFO - Buffered messages logged at 23:57:00
[task 2019-08-22T23:57:35.141Z] 23:57:35 INFO - 192 INFO Doing Step ["http://mochi.test:8888/",1]
[task 2019-08-22T23:57:35.142Z] 23:57:35 INFO - Buffered messages logged at 23:57:15
[task 2019-08-22T23:57:35.142Z] 23:57:35 INFO - 193 INFO TEST-PASS | dom/security/test/general/test_cache_split.html | cookieBehavior interaction 2 req to: Same Origin expected 1 request to Server, got 1
[task 2019-08-22T23:57:35.143Z] 23:57:35 INFO - 194 INFO Doing Step ["http://example.com/",2]
[task 2019-08-22T23:57:35.143Z] 23:57:35 INFO - Buffered messages finished
[task 2019-08-22T23:57:35.143Z] 23:57:35 INFO - 195 INFO TEST-UNEXPECTED-FAIL | dom/security/test/general/test_cache_split.html | Test timed out.
[task 2019-08-22T23:57:35.144Z] 23:57:35 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2019-08-22T23:57:35.144Z] 23:57:35 INFO - reportError@SimpleTest/TestRunner.js:121:22
[task 2019-08-22T23:57:35.144Z] 23:57:35 INFO - TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:18
[task 2019-08-22T23:57:35.145Z] 23:57:35 INFO - 196 INFO TEST-PASS | dom/security/test/general/test_cache_split.html | cookieBehavior interaction 2 req to: Cross Origin expected 2 request to Server, got 2
[task 2019-08-22T23:57:35.145Z] 23:57:35 INFO - 197 INFO Clearing Cache
[task 2019-08-22T23:57:35.145Z] 23:57:35 INFO - 198 INFO add_task | Leaving test
[task 2019-08-22T23:57:35.146Z] 23:57:35 INFO - 199 INFO add_task | Entering test
[task 2019-08-22T23:57:35.146Z] 23:57:35 INFO - 200 INFO Starting Job with - 3 - Requests
[task 2019-08-22T23:57:35.146Z] 23:57:35 INFO - 201 INFO TEST-OK | dom/security/test/general/test_cache_split.html | took 310541ms
[task 2019-08-22T23:57:35.147Z] 23:57:35 INFO - 202 INFO TEST-UNEXPECTED-FAIL | dom/security/test/general/test_cache_split.html | TypeError: NetworkError when attempting to fetch resource. - Should not throw any errors
[task 2019-08-22T23:57:35.147Z] 23:57:35 INFO - nextTick/<@SimpleTest/SimpleTest.js:1803:26
[task 2019-08-22T23:57:35.148Z] 23:57:35 INFO - 203 ERROR [SimpleTest.finish()] this test already called finish!
[task 2019-08-22T23:57:35.148Z] 23:57:35 INFO - 204 INFO TEST-UNEXPECTED-ERROR | dom/security/test/general/test_cache_split.html | called finish() multiple times
[task 2019-08-22T23:57:35.148Z] 23:57:35 INFO - TEST-INFO
[task 2019-08-22T23:57:45.667Z] 23:57:45 INFO - 205 INFO TEST-START | dom/security/test/general/test_contentpolicytype_targeted_link_iframe.html
[task 2019-08-22T23:57:56.192Z] 23:57:56 INFO - 206 INFO TEST-OK | dom/security/test/general/test_contentpolicytype_targeted_link_iframe.html | took 10960ms
[task 2019-08-22T23:57:56.193Z] 23:57:56 INFO - 207 INFO TEST-START | dom/security/test/general/test_nosniff.html
[task 2019-08-22T23:58:06.728Z] 23:58:06 INFO - 208 INFO TEST-OK | dom/security/test/general/test_nosniff.html | took 7698ms
[task 2019-08-22T23:58:06.729Z] 23:58:06 INFO - 209 INFO TEST-START | dom/security/test/general/test_nosniff_navigation.html
[task 2019-08-22T23:58:39.528Z] 23:58:39 INFO - 210 INFO TEST-OK | dom/security/test/general/test_nosniff_navigation.html | took 31239ms
[task 2019-08-22T23:58:50.060Z] 23:58:50 INFO - 211 INFO TEST-START | dom/security/test/general/test_same_site_cookies_about.html
[task 2019-08-23T00:00:47.154Z] 00:00:47 INFO - 212 INFO TEST-OK | dom/security/test/general/test_same_site_cookies_about.html | took 124733ms
[task 2019-08-23T00:00:57.684Z] 00:00:57 INFO - 213 INFO TEST-START | dom/security/test/general/test_same_site_cookies_cross_origin_context.html
[task 2019-08-23T00:01:18.938Z] 00:01:18 INFO - 214 INFO TEST-OK | dom/security/test/general/test_same_site_cookies_cross_origin_context.html | took 21018ms
[task 2019-08-23T00:01:18.939Z] 00:01:18 INFO - 215 INFO TEST-START | dom/security/test/general/test_same_site_cookies_from_script.html
[task 2019-08-23T00:01:40.094Z] 00:01:40 INFO - 216 INFO TEST-OK | dom/security/test/general/test_same_site_cookies_from_script.html | took 24136ms
[task 2019-08-23T00:01:50.616Z] 00:01:50 INFO - 217 INFO TEST-START | dom/security/test/general/test_same_site_cookies_iframe.html
[task 2019-08-23T00:04:29.055Z] 00:04:29 INFO - 218 INFO TEST-OK | dom/security/test/general/test_same_site_cookies_iframe.html | took 160580ms
[task 2019-08-23T00:04:39.580Z] 00:04:39 INFO - 219 INFO TEST-START | dom/security/test/general/test_same_site_cookies_laxByDefault.html
[task 2019-08-23T00:05:54.219Z] 00:05:54 INFO - 220 INFO TEST-OK | dom/security/test/general/test_same_site_cookies_laxByDefault.html | took 74791ms
[task 2019-08-23T00:06:04.742Z] 00:06:04 INFO - 221 INFO TEST-START | dom/security/test/general/test_same_site_cookies_redirect.html
[task 2019-08-23T00:06:46.872Z] 00:06:46 INFO - 222 INFO TEST-OK | dom/security/test/general/test_same_site_cookies_redirect.html | took 50859ms
[task 2019-08-23T00:06:57.411Z] 00:06:57 INFO - 223 INFO TEST-START | dom/security/test/general/test_same_site_cookies_subrequest.html
[task 2019-08-23T00:07:50.106Z] 00:07:50 INFO - 224 INFO TEST-OK | dom/security/test/general/test_same_site_cookies_subrequest.html | took 54027ms
[task 2019-08-23T00:08:00.642Z] 00:08:00 INFO - 225 INFO TEST-START | dom/security/test/general/test_same_site_cookies_toplevel_nav.html
[task 2019-08-23T00:09:24.954Z] 00:09:24 INFO - 226 INFO TEST-OK | dom/security/test/general/test_same_site_cookies_toplevel_nav.html | took 90098ms
[task 2019-08-23T00:09:35.491Z] 00:09:35 INFO - 227 INFO TEST-START | dom/security/test/general/test_same_site_cookies_toplevel_set_cookie.html
[task 2019-08-23T00:10:19.081Z] 00:10:19 INFO - 228 INFO TEST-OK | dom/security/test/general/test_same_site_cookies_toplevel_set_cookie.html | took 40193ms
[task 2019-08-23T00:10:29.613Z] 00:10:29 INFO - 229 INFO TEST-START | Shutdown
[task 2019-08-23T00:10:29.613Z] 00:10:29 INFO - 230 INFO Passed: 152
[task 2019-08-23T00:10:29.615Z] 00:10:29 WARNING - 231 INFO Failed: 2
[task 2019-08-23T00:10:29.615Z] 00:10:29 WARNING - One or more unittests failed.
[task 2019-08-23T00:10:29.615Z] 00:10:29 INFO - 232 INFO Todo: 0
[task 2019-08-23T00:10:29.615Z] 00:10:29 INFO - 233 INFO Mode: non-e10s
[task 2019-08-23T00:10:29.616Z] 00:10:29 INFO - 234 INFO Slowest: 310541ms - /tests/dom/security/test/general/test_cache_split.html
[task 2019-08-23T00:10:29.617Z] 00:10:29 INFO - 235 INFO SimpleTest FINISHED
[task 2019-08-23T00:11:31.500Z] 00:11:31 INFO - Failed to get top activity, retrying, once...
[task 2019-08-23T00:11:32.431Z] 00:11:32 INFO - wait for org.mozilla.fennec_aurora complete; top activity=com.android.launcher
[task 2019-08-23T00:11:32.636Z] 00:11:32 INFO - remoteautomation.py | Application ran for: 0:23:07.518443
[task 2019-08-23T00:11:33.566Z] 00:11:33 INFO - Stopping web server
[task 2019-08-23T00:11:33.571Z] 00:11:33 INFO - Stopping web socket server
[task 2019-08-23T00:11:33.591Z] 00:11:33 INFO - Stopping ssltunnel
[task 2019-08-23T00:11:33.612Z] 00:11:33 INFO - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2019-08-23T00:11:33.612Z] 00:11:33 INFO - runtests.py | Running tests: end.
[task 2019-08-23T00:11:35.080Z] 00:11:35 INFO - Buffered messages finished
[task 2019-08-23T00:11:35.081Z] 00:11:35 INFO - Running manifest: dom/security/test/mixedcontentblocker/mochitest.ini
[task 2019-08-23T00:11:35.081Z] 00:11:35 INFO - The following extra prefs will be set:
[task 2019-08-23T00:11:35.081Z] 00:11:35 INFO - security.mixed_content.upgrade_display_content=false
[task 2019-08-23T00:11:37.340Z] 00:11:37 INFO - runtests.py | Failed to copy /builds/worker/workspace/build/tests/mochitest/hyphenation to profile
[task 2019-08-23T00:11:37.417Z] 00:11:37 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2019-08-23T00:11:37.574Z] 00:11:37 INFO - MochitestServer : launching [u'/builds/worker/workspace/build/hostutils/host-utils-68.0a1.en-US.linux-x86_64/xpcshell', '-g', '/builds/worker/workspace/build/hostutils/host-utils-68.0a1.en-US.linux-x86_64', '-f', '/builds/worker/workspace/build/hostutils/host-utils-68.0a1.en-US.linux-x86_64/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmpRWctmf.mozrunner'; const _SERVER_PORT = '8854'; const _SERVER_ADDR = '10.0.2.2'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/worker/workspace/build/tests/mochitest/server.js']
[task 2019-08-23T00:11:37.574Z] 00:11:37 INFO - runtests.py | Server pid: 8147
[task 2019-08-23T00:11:37.579Z] 00:11:37 INFO - runtests.py | Websocket server pid: 8150
[task 2019-08-23T00:11:37.589Z] 00:11:37 INFO - runtests.py | SSL tunnel pid: 8153
[task 2019-08-23T00:11:41.349Z] 00:11:41 INFO - runtests.py | Running with scheme: http
[task 2019-08-23T00:11:41.349Z] 00:11:41 INFO - runtests.py | Running with e10s: False
[task 2019-08-23T00:11:41.349Z] 00:11:41 INFO - runtests.py | Running with serviceworker_e10s: False
[task 2019-08-23T00:11:41.349Z] 00:11:41 INFO - runtests.py | Running with socketprocess_e10s: False
[task 2019-08-23T00:11:41.349Z] 00:11:41 INFO - runtests.py | Running tests: start.
[task 2019-08-23T00:11:41.666Z] 00:11:41 INFO - adb launch_application: am start -W -n org.mozilla.fennec_aurora/org.mozilla.gecko.BrowserApp -a android.intent.action.VIEW --es env9 MOZ_UPLOAD_DIR=/sdcard/tests/mozlog --es env8 R_LOG_DESTINATION=stderr --es args "-no-remote -profile /sdcard/tests/profile//" --es env3 R_LOG_VERBOSE=1 --es env2 XPCOM_DEBUG_BREAK=stack --es env1 MOZ_WEBRENDER=0 --es env0 MOZ_CRASHREPORTER=1 --es env7 MOZ_CRASHREPORTER_SHUTDOWN=1 --es env6 MOZ_IN_AUTOMATION=1 --es env5 MOZ_DISABLE_NONLOCAL_CONNECTIONS=1 --es env4 DISABLE_UNSAFE_CPOW_WARNINGS=1 --es env12 MOZ_HIDE_RESULTS_TABLE=1 --es env11 R_LOG_LEVEL=6 --es env10 MOZ_CRASHREPORTER_NO_REPORT=1 -d "http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&logFile=%2Fsdcard%2Ftests%2Flogs%2Fmochitest.log&fileLevel=INFO&consoleLevel=INFO&hideResultsTable=1&manifestFile=tests.json&dumpOutputDirectory=%2Fsdcard%2Ftests"
[task 2019-08-23T00:11:51.097Z] 00:11:51 INFO - remoteautomation.py | Application pid: 7694
[task 2019-08-23T00:14:24.326Z] 00:14:24 INFO - 236 INFO SimpleTest START
[task 2019-08-23T00:14:24.326Z] 00:14:24 INFO - 237 INFO TEST-START | dom/security/test/mixedcontentblocker/test_redirect.html

Comment 1

[Alexandru Michis [:malexandru]]

Sebastian, this looks to be caused by the changes in Bug 1536058, could you please take a look at it?

Comment 2

[Intermittent Failures Robot]

16 failures in 5073 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 14
• try: 2

Platform breakdown:

• android-em-4-3-armv7-api16: 16

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

Comment 3

[Sebastian Streich [:sstreich]]

Attachment: Bug 1576039 - Adding more Time to Prevent Timeouts r=pbz

Comment 4

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/113859f7ed84
Adding more Time to Prevent Timeouts r=pbz

Comment 5

[Alexandru Michis [:malexandru]]

https://hg.mozilla.org/mozilla-central/rev/113859f7ed84

Comment 6

[Intermittent Failures Robot]

3 failures in 5047 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 2
• try: 1

Platform breakdown:

• android-em-4-3-armv7-api16: 3

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