1599516 - Intermittent TEST-UNEXPECTED-TIMEOUT | dom/base/test/test_postMessage_solidus.html | application timed out after 370 seconds with no output

Status: RESOLVED FIXED

(Core :: DOM: Core & HTML, defect)

Description

[Bogdan Tara[:bogdan_tara | bogdant]]

+++ This bug was initially created as a clone of Bug #1597882 +++

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

---

[task 2019-11-20T03:06:58.963Z] 03:06:58 INFO - TEST-START | dom/base/test/test_postMessage_solidus.html
[task 2019-11-20T03:06:58.964Z] 03:06:58 INFO - GECKO(2845) | [Parent 2845, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4562
[task 2019-11-20T03:06:59.032Z] 03:06:59 INFO - GECKO(2845) | [Parent 2845, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4562
[task 2019-11-20T03:06:59.060Z] 03:06:59 INFO - GECKO(2845) | [Parent 2845, QuotaManager IO] WARNING: '!outputStream', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 2395
[task 2019-11-20T03:06:59.061Z] 03:06:59 INFO - GECKO(2845) | [Parent 2845, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8348
[task 2019-11-20T03:06:59.061Z] 03:06:59 INFO - GECKO(2845) | [Parent 2845, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8210
[task 2019-11-20T03:06:59.061Z] 03:06:59 INFO - GECKO(2845) | [Parent 2845, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8120
[task 2019-11-20T03:06:59.061Z] 03:06:59 INFO - GECKO(2845) | [Parent 2845, QuotaManager IO] WARNING: '!outputStream', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 2395
[task 2019-11-20T03:06:59.062Z] 03:06:59 INFO - GECKO(2845) | [Parent 2845, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8348
[task 2019-11-20T03:06:59.062Z] 03:06:59 INFO - GECKO(2845) | [Parent 2845, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8210
[task 2019-11-20T03:06:59.063Z] 03:06:59 INFO - GECKO(2845) | [Parent 2845, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8120
[task 2019-11-20T03:06:59.281Z] 03:06:59 INFO - GECKO(2845) | --DOCSHELL 0x7f16a0f1c800 == 3 [pid = 3021] [id = {5f76cc63-3412-49a6-9e4c-6c5cf56db177}] [url = http://mochi.test:8888/tests/dom/base/test/file_pluginAudioNonAutoStart.html]
[task 2019-11-20T03:06:59.281Z] 03:06:59 INFO - GECKO(2845) | --DOMWINDOW == 43 (0x7f16a0dc0400) [pid = 3021] [serial = 1704] [outer = (nil)] [url = about:blank]
[task 2019-11-20T03:06:59.281Z] 03:06:59 INFO - GECKO(2845) | --DOMWINDOW == 42 (0x7f16a0e03000) [pid = 3021] [serial = 1707] [outer = (nil)] [url = about:blank]
[task 2019-11-20T03:06:59.369Z] 03:06:59 INFO - JavaScript error: /builds/worker/workspace/build/tests/bin/components/httpd.js, line 3824: NS_ERROR_NOT_AVAILABLE:
[task 2019-11-20T03:06:59.370Z] 03:06:59 INFO - JavaScript error: /builds/worker/workspace/build/tests/bin/components/httpd.js, line 3824: NS_ERROR_NOT_AVAILABLE:
[task 2019-11-20T03:06:59.534Z] 03:06:59 INFO - GECKO(2845) | [Child 3021, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/workspace/build/src/dom/base/Document.cpp, line 6826
[task 2019-11-20T03:06:59.535Z] 03:06:59 INFO - GECKO(2845) | [Child 3021, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/workspace/build/src/dom/base/Document.cpp, line 6826
[task 2019-11-20T03:06:59.536Z] 03:06:59 INFO - GECKO(2845) | --DOMWINDOW == 41 (0x7f16a95c1020) [pid = 3021] [serial = 1703] [outer = (nil)] [url = about:blank]
[task 2019-11-20T03:06:59.537Z] 03:06:59 INFO - GECKO(2845) | --DOMWINDOW == 40 (0x7f16a95c17a0) [pid = 3021] [serial = 1706] [outer = (nil)] [url = about:blank]
[task 2019-11-20T03:06:59.537Z] 03:06:59 INFO - GECKO(2845) | --DOMWINDOW == 39 (0x7f16a95c13e0) [pid = 3021] [serial = 1716] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/base/test/file_pluginAudioNonAutoStart.html]
[task 2019-11-20T03:06:59.538Z] 03:06:59 INFO - GECKO(2845) | --DOMWINDOW == 38 (0x7f16a95c1200) [pid = 3021] [serial = 1711] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/base/test/file_pluginAudio.html]

[task 2019-11-20T03:13:36.739Z] 03:13:36 INFO - JavaScript error: /builds/worker/workspace/build/tests/bin/components/httpd.js, line 3824: NS_ERROR_NOT_AVAILABLE:
[task 2019-11-20T03:13:37.241Z] 03:13:37 INFO - JavaScript error: /builds/worker/workspace/build/tests/bin/components/httpd.js, line 3824: NS_ERROR_NOT_AVAILABLE:
[task 2019-11-20T03:13:37.241Z] 03:13:37 INFO - JavaScript error: /builds/worker/workspace/build/tests/bin/components/httpd.js, line 3824: NS_ERROR_NOT_AVAILABLE:
[task 2019-11-20T03:13:37.462Z] 03:13:37 INFO - Buffered messages finished
[task 2019-11-20T03:13:37.464Z] 03:13:37 ERROR - TEST-UNEXPECTED-TIMEOUT | dom/base/test/test_postMessage_solidus.html | application timed out after 370 seconds with no output
[task 2019-11-20T03:13:37.466Z] 03:13:37 ERROR - Force-terminating active process(es).
[task 2019-11-20T03:13:37.467Z] 03:13:37 INFO - Determining child pids from psutil...
[task 2019-11-20T03:13:37.467Z] 03:13:37 INFO - [3055, 2998, 2881, 4248, 3021, 2914]
[task 2019-11-20T03:13:37.467Z] 03:13:37 INFO - ==> process 2845 launched child process 2863
[task 2019-11-20T03:13:37.468Z] 03:13:37 INFO - ==> process 2845 launched child process 2881
[task 2019-11-20T03:13:37.468Z] 03:13:37 INFO - ==> process 2845 launched child process 2914
[task 2019-11-20T03:13:37.468Z] 03:13:37 INFO - ==> process 2845 launched child process 2935
[task 2019-11-20T03:13:37.470Z] 03:13:37 INFO - ==> process 2845 launched child process 2998
[task 2019-11-20T03:13:37.470Z] 03:13:37 INFO - ==> process 2845 launched child process 3021
[task 2019-11-20T03:13:37.471Z] 03:13:37 INFO - ==> process 2845 launched child process 3055
[task 2019-11-20T03:13:37.472Z] 03:13:37 INFO - ==> process 2845 launched child process 3101
[task 2019-11-20T03:13:37.473Z] 03:13:37 INFO - ==> process 2845 launched child process 3127
[task 2019-11-20T03:13:37.474Z] 03:13:37 INFO - ==> process 2845 launched child process 3152
[task 2019-11-20T03:13:37.476Z] 03:13:37 INFO - ==> process 2845 launched child process 3177

[task 2019-11-20T03:13:37.527Z] 03:13:37 INFO - Found child pids: set([4103, 3597, 5134, 3101, 4643, 3625, 5163, 4653, 3127, 3679, 4156, 3651, 5189, 3152, 4184, 5215, 4713, 4211, 3177, 5240, 3202, 4741, 5265, 3734, 4248, 3228, 4768, 5290, 3762, 3253, 4279, 4793, 5315, 4296, 3279, 3792, 3704, 4818, 4131, 5340, 3304, 3817, 4843, 5367, 3967, 3842, 3331, 4868, 5392, 4377, 3867, 3356, 4893, 5417, 2863, 3892, 3381, 4928, 2881, 5442, 3917, 3407, 4438, 4954, 5467, 2914, 3942, 3437, 4979, 5493, 2935, 4479, 5639, 3466, 5518, 5008, 4503, 3992, 3491, 5543, 5033, 4528, 4020, 2998, 3519, 5569, 5058, 3021, 4050, 4565, 3544, 5083, 5597, 4575, 4078, 3055, 3572, 5109])
[task 2019-11-20T03:13:37.527Z] 03:13:37 INFO - Failed to get child procs
[task 2019-11-20T03:13:37.528Z] 03:13:37 INFO - Killing process: 4103
[task 2019-11-20T03:13:37.528Z] 03:13:37 INFO - TEST-INFO | started process screentopng
[task 2019-11-20T03:13:37.746Z] 03:13:37 INFO - JavaScript error: /builds/worker/workspace/build/tests/bin/components/httpd.js, line 3824: NS_ERROR_NOT_AVAILABLE:
[task 2019-11-20T03:13:37.747Z] 03:13:37 INFO - JavaScript error: /builds/worker/workspace/build/tests/bin/components/httpd.js, line 3824: NS_ERROR_NOT_AVAILABLE:
[task 2019-11-20T03:13:37.777Z] 03:13:37 INFO - TEST-INFO | screentopng: exit 0
[task 2019-11-20T03:13:37.778Z] 03:13:37 INFO - Can't trigger Breakpad, process no longer exists

Comment 1

[Bogdan Tara[:bogdan_tara | bogdant]]

So far this seems intermittent:
https://treeherder.mozilla.org/#/jobs?repo=autoland&resultStatus=pending%2Crunning%2Csuccess%2Ctestfailed%2Cbusted%2Cexception&classifiedState=unclassified&searchStr=linux%2Cx64%2Cdebug%2Cmochitests%2Ctest-linux64%2Fdebug-mochitest-e10s-2%2Cm%282%29&tochange=d89bbe494f6b6f1fc9839bdb204afaf64d42f75c&selectedJob=278251093

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=278251093&repo=autoland

[task 2019-11-26T17:04:29.724Z] 17:04:29 INFO - TEST-START | dom/base/test/test_postMessage_solidus.html
[task 2019-11-26T17:04:29.759Z] 17:04:29 INFO - GECKO(2108) | [Parent 2108, Main Thread] WARNING: we only accept nsIURI interface type, patch welcome: file /builds/worker/workspace/build/src/dom/ipc/PropertyBagUtils.cpp, line 112
[task 2019-11-26T17:04:29.805Z] 17:04:29 INFO - GECKO(2108) | [Parent 2108, QuotaManager IO] WARNING: '!outputStream', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 2399
[task 2019-11-26T17:04:29.806Z] 17:04:29 INFO - GECKO(2108) | [Parent 2108, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8450
[task 2019-11-26T17:04:29.806Z] 17:04:29 INFO - GECKO(2108) | [Parent 2108, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8312
[task 2019-11-26T17:04:29.806Z] 17:04:29 INFO - GECKO(2108) | [Parent 2108, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8222
[task 2019-11-26T17:04:29.806Z] 17:04:29 INFO - GECKO(2108) | [Parent 2108, QuotaManager IO] WARNING: '!outputStream', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 2399
[task 2019-11-26T17:04:29.806Z] 17:04:29 INFO - GECKO(2108) | [Parent 2108, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8450
[task 2019-11-26T17:04:29.806Z] 17:04:29 INFO - GECKO(2108) | [Parent 2108, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8312
[task 2019-11-26T17:04:29.806Z] 17:04:29 INFO - GECKO(2108) | [Parent 2108, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/quota/ActorsParent.cpp, line 8222
[task 2019-11-26T17:04:29.906Z] 17:04:29 INFO - JavaScript error: /builds/worker/workspace/build/tests/bin/components/httpd.js, line 3824: NS_ERROR_NOT_AVAILABLE:
[task 2019-11-26T17:04:29.906Z] 17:04:29 INFO - JavaScript error: /builds/worker/workspace/build/tests/bin/components/httpd.js, line 3824: NS_ERROR_NOT_AVAILABLE:
[task 2019-11-26T17:04:29.967Z] 17:04:29 INFO - GECKO(2108) | --DOCSHELL 0x7faab9bed000 == 5 [pid = 2181] [id = {f4055364-f6f1-4128-ba68-0273b36e67a5}] [url = http://mochi.test:8888/tests/dom/base/test/file_pluginAudio.html]
[task 2019-11-26T17:04:29.968Z] 17:04:29 INFO - GECKO(2108) | --DOCSHELL 0x7faab85e6000 == 4 [pid = 2181] [id = {03b1c332-d986-4222-ac5a-d42b6c884cd5}] [url = http://mochi.test:8888/tests/dom/base/test/file_pluginAudioNonAutoStart.html]
[task 2019-11-26T17:04:29.971Z] 17:04:29 INFO - GECKO(2108) | --DOMWINDOW == 43 (0x7faac103ac00) [pid = 2181] [serial = 2379] [outer = (nil)] [url = about:blank]
...
[task 2019-11-26T17:11:08.783Z] 17:11:08 INFO - JavaScript error: /builds/worker/workspace/build/tests/bin/components/httpd.js, line 3824: NS_ERROR_NOT_AVAILABLE:
[task 2019-11-26T17:11:08.784Z] 17:11:08 INFO - JavaScript error: /builds/worker/workspace/build/tests/bin/components/httpd.js, line 3824: NS_ERROR_NOT_AVAILABLE:
[task 2019-11-26T17:11:08.824Z] 17:11:08 INFO - Buffered messages finished
[task 2019-11-26T17:11:08.825Z] 17:11:08 ERROR - TEST-UNEXPECTED-TIMEOUT | dom/base/test/test_postMessage_solidus.html | application timed out after 370 seconds with no output
[task 2019-11-26T17:11:08.826Z] 17:11:08 ERROR - Force-terminating active process(es).
[task 2019-11-26T17:11:08.826Z] 17:11:08 INFO - Determining child pids from psutil...
[task 2019-11-26T17:11:08.831Z] 17:11:08 INFO - [2181, 2289, 2160, 2236]
[task 2019-11-26T17:11:08.831Z] 17:11:08 INFO - ==> process 2108 launched child process 2122
[task 2019-11-26T17:11:08.833Z] 17:11:08 INFO - ==> process 2108 launched child process 2160
[task 2019-11-26T17:11:08.833Z] 17:11:08 INFO - ==> process 2108 launched child process 2181
[task 2019-11-26T17:11:08.834Z] 17:11:08 INFO - ==> process 2108 launched child process 2236
[task 2019-11-26T17:11:08.835Z] 17:11:08 INFO - ==> process 2108 launched child process 2289
[task 2019-11-26T17:11:08.835Z] 17:11:08 INFO - ==> process 2108 launched child process 2559
[task 2019-11-26T17:11:08.836Z] 17:11:08 INFO - Found child pids: set([2181, 2122, 2160, 2289, 2236, 2559])
[task 2019-11-26T17:11:08.836Z] 17:11:08 INFO - Failed to get child procs
[task 2019-11-26T17:11:08.837Z] 17:11:08 INFO - Killing process: 2181
[task 2019-11-26T17:11:08.838Z] 17:11:08 INFO - TEST-INFO | started process screentopng
[task 2019-11-26T17:11:09.095Z] 17:11:09 INFO - TEST-INFO | screentopng: exit 0

Comment 2

[Intermittent Failures Robot]

46 failures in 899 pushes (0.051 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 37
• mozilla-central: 9

Platform breakdown:

• windows7-32: 7
• linux64-qr: 11
• linux64: 7
• windows7-32-shippable: 4
• macosx1014-64: 6
• windows10-64-shippable: 3
• windows10-64-qr: 2
• windows10-64-shippable-qr: 4
• windows10-64: 2

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

Comment 3

[Andreea Pavel [:apavel]]

Fixed by https://hg.mozilla.org/integration/autoland/rev/056ea65222b5

Comment 5

[Intermittent Failures Robot]

46 failures in 4331 pushes (0.011 failures/push) were associated with this bug in the last 7 days.

This is the #13 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 37
• mozilla-central: 9

Platform breakdown:

• linux64-qr: 11
• linux64: 7
• windows7-32: 7
• windows7-32-shippable: 4
• macosx1014-64: 6
• windows10-64: 2
• windows10-64-qr: 2
• windows10-64-shippable: 3
• windows10-64-shippable-qr: 4

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