Open Bug 1271190 Opened 4 years ago Updated 4 months ago

Intermittent test_SpecialPowersPushPermissions.html | Test timed out.

Categories

(Testing :: Mochitest, defect)

defect
Not set

Tracking

(Not tracked)

People

(Reporter: cbook, Unassigned)

References

()

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown])

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

 12:55:37 INFO - 337 INFO TEST-UNEXPECTED-FAIL | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | Test timed out.
I think this component might be a better fit. :-)
Component: DOM: Push Notifications → Mochitest
Product: Core → Testing
interesting that this is failing, this picked up on android debug starting Feb 2, I did a bunch of retriggers here:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&filter-searchStr=android%20debug%20mochitest-32&tochange=7259adb4d564cecb66b418c8937d917ba530b4ed&fromchange=ad428bc273fea671c412d5a498a492b31e20073b&selectedJob=73744667

I will update this bug when those retriggers are done
Flags: needinfo?(jmaher)
according to the retriggers, bug 1260548 is the cause.  as bug 1260548 is changing android stuff and this test is failing on android, I have higher confidence this is correct.


[task 2017-02-08T12:11:00.138452Z] 12:11:00     INFO -  23 INFO TEST-START | testing/mochitest/tests/Harness_sanity/test_SpecialPowersLoadPrivilegedScript.html
[task 2017-02-08T12:11:00.138901Z] 12:11:00     INFO -  24 INFO TEST-OK | testing/mochitest/tests/Harness_sanity/test_SpecialPowersLoadPrivilegedScript.html | took 2949ms
[task 2017-02-08T12:11:00.139174Z] 12:11:00     INFO -  25 INFO TEST-START | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html
[task 2017-02-08T12:16:08.989585Z] 12:16:08     INFO -  Buffered messages logged at 12:11:02
[task 2017-02-08T12:16:08.990305Z] 12:16:08     INFO -  26 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | A valid string reason is expected
[task 2017-02-08T12:16:08.990390Z] 12:16:08     INFO -  27 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | Reason cannot be empty
[task 2017-02-08T12:16:08.990465Z] 12:16:08     INFO -  Buffered messages logged at 12:11:03
[task 2017-02-08T12:16:08.992167Z] 12:16:08     INFO -  28 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pUNKNOWN value should have UNKOWN permission
[task 2017-02-08T12:16:08.992233Z] 12:16:08     INFO -  Buffered messages logged at 12:11:04
[task 2017-02-08T12:16:08.992318Z] 12:16:08     INFO -  29 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pUNKNOWN value should have ALLOW permission
[task 2017-02-08T12:16:08.992413Z] 12:16:08     INFO -  30 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pPROMPT value should have ALLOW permission
[task 2017-02-08T12:16:08.992494Z] 12:16:08     INFO -  31 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pALLOW should have DENY permission
[task 2017-02-08T12:16:08.992579Z] 12:16:08     INFO -  32 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pDENY should have ALLOW permission
[task 2017-02-08T12:16:08.992672Z] 12:16:08     INFO -  33 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pREMOVE should have REMOVE permission
[task 2017-02-08T12:16:08.993195Z] 12:16:08     INFO -  34 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pSESSION should have ALLOW permission
[task 2017-02-08T12:16:08.993715Z] 12:16:08     INFO -  35 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pFIRSTPARTY should have ALLOW permission
[task 2017-02-08T12:16:08.994327Z] 12:16:08     INFO -  36 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pTHIRDPARTY should have ALLOW permission
[task 2017-02-08T12:16:08.994966Z] 12:16:08     INFO -  Buffered messages logged at 12:11:05
[task 2017-02-08T12:16:08.995684Z] 12:16:08     INFO -  37 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pPROMPT value should have DENY permission
[task 2017-02-08T12:16:08.996460Z] 12:16:08     INFO -  38 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pUNKNOWN value should have DENY permission
[task 2017-02-08T12:16:08.997078Z] 12:16:08     INFO -  39 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pPROMPT value should have ALLOW permission
[task 2017-02-08T12:16:08.997659Z] 12:16:08     INFO -  40 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pALLOW should have PROMPT permission
[task 2017-02-08T12:16:08.998287Z] 12:16:08     INFO -  41 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pDENY should have PROMPT permission
[task 2017-02-08T12:16:08.998388Z] 12:16:08     INFO -  Buffered messages logged at 12:11:06
[task 2017-02-08T12:16:08.998835Z] 12:16:08     INFO -  42 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pUNKNOWN should have UNKNOWN permission
[task 2017-02-08T12:16:08.999370Z] 12:16:08     INFO -  43 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pALLOW should have ALLOW permission
[task 2017-02-08T12:16:08.999610Z] 12:16:08     INFO -  44 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pDENY should have DENY permission
[task 2017-02-08T12:16:09.000170Z] 12:16:08     INFO -  45 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pPROMPT should have PROMPT permission
[task 2017-02-08T12:16:09.000510Z] 12:16:09     INFO -  46 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pREMOVE should have ALLOW permission
[task 2017-02-08T12:16:09.001220Z] 12:16:09     INFO -  47 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pSESSION should have ACCESS_SESSION permission
[task 2017-02-08T12:16:09.001324Z] 12:16:09     INFO -  48 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pFIRSTPARTY should have ACCESS_ALLOW_FIRST_PARTY_ONLY permission
[task 2017-02-08T12:16:09.001424Z] 12:16:09     INFO -  49 INFO TEST-PASS | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | pTHIRDPARTY should have ACCESS_LIMIT_THIRD_PARTY permission
[task 2017-02-08T12:16:09.001979Z] 12:16:09     INFO -  Buffered messages logged at 12:11:07
[task 2017-02-08T12:16:09.002359Z] 12:16:09     INFO -  50 INFO TEST-FAIL | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | The author of the test has indicated that flaky timeouts are expected.  Reason: untriaged
[task 2017-02-08T12:16:09.002415Z] 12:16:09     INFO -  Buffered messages logged at 12:11:12
[task 2017-02-08T12:16:09.002472Z] 12:16:09     INFO -  51 INFO Wait for permission-changed signal!
[task 2017-02-08T12:16:09.002528Z] 12:16:09     INFO -  Buffered messages finished
[task 2017-02-08T12:16:09.002803Z] 12:16:09     INFO -  52 INFO TEST-UNEXPECTED-FAIL | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | Test timed out.
[task 2017-02-08T12:16:09.003058Z] 12:16:09     INFO -      reportError@SimpleTest/TestRunner.js:114:7
[task 2017-02-08T12:16:09.003418Z] 12:16:09     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:135:7
[task 2017-02-08T12:16:09.003672Z] 12:16:09     INFO -  53 ERROR [SimpleTest.finish()] this test already called finish!
[task 2017-02-08T12:16:09.003914Z] 12:16:09     INFO -  54 INFO TEST-UNEXPECTED-ERROR | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | called finish() multiple times
[task 2017-02-08T12:16:09.004277Z] 12:16:09     INFO -  TEST-INFO took 307226ms
[task 2017-02-08T12:16:40.723349Z] 12:16:40     INFO -  55 INFO TEST-UNEXPECTED-FAIL | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | Test timed out.
[task 2017-02-08T12:16:40.723724Z] 12:16:40     INFO -      reportError@SimpleTest/TestRunner.js:114:7
[task 2017-02-08T12:16:40.723945Z] 12:16:40     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:135:7
[task 2017-02-08T12:16:40.724694Z] 12:16:40     INFO -  56 ERROR [SimpleTest.finish()] this test already called finish!
[task 2017-02-08T12:16:40.724758Z] 12:16:40     INFO -  57 INFO TEST-UNEXPECTED-ERROR | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | called finish() multiple times
[task 2017-02-08T12:16:40.724785Z] 12:16:40     INFO -  TEST-INFO
[task 2017-02-08T12:17:12.341147Z] 12:17:12     INFO -  58 INFO TEST-UNEXPECTED-FAIL | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | Test timed out.
[task 2017-02-08T12:17:12.341774Z] 12:17:12     INFO -      reportError@SimpleTest/TestRunner.js:114:7
[task 2017-02-08T12:17:12.341845Z] 12:17:12     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:135:7
[task 2017-02-08T12:17:12.342543Z] 12:17:12     INFO -  59 ERROR [SimpleTest.finish()] this test already called finish!
[task 2017-02-08T12:17:12.342947Z] 12:17:12     INFO -  60 INFO TEST-UNEXPECTED-ERROR | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | called finish() multiple times
[task 2017-02-08T12:17:12.343120Z] 12:17:12     INFO -  TEST-INFO
[task 2017-02-08T12:17:44.015952Z] 12:17:44     INFO -  61 INFO TEST-UNEXPECTED-FAIL | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | Test timed out.
[task 2017-02-08T12:17:44.016025Z] 12:17:44     INFO -      reportError@SimpleTest/TestRunner.js:114:7
[task 2017-02-08T12:17:44.016097Z] 12:17:44     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:135:7
[task 2017-02-08T12:17:44.016168Z] 12:17:44     INFO -  62 INFO TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | 4 test timeouts, giving up.
[task 2017-02-08T12:17:44.016290Z] 12:17:44     INFO -      reportError@SimpleTest/TestRunner.js:114:7
[task 2017-02-08T12:17:44.016549Z] 12:17:44     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:143:9
[task 2017-02-08T12:17:44.016829Z] 12:17:44     INFO -  63 INFO TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | Skipping 126 remaining tests.
[task 2017-02-08T12:17:44.017143Z] 12:17:44     INFO -      reportError@SimpleTest/TestRunner.js:114:7
[task 2017-02-08T12:17:44.017588Z] 12:17:44     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:145:9
[task 2017-02-08T12:17:44.018096Z] 12:17:44     INFO -  64 ERROR [SimpleTest.finish()] this test already called finish!
[task 2017-02-08T12:17:44.018427Z] 12:17:44     INFO -  65 INFO TEST-UNEXPECTED-ERROR | (SimpleTest/TestRunner.js) | called finish() multiple times
[task 2017-02-08T12:17:44.018740Z] 12:17:44     INFO -  TEST-INFO
[task 2017-02-08T12:23:46.548985Z] 12:23:46     INFO -  TEST-INFO | started process screentopng
[task 2017-02-08T12:23:46.964191Z] 12:23:46     INFO -  TEST-INFO | screentopng: exit 0
[task 2017-02-08T12:23:50.757286Z] 12:23:50     INFO -  org.mozilla.fennec still alive after SIGABRT: waiting...
[task 2017-02-08T12:23:55.927591Z] 12:23:55  WARNING -  TEST-UNEXPECTED-FAIL | testing/mochitest/tests/Harness_sanity/test_SpecialPowersPushPermissions.html | application timed out after 330 seconds with no output

possibly what stands out to me is:
[task 2017-02-08T12:16:09.002472Z] 12:16:09     INFO -  51 INFO Wait for permission-changed signal!


:kmag, I see you are the patch author of bug 1260548, could you take a look at this in the next week or two?
Blocks: 1260548
Flags: needinfo?(jmaher) → needinfo?(kmaglione+bmo)
None of our tests actually run in the same group as the failing test, which means none of the code changed by bug 1260548 should even be loaded. If it's actually the cause of the failures, my best guess is that it's because the additional tests changed what runs in that group, or some changes to the profile are being preserved across test runs.
Flags: needinfo?(kmaglione+bmo)
Whiteboard: [stockwell unknown]
You need to log in before you can comment on or make changes to this bug.