Closed Bug 1471922 Opened Last year Closed Last year

Provide more information in failure summary than line "thread '<unnamed>' panicked at 'assertion failed: `(left != right)`"

Categories

(Core :: Audio/Video: cubeb, defect, P3)

defect

Tracking

()

RESOLVED FIXED
mozilla63
Tracking Status
firefox63 --- fixed

People

(Reporter: aryx, Assigned: kinetik)

References

Details

The failure line with "Assertion failure"

See  e.g. https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=a2878ea8e1f02d64e26e4fa458e9409cc8bb969c&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=runnable&selectedJob=185167708

Only "GECKO(2865) | thread '<unnamed>' panicked at 'assertion failed: `(left != right)`" is shown in the log summary but the full logs shows

[task 2018-06-27T14:29:54.682Z] 14:29:54    ERROR - GECKO(2865) | thread '<unnamed>' panicked at 'assertion failed: `(left != right)`
[task 2018-06-27T14:29:54.683Z] 14:29:54     INFO - GECKO(2865) |   left: `0`,
[task 2018-06-27T14:29:54.684Z] 14:29:54     INFO - GECKO(2865) |  right: `0`', media/libcubeb/cubeb-pulse-rs/src/backend/stream.rs:905:5
[task 2018-06-27T14:29:54.689Z] 14:29:54     INFO - GECKO(2865) | stack backtrace:
[task 2018-06-27T14:29:54.690Z] 14:29:54     INFO - GECKO(2865) | [Child 2917: Socket Thread]: D/mtransport Attempting to protect RTP...
[task 2018-06-27T14:29:54.691Z] 14:29:54     INFO - GECKO(2865) | [Child 2917: Socket Thread]: D/mtransport Attempting to unprotect RTP...
[task 2018-06-27T14:29:54.691Z] 14:29:54     INFO - GECKO(2865) | [Child 2917: Socket Thread]: D/mtransport Attempting to protect RTP...
[task 2018-06-27T14:29:54.694Z] 14:29:54     INFO - GECKO(2865) | [Child 2917: Socket Thread]: D/mtransport Attempting to unprotect RTP...
[task 2018-06-27T14:29:55.055Z] 14:29:55     INFO - GECKO(2865) | [Child 2917: Socket Thread]: D/mtransport Attempting to protect RTCP...
[task 2018-06-27T14:29:55.056Z] 14:29:55     INFO - GECKO(2865) | [Child 2917: Socket Thread]: D/mtransport Attempting to unprotect RTCP...
[task 2018-06-27T14:29:55.059Z] 14:29:55     INFO - GECKO(2865) | [Child 2917: Socket Thread]: W/signaling [Socket Thread|MediaPipeline] MediaPipeline.cpp:1176: Dropping incoming RTCP packet; filtered out
[task 2018-06-27T14:29:55.157Z] 14:29:55     INFO - GECKO(2865) | [Child 2917: Socket Thread]: D/mtransport Attempting to protect RTCP...
[task 2018-06-27T14:29:55.159Z] 14:29:55     INFO - GECKO(2865) | [Child 2917: Socket Thread]: D/mtransport Attempting to unprotect RTCP...
[task 2018-06-27T14:29:55.197Z] 14:29:55     INFO - GECKO(2865) |    0: 0xf2cb1c3d - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h1161623548489f53
[task 2018-06-27T14:29:55.197Z] 14:29:55     INFO - GECKO(2865) |    1: 0xf2cc3463 - std::sys_common::backtrace::print::hf81721988fc483b5
[task 2018-06-27T14:29:55.198Z] 14:29:55     INFO - GECKO(2865) |    2: 0xf2ca1af6 - std::panicking::default_hook::{{closure}}::h307410a777a3bd25
[task 2018-06-27T14:29:55.198Z] 14:29:55     INFO - GECKO(2865) |    3: 0xf2ca16ff - std::panicking::default_hook::heb8feab19bd5fff3
[task 2018-06-27T14:29:55.198Z] 14:29:55     INFO - GECKO(2865) |    4: 0xf25ba640 - <unknown>
[task 2018-06-27T14:29:55.201Z] 14:29:55     INFO - GECKO(2865) | Redirecting call to abort() to mozalloc_abort
[task 2018-06-27T14:29:55.201Z] 14:29:55     INFO - GECKO(2865) | Hit MOZ_CRASH() at /builds/worker/workspace/build/src/memory/mozalloc/mozalloc_abort.cpp:34
[task 2018-06-27T14:29:55.223Z] 14:29:55     INFO - GECKO(2865) | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2018-06-27T14:29:55.224Z] 14:29:55     INFO - GECKO(2865) | Hit MOZ_CRASH(Aborting on channel error.) at /builds/worker/workspace/build/src/ipc/glue/MessageChannel.cpp:2548
[task 2018-06-27T14:30:30.408Z] 14:30:30     INFO - GECKO(2865) | #01: mozilla::ipc::MessageChannel::OnChannelErrorFromLink() [ipc/glue/MessageChannel.cpp:2548]
[task 2018-06-27T14:30:30.409Z] 14:30:30     INFO - 
[task 2018-06-27T14:30:30.410Z] 14:30:30     INFO - GECKO(2865) | #02: mozilla::ipc::ProcessLink::OnChannelError() [ipc/glue/MessageLink.cpp:389]
[task 2018-06-27T14:30:30.411Z] 14:30:30     INFO - 
[task 2018-06-27T14:30:30.412Z] 14:30:30     INFO - GECKO(2865) | #03: IPC::Channel::ChannelImpl::OnFileCanReadWithoutBlocking(int) [ipc/chromium/src/chrome/common/ipc_channel_posix.cc:822]
[task 2018-06-27T14:30:30.413Z] 14:30:30     INFO - 
[task 2018-06-27T14:30:30.414Z] 14:30:30     INFO - GECKO(2865) | #04: event_process_active_single_queue [ipc/chromium/src/third_party/libevent/event.c:1648]
[task 2018-06-27T14:30:30.415Z] 14:30:30     INFO - 
[task 2018-06-27T14:30:30.416Z] 14:30:30     INFO - GECKO(2865) | #05: event_base_loop [ipc/chromium/src/third_party/libevent/event.c:1741]
[task 2018-06-27T14:30:30.417Z] 14:30:30     INFO - 
[task 2018-06-27T14:30:30.419Z] 14:30:30     INFO - GECKO(2865) | #06: base::MessagePumpLibevent::Run(base::MessagePump::Delegate*) [ipc/chromium/src/base/message_pump_libevent.cc:381]
[task 2018-06-27T14:30:30.423Z] 14:30:30     INFO - 
[task 2018-06-27T14:30:30.425Z] 14:30:30     INFO - GECKO(2865) | #07: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:326]
[task 2018-06-27T14:30:30.429Z] 14:30:30     INFO - 
[task 2018-06-27T14:30:30.430Z] 14:30:30     INFO - GECKO(2865) | #08: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:297]
[task 2018-06-27T14:30:30.432Z] 14:30:30     INFO - 
[task 2018-06-27T14:30:30.433Z] 14:30:30     INFO - GECKO(2865) | #09: base::Thread::ThreadMain() [ipc/chromium/src/base/thread.cc:184]
[task 2018-06-27T14:30:30.434Z] 14:30:30     INFO - 
[task 2018-06-27T14:30:30.435Z] 14:30:30     INFO - GECKO(2865) | #10: ThreadFunc [ipc/chromium/src/base/platform_thread_posix.cc:40]
[task 2018-06-27T14:30:30.437Z] 14:30:30     INFO - 
[task 2018-06-27T14:30:30.438Z] 14:30:30     INFO - GECKO(2865) | #11: libpthread.so.0 + 0x6295

Any assertion comparing two values looks like the same in the log summary.
media/libcubeb/cubeb-pulse-rs is in media code, moving components.
Component: Graphics: WebRender → Audio/Video
Component: Audio/Video → Audio/Video: cubeb
Bug 1458824 has it webrender. Is there any meta component this bug belongs into?
Not really. Really what want is for the log scraper to be smarter about picking up the details of the code that's triggering the panic.
(In reply to Kartikaya Gupta (away until Jul03) (email:kats@mozilla.com) from comment #3)
> Not really. Really what want is for the log scraper to be smarter about
> picking up the details of the code that's triggering the panic.

Shouldn't this be filed against the TreeHerder tooling, then?  Or are you asking for the cubeb-pulse-rs code to be changed to report something different?
Priority: -- → P5
The panic is a legitimate problem in libcubeb that manifests as an intermittent failure, this bug is about that. My previous comment was a side discussion about how to better categorize such bugs so that they can more easily be put into the correct component. i.e. how sheriffs can distinguish between this panic and the one in bug 1458824 which is a similar panic but in WebRender.
Severity: enhancement → normal
Priority: P5 → P3
Assignee: nobody → kinetik
Status: NEW → ASSIGNED
The old C cubeb_pulse backend didn't assert here (and Chromium doesn't, either), so it should be safe to drop this assert since we can't really do anything different and these are likely caused by internal command timeouts within PA.
https://hg.mozilla.org/mozilla-central/rev/5c7e7dae1b81
Status: ASSIGNED → RESOLVED
Closed: Last year
Resolution: --- → FIXED
Target Milestone: --- → mozilla63
You need to log in before you can comment on or make changes to this bug.