538537 - "###!!! ABORT: not on worker thread!: 'mWorkerLoop == MessageLoop::current()" or segfault [@AsyncChannel::AssertWorkerThread] when playing quicktime video with totem plugin

Status: RESOLVED FIXED

(Core Graveyard :: Plug-ins, defect)

Description

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

[PluginModuleChild] Init
LoadPlugin() /usr/lib/mozilla/plugins/libtotem-narrowspace-plugin.so returned ff4de0
[PluginModuleParent] NP_Initialize
[PluginModuleChild] AnswerNP_Initialize
** (<unknown>:28209): DEBUG: NP_Initialize
** (<unknown>:28209): DEBUG: NP_Initialize succeeded
[PluginModuleParent] NPP_New
[PluginModuleChild] AllocPPluginInstance
[PluginModuleChild] AnswerPPluginInstanceConstructor
(plugin args: src=quicktime/waterballoon.mov, autoplay=false, controller=true, pluginspage=http://www.apple.com/quicktime/download/, height=256, width=320, )
** (<unknown>:28209): DEBUG: totemPlugin [0x10013e0]
** (<unknown>:28209): DEBUG: 0x10013e0: "Init mimetype 'video/quicktime' mode 1"
[PluginModuleChild] _getvalue
[PluginInstanceChild] NPN_GetValue(NPNVPluginElementNPObject)
[PluginInstanceParent] NPP_GetValue(NPPVpluginScriptableNPObject)
** (<unknown>:28209): DEBUG: 0x10013e0: "GetScriptableNPObject [0x10013e0]"
[PluginModuleChild] _memalloc
[PluginModuleChild] _getstringidentifiers
[PluginModuleChild] _createobject
** (<unknown>:28209): DEBUG: totemNarrowSpacePlayer [0xdb78e0]
[PluginModuleChild] _retainobject: object 0xdb78e8, refcnt 2
[PluginModuleChild] _retainobject: object 0xdb78e8, refcnt 3
[PluginModuleChild] _releaseobject: object 0xdb78e8, refcnt 2
[PluginModuleChild] _createobject
[PluginModuleChild] _memalloc
[PluginModuleChild] _retainobject: object 0x1002cf0, refcnt 1
[PluginModuleChild] _getstringidentifier
[PluginModuleChild] _getproperty
[PluginModuleChild] _getstringidentifier
** (<unknown>:28209): DEBUG: 0x10013e0: "Base URI is 'http://spaceflightsystems.grc.nasa.gov/WaterBalloon/'"
** (<unknown>:28209): DEBUG: 0x10013e0: "Real mimetype for 'video/quicktime' is 'video/quicktime'"
argv[0] src quicktime/waterballoon.mov
argv[1] autoplay false
argv[2] controller true
argv[3] pluginspage http://www.apple.com/quicktime/download/
argv[4] height 256
argv[5] width 320
** (<unknown>:28209): DEBUG: 0x10013e0: "mSrcURI: quicktime/waterballoon.mov"
** (<unknown>:28209): DEBUG: 0x10013e0: "mCache: 0"
** (<unknown>:28209): DEBUG: 0x10013e0: "mControllerHidden: 0"
** (<unknown>:28209): DEBUG: 0x10013e0: "mShowStatusbar: 0"
** (<unknown>:28209): DEBUG: 0x10013e0: "mHidden: 0"
** (<unknown>:28209): DEBUG: 0x10013e0: "mAudioOnly: 0"
** (<unknown>:28209): DEBUG: 0x10013e0: "mAutoPlay: 0, mRepeat: 0"
** (<unknown>:28209): DEBUG: 0x10013e0: "mHref: "
** (<unknown>:28209): DEBUG: 0x10013e0: "mTarget: "
** (<unknown>:28209): DEBUG: 0x10013e0: "Viewer spawned, PID 28228"
[PluginModuleChild] _releasevariantvalue
[PluginModuleChild] AnswerPPluginInstanceConstructor: returning 0
[PluginModuleParent] NPP_New: got return value 0
[PluginInstanceParent] NPP_GetValue(NPPVpluginNeedsXEmbed)
nsPluginNativeWindowGtk2: NPPVpluginNeedsXEmbed=1
nsPluginNativeWindowGtk2: call SetWindow with xid=0x52007cb
[PluginModuleParent] NPP_SetWindow
[PluginInstanceChild] NPP_SetWindow(0x52007cb, 773, 960, 320 x 256)
** (<unknown>:28209): DEBUG: 0x10013e0: "Initial window set, XID 52007cb size 320x256"
** (<unknown>:28209): DEBUG: 0x10013e0: "No viewer proxy yet, deferring SetWindow"
[PluginInstanceParent] NPP_GetValue(NPPVpluginScriptableNPObject)
** (<unknown>:28209): DEBUG: 0x10013e0: "GetScriptableNPObject [0x10013e0]"
[PluginModuleChild] _retainobject: object 0xdb78e8, refcnt 3
[PluginModuleChild] _releaseobject: object 0xdb78e8, refcnt 2
nsPluginNativeWindowGtk2: call SetWindow with xid=0x52007cb
[PluginModuleParent] NPP_SetWindow
[PluginInstanceChild] NPP_SetWindow(0x52007cb, 773, 960, 320 x 256)
** (<unknown>:28209): DEBUG: 0x10013e0: "Viewer DBus interface name is 'org.gnome.totem.PluginViewer_28228'"
** (<unknown>:28209): DEBUG: 0x10013e0: "NameOwnerChanged old-owner '' new-owner ':1.600'"
** (<unknown>:28209): DEBUG: 0x10013e0: "Viewer now connected to the bus"
** (<unknown>:28209): DEBUG: 0x10013e0: "ViewerSetup"
** (<unknown>:28209): DEBUG: 0x10013e0: "Calling SetWindow"
Viewer: SetWindow XID 85985227 size 320:256
TotemEmbedded-Message: Viewer state: STOPPED
** (<unknown>:28209): DEBUG: SetWindow reply
** (<unknown>:28209): DEBUG: 0x10013e0: "ViewerReady"
[PluginModuleParent] NPP_NewStream
BrowserStreamParent::BrowserStreamParent<0x2ae2220>
** (<unknown>:28209): DEBUG: 0x10013e0: "NewStream mimetype 'video/quicktime' URL 'http://spaceflightsystems.grc.nasa.gov/WaterBalloon/quicktime/waterballoon.mov'"
** (<unknown>:28209): DEBUG: 0x10013e0: "Not expecting a new stream; aborting stream"
[PluginModuleChild] _destroystream
###!!! ABORT: not on worker thread!: 'mWorkerLoop == MessageLoop::current()', file ../../dist/include/mozilla/ipc/AsyncChannel.h, line 130

Also see a segfault

#0  0x00007fe677f3b297 in mozilla::ipc::AsyncChannel::AssertWorkerThread (this=0x0) at ../../dist/include/mozilla/ipc/AsyncChannel.h:129
#1  0x00007fe677f4043e in mozilla::ipc::RPCChannel::Call (this=0x0, msg=0x7fe66824df60, reply=0x7fe66d3a5230) at /home/cjones/mozilla/mozilla-central/ipc/glue/RPCChannel.cpp:86
#2  0x00007fe677f9a017 in mozilla::plugins::PBrowserStreamChild::Call__delete__ (actor=0x7fe66824e120, reason=@0x7fe66d3a52dc, artificial=@0x7fe66d3a531f) at PBrowserStreamChild.cpp:125
#3  0x00007fe677f28d5a in _destroystream (aNPP=0x7fe668246e80, aStream=0x7fe66824e158, aReason=0) at /home/cjones/mozilla/mozilla-central/dom/plugins/PluginModuleChild.cpp:755
#4  0x00007fe677f37bc6 in BrowserStreamChild (this=0x7fe66824e120, instance=0x7fe668246e30, url=..., length=@0x7fe66d3a55fc, lastmodified=@0x7fe66d3a54f8, notifyData=0x0, headers=..., mimeType=..., seekable=@0x7fe66d3a5612, rv=0x7fe66d3a5610, stype=0x7fe66d3a560e) at /home/cjones/mozilla/mozilla-central/dom/plugins/BrowserStreamChild.cpp:74
#5  0x00007fe677f244a0 in mozilla::plugins::PluginInstanceChild::AllocPBrowserStream (this=0x7fe668246e30, url=..., length=@0x7fe66d3a55fc, lastmodified=@0x7fe66d3a54f8, notifyData=0x0, headers=..., mimeType=..., seekable=@0x7fe66d3a5612, rv=0x7fe66d3a5610, stype=0x7fe66d3a560e) at /home/cjones/mozilla/mozilla-central/dom/plugins/PluginInstanceChild.cpp:936
#6  0x00007fe677f8fd80 in mozilla::plugins::PPluginInstanceChild::OnCallReceived (this=0x7fe668246e30, msg=..., reply=@0x7fe66d3a5870) at PPluginInstanceChild.cpp:1076
#7  0x00007fe677f8a08d in mozilla::plugins::PPluginModuleChild::OnCallReceived (this=0xf42c68, msg=..., reply=@0x7fe66d3a5870) at PPluginModuleChild.cpp:375
#8  0x00007fe677f413f4 in mozilla::ipc::RPCChannel::DispatchIncall (this=0xf42c78, call=...) at /home/cjones/mozilla/mozilla-central/ipc/glue/RPCChannel.cpp:347
#9  0x00007fe677f4130d in mozilla::ipc::RPCChannel::Incall (this=0xf42c78, call=..., stackDepth=0) at /home/cjones/mozilla/mozilla-central/ipc/glue/RPCChannel.cpp:332
#10 0x00007fe677f40fc3 in mozilla::ipc::RPCChannel::OnMaybeDequeueOne (this=0xf42c78) at /home/cjones/mozilla/mozilla-central/ipc/glue/RPCChannel.cpp:267
#11 0x00007fe677f43c1a in DispatchToMethod<mozilla::ipc::RPCChannel, void (mozilla::ipc::RPCChannel::*)()> (obj=0xf42c78, method=0x7fe677f40e42 <mozilla::ipc::RPCChannel::OnMaybeDequeueOne()>, arg=...) at /home/cjones/mozilla/mozilla-central/ipc/chromium/src/base/tuple.h:383
#12 0x00007fe677f43a70 in RunnableMethod<mozilla::ipc::RPCChannel, void (mozilla::ipc::RPCChannel::*)(), Tuple0>::Run (this=0xf46190) at /home/cjones/mozilla/mozilla-central/ipc/chromium/src/base/task.h:307
#13 0x00007fe677fdfa7e in MessageLoop::RunTask (this=0x7fe66d3a5e20, task=0xf46190) at /home/cjones/mozilla/mozilla-central/ipc/chromium/src/base/message_loop.cc:326
#14 0x00007fe677fdfaee in MessageLoop::DeferOrRunPendingTask (this=0x7fe66d3a5e20, pending_task=...) at /home/cjones/mozilla/mozilla-central/ipc/chromium/src/base/message_loop.cc:334
#15 0x00007fe677fdfeec in MessageLoop::DoWork (this=0x7fe66d3a5e20) at /home/cjones/mozilla/mozilla-central/ipc/chromium/src/base/message_loop.cc:434
#16 0x00007fe677f3f2b9 in mozilla::ipc::DoWorkRunnable::Run (this=0x7fe668000ba0) at /home/cjones/mozilla/mozilla-central/ipc/glue/MessagePump.cpp:75
#17 0x00007fe6780de3d9 in nsThread::ProcessNextEvent (this=0x7fe668003660, mayWait=1, result=0x7fe66d3a5b7c) at /home/cjones/mozilla/mozilla-central/xpcom/threads/nsThread.cpp:527
#18 0x00007fe67806e868 in NS_ProcessNextEvent_P (thread=0x7fe668003660, mayWait=1) at nsThreadUtils.cpp:250
#19 0x00007fe677f3f6eb in mozilla::ipc::MessagePump::Run (this=0x7fe668000b00, aDelegate=0x7fe66d3a5e20) at /home/cjones/mozilla/mozilla-central/ipc/glue/MessagePump.cpp:142
#20 0x00007fe677f3faeb in mozilla::ipc::MessagePumpForChildProcess::Run (this=0x7fe668000b00, aDelegate=0x7fe66d3a5e20) at /home/cjones/mozilla/mozilla-central/ipc/glue/MessagePump.cpp:232
#21 0x00007fe677fdf5b9 in MessageLoop::RunInternal (this=0x7fe66d3a5e20) at /home/cjones/mozilla/mozilla-central/ipc/chromium/src/base/message_loop.cc:211
#22 0x00007fe677fdf53e in MessageLoop::RunHandler (this=0x7fe66d3a5e20) at /home/cjones/mozilla/mozilla-central/ipc/chromium/src/base/message_loop.cc:194
#23 0x00007fe677fdf4cf in MessageLoop::Run (this=0x7fe66d3a5e20) at /home/cjones/mozilla/mozilla-central/ipc/chromium/src/base/message_loop.cc:168
#24 0x00007fe677dee21d in nsBaseAppShell::Run (this=0x7fe668244710) at /home/cjones/mozilla/mozilla-central/widget/src/xpwidgets/nsBaseAppShell.cpp:174
#25 0x00007fe676c15d22 in XRE_RunAppShell () at /home/cjones/mozilla/mozilla-central/toolkit/xre/nsEmbedFunctions.cpp:444
#26 0x00007fe677f3fa26 in mozilla::ipc::MessagePumpForChildProcess::Run (this=0x7fe668000b00, aDelegate=0x7fe66d3a5e20) at /home/cjones/mozilla/mozilla-central/ipc/glue/MessagePump.cpp:218
#27 0x00007fe677fdf5b9 in MessageLoop::RunInternal (this=0x7fe66d3a5e20) at /home/cjones/mozilla/mozilla-central/ipc/chromium/src/base/message_loop.cc:211
#28 0x00007fe677fdf53e in MessageLoop::RunHandler (this=0x7fe66d3a5e20) at /home/cjones/mozilla/mozilla-central/ipc/chromium/src/base/message_loop.cc:194
#29 0x00007fe677fdf4cf in MessageLoop::Run (this=0x7fe66d3a5e20) at /home/cjones/mozilla/mozilla-central/ipc/chromium/src/base/message_loop.cc:168
#30 0x00007fe6780067be in base::Thread::ThreadMain (this=0xf42bc0) at /home/cjones/mozilla/mozilla-central/ipc/chromium/src/base/thread.cc:165
#31 0x00007fe67803b453 in ThreadFunc (closure=0xf42bc0) at /home/cjones/mozilla/mozilla-central/ipc/chromium/src/base/platform_thread_posix.cc:26
#32 0x00007fe679863a04 in start_thread (arg=<value optimized out>) at pthread_create.c:300
#33 0x00007fe67539f7bd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#34 0x0000000000000000 in ?? ()

These errors point to use-after-free.  valgrind will tell all.

Comment 1

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Attachment: valgrind log

Little trickier than I thought.  Will play around some more tonight before sleep.

Comment 2

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Apparently the totem plugin doesn't like a BrowserStream, and is destroying it from within the BrowserStreamChild constructor (mInstance->mPluginIface->newstream()).  Soon after this in _destroystream (PBrowserStreamChild::Call__delete__(bs, aReason, false)), the world ends.  This is apparently because when the BrowserStreamChild is deleted (from within its ctor), its RPCChannel hasn't yet been set by IPDL-generated code, and after that point, all hell breaks loose.

IMHO this is a BrowserStreamChild bug, because IPC is being done from an AllocPBrowserStreamChild() call.  I think the same ends could be achieved by moving this call to an AnswerPBrowserStreamConstructor() callback.  Will pursue tomorrow after sleep.

Comment 3

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Attachment: guard the browser stream against being destroyed from within its ctor

Comment 4

[Chris Jones [:cjones] inactive; ni?/f?/r? if you need me]

Pushed http://hg.mozilla.org/mozilla-central/rev/244da611e0f5