Closed Bug 1443774 Opened 6 years ago Closed 6 years ago

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

Categories

(Core :: WebRTC: Audio/Video, defect, P2)

defect

Tracking

()

RESOLVED WONTFIX

People

(Reporter: apavel, Unassigned)

References

(Depends on 1 open bug)

Details

(Keywords: intermittent-failure, regression)

Crash Data

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

Filed by: ncsoregi [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=163548191&repo=mozilla-central

https://queue.taskcluster.net/v1/task/WMCGAvmCQLGOVQtsTBnrRA/runs/0/artifacts/public/logs/live_backing.log


A more recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=166430160&repo=mozilla-inbound&lineNumber=11273

The crash signature from the previous bug changed from [@ mozilla::ThreadSafeAutoRefCnt::get] to [@ mozilla::MediaEngineWebRTCMicrophoneSource::Stop]


[task 2018-03-07T09:48:46.722Z] 09:48:46     INFO - GECKO(1047) | [1103:WebRTCPD #2]: E/signaling [WebRTCPD #2|WebrtcAudioSessionConduit] AudioConduit.cpp:706: SendAudioFrame Engine not transmitting
[task 2018-03-07T09:48:46.779Z] 09:48:46     INFO - GECKO(1047) | MEMORY STAT | vsize 1955MB | residentFast 158MB | heapAllocated 35MB
[task 2018-03-07T09:48:46.876Z] 09:48:46     INFO - TEST-OK | dom/media/tests/mochitest/test_peerConnection_verifyAudioAfterRenegotiation.html | took 7810ms
[task 2018-03-07T09:48:47.196Z] 09:48:47     INFO - GECKO(1047) | [Parent 1047, Gecko_IOThread] WARNING: pipe error (75): Connection reset by peer: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 353
[task 2018-03-07T09:48:47.200Z] 09:48:47     INFO - GECKO(1047) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x15007F,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv
[task 2018-03-07T09:54:57.207Z] 09:54:57     INFO - Buffered messages finished
[task 2018-03-07T09:54:57.208Z] 09:54:57    ERROR - TEST-UNEXPECTED-TIMEOUT | dom/media/tests/mochitest/test_peerConnection_verifyAudioAfterRenegotiation.html | application timed out after 370 seconds with no output
[task 2018-03-07T09:54:57.210Z] 09:54:57    ERROR - Force-terminating active process(es).
[task 2018-03-07T09:54:57.210Z] 09:54:57     INFO - Determining child pids from psutil...
[task 2018-03-07T09:54:57.211Z] 09:54:57     INFO - [1135]
[task 2018-03-07T09:54:57.212Z] 09:54:57     INFO - ==> process 1047 launched child process 1069
[task 2018-03-07T09:54:57.214Z] 09:54:57     INFO - ==> process 1047 launched child process 1103
[task 2018-03-07T09:54:57.215Z] 09:54:57     INFO - ==> process 1047 launched child process 1135
[task 2018-03-07T09:54:57.215Z] 09:54:57     INFO - ==> process 1047 launched child process 1751
[task 2018-03-07T09:54:57.216Z] 09:54:57     INFO - Found child pids: set([1103, 1069, 1751, 1135])
[task 2018-03-07T09:54:57.217Z] 09:54:57     INFO - Failed to get child procs
[task 2018-03-07T09:54:57.218Z] 09:54:57     INFO - Killing process: 1103
[task 2018-03-07T09:54:57.218Z] 09:54:57     INFO - TEST-INFO | started process screentopng
[task 2018-03-07T09:54:57.506Z] 09:54:57     INFO - TEST-INFO | screentopng: exit 0
[task 2018-03-07T09:54:57.506Z] 09:54:57     INFO - Can't trigger Breakpad, process no longer exists
[task 2018-03-07T09:54:57.507Z] 09:54:57     INFO - Killing process: 1069
[task 2018-03-07T09:54:57.508Z] 09:54:57     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-03-07T09:54:57.508Z] 09:54:57     INFO - Can't trigger Breakpad, process no longer exists
[task 2018-03-07T09:54:57.508Z] 09:54:57     INFO - Killing process: 1751
[task 2018-03-07T09:54:57.509Z] 09:54:57     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-03-07T09:54:57.511Z] 09:54:57     INFO - Can't trigger Breakpad, process no longer exists
[task 2018-03-07T09:54:57.518Z] 09:54:57     INFO - Killing process: 1135
[task 2018-03-07T09:54:57.518Z] 09:54:57     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-03-07T09:54:57.519Z] 09:54:57     INFO - Killing process: 1047
[task 2018-03-07T09:54:57.521Z] 09:54:57     INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-03-07T09:54:57.767Z] 09:54:57     INFO - psutil found pid 1047 dead
[task 2018-03-07T09:54:57.797Z] 09:54:57  WARNING - runtests.py | Failed to get app exit code - running/crashed?
[task 2018-03-07T09:54:57.797Z] 09:54:57     INFO - TEST-INFO | Main app process: exit 0
[task 2018-03-07T09:54:57.798Z] 09:54:57     INFO - runtests.py | Application ran for: 0:09:02.879206
[task 2018-03-07T09:54:57.799Z] 09:54:57     INFO - zombiecheck | Reading PID log: /tmp/tmp8MiaAtpidlog
[task 2018-03-07T09:54:57.800Z] 09:54:57     INFO - ==> process 1047 launched child process 1069
[task 2018-03-07T09:54:57.801Z] 09:54:57     INFO - ==> process 1047 launched child process 1103
[task 2018-03-07T09:54:57.802Z] 09:54:57     INFO - ==> process 1047 launched child process 1135
[task 2018-03-07T09:54:57.803Z] 09:54:57     INFO - ==> process 1047 launched child process 1751
[task 2018-03-07T09:54:57.804Z] 09:54:57     INFO - zombiecheck | Checking for orphan process with PID: 1135
[task 2018-03-07T09:54:57.805Z] 09:54:57     INFO - zombiecheck | Checking for orphan process with PID: 1069
[task 2018-03-07T09:54:57.806Z] 09:54:57     INFO - zombiecheck | Checking for orphan process with PID: 1751
[task 2018-03-07T09:54:57.807Z] 09:54:57     INFO - zombiecheck | Checking for orphan process with PID: 1103
[task 2018-03-07T09:54:57.808Z] 09:54:57     INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/Q7d4SAM-TnC5nj-B-LPgDQ/artifacts/public/build/target.crashreporter-symbols.zip
[task 2018-03-07T09:55:04.637Z] 09:55:04     INFO - mozcrash Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmpeQR5NE.mozrunner/minidumps/6c1f68b3-e542-0976-4785-be21a5a8a85c.dmp /tmp/tmp2XaQeX
[task 2018-03-07T09:55:13.234Z] 09:55:13     INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/6c1f68b3-e542-0976-4785-be21a5a8a85c.dmp
[task 2018-03-07T09:55:13.236Z] 09:55:13     INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/6c1f68b3-e542-0976-4785-be21a5a8a85c.extra
[task 2018-03-07T09:55:13.382Z] 09:55:13     INFO - PROCESS-CRASH | Main app process exited normally | application crashed [@ libc-2.23.so + 0xfb74d]
[task 2018-03-07T09:55:13.383Z] 09:55:13     INFO - Crash dump filename: /tmp/tmpeQR5NE.mozrunner/minidumps/6c1f68b3-e542-0976-4785-be21a5a8a85c.dmp
[task 2018-03-07T09:55:13.385Z] 09:55:13     INFO - Operating system: Linux
[task 2018-03-07T09:55:13.386Z] 09:55:13     INFO -                   0.0.0 Linux 4.4.0-1014-aws #14taskcluster-Ubuntu SMP Mon Feb 19 11:31:26 UTC 2018 x86_64
[task 2018-03-07T09:55:13.387Z] 09:55:13     INFO - CPU: amd64
[task 2018-03-07T09:55:13.388Z] 09:55:13     INFO -      family 6 model 62 stepping 4
[task 2018-03-07T09:55:13.390Z] 09:55:13     INFO -      2 CPUs
[task 2018-03-07T09:55:13.391Z] 09:55:13     INFO - 
[task 2018-03-07T09:55:13.395Z] 09:55:13     INFO - GPU: UNKNOWN
[task 2018-03-07T09:55:13.396Z] 09:55:13     INFO - 
[task 2018-03-07T09:55:13.397Z] 09:55:13     INFO - Crash reason:  SIGABRT
[task 2018-03-07T09:55:13.399Z] 09:55:13     INFO - Crash address: 0x3e8000003d8
[task 2018-03-07T09:55:13.400Z] 09:55:13     INFO - Process uptime: not available
[task 2018-03-07T09:55:13.401Z] 09:55:13     INFO - 
[task 2018-03-07T09:55:13.402Z] 09:55:13     INFO - Thread 0 (crashed)
[task 2018-03-07T09:55:13.403Z] 09:55:13     INFO -  0  libc-2.23.so + 0xfb74d
[task 2018-03-07T09:55:13.405Z] 09:55:13     INFO -     rax = 0xfffffffffffffffc   rdx = 0x00000000ffffffff
[task 2018-03-07T09:55:13.406Z] 09:55:13     INFO -     rcx = 0x00007f3ce957574d   rbx = 0x00007f3cb0a46e50
[task 2018-03-07T09:55:13.407Z] 09:55:13     INFO -     rsi = 0x0000000000000005   rdi = 0x00007f3cb0a46e50
[task 2018-03-07T09:55:13.407Z] 09:55:13     INFO -     rbp = 0x00007ffe11e64780   rsp = 0x00007ffe11e64750
[task 2018-03-07T09:55:13.408Z] 09:55:13     INFO -      r8 = 0x0000000000000005    r9 = 0x0000000000000001
[task 2018-03-07T09:55:13.409Z] 09:55:13     INFO -     r10 = 0x00007f3cb0a22f40   r11 = 0x0000000000000293
[task 2018-03-07T09:55:13.409Z] 09:55:13     INFO -     r12 = 0x0000000000000005   r13 = 0x00000000ffffffff
[task 2018-03-07T09:55:13.410Z] 09:55:13     INFO -     r14 = 0x00007f3cdadb9460   r15 = 0x0000000000000005
[task 2018-03-07T09:55:13.410Z] 09:55:13     INFO -     rip = 0x00007f3ce957574d
[task 2018-03-07T09:55:13.411Z] 09:55:13     INFO -     Found by: given as instruction pointer in context
[task 2018-03-07T09:55:13.412Z] 09:55:13     INFO -  1  libxul.so!PollWrapper [nsAppShell.cpp:aa30c92136b8cdeb7389022592900ed097add981 : 53 + 0xf]
[task 2018-03-07T09:55:13.413Z] 09:55:13     INFO -     rbp = 0x00007ffe11e64780   rsp = 0x00007ffe11e64760
[task 2018-03-07T09:55:13.414Z] 09:55:13     INFO -     rip = 0x00007f3cdadb948f
[task 2018-03-07T09:55:13.415Z] 09:55:13     INFO -     Found by: stack scanning
[task 2018-03-07T09:55:13.416Z] 09:55:13     INFO -  2  libglib-2.0.so.0.4800.2 + 0x4a38c
[task 2018-03-07T09:55:13.417Z] 09:55:13     INFO -     rbx = 0x00007f3ce92db2f0   rbp = 0x0000000000000005
[task 2018-03-07T09:55:13.418Z] 09:55:13     INFO -     rsp = 0x00007ffe11e64790   r12 = 0x00007f3cb0a46e50
[task 2018-03-07T09:55:13.419Z] 09:55:13     INFO -     r13 = 0x00000000ffffffff   rip = 0x00007f3ce43ba38c
[task 2018-03-07T09:55:13.420Z] 09:55:13     INFO -     Found by: call frame info
[task 2018-03-07T09:55:13.420Z] 09:55:13     INFO -  3  libglib-2.0.so.0.4800.2 + 0x4a49c
[task 2018-03-07T09:55:13.421Z] 09:55:13     INFO -     rsp = 0x00007ffe11e647f0   rip = 0x00007f3ce43ba49c
[task 2018-03-07T09:55:13.422Z] 09:55:13     INFO -     Found by: stack scanning
[task 2018-03-07T09:55:13.423Z] 09:55:13     INFO -  4  libxul.so!nsAppShell::ProcessNextNativeEvent [nsAppShell.cpp:aa30c92136b8cdeb7389022592900ed097add981 : 295 + 0x5]
[task 2018-03-07T09:55:13.424Z] 09:55:13     INFO -     rsp = 0x00007ffe11e64810   rip = 0x00007f3cdadb94df
[task 2018-03-07T09:55:13.425Z] 09:55:13     INFO -     Found by: stack scanning
[task 2018-03-07T09:55:13.426Z] 09:55:13     INFO -  5  libxul.so!nsBaseAppShell::DoProcessNextNativeEvent [nsBaseAppShell.cpp:aa30c92136b8cdeb7389022592900ed097add981 : 139 + 0x10]
[task 2018-03-07T09:55:13.427Z] 09:55:13     INFO -     rsp = 0x00007ffe11e64820   rip = 0x00007f3cdad82bac
[task 2018-03-07T09:55:13.428Z] 09:55:13     INFO -     Found by: stack scanning
[task 2018-03-07T09:55:13.429Z] 09:55:13     INFO -  6  libxul.so!nsBaseAppShell::OnProcessNextEvent [nsBaseAppShell.cpp:aa30c92136b8cdeb7389022592900ed097add981 : 290 + 0x8]
[task 2018-03-07T09:55:13.430Z] 09:55:13     INFO -     rsp = 0x00007ffe11e64850   rip = 0x00007f3cdad82d60
[task 2018-03-07T09:55:13.430Z] 09:55:13     INFO -     Found by: stack scanning
[task 2018-03-07T09:55:13.431Z] 09:55:13     INFO -  7  libxul.so!nsThread::ProcessNextEvent [nsThread.cpp:aa30c92136b8cdeb7389022592900ed097add981 : 952 + 0xf]
[task 2018-03-07T09:55:13.432Z] 09:55:13     INFO -     rsp = 0x00007ffe11e648a0   rip = 0x00007f3cd8d31dd2
[task 2018-03-07T09:55:13.433Z] 09:55:13     INFO -     Found by: stack scanning
[task 2018-03-07T09:55:13.434Z] 09:55:13     INFO -  8  firefox!arena_t::SplitRun [mozjemalloc.cpp:aa30c92136b8cdeb7389022592900ed097add981 : 2373 + 0x2]
[task 2018-03-07T09:55:13.435Z] 09:55:13     INFO -     rsp = 0x00007ffe11e64930   rip = 0x000000000040da01
[task 2018-03-07T09:55:13.436Z] 09:55:13     INFO -     Found by: stack scanning
[task 2018-03-07T09:55:13.437Z] 09:55:13     INFO - 
[task 2018-03-07T09:55:13.438Z] 09:55:13     INFO - Thread 1
[task 2018-03-07T09:55:13.439Z] 09:55:13     INFO -  0  libc-2.23.so + 0x1014d9
[task 2018-03-07T09:55:13.440Z] 09:55:13     INFO -     rax = 0xfffffffffffffffc   rdx = 0x0000000000000020
[task 2018-03-07T09:55:13.441Z] 09:55:13     INFO -     rcx = 0x00007f3ce957b4d9   rbx = 0x0000000000000000
[task 2018-03-07T09:55:13.442Z] 09:55:13     INFO -     rsi = 0x00007f3ce9287200   rdi = 0x0000000000000011
[task 2018-03-07T09:55:13.443Z] 09:55:13     INFO -     rbp = 0x00007f3cd74beba0   rsp = 0x00007f3cd74beb98
[task 2018-03-07T09:55:13.444Z] 09:55:13     INFO -      r8 = 0x00000000000c65f0    r9 = 0x00007f3cd74bebf0
[task 2018-03-07T09:55:13.445Z] 09:55:13     INFO -     r10 = 0x00000000ffffffff   r11 = 0x0000000000000246
[task 2018-03-07T09:55:13.446Z] 09:55:13     INFO -     r12 = 0x0000000000000000   r13 = 0x00007f3ce92ff4bc
[task 2018-03-07T09:55:13.447Z] 09:55:13     INFO -     r14 = 0x00007f3ce92ff4b0   r15 = 0x00007f3ce921ac00
[task 2018-03-07T09:55:13.447Z] 09:55:13     INFO -     rip = 0x00007f3ce957b4d9
[task 2018-03-07T09:55:13.448Z] 09:55:13     INFO -     Found by: given as instruction pointer in context
[task 2018-03-07T09:55:13.449Z] 09:55:13     INFO -  1  libxul.so!epoll_dispatch [epoll.c:aa30c92136b8cdeb7389022592900ed097add981 : 462 + 0x14]
[task 2018-03-07T09:55:13.450Z] 09:55:13     INFO -     rbp = 0x00007f3cd74bebf0   rsp = 0x00007f3cd74bebb0
[task 2018-03-07T09:55:13.451Z] 09:55:13     INFO -     rip = 0x00007f3cd9150ae9
[task 2018-03-07T09:55:13.452Z] 09:55:13     INFO -     Found by: previous frame's frame pointer
[task 2018-03-07T09:55:13.453Z] 09:55:13     INFO -  2  libxul.so!event_base_loop [event.c:aa30c92136b8cdeb7389022592900ed097add981 : 1947 + 0x6]
[task 2018-03-07T09:55:13.454Z] 09:55:13     INFO -     rbx = 0x0000000000000000   rbp = 0x00007f3cd74bec80
[task 2018-03-07T09:55:13.455Z] 09:55:13     INFO -     rsp = 0x00007f3cd74bec00   r12 = 0x00007f3ce9292540
[task 2018-03-07T09:55:13.456Z] 09:55:13     INFO -     r13 = 0x0000000000000009   r14 = 0x0000000000000000
[task 2018-03-07T09:55:13.457Z] 09:55:13     INFO -     r15 = 0x00007f3ce921ac00   rip = 0x00007f3cd91533ad
[task 2018-03-07T09:55:13.458Z] 09:55:13     INFO -     Found by: call frame info
No longer blocks: 1299515, 1436694
No longer depends on: 1440169
See Also: → 1440169, 1439886
One too many.
Blocks: 1299515
:pehrsons thank you!
See Also: → 1452472
Closing because no crash reported since 12 weeks.
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → WONTFIX
Closing because no crash reported since 12 weeks.
You need to log in before you can comment on or make changes to this bug.