548214 - ASSERTION: recvd.is_reply_error() || (recvd.type() == (outcall.type()+1) && recvd.seqno() == outcall.seqno())", why=0x2843357 "somebody's misbehavin'

Status: RESOLVED FIXED

(Core :: IPC, defect)

Description

[Benjamin Smedberg]

(gdb) p recvd.seqno()
$6 = -51
(gdb) p outcall.seqno()
$7 = -52
(gdb) bt
#0  mozilla::ipc::RPCChannel::DebugAbort (this=0x9446cc8, file=
    0x2843250 "../../../src/ipc/glue/RPCChannel.cpp", line=222, cond=
    0x2843370 "recvd.is_reply_error() || (recvd.type() == (outcall.type()+1) && recvd.seqno() == outcall.seqno())", why=0x2843357 "somebody's misbehavin'", 
    type=0x2843227 "rpc", reply=true)
    at ../../../src/ipc/glue/RPCChannel.cpp:559
#1  0x02128bd9 in mozilla::ipc::RPCChannel::Call (this=0x9446cc8, msg=
    0xf6b33938, reply=0xf76d57ac) at ../../../src/ipc/glue/RPCChannel.cpp:218
#2  0x0217ff91 in mozilla::plugins::PPluginInstanceChild::CallNPN_GetURL (this=
    0xf6b339d8, url=..., target=..., result=0xf76d5816)
    at PPluginInstanceChild.cpp:423
#3  0x0211000c in mozilla::plugins::child::_geturl (aNPP=0xf6b33a00, 
    aRelativeURL=
    0xf6b6ca54 "data:text/html,Lorem%20ipsum%20dolor%20sit%20amet,%20consetetur%20sadipscing%20elitr,%20sed%20diam%20nonumy%20eirmod%20tempor%20invidunt%20ut%20labore%20et%20dolore%20magna%20aliquyam%20erat,%20sed%20"..., aTarget=
    0xf6b39f6c "testframe")
    at ../../../src/dom/plugins/PluginModuleChild.cpp:724
#4  0x02a65d07 in NPN_GetURL (instance=0xf6b33a00, url=
    0xf6b6ca54 "data:text/html,Lorem%20ipsum%20dolor%20sit%20amet,%20consetetur%20sadipscing%20elitr,%20sed%20diam%20nonumy%20eirmod%20tempor%20invidunt%20ut%20labore%20et%20dolore%20magna%20aliquyam%20erat,%20sed%20"..., target=
    0xf6b39f6c "testframe")
---Type <return> to continue, or q <return> to quit---
    at ../../../../../src/modules/plugin/test/testplugin/nptest.cpp:1288
#5  0x02a63cad in sendBufferToFrame (instance=0xf6b33a00)
    at ../../../../../src/modules/plugin/test/testplugin/nptest.cpp:413
#6  0x02a64faf in NPP_DestroyStream (instance=0xf6b33a00, stream=0xf6b3481c, 
    reason=1)
    at ../../../../../src/modules/plugin/test/testplugin/nptest.cpp:912
#7  0x02120781 in mozilla::plugins::BrowserStreamChild::RecvNPP_DestroyStream (
    this=0xf6b34800, reason=@0xf76d599a)
    at ../../../src/dom/plugins/BrowserStreamChild.cpp:158
#8  0x0218d85c in mozilla::plugins::PBrowserStreamChild::OnMessageReceived (
    this=0xf6b34800, msg=...) at PBrowserStreamChild.cpp:157
#9  0x0217ccd9 in mozilla::plugins::PPluginModuleChild::OnMessageReceived (
    this=0x9446cc0, msg=...) at PPluginModuleChild.cpp:356
#10 0x02123793 in mozilla::ipc::AsyncChannel::OnDispatchMessage (this=
    0x9446cc8, msg=...) at ../../../src/ipc/glue/AsyncChannel.cpp:244
#11 0x02128942 in mozilla::ipc::RPCChannel::Call (this=0x9446cc8, msg=
    0xf6b5fda0, reply=0xf76d5b1c) at ../../../src/ipc/glue/RPCChannel.cpp:193
#12 0x0217ff91 in mozilla::plugins::PPluginInstanceChild::CallNPN_GetURL (this=
    0xf6b339d8, url=..., target=..., result=0xf76d5b86)
    at PPluginInstanceChild.cpp:423
#13 0x0211000c in mozilla::plugins::child::_geturl (aNPP=0xf6b33a00, 
    aRelativeURL=
    0xf6b6804c "data:text/html,Lorem%20ipsum%20dolor%20sit%20amet,%20consetetur%---Typ------T---Type ----------T-------------Type <return> to continue, or q <return> to quit---
20sadipscing%20elitr,%20sed%20diam%20nonumy%20eirmod%20tempor%20invidunt%20ut%20labore%20et%20dolore%20magna%20aliquyam%20erat,%20sed%20"..., aTarget=
    0xf6b39f6c "testframe")
    at ../../../src/dom/plugins/PluginModuleChild.cpp:724
#14 0x02a65d07 in NPN_GetURL (instance=0xf6b33a00, url=
    0xf6b6804c "data:text/html,Lorem%20ipsum%20dolor%20sit%20amet,%20consetetur%20sadipscing%20elitr,%20sed%20diam%20nonumy%20eirmod%20tempor%20invidunt%20ut%20labore%20et%20dolore%20magna%20aliquyam%20erat,%20sed%20"..., target=
    0xf6b39f6c "testframe")
    at ../../../../../src/modules/plugin/test/testplugin/nptest.cpp:1288
#15 0x02a63cad in sendBufferToFrame (instance=0xf6b33a00)
    at ../../../../../src/modules/plugin/test/testplugin/nptest.cpp:413
#16 0x02a653e2 in NPP_Write (instance=0xf6b33a00, stream=0xf6b3481c, offset=
    100, len=100, buffer=0xf6b64908)
    at ../../../../../src/modules/plugin/test/testplugin/nptest.cpp:1015
#17 0x021209e5 in mozilla::plugins::BrowserStreamChild::DeliverData (this=
    0xf6b34800) at ../../../src/dom/plugins/BrowserStreamChild.cpp:215
#18 0x021205dd in mozilla::plugins::BrowserStreamChild::RecvWrite (this=
    0xf6b34800, offset=@0xf76d5d6c, data=..., newlength=@0xf76d5d5c)
    at ../../../src/dom/plugins/BrowserStreamChild.cpp:128
#19 0x0218d792 in mozilla::plugins::PBrowserStreamChild::OnMessageReceived (
    this=0xf6b34800, msg=...) at PBrowserStreamChild.cpp:139
#20 0x0217ccd9 in mozilla::plugins::PPluginModuleChild::OnMessageReceived (
---Type <return> to continue, or q <return> to quit---
    this=0x9446cc0, msg=...) at PPluginModuleChild.cpp:356
#21 0x02123793 in mozilla::ipc::AsyncChannel::OnDispatchMessage (this=
    0x9446cc8, msg=...) at ../../../src/ipc/glue/AsyncChannel.cpp:244
#22 0x02129198 in mozilla::ipc::RPCChannel::OnMaybeDequeueOne (this=0x9446cc8)
    at ../../../src/ipc/glue/RPCChannel.cpp:346
#23 0x0212d4a1 in DispatchToMethod<mozilla::ipc::RPCChannel, void (mozilla::ipc::RPCChannel::*)()> (obj=0x9446cc8, method=
    (void (mozilla::ipc::RPCChannel::*)(mozilla::ipc::RPCChannel *)) 0x212906a <mozilla::ipc::RPCChannel::OnMaybeDequeueOne()>, arg=...)
    at ../../../src/ipc/chromium/src/base/tuple.h:383
#24 0x0212d361 in RunnableMethod<mozilla::ipc::RPCChannel, void (mozilla::ipc::RPCChannel::*)(), Tuple0>::Run (this=0x94474f0)
    at ../../../src/ipc/chromium/src/base/task.h:307
#25 0x022873a2 in MessageLoop::RunTask (this=0xf76d61a8, task=0x94474f0)
    at ../../../src/ipc/chromium/src/base/message_loop.cc:336
#26 0x0228740b in MessageLoop::DeferOrRunPendingTask (this=0xf76d61a8, 
    pending_task=...) at ../../../src/ipc/chromium/src/base/message_loop.cc:344
#27 0x022877e1 in MessageLoop::DoWork (this=0xf76d61a8)
    at ../../../src/ipc/chromium/src/base/message_loop.cc:444
#28 0x022f167c in base::MessagePumpForUI::HandleDispatch (this=0xf6b00490)
    at ../../../src/ipc/chromium/src/base/message_pump_glib.cc:264
#29 0x022f1025 in (anonymous namespace)::WorkSourceDispatch (source=
    0xf6b00600, unused_func=0, unused_data=0x0)
---Type <return> to continue, or q <return> to quit---
    at ../../../src/ipc/chromium/src/base/message_pump_glib.cc:109
#30 0x083e3f88 in g_main_context_dispatch () from /lib/libglib-2.0.so.0
#31 0x083e78b8 in ?? () from /lib/libglib-2.0.so.0
#32 0x083e79e4 in g_main_context_iteration () from /lib/libglib-2.0.so.0
#33 0x022f13dc in base::MessagePumpForUI::RunWithDispatcher (this=0xf6b00490, 
    delegate=0xf76d61a8, dispatcher=0x0)
    at ../../../src/ipc/chromium/src/base/message_pump_glib.cc:195
#34 0x022f1a3b in base::MessagePumpForUI::Run(base::MessagePump::Delegate*) ()
   from /builds/mozilla-central/ff-debug-32/dist/bin/libxul.so
#35 0x02286e9f in MessageLoop::RunInternal (this=0xf76d61a8)
    at ../../../src/ipc/chromium/src/base/message_loop.cc:216
#36 0x02286e1b in MessageLoop::RunHandler (this=0xf76d61a8)
    at ../../../src/ipc/chromium/src/base/message_loop.cc:199
#37 0x02286d9f in MessageLoop::Run (this=0xf76d61a8)
    at ../../../src/ipc/chromium/src/base/message_loop.cc:173
#38 0x022ab24a in base::Thread::ThreadMain (this=0x9446c68)
    at ../../../src/ipc/chromium/src/base/thread.cc:165
#39 0x022da656 in ThreadFunc (closure=0x9446c68)

This is with the yet-unposted patch for bug 532208, the stream code now has a mix of async and RPC messages. Here's what I *think* is happening:

1. browser sends async write message, keeps going
2. plugin responds by sending an async NPN_DestroyStream message, and then immediately (same stack frame)
2. plugin calls RPC NPN_GetURL message #1, waits for reply
3. browser processes NPN_DestroyStream message, sends async NPP_DestroyStream message
4. browser processes NPN_GetURL message #1, sends reply
5. plugin receives NPP_DestroyStream message, calls RPC NPN_GetURL #2
6. plugin receives the answer for NPN_GetURL #1

I think I'm going to work around this in the test plugin for right now because it really shouldn't be calling NPN_GetURL twice, but this might bite us in the ass for alpha.

Comment 1

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

Attachment: IPDL/C++ test

Comment 2

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

Attachment: Seqno's go up in the parent, down in the child

Braindead.  Can't believe we haven't hit this yet on windows.

Comment 3

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

Attachment: Seqno's go up in the parent, down in the child, v2

Better fix

Comment 4

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

http://hg.mozilla.org/mozilla-central/rev/9efba974e6f1
http://hg.mozilla.org/mozilla-central/rev/7712f2c56f47