Closed Bug 1714594 Opened 3 years ago Closed 3 years ago

Perma [tier2] fission xorig TEST-UNEXPECTED-TIMEOUT | layout/base/tests/test_reftests_with_caret.html | application timed out after 370 seconds with no output

Categories

(Core :: Layout, defect, P5)

defect

Tracking

()

RESOLVED FIXED
91 Branch
Tracking Status
firefox-esr78 --- unaffected
firefox89 --- unaffected
firefox90 --- unaffected
firefox91 --- fixed

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Attachments

(1 file)

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=341743369&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ArWbsYp9RoaaYO9xSEOTfg/runs/0/artifacts/public/logs/live_backing.log


[task 2021-06-04T10:56:34.609Z] 10:56:34     INFO - TEST-START | layout/base/tests/test_reftests_with_caret.html
[task 2021-06-04T10:56:34.627Z] 10:56:34     INFO - GECKO(7035) | [Child 7174, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-06-04T10:56:34.654Z] 10:56:34     INFO - GECKO(7035) | [Child 7174, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-06-04T10:56:34.711Z] 10:56:34     INFO - GECKO(7035) | [Child 7174, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-06-04T10:56:34.769Z] 10:56:34     INFO - GECKO(7035) | [Child 9462, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3357
[task 2021-06-04T10:56:34.790Z] 10:56:34     INFO - GECKO(7035) | [Child 9462, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4442
[task 2021-06-04T10:56:34.860Z] 10:56:34     INFO - GECKO(7035) | [Parent 7035, Main Thread] WARNING: WebProgress Ignored: no longer current window global: file /builds/worker/checkouts/gecko/dom/ipc/BrowserParent.cpp:2925
[task 2021-06-04T10:56:35.039Z] 10:56:35     INFO - GECKO(7035) | JavaScript error: http://mochi.test:8888/tests/layout/base/tests/test_reftests_with_caret.html?currentTestURL=layout%2Fbase%2Ftests%2Ftest_reftests_with_caret.html&closeWhenDone=1&showTestReport=false&expected=fail, line 101: SecurityError: Permission denied to access property "document" on cross-origin object
[task 2021-06-04T10:56:35.093Z] 10:56:35     INFO - GECKO(7035) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpta_8w2kv.mozrunner/runtests_leaks_tab_pid9544.log
[task 2021-06-04T10:56:35.095Z] 10:56:35     INFO - GECKO(7035) | [9544, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:254
[task 2021-06-04T10:56:35.123Z] 10:56:35     INFO - GECKO(7035) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpta_8w2kv.mozrunner/runtests_leaks_tab_pid9547.log
[task 2021-06-04T10:56:35.123Z] 10:56:35     INFO - GECKO(7035) | [9547, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:254
[task 2021-06-04T10:56:35.199Z] 10:56:35     INFO - GECKO(7035) | [Child 9544, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:619
[task 2021-06-04T10:56:35.223Z] 10:56:35     INFO - GECKO(7035) | [Child 9547, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:619
[task 2021-06-04T10:58:24.576Z] 10:58:24     INFO - GECKO(7035) | 1622804304574	addons.xpi	ERROR	System addon update list error Error: got node name: html, expected: updates
[task 2021-06-04T11:04:34.586Z] 11:04:34     INFO - Buffered messages logged at 10:56:35
[task 2021-06-04T11:04:34.588Z] 11:04:34     INFO - must wait for load
[task 2021-06-04T11:04:34.589Z] 11:04:34     INFO - must wait for focus
[task 2021-06-04T11:04:34.590Z] 11:04:34     INFO - Buffered messages finished
[task 2021-06-04T11:04:34.591Z] 11:04:34    ERROR - TEST-UNEXPECTED-TIMEOUT | layout/base/tests/test_reftests_with_caret.html | application timed out after 370 seconds with no output
[task 2021-06-04T11:04:34.592Z] 11:04:34    ERROR - Force-terminating active process(es).
[task 2021-06-04T11:04:34.593Z] 11:04:34     INFO - Determining child pids from psutil...
[task 2021-06-04T11:04:34.608Z] 11:04:34     INFO - [7093, 7115, 7168, 7174, 7187, 7190, 7259, 7263, 7311, 7337, 7362, 7387, 7412, 7438, 7463, 7488, 7513, 7538, 7563, 7588, 7616, 7641, 7670, 7696, 7721, 7747, 7774, 7799, 7824, 7849, 7874, 7898, 7923, 7948, 7973, 7998, 8023, 8048, 8073, 8098, 8123, 8148, 8173, 8197, 8227, 8252, 8277, 8302, 8327, 8352, 8377, 8402, 8427, 8454, 8461, 8504, 8529, 8554, 8579, 8604, 8629, 8654, 8679, 8704, 8729, 8754, 8779, 8804, 8829, 8854, 8879, 8904, 8929, 8956, 8981, 9006, 9031, 9056, 9082, 9107, 9136, 9161, 9186, 9211, 9236, 9261, 9286, 9311, 9336, 9361, 9386, 9411, 9437, 9462, 9488, 9513, 9544, 9547]
[task 2021-06-04T11:04:34.609Z] 11:04:34     INFO - ==> process 7035 launched child process 7055
[task 2021-06-04T11:04:34.610Z] 11:04:34     INFO - ==> process 7035 launched child process 7093

[task 2021-06-04T11:04:34.682Z] 11:04:34     INFO - ==> process 7035 launched child process 9488
[task 2021-06-04T11:04:34.682Z] 11:04:34     INFO - ==> process 7035 launched child process 9513
[task 2021-06-04T11:04:34.682Z] 11:04:34     INFO - ==> process 7035 launched child process 9544
[task 2021-06-04T11:04:34.683Z] 11:04:34     INFO - ==> process 7035 launched child process 9547
[task 2021-06-04T11:04:34.683Z] 11:04:34     INFO - Found child pids: {7168, 8704, 8197, 7174, 7696, 7187, 9236, 7190, 8729, 8227, 7721, 9261, 8754, 8252, 7747, 9286, 8779, 8277, 7259, 7774, 7263, 9311, 8804, 8302, 7799, 9336, 8829, 8327, 7311, 7824, 9361, 8854, 8352, 7337, 7849, 9386, 8879, 8377, 7362, 7874, 9411, 8904, 8402, 7898, 7387, 9437, 8929, 8427, 7923, 7412, 9462, 8956, 8454, 7948, 8461, 7438, 9488, 8981, 7973, 7463, 9513, 9006, 8504, 7998, 7488, 9031, 9544, 9547, 8529, 8023, 7513, 9056, 8554, 8048, 7538, 9082, 8579, 8073, 7563, 7055, 9107, 8604, 8098, 7588, 9136, 7093, 8629, 8123, 7616, 9161, 7115, 8654, 8148, 7641, 9186, 8679, 8173, 7670, 9211}
[task 2021-06-04T11:04:34.683Z] 11:04:34     INFO - Failed to get child procs
[task 2021-06-04T11:04:34.684Z] 11:04:34     INFO - Killing process: 7168
[task 2021-06-04T11:04:34.684Z] 11:04:34     INFO - TEST-INFO | started process screentopng
[task 2021-06-04T11:04:34.794Z] 11:04:34     INFO - TEST-INFO | screentopng: exit 0

Bisection points to bug 1712900 as the regressor.

Flags: needinfo?(enndeakin)
Keywords: regression
Regressed by: 1712900
Summary: Perma [tier2] TEST-UNEXPECTED-TIMEOUT | layout/base/tests/test_reftests_with_caret.html | application timed out after 370 seconds with no output → Perma [tier2] fission xorig TEST-UNEXPECTED-TIMEOUT | layout/base/tests/test_reftests_with_caret.html | application timed out after 370 seconds with no output
Has Regression Range: --- → yes

The test was actually failing, but still printing out the exception, before 1712900 in cross-origin mode as well, but the exception was being silently ignored. The test is marked as always failing with xorigin mode on. This test should probably be marked as 'skip-if' rather than 'fail-if' since the test doesn't fail, it throws an exception.

Flags: needinfo?(enndeakin)
Assignee: nobody → enndeakin
Status: NEW → ASSIGNED

Or, better, the patch above, just fixes the problem in cross origin mode.

Pushed by neil@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/6ec611a9ef3e
fix test_reftests_with_caret.html to use SpecialPowers.spawn to adjust the parent frame, and re-enable in xorigin mode, r=emilio
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → 91 Branch
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: