Closed Bug 1590333 Opened 6 years ago Closed 6 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | dom/tests/mochitest/fetch/test_formdataparsing.html | application timed out after 370 seconds with no output

Categories

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

Product:
Core
Component:
DOM: Networking
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, Whiteboard: [necko-triaged])

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

...
[task 2019-10-22T07:30:29.379Z] 07:30:29 INFO - Content-Disposition: form-data; name="file"; filename="file with spaces"
[task 2019-10-22T07:30:29.379Z] 07:30:29 INFO -
[task 2019-10-22T07:30:29.379Z] 07:30:29 INFO -
[task 2019-10-22T07:30:29.380Z] 07:30:29 INFO - 1234567891011121314151617-
[task 2019-10-22T07:30:29.380Z] 07:30:29 INFO - TEST-PASS | dom/tests/mochitest/fetch/test_formdataparsing.html | NestedWorker: true: Entry with filename attribute should be read as File.
[task 2019-10-22T07:30:29.380Z] 07:30:29 INFO - TEST-PASS | dom/tests/mochitest/fetch/test_formdataparsing.html | NestedWorker: file with spaces === file with spaces: Filename should match.
[task 2019-10-22T07:30:29.381Z] 07:30:29 INFO - TEST-PASS | dom/tests/mochitest/fetch/test_formdataparsing.html | NestedWorker: true: Expected test to be valid FormData for 1234567891011121314151617
[task 2019-10-22T07:30:29.381Z] 07:30:29 INFO - Content-Disposition: form-data; name="file"; filename="xml.txt"
[task 2019-10-22T07:30:29.381Z] 07:30:29 INFO - content-type : application/xml
[task 2019-10-22T07:30:29.381Z] 07:30:29 INFO -
[task 2019-10-22T07:30:29.382Z] 07:30:29 INFO - <body>foobar
[task 2019-10-22T07:30:29.382Z] 07:30:29 INFO -
[task 2019-10-22T07:30:29.382Z] 07:30:29 INFO - </body>
[task 2019-10-22T07:30:29.383Z] 07:30:29 INFO - 1234567891011121314151617-
[task 2019-10-22T07:30:29.383Z] 07:30:29 INFO - TEST-PASS | dom/tests/mochitest/fetch/test_formdataparsing.html | NestedWorker: true: Entry with filename attribute should be read as File.
[task 2019-10-22T07:30:29.383Z] 07:30:29 INFO - TEST-PASS | dom/tests/mochitest/fetch/test_formdataparsing.html | NestedWorker: xml.txt === xml.txt: Filename should match.
[task 2019-10-22T07:30:29.384Z] 07:30:29 INFO - TEST-PASS | dom/tests/mochitest/fetch/test_formdataparsing.html | NestedWorker: application/xml === application/xml: content-type should be application/xml.
[task 2019-10-22T07:30:29.384Z] 07:30:29 INFO - TEST-PASS | dom/tests/mochitest/fetch/test_formdataparsing.html | NestedWorker: === : File should be empty.
[task 2019-10-22T07:30:29.385Z] 07:30:29 INFO - TEST-PASS | dom/tests/mochitest/fetch/test_formdataparsing.html | NestedWorker: === : File should be empty.
[task 2019-10-22T07:30:29.385Z] 07:30:29 INFO - TEST-PASS | dom/tests/mochitest/fetch/test_formdataparsing.html | NestedWorker: === : File should be empty.
[task 2019-10-22T07:30:29.385Z] 07:30:29 INFO - TEST-PASS | dom/tests/mochitest/fetch/test_formdataparsing.html | NestedWorker: === : File should be empty.
[task 2019-10-22T07:30:29.386Z] 07:30:29 INFO - TEST-PASS | dom/tests/mochitest/fetch/test_formdataparsing.html | NestedWorker: <body>foobar
[task 2019-10-22T07:30:29.386Z] 07:30:29 INFO -
[task 2019-10-22T07:30:29.386Z] 07:30:29 INFO - </body> === <body>foobar
[task 2019-10-22T07:30:29.387Z] 07:30:29 INFO -
[task 2019-10-22T07:30:29.387Z] 07:30:29 INFO - </body>: File should have correct text.
[task 2019-10-22T07:30:29.387Z] 07:30:29 INFO - TEST-PASS | dom/tests/mochitest/fetch/test_formdataparsing.html | NestedWorker: <body>foobar
[task 2019-10-22T07:30:29.388Z] 07:30:29 INFO -
[task 2019-10-22T07:30:29.388Z] 07:30:29 INFO - </body> === <body>foobar
[task 2019-10-22T07:30:29.388Z] 07:30:29 INFO -
[task 2019-10-22T07:30:29.388Z] 07:30:29 INFO - </body>: File should have correct text.
[task 2019-10-22T07:30:29.389Z] 07:30:29 INFO - Buffered messages finished
[task 2019-10-22T07:30:29.389Z] 07:30:29 ERROR - TEST-UNEXPECTED-TIMEOUT | dom/tests/mochitest/fetch/test_formdataparsing.html | application timed out after 370 seconds with no output
[task 2019-10-22T07:30:29.390Z] 07:30:29 ERROR - Force-terminating active process(es).
[task 2019-10-22T07:30:29.390Z] 07:30:29 INFO - Determining child pids from psutil...
[task 2019-10-22T07:30:29.391Z] 07:30:29 INFO - [2066, 2088]
[task 2019-10-22T07:30:29.391Z] 07:30:29 INFO - ==> process 2013 launched child process 2031
[task 2019-10-22T07:30:29.391Z] 07:30:29 INFO - ==> process 2013 launched child process 2066
[task 2019-10-22T07:30:29.392Z] 07:30:29 INFO - ==> process 2013 launched child process 2088
[task 2019-10-22T07:30:29.392Z] 07:30:29 INFO - ==> process 2013 launched child process 2142
[task 2019-10-22T07:30:29.393Z] 07:30:29 INFO - Found child pids: set([2088, 2066, 2142, 2031])
[task 2019-10-22T07:30:29.393Z] 07:30:29 INFO - Failed to get child procs
[task 2019-10-22T07:30:29.394Z] 07:30:29 INFO - Killing process: 2088
[task 2019-10-22T07:30:29.394Z] 07:30:29 INFO - TEST-INFO | started process screentopng
[task 2019-10-22T07:30:29.611Z] 07:30:29 INFO - TEST-INFO | screentopng: exit 0
[task 2019-10-22T07:30:29.611Z] 07:30:29 INFO - Killing process: 2066
[task 2019-10-22T07:30:29.612Z] 07:30:29 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-10-22T07:30:29.612Z] 07:30:29 INFO - Killing process: 2142
[task 2019-10-22T07:30:29.612Z] 07:30:29 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-10-22T07:30:29.612Z] 07:30:29 INFO - Can't trigger Breakpad, process no longer exists
[task 2019-10-22T07:30:29.613Z] 07:30:29 INFO - Killing process: 2031
[task 2019-10-22T07:30:29.614Z] 07:30:29 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-10-22T07:30:29.616Z] 07:30:29 INFO - Can't trigger Breakpad, process no longer exists
[task 2019-10-22T07:30:29.616Z] 07:30:29 INFO - Killing process: 2013
[task 2019-10-22T07:30:29.616Z] 07:30:29 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-10-22T07:30:29.744Z] 07:30:29 INFO - psutil found pid 2013 dead
[task 2019-10-22T07:30:29.768Z] 07:30:29 WARNING - runtests.py | Failed to get app exit code - running/crashed?
[task 2019-10-22T07:30:29.768Z] 07:30:29 INFO - TEST-INFO | Main app process: exit 0
[task 2019-10-22T07:30:29.768Z] 07:30:29 INFO - runtests.py | Application ran for: 0:08:47.207300
[task 2019-10-22T07:30:29.768Z] 07:30:29 INFO - zombiecheck | Reading PID log: /tmp/tmpfR30nupidlog
[task 2019-10-22T07:30:29.768Z] 07:30:29 INFO - ==> process 2013 launched child process 2031
[task 2019-10-22T07:30:29.768Z] 07:30:29 INFO - ==> process 2013 launched child process 2066
[task 2019-10-22T07:30:29.768Z] 07:30:29 INFO - ==> process 2013 launched child process 2088
[task 2019-10-22T07:30:29.770Z] 07:30:29 INFO - ==> process 2013 launched child process 2142
[task 2019-10-22T07:30:29.770Z] 07:30:29 INFO - zombiecheck | Checking for orphan process with PID: 2088
[task 2019-10-22T07:30:29.770Z] 07:30:29 INFO - zombiecheck | Checking for orphan process with PID: 2066
[task 2019-10-22T07:30:29.771Z] 07:30:29 INFO - zombiecheck | Checking for orphan process with PID: 2142
[task 2019-10-22T07:30:29.771Z] 07:30:29 INFO - zombiecheck | Checking for orphan process with PID: 2031
[task 2019-10-22T07:30:29.772Z] 07:30:29 INFO - mozcrash Copy/paste: /builds/worker/workspace/build/linux64-minidump_stackwalk /tmp/tmpg6gylI.mozrunner/minidumps/57f4ac19-6cfe-e0e7-69cc-e95494604933.dmp /builds/worker/workspace/build/symbols
[task 2019-10-22T07:30:36.082Z] 07:30:36 INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/57f4ac19-6cfe-e0e7-69cc-e95494604933.dmp
[task 2019-10-22T07:30:36.083Z] 07:30:36 INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/57f4ac19-6cfe-e0e7-69cc-e95494604933.extra
[task 2019-10-22T07:30:36.205Z] 07:30:36 INFO - PROCESS-CRASH | Main app process exited normally | application crashed [@ libc-2.23.so + 0xfb74d]
[task 2019-10-22T07:30:36.205Z] 07:30:36 INFO - Crash dump filename: /tmp/tmpg6gylI.mozrunner/minidumps/57f4ac19-6cfe-e0e7-69cc-e95494604933.dmp
[task 2019-10-22T07:30:36.205Z] 07:30:36 INFO - Operating system: Linux
[task 2019-10-22T07:30:36.205Z] 07:30:36 INFO - 0.0.0 Linux 4.4.0-1014-aws #14taskcluster1-Ubuntu SMP Tue Apr 3 10:27:00 UTC 2018 x86_64
[task 2019-10-22T07:30:36.205Z] 07:30:36 INFO - CPU: amd64
[task 2019-10-22T07:30:36.206Z] 07:30:36 INFO - family 6 model 85 stepping 4
[task 2019-10-22T07:30:36.206Z] 07:30:36 INFO - 1 CPU
[task 2019-10-22T07:30:36.206Z] 07:30:36 INFO -
[task 2019-10-22T07:30:36.206Z] 07:30:36 INFO - GPU: UNKNOWN
[task 2019-10-22T07:30:36.207Z] 07:30:36 INFO -
[task 2019-10-22T07:30:36.207Z] 07:30:36 INFO - Crash reason: SIGABRT
[task 2019-10-22T07:30:36.207Z] 07:30:36 INFO - Crash address: 0x3e800000445
[task 2019-10-22T07:30:36.207Z] 07:30:36 INFO - Process uptime: not available
[task 2019-10-22T07:30:36.208Z] 07:30:36 INFO -
[task 2019-10-22T07:30:36.208Z] 07:30:36 INFO - Thread 0 (crashed)
[task 2019-10-22T07:30:36.208Z] 07:30:36 INFO - 0 libc-2.23.so + 0xfb74d
[task 2019-10-22T07:30:36.208Z] 07:30:36 INFO - rax = 0xfffffffffffffffc rdx = 0x00000000ffffffff
[task 2019-10-22T07:30:36.209Z] 07:30:36 INFO - rcx = 0x00007f47b0fcb74d rbx = 0x00007ffd266091e8
[task 2019-10-22T07:30:36.209Z] 07:30:36 INFO - rsi = 0x0000000000000003 rdi = 0x00007f47956fe060
[task 2019-10-22T07:30:36.209Z] 07:30:36 INFO - rbp = 0x00007ffd26609230 rsp = 0x00007ffd266091d0
[task 2019-10-22T07:30:36.209Z] 07:30:36 INFO - r8 = 0x0000000000000001 r9 = 0x0000000000000000
[task 2019-10-22T07:30:36.211Z] 07:30:36 INFO - r10 = 0x00007f47972ab5a0 r11 = 0x0000000000000293
[task 2019-10-22T07:30:36.211Z] 07:30:36 INFO - r12 = 0x00007f47956fe060 r13 = 0x00007ffd266091e0
[task 2019-10-22T07:30:36.211Z] 07:30:36 INFO - r14 = 0x00000000ffffffff r15 = 0x0000000000000003
[task 2019-10-22T07:30:36.211Z] 07:30:36 INFO - rip = 0x00007f47b0fcb74d
[task 2019-10-22T07:30:36.212Z] 07:30:36 INFO - Found by: given as instruction pointer in context
[task 2019-10-22T07:30:36.212Z] 07:30:36 INFO - 1 libxul.so!PollWrapper(_GPollFD*, unsigned int, int) [nsAppShell.cpp:548f97078fb734a0a02a99b09c3c54d3c367764b : 58 + 0xf]
[task 2019-10-22T07:30:36.212Z] 07:30:36 INFO - rbp = 0x00007ffd26609230 rsp = 0x00007ffd266091e0
[task 2019-10-22T07:30:36.212Z] 07:30:36 INFO - rip = 0x00007f47a0fa48f3
[task 2019-10-22T07:30:36.213Z] 07:30:36 INFO - Found by: stack scanning
[task 2019-10-22T07:30:36.213Z] 07:30:36 INFO - 2 libglib-2.0.so.0.4800.2 + 0x4a38c
[task 2019-10-22T07:30:36.213Z] 07:30:36 INFO - rbx = 0x00007f47b0cc5450 rbp = 0x0000000000000003
[task 2019-10-22T07:30:36.213Z] 07:30:36 INFO - rsp = 0x00007ffd26609240 r12 = 0x00007f47956fe060
[task 2019-10-22T07:30:36.213Z] 07:30:36 INFO - r13 = 0x00000000ffffffff r14 = 0x00007f47a0fa4833
[task 2019-10-22T07:30:36.214Z] 07:30:36 INFO - r15 = 0x0000000000000003 rip = 0x00007f47acd9338c
[task 2019-10-22T07:30:36.214Z] 07:30:36 INFO - Found by: call frame info
[task 2019-10-22T07:30:36.214Z] 07:30:36 INFO - 3 libglib-2.0.so.0.4800.2 + 0x4a49c
[task 2019-10-22T07:30:36.214Z] 07:30:36 INFO - rsp = 0x00007ffd266092a0 rip = 0x00007f47acd9349c
[task 2019-10-22T07:30:36.215Z] 07:30:36 INFO - Found by: stack scanning
[task 2019-10-22T07:30:36.215Z] 07:30:36 INFO - 4 libxul.so!nsAppShell::ProcessNextNativeEvent(bool) [nsAppShell.cpp:548f97078fb734a0a02a99b09c3c54d3c367764b : 274 + 0x7]
[task 2019-10-22T07:30:36.215Z] 07:30:36 INFO - rsp = 0x00007ffd266092c0 rip = 0x00007f47a0fa4a6b
[task 2019-10-22T07:30:36.215Z] 07:30:36 INFO - Found by: stack scanning
[task 2019-10-22T07:30:36.215Z] 07:30:36 INFO - 5 libxul.so!_fini + 0x2a44024
[task 2019-10-22T07:30:36.216Z] 07:30:36 INFO - rsp = 0x00007ffd266092c8 rip = 0x00007f47a69acdd8
[task 2019-10-22T07:30:36.216Z] 07:30:36 INFO - Found by: stack scanning
[task 2019-10-22T07:30:36.216Z] 07:30:36 INFO - 6 libxul.so!nsBaseAppShell::DoProcessNextNativeEvent(bool) [nsBaseAppShell.cpp:548f97078fb734a0a02a99b09c3c54d3c367764b : 120 + 0xf]
[task 2019-10-22T07:30:36.216Z] 07:30:36 INFO - rsp = 0x00007ffd266092e0 rip = 0x00007f47a0f5fc82
[task 2019-10-22T07:30:36.216Z] 07:30:36 INFO - Found by: stack scanning
[task 2019-10-22T07:30:36.216Z] 07:30:36 INFO - 7 libxul.so!nsBaseAppShell::OnProcessNextEvent(nsIThreadInternal*, bool) [nsBaseAppShell.cpp:548f97078fb734a0a02a99b09c3c54d3c367764b : 259 + 0xc]
[task 2019-10-22T07:30:36.217Z] 07:30:36 INFO - rsp = 0x00007ffd26609310 rip = 0x00007f47a0f5ff48
[task 2019-10-22T07:30:36.217Z] 07:30:36 INFO - Found by: stack scanning
[task 2019-10-22T07:30:36.217Z] 07:30:36 INFO - 8 libxul.so!non-virtual thunk to nsBaseAppShell::OnProcessNextEvent(nsIThreadInternal*, bool) [nsBaseAppShell.cpp:548f97078fb734a0a02a99b09c3c54d3c367764b : 0 + 0xd]
[task 2019-10-22T07:30:36.217Z] 07:30:36 INFO - rsp = 0x00007ffd26609370 rip = 0x00007f47a0f6006d
[task 2019-10-22T07:30:36.218Z] 07:30:36 INFO - Found by: stack scanning
[task 2019-10-22T07:30:36.218Z] 07:30:36 INFO - 9 libxul.so!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:548f97078fb734a0a02a99b09c3c54d3c367764b : 1118 + 0x14]
[task 2019-10-22T07:30:36.218Z] 07:30:36 INFO - rsp = 0x00007ffd26609380 rip = 0x00007f479e469079
[task 2019-10-22T07:30:36.219Z] 07:30:36 INFO - Found by: stack scanning
[task 2019-10-22T07:30:36.219Z] 07:30:36 INFO -

Whiteboard: [necko-triaged]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.