Closed Bug 1556696 Opened 5 years ago Closed 5 years ago

Intermittent TVW /webrtc/RTCPeerConnection-mandatory-getStats.https.html | application crashed [@ mozilla::VideoFrameConverter::ProcessVideoFrame(RefPtr<mozilla::layers::Image> const&, mozilla::TimeStamp, mozilla::gfx::IntSizeTyped<mozilla::gfx::UnknownUn

Categories

(Core :: WebRTC, defect, P2)

Product:
Core
Component:
WebRTC
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla69
Tracking Flags:
Tracking Status
firefox-esr60 --- wontfix
firefox67.0.1 --- wontfix
firefox68 --- wontfix
firefox69 --- fixed

People

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

References

(Regression)

Details

(Keywords: crash, intermittent-failure, regression)

Crash Data

Attachments

(1 file)

Bug 1556696 - Only fail the VideoFrameConverter out-of-buffers assert if we dropped 100 frames in a row. r?dminor
47 bytes, text/x-phabricator-request
Details | Review

Filed by: btara [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=249874715&repo=mozilla-inbound
Full log: https://queue.taskcluster.net/v1/task/YkV8iJiTT8Ogt3R13u---w/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/YkV8iJiTT8Ogt3R13u---w/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2019-06-04T06:04:03.713Z] 06:04:03 INFO - TEST-START | /webrtc/RTCPeerConnection-mandatory-getStats.https.html
[task 2019-06-04T06:04:03.714Z] 06:04:03 INFO - Run 9/10
[task 2019-06-04T06:04:03.715Z] 06:04:03 INFO - Closing window 25769803777
[task 2019-06-04T06:04:04.136Z] 06:04:04 INFO - PID 5875 | [Child 6690: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:330: PeerConnectionImpl: PeerConnectionImpl constructor for
[task 2019-06-04T06:04:04.136Z] 06:04:04 INFO - PID 5875 | (unknown/INFO) insert '' (registry) succeeded:
[task 2019-06-04T06:04:04.136Z] 06:04:04 INFO - PID 5875 | (registry/INFO) Initialized registry
[task 2019-06-04T06:04:04.136Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice' (registry) succeeded: ice
[task 2019-06-04T06:04:04.137Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice.pref' (registry) succeeded: ice.pref
[task 2019-06-04T06:04:04.137Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice.pref.type' (registry) succeeded: ice.pref.type
[task 2019-06-04T06:04:04.137Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice.pref.type.srv_rflx' (UCHAR) succeeded: 0x64
[task 2019-06-04T06:04:04.137Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice.pref.type.peer_rflx' (UCHAR) succeeded: 0x6e
[task 2019-06-04T06:04:04.137Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice.pref.type.host' (UCHAR) succeeded: 0x7e
[task 2019-06-04T06:04:04.137Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice.pref.type.relayed' (UCHAR) succeeded: 0x05
[task 2019-06-04T06:04:04.137Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice.pref.type.srv_rflx_tcp' (UCHAR) succeeded: 0x63
[task 2019-06-04T06:04:04.138Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice.pref.type.peer_rflx_tcp' (UCHAR) succeeded: 0x6d
[task 2019-06-04T06:04:04.139Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice.pref.type.host_tcp' (UCHAR) succeeded: 0x7d
[task 2019-06-04T06:04:04.140Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice.pref.type.relayed_tcp' (UCHAR) succeeded: 0x00
[task 2019-06-04T06:04:04.140Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'stun' (registry) succeeded: stun
[task 2019-06-04T06:04:04.141Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'stun.client' (registry) succeeded: stun.client
[task 2019-06-04T06:04:04.142Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'stun.client.maximum_transmits' (UINT4) succeeded: 7
[task 2019-06-04T06:04:04.143Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice.trickle_grace_period' (UINT4) succeeded: 5000
[task 2019-06-04T06:04:04.144Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice.tcp' (registry) succeeded: ice.tcp
[task 2019-06-04T06:04:04.145Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice.tcp.so_sock_count' (INT4) succeeded: 0
[task 2019-06-04T06:04:04.146Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice.tcp.listen_backlog' (INT4) succeeded: 10
[task 2019-06-04T06:04:04.147Z] 06:04:04 INFO - PID 5875 | (registry/INFO) insert 'ice.tcp.disable' (char) succeeded: \000
[task 2019-06-04T06:04:04.148Z] 06:04:04 INFO - PID 5875 | [Parent 5875: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses
[task 2019-06-04T06:04:04.149Z] 06:04:04 INFO - PID 5875 | [Child 6690: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:330: PeerConnectionImpl: PeerConnectionImpl constructor for
[task 2019-06-04T06:04:04.150Z] 06:04:04 INFO - PID 5875 | [Parent 5875: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses
[task 2019-06-04T06:04:04.152Z] 06:04:04 INFO - PID 5875 | [Child 6690: Main Thread]: D/DataChannel Constructor DataChannelConnection=0x7f64c6478800, listener=0x7f64c6174668
[task 2019-06-04T06:04:04.153Z] 06:04:04 INFO - PID 5875 | [Child 6690: Main Thread]: D/DataChannel Use PPID-based fragmentation/reassembly: no (enforced=no)
...
[task 2019-06-04T06:04:04.376Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/mtransport Trickle candidate is redundant for stream 'PC:1559628244128618 (id=27917287428 url=https://web-platform.test:8443/webrtc/RTCPeerConnection-mandatory-getStats.https.html) transport-id=transport_0' because it is completed: candidate:3 1 TCP 2105524479 fd15:4ba5:5a2b:100a:0:242:ac11:5 9 typ host tcptype active
[task 2019-06-04T06:04:04.378Z] 06:04:04 INFO - PID 5875 | (ice/ERR) ICE(PC:1559628244128618 (id=27917287428 url=https://web-platform.test:8443/webrtc/RTCPeerConnection-mandatory-getStats.https.html)): peer (PC:1559628244128618 (id=27917287428 url=https://web-platform.test:8443/webrtc/RTCPeerConnection-mandatory-getStats.https.html):default), stream(PC:1559628244128618 (id=27917287428 url=https://web-platform.test:8443/webrtc/RTCPeerConnection-mandatory-getStats.https.html) transport-id=transport_0 - e9d7316f:4e6b363cfa0cc7512f2c6f50d3405d86) tried to trickle ICE in inappropriate state 4
[task 2019-06-04T06:04:04.378Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/mtransport Trickle candidate is redundant for stream 'PC:1559628244128618 (id=27917287428 url=https://web-platform.test:8443/webrtc/RTCPeerConnection-mandatory-getStats.https.html) transport-id=transport_0' because it is completed:
[task 2019-06-04T06:04:04.378Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel SendDeferredMessages called, pending type: 0
[task 2019-06-04T06:04:04.380Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel SendDeferredMessages called, pending type: 0
[task 2019-06-04T06:04:04.380Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Association change: SCTP_COMM_UP
[task 2019-06-04T06:04:04.380Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Negotiated number of incoming streams: 256
[task 2019-06-04T06:04:04.382Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel DTLS connect() succeeded! Entering connected mode
[task 2019-06-04T06:04:04.382Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Processing queued open for 0x7f64c2d811f0 (0)
[task 2019-06-04T06:04:04.383Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Association change: streams (in/out) = (256/256)
[task 2019-06-04T06:04:04.383Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Supports: PR
[task 2019-06-04T06:04:04.384Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Supports: AUTH
[task 2019-06-04T06:04:04.384Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Supports: ASCONF
[task 2019-06-04T06:04:04.385Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Supports: MULTIBUF
[task 2019-06-04T06:04:04.385Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Supports: RE-CONFIG
[task 2019-06-04T06:04:04.386Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Association change: SCTP_COMM_UP
[task 2019-06-04T06:04:04.387Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Negotiated number of incoming streams: 256
[task 2019-06-04T06:04:04.390Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel DTLS connect() succeeded! Entering connected mode
[task 2019-06-04T06:04:04.391Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Processing queued open for 0x7f64c2d81280 (0)
[task 2019-06-04T06:04:04.391Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Association change: streams (in/out) = (256/256)
[task 2019-06-04T06:04:04.392Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Supports: PR
[task 2019-06-04T06:04:04.393Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Supports: AUTH
[task 2019-06-04T06:04:04.393Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Supports: ASCONF
[task 2019-06-04T06:04:04.394Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Supports: MULTIBUF
[task 2019-06-04T06:04:04.394Z] 06:04:04 INFO - PID 5875 | [Child 6690: Socket Thread]: D/DataChannel Supports: RE-CONFIG
[task 2019-06-04T06:04:04.395Z] 06:04:04 INFO - PID 5875 | [Child 6690: Main Thread]: D/DataChannel operator(): sending ON_CHANNEL_OPEN for dummy/: 0
[task 2019-06-04T06:04:04.395Z] 06:04:04 INFO - PID 5875 | [Child 6690: Main Thread]: D/DataChannel 0x7f64c2d87d40(0x7f64c2d811f0): OnChannelConnected - Dispatching
[task 2019-06-04T06:04:04.396Z] 06:04:04 INFO - PID 5875 | [Child 6690: Main Thread]: D/DataChannel operator(): sending ON_CHANNEL_OPEN for dummy/: 0
[task 2019-06-04T06:04:04.396Z] 06:04:04 INFO - PID 5875 | [Child 6690: Main Thread]: D/DataChannel 0x7f64c2d87df0(0x7f64c2d81280): OnChannelConnected - Dispatching
[task 2019-06-04T06:04:06.004Z] 06:04:06 INFO - PID 5875 | [Child 6690: Unnamed thread 0x7f64baa27a60]: I/signaling [|WebrtcVideoSessionConduit] VideoStreamFactory.cpp:197: CreateEncoderStreams Input frame 640x480, RID scaling to 640x480
[task 2019-06-04T06:04:06.161Z] 06:04:06 INFO - PID 5875 | [Parent 5875, Gecko_IOThread] WARNING: pipe error (83): Connection reset by peer: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 358
[task 2019-06-04T06:04:06.161Z] 06:04:06 INFO - PID 5875 | [Parent 5875, Gecko_IOThread] WARNING: pipe error (141): Connection reset by peer: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 358
[task 2019-06-04T06:04:06.218Z] 06:04:06 ERROR - PID 5875 | A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down
[task 2019-06-04T06:04:06.343Z] 06:04:06 INFO - Browser not responding, setting status to CRASH
[task 2019-06-04T06:04:06.348Z] 06:04:06 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/UTXbLlUgTdW6u4mNRGGTRQ/artifacts/public/build/target.crashreporter-symbols.zip
[task 2019-06-04T06:04:06.550Z] 06:04:06 INFO - PID 5875 | 1559628246545 Marionette INFO Stopped listening on port 2834
[task 2019-06-04T06:04:10.356Z] 06:04:10 INFO - mozcrash Copy/paste: /builds/worker/workspace/build/linux64-minidump_stackwalk /tmp/tmp4cOkGO.mozrunner/minidumps/4672012d-c918-5bb4-997c-b3670dbad55f.dmp /tmp/tmpu2JzsM
[task 2019-06-04T06:04:15.581Z] 06:04:15 INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/4672012d-c918-5bb4-997c-b3670dbad55f.dmp
[task 2019-06-04T06:04:15.583Z] 06:04:15 INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/4672012d-c918-5bb4-997c-b3670dbad55f.extra
[task 2019-06-04T06:04:15.690Z] 06:04:15 INFO - PROCESS-CRASH | /webrtc/RTCPeerConnection-mandatory-getStats.https.html | application crashed [@ mozilla::VideoFrameConverter::ProcessVideoFrame(RefPtr<mozilla::layers::Image> const&, mozilla::TimeStamp, mozilla::gfx::IntSizeTyped<mozilla::gfx::UnknownUnits>, bool)]
[task 2019-06-04T06:04:15.690Z] 06:04:15 INFO - Crash dump filename: /tmp/tmp4cOkGO.mozrunner/minidumps/4672012d-c918-5bb4-997c-b3670dbad55f.dmp
[task 2019-06-04T06:04:15.690Z] 06:04:15 INFO - Operating system: Linux
[task 2019-06-04T06:04:15.691Z] 06:04:15 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-06-04T06:04:15.691Z] 06:04:15 INFO - CPU: amd64
[task 2019-06-04T06:04:15.691Z] 06:04:15 INFO - family 6 model 62 stepping 4
[task 2019-06-04T06:04:15.691Z] 06:04:15 INFO - 4 CPUs
[task 2019-06-04T06:04:15.691Z] 06:04:15 INFO -
[task 2019-06-04T06:04:15.692Z] 06:04:15 INFO - GPU: UNKNOWN
[task 2019-06-04T06:04:15.692Z] 06:04:15 INFO -
[task 2019-06-04T06:04:15.692Z] 06:04:15 INFO - Crash reason: SIGSEGV /SEGV_MAPERR
[task 2019-06-04T06:04:15.692Z] 06:04:15 INFO - Crash address: 0x0
[task 2019-06-04T06:04:15.693Z] 06:04:15 INFO - Process uptime: not available
[task 2019-06-04T06:04:15.693Z] 06:04:15 INFO -
[task 2019-06-04T06:04:15.693Z] 06:04:15 INFO - Thread 43 (crashed)
[task 2019-06-04T06:04:15.693Z] 06:04:15 INFO - 0 libxul.so!mozilla::VideoFrameConverter::ProcessVideoFrame(RefPtr<mozilla::layers::Image> const&, mozilla::TimeStamp, mozilla::gfx::IntSizeTyped<mozilla::gfx::UnknownUnits>, bool) [VideoFrameConverter.h:360fe85b587f76c9edbf49f9683355bdbc15d5bf : 312 + 0x11]
[task 2019-06-04T06:04:15.693Z] 06:04:15 INFO - rax = 0x00007f64d2e959b1 rdx = 0x0000000000000280
[task 2019-06-04T06:04:15.693Z] 06:04:15 INFO - rcx = 0x0000557a4bf65910 rbx = 0x00000000000001e0
[task 2019-06-04T06:04:15.694Z] 06:04:15 INFO - rsi = 0x00007f64c163ba90 rdi = 0x0000000000000000
[task 2019-06-04T06:04:15.694Z] 06:04:15 INFO - rbp = 0x00007f64c157c750 rsp = 0x00007f64c157c6d0
[task 2019-06-04T06:04:15.694Z] 06:04:15 INFO - r8 = 0x00000000005fc278 r9 = 0x0000000000000000
[task 2019-06-04T06:04:15.694Z] 06:04:15 INFO - r10 = 0x00148faa0b20aa8e r11 = 0x0000000000000246
[task 2019-06-04T06:04:15.695Z] 06:04:15 INFO - r12 = 0x00007f64c163ba60 r13 = 0x0000000000000000
[task 2019-06-04T06:04:15.695Z] 06:04:15 INFO - r14 = 0x000001e000000280 r15 = 0x00007f64baae0f30
[task 2019-06-04T06:04:15.695Z] 06:04:15 INFO - rip = 0x00007f64cdb7cb83
[task 2019-06-04T06:04:15.695Z] 06:04:15 INFO - Found by: given as instruction pointer in context
[task 2019-06-04T06:04:15.696Z] 06:04:15 INFO - 1 libxul.so!mozilla::detail::RunnableMethodImpl<mozilla::VideoFrameConverter*, void (mozilla::VideoFrameConverter::)(RefPtr<mozilla::layers::Image> const&, mozilla::TimeStamp, mozilla::gfx::IntSizeTyped<mozilla::gfx::UnknownUnits>, bool), true, (mozilla::RunnableKind)0, StoreCopyPassByLRef<RefPtr<mozilla::layers::Image> >, mozilla::TimeStamp, mozilla::gfx::IntSizeTyped<mozilla::gfx::UnknownUnits>, bool>::Run() [nsThreadUtils.h:360fe85b587f76c9edbf49f9683355bdbc15d5bf : 1174 + 0x2e]
[task 2019-06-04T06:04:15.696Z] 06:04:15 INFO - rbx = 0x00007f64c1655020 rbp = 0x00007f64c157c760
[task 2019-06-04T06:04:15.696Z] 06:04:15 INFO - rsp = 0x00007f64c157c760 r12 = 0x00007f64baae0ee0
[task 2019-06-04T06:04:15.696Z] 06:04:15 INFO - r13 = 0x00007f64c164c000 r14 = 0x00007f64baac7a90
[task 2019-06-04T06:04:15.697Z] 06:04:15 INFO - r15 = 0x00007f64c157c770 rip = 0x00007f64cdb81c8a
[task 2019-06-04T06:04:15.697Z] 06:04:15 INFO - Found by: call frame info
[task 2019-06-04T06:04:15.697Z] 06:04:15 INFO - 2 libxul.so!mozilla::TaskQueue::Runner::Run() [TaskQueue.cpp:360fe85b587f76c9edbf49f9683355bdbc15d5bf : 199 + 0xa]
[task 2019-06-04T06:04:15.697Z] 06:04:15 INFO - rbx = 0x00007f64c1655020 rbp = 0x00007f64c157c820
[task 2019-06-04T06:04:15.698Z] 06:04:15 INFO - rsp = 0x00007f64c157c770 r12 = 0x00007f64baae0ee0
[task 2019-06-04T06:04:15.698Z] 06:04:15 INFO - r13 = 0x00007f64c164c000 r14 = 0x00007f64baac7a90
[task 2019-06-04T06:04:15.698Z] 06:04:15 INFO - r15 = 0x00007f64c157c770 rip = 0x00007f64d0f0ffa6
[task 2019-06-04T06:04:15.698Z] 06:04:15 INFO - Found by: call frame info
[task 2019-06-04T06:04:15.699Z] 06:04:15 INFO - 3 libxul.so!nsThreadPool::Run() [nsThreadPool.cpp:360fe85b587f76c9edbf49f9683355bdbc15d5bf : 244 + 0x9]
[task 2019-06-04T06:04:15.699Z] 06:04:15 INFO - rbx = 0x00007f64baac7a90 rbp = 0x00007f64c157c8c0
[task 2019-06-04T06:04:15.699Z] 06:04:15 INFO - rsp = 0x00007f64c157c830 r12 = 0x00000d3d3ea0c3aa
[task 2019-06-04T06:04:15.699Z] 06:04:15 INFO - r13 = 0x7fffffffffffffff r14 = 0x00007f64c2d781f0
[task 2019-06-04T06:04:15.699Z] 06:04:15 INFO - r15 = 0x00007f64c2d78218 rip = 0x00007f64d0f19511
[task 2019-06-04T06:04:15.700Z] 06:04:15 INFO - Found by: call frame info
[task 2019-06-04T06:04:15.700Z] 06:04:15 INFO - 4 libxul.so!non-virtual thunk to nsThreadPool::Run() [nsThreadPool.cpp:360fe85b587f76c9edbf49f9683355bdbc15d5bf : 0 + 0xd]
[task 2019-06-04T06:04:15.700Z] 06:04:15 INFO - rbx = 0x0000000000000000 rbp = 0x00007f64c157c8d0
[task 2019-06-04T06:04:15.700Z] 06:04:15 INFO - rsp = 0x00007f64c157c8d0 r12 = 0x00007f64de6289d0
[task 2019-06-04T06:04:15.701Z] 06:04:15 INFO - r13 = 0x00000000ffffffff r14 = 0x0000000000000001
[task 2019-06-04T06:04:15.701Z] 06:04:15 INFO - r15 = 0x00007f64c164b100 rip = 0x00007f64d0f19c8d
[task 2019-06-04T06:04:15.701Z] 06:04:15 INFO - Found by: call frame info
[task 2019-06-04T06:04:15.701Z] 06:04:15 INFO - 5 libxul.so!nsThread::ProcessNextEvent(bool, bool) [nsThread.cpp:360fe85b587f76c9edbf49f9683355bdbc15d5bf : 1176 + 0x6]
[task 2019-06-04T06:04:15.702Z] 06:04:15 INFO - rbx = 0x0000000000000000 rbp = 0x00007f64c157cdc0
[task 2019-06-04T06:04:15.702Z] 06:04:15 INFO - rsp = 0x00007f64c157c8e0 r12 = 0x00007f64de6289d0
[task 2019-06-04T06:04:15.702Z] 06:04:15 INFO - r13 = 0x00000000ffffffff r14 = 0x0000000000000001
[task 2019-06-04T06:04:15.702Z] 06:04:15 INFO - r15 = 0x00007f64c164b100 rip = 0x00007f64d085b45a
[task 2019-06-04T06:04:15.703Z] 06:04:15 INFO - Found by: call frame info
[task 2019-06-04T06:04:15.703Z] 06:04:15 INFO - 6 libxul.so!<name omitted> [nsThreadUtils.cpp:360fe85b587f76c9edbf49f9683355bdbc15d5bf : 486 + 0x23]
[task 2019-06-04T06:04:15.703Z] 06:04:15 INFO - rbx = 0x00007f64c164b100 rbp = 0x00007f64c157cdf0
[task 2019-06-04T06:04:15.703Z] 06:04:15 INFO - rsp = 0x00007f64c157cdd0 r12 = 0x00007f64de6289d0
[task 2019-06-04T06:04:15.704Z] 06:04:15 INFO - r13 = 0x00007f64de6e0e50 r14 = 0x0000000000000000
[task 2019-06-04T06:04:15.704Z] 06:04:15 INFO - r15 = 0x00007f64c164b100 rip = 0x00007f64d085cab6
[task 2019-06-04T06:04:15.704Z] 06:04:15 INFO - Found by: call frame info
[task 2019-06-04T06:04:15.704Z] 06:04:15 INFO - 7 libxul.so!mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [MessagePump.cpp:360fe85b587f76c9edbf49f9683355bdbc15d5bf : 303 + 0xa]
[task 2019-06-04T06:04:15.705Z] 06:04:15 INFO - rbx = 0x00007f64c2dd05e0 rbp = 0x00007f64c157ce40
[task 2019-06-04T06:04:15.705Z] 06:04:15 INFO - rsp = 0x00007f64c157ce00 r12 = 0x00007f64de6289d0
[task 2019-06-04T06:04:15.705Z] 06:04:15 INFO - r13 = 0x00007f64de6e0e50 r14 = 0x00007f64c1657040
[task 2019-06-04T06:04:15.706Z] 06:04:15 INFO - r15 = 0x00007f64c164b100 rip = 0x00007f64d0899b2e
[task 2019-06-04T06:04:15.706Z] 06:04:15 INFO - Found by: call frame info
[task 2019-06-04T06:04:15.706Z] 06:04:15 INFO - 8 libxul.so!MessageLoop::Run() [message_loop.cc:360fe85b587f76c9edbf49f9683355bdbc15d5bf : 290 + 0xc]
[task 2019-06-04T06:04:15.706Z] 06:04:15 INFO - rbx = 0x00007f64de6e0e50 rbp = 0x00007f64c157ce70
[task 2019-06-04T06:04:15.707Z] 06:04:15 INFO - rsp = 0x00007f64c157ce50 r12 = 0x00007f64de6289d0
[task 2019-06-04T06:04:15.707Z] 06:04:15 INFO - r13 = 0x00007f64c2dd05e0 r14 = 0x00007f64c164b100
[task 2019-06-04T06:04:15.707Z] 06:04:15 INFO - r15 = 0x00007ffffcb1b190 rip = 0x00007f64d10fa47f
[task 2019-06-04T06:04:15.707Z] 06:04:15 INFO - Found by: call frame info
[task 2019-06-04T06:04:15.708Z] 06:04:15 INFO - 9 libxul.so!nsThread::ThreadFunc(void*) [nsThread.cpp:360fe85b587f76c9edbf49f9683355bdbc15d5bf : 455 + 0x8]
[task 2019-06-04T06:04:15.708Z] 06:04:15 INFO - rbx = 0x00007f64de6e0e50 rbp = 0x00007f64c157cec0
[task 2019-06-04T06:04:15.708Z] 06:04:15 INFO - rsp = 0x00007f64c157ce80 r12 = 0x00007f64de6289d0
[task 2019-06-04T06:04:15.709Z] 06:04:15 INFO - r13 = 0x00007f64c2dd05e0 r14 = 0x00007f64c164b100
[task 2019-06-04T06:04:15.709Z] 06:04:15 INFO - r15 = 0x00007ffffcb1b190 rip = 0x00007f64d0f151b9
[task 2019-06-04T06:04:15.709Z] 06:04:15 INFO - Found by: call frame info
[task 2019-06-04T06:04:15.710Z] 06:04:15 INFO - 10 libnspr4.so!_pt_root [ptthread.c:360fe85b587f76c9edbf49f9683355bdbc15d5bf : 201 + 0x8]
[task 2019-06-04T06:04:15.710Z] 06:04:15 INFO - rbx = 0x0000000000000002 rbp = 0x00007f64c157cf10
[task 2019-06-04T06:04:15.710Z] 06:04:15 INFO - rsp = 0x00007f64c157ced0 r12 = 0x00007f64de6289d0
[task 2019-06-04T06:04:15.710Z] 06:04:15 INFO - r13 = 0x00007f64c2dd05e0 r14 = 0x00007f64c157d700
[task 2019-06-04T06:04:15.710Z] 06:04:15 INFO - r15 = 0x0000000000001aa1 rip = 0x00007f64dfd558fe
[task 2019-06-04T06:04:15.711Z] 06:04:15 INFO - Found by: call frame info
[task 2019-06-04T06:04:15.711Z] 06:04:15 INFO - 11 libpthread-2.23.so + 0x76ba
[task 2019-06-04T06:04:15.711Z] 06:04:15 INFO - rbx = 0x0000000000000000 rbp = 0x0000000000000000
[task 2019-06-04T06:04:15.711Z] 06:04:15 INFO - rsp = 0x00007f64c157cf20 r12 = 0x0000000000000000
[task 2019-06-04T06:04:15.712Z] 06:04:15 INFO - r13 = 0x00007ffffcb1b04f r14 = 0x00007f64c157d9c0
[task 2019-06-04T06:04:15.712Z] 06:04:15 INFO - r15 = 0x00007ffffcb1b190 rip = 0x00007f64df9786ba
[task 2019-06-04T06:04:15.712Z] 06:04:15 INFO - Found by: call frame info
[task 2019-06-04T06:04:15.712Z] 06:04:15 INFO - 12 libc-2.23.so + 0x10741d
[task 2019-06-04T06:04:15.713Z] 06:04:15 INFO - rsp = 0x00007f64c157cfc0 rip = 0x00007f64dea0141d
[task 2019-06-04T06:04:15.713Z] 06:04:15 INFO - Found by: stack scanning

This problem is showing up on wpt.fyi as well, which is unfortunate (logs there show this intermittent is quite frequent there).

This test was added in bug 1555568, but that doesn't mean the crash didn't exist before.

Andreas, you poked in VideoFrameConverter::ProcessVideoFrame last. Any sense of if this could be a regression?

Flags: needinfo?(apehrson)
Priority: -- → P2

This indicates our converting code's buffer pool ran out of buffers. It has 5 buffers [1], that must have all been held up queued for encoding.

We could do one of

  1. increase the number
  2. allow for us to run out of buffers, and skip frames as we do
  3. figure out why all the buffers are held up and ensure they won't be in the future

The negative thing about 1) and 2) is that they may mask leak issues. But then, those would hopefully be caught in manual testing, which is not well known for catching things before they hit release.

Note that we already allow this in release and beta, dev edition and nightly would fail the assert. wpt.fyi runs on nightly.

I suppose we could do a hybrid of 2), where we allow ourselves to skip frames, but only for a certain time before failing an assert. So as to ensure ourselves that those buffers are not all leaked somewhere (meaning we'd skip all future frames for this track).

[1] https://searchfox.org/mozilla-central/rev/b3b401254229f0a26f7ee625ef5f09c6c31e3949/dom/media/VideoFrameConverter.h#31

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

Five buffers is evidently not enough to ensure we don't run out.
What we really want the assert for is that we are not leaking buffers so that
they never recycle, while also keeping memory usage down. This achieves that
by allowing for 100 frames to drop before failing the out-of-buffers assert.

Pushed by pehrsons@gmail.com: https://hg.mozilla.org/integration/autoland/rev/8ba736c35de8 Only fail the VideoFrameConverter out-of-buffers assert if we dropped 100 frames in a row. r=dminor

https://hg.mozilla.org/mozilla-central/rev/8ba736c35de8

Status: ASSIGNED → RESOLVED
Closed: 5 years ago
status-firefox69: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla69

Given that this only involves diagnostic asserts, I don't think this needs backport anywhere.

status-firefox67.0.1: --- → wontfix
status-firefox68: --- → wontfix
status-firefox-esr60: --- → wontfix
Regressed by: 1299515
Has Regression Range: --- → yes
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: