841336 - [Bluetooth] Segmentation fault after re-pairing with Bluetooth device

Status: RESOLVED FIXED

(Firefox OS Graveyard :: Bluetooth, defect)

Description

[Thomas Zimmermann [:tzimmermann] [:tdz]]

Attachment: logcat

I was trying to reproduce bug 840925 with b2g-18, when the phone crashed during an attempt to re-pair with a headset.The gdb session is shown below. Something is supposed to run in the main thread, but runs in the DBus thread instead. You probably won't see this error without debugging enabled.

STR:
  - pair phone with headset
  - disconnect
  - connect
  - unpair from headset
  - pair again

Expected result:
  - phone and headset pair again

Actual result:
  - an 'unable to pair' message is displayed
  - clicking 'ok' results in a segmentation fault.

-----

tdz@linux-6f0r:~/Projects/mozilla/src/B2G-unagi> ./run-gdb.sh attach 109
Attached; pid = 109
Listening on port 11109
prebuilt/linux-x86/toolchain/arm-linux-androideabi-4.4.x/bin/arm-linux-androideabi-gdb -x /tmp/b2g.gdbinit.tdz /home/tdz/Projects/mozilla/src/B2G-unagi/objdir-gecko-debug/dist/bin/b2g
GNU gdb (GDB) 7.1-android-gg2
Copyright (C) 2010 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "--host=i686-linux-gnu --target=arm-elf-linux".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Really redefine built-in command "frame"? (y or n) [answered Y; input not from terminal]
Really redefine built-in command "thread"? (y or n) [answered Y; input not from terminal]
Really redefine built-in command "start"? (y or n) [answered Y; input not from terminal]
Reading symbols from /home/tdz/Projects/mozilla/src/B2G-unagi/objdir-gecko-debug/dist/bin/b2g...done.
Remote debugging from host 127.0.0.1
_______________________________________________________________________________
Error while running hook_stop:
Value can't be converted to integer.
syscall () at bionic/libc/arch-arm/bionic/syscall.S:50
50	    ldmfd   sp!, {r4, r5, r6, r7}
gdb> c
[New Thread 109.461]

Program received signal SIGSEGV, Segmentation fault.
_______________________________________________________________________________
Error while running hook_stop:
Value can't be converted to integer.
0x4118ca86 in RunDBusCallback (aMsg=0x449bcf20, aBluetoothReplyRunnable=0x497f1af0, aFunc=0x4118ed01 <UnpackVoidMessage(DBusMessage*, DBusError*, mozilla::dom::bluetooth::BluetoothValue&, nsAString_internal&)>) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/dom/bluetooth/linux/BluetoothDBusService.cpp:892
892	  MOZ_ASSERT(!NS_IsMainThread());
gdb> bt
#0  0x4118ca86 in RunDBusCallback (aMsg=0x449bcf20, aBluetoothReplyRunnable=0x497f1af0, aFunc=0x4118ed01 <UnpackVoidMessage(DBusMessage*, DBusError*, mozilla::dom::bluetooth::BluetoothValue&, nsAString_internal&)>) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/dom/bluetooth/linux/BluetoothDBusService.cpp:892
#1  0x4118cb74 in GetVoidCallback (aMsg=0x99, aBluetoothReplyRunnable=0xbe8ea020) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/dom/bluetooth/linux/BluetoothDBusService.cpp:939
#2  0x4174a892 in mozilla::ipc::dbus_func_args_async_callback (call=0x497f1b20, data=<value optimized out>) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/ipc/dbus/DBusUtils.cpp:68
#3  0x4174a8f2 in mozilla::ipc::dbus_func_send_async (conn=<value optimized out>, msg=0x449bd1f0, timeout_ms=0x3e8, user_cb=0x4118cb69 <GetVoidCallback(DBusMessage*, void*)>, user=0x497f1af0) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/ipc/dbus/DBusUtils.cpp:115
#4  0x4118e71a in mozilla::dom::bluetooth::BluetoothDBusService::SetProperty (this=<value optimized out>, aType=<value optimized out>, aPath=<value optimized out>, aValue=<value optimized out>, aRunnable=0x497f1af0) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/dom/bluetooth/linux/BluetoothDBusService.cpp:2069
#5  0x41182ba0 in mozilla::dom::bluetooth::BluetoothRequestParent::DoRequest (this=0x497f1ac0, aRequest=...) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/dom/bluetooth/ipc/BluetoothParent.cpp:315
#6  0x411838be in mozilla::dom::bluetooth::BluetoothParent::RecvPBluetoothRequestConstructor (this=<value optimized out>, aActor=0x497f1ac0, aRequest=...) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/dom/bluetooth/ipc/BluetoothParent.cpp:191
#7  0x415e5a88 in mozilla::dom::bluetooth::PBluetoothParent::OnMessageReceived (this=0x47d16ac0, __msg=<value optimized out>) at /home/tdz/Projects/mozilla/src/B2G-unagi/objdir-gecko-debug/ipc/ipdl/PBluetoothParent.cpp:433
#8  0x41619f04 in mozilla::dom::PContentParent::OnMessageReceived (this=0x47d8b000, __msg=...) at /home/tdz/Projects/mozilla/src/B2G-unagi/objdir-gecko-debug/ipc/ipdl/PContentParent.cpp:1394
#9  0x415c85a6 in mozilla::ipc::AsyncChannel::OnDispatchMessage (this=0x47d8b008, msg=...) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/ipc/glue/AsyncChannel.cpp:473
#10 0x415cee64 in mozilla::ipc::RPCChannel::OnMaybeDequeueOne (this=0x47d8b008) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/ipc/glue/RPCChannel.cpp:402
#11 0x4159c390 in DispatchToMethod<mozilla::dom::ContentParent, void (mozilla::dom::ContentParent::*)()> (this=<value optimized out>) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/ipc/chromium/src/base/tuple.h:383
#12 RunnableMethod<mozilla::dom::ContentParent, void (mozilla::dom::ContentParent::*)(), Tuple0>::Run (this=<value optimized out>) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/ipc/chromium/src/base/task.h:307
#13 0x415cd2b6 in mozilla::ipc::RPCChannel::RefCountedTask::Run (this=0x4ac05720) at ../../dist/include/mozilla/ipc/RPCChannel.h:425
#14 mozilla::ipc::RPCChannel::DequeueTask::Run (this=0x4ac05720) at ../../dist/include/mozilla/ipc/RPCChannel.h:448
#15 0x417c048e in MessageLoop::RunTask (this=0x4042b0c0, task=0x4ac05720) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/ipc/chromium/src/base/message_loop.cc:333
#16 0x417c0cb8 in MessageLoop::DeferOrRunPendingTask (this=0x99, pending_task=<value optimized out>) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/ipc/chromium/src/base/message_loop.cc:341
#17 0x417c1a0a in MessageLoop::DoWork (this=0x4042b0c0) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/ipc/chromium/src/base/message_loop.cc:441
#18 0x415cc8d4 in mozilla::ipc::DoWorkRunnable::Run (this=<value optimized out>) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/ipc/glue/MessagePump.cpp:42
#19 0x4178ad4e in nsThread::ProcessNextEvent (this=0x40404390, mayWait=<value optimized out>, result=0xbe8eb6ef) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/xpcom/threads/nsThread.cpp:620
#20 0x41752578 in NS_ProcessNextEvent_P (thread=0x99, mayWait=0x0) at /home/tdz/Projects/mozilla/src/B2G-unagi/objdir-gecko-debug/xpcom/build/nsThreadUtils.cpp:237
#21 0x415cca8a in mozilla::ipc::MessagePump::Run (this=0x40402430, aDelegate=0x4042b0c0) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/ipc/glue/MessagePump.cpp:82
#22 0x417c0a42 in MessageLoop::RunInternal (this=0x4042b0c0) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/ipc/chromium/src/base/message_loop.cc:215
#23 0x417c0aa2 in MessageLoop::RunHandler (this=0x4042b0c0) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/ipc/chromium/src/base/message_loop.cc:208
#24 MessageLoop::Run (this=0x4042b0c0) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/ipc/chromium/src/base/message_loop.cc:182
#25 0x4150767a in nsBaseAppShell::Run (this=0x4350e7c0) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/widget/xpwidgets/nsBaseAppShell.cpp:163
#26 0x4140026e in nsAppStartup::Run (this=0x43692eb0) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/toolkit/components/startup/nsAppStartup.cpp:290
#27 0x40a143e6 in XREMain::XRE_mainRun (this=0xbe8eb984) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/toolkit/xre/nsAppRunner.cpp:3794
#28 0x40a16acc in XREMain::XRE_main (this=0xbe8eb984, argc=<value optimized out>, argv=0xbe8edb84, aAppData=0x21160) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/toolkit/xre/nsAppRunner.cpp:3860
#29 0x40a16c7a in XRE_main (argc=0x1, argv=0xbe8edb84, aAppData=0x21160, aFlags=<value optimized out>) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/toolkit/xre/nsAppRunner.cpp:3935
#30 0x000099fc in do_main (argc=0x1, argv=0xbe8edb84) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/b2g/app/nsBrowserApp.cpp:164
#31 main (argc=0x1, argv=0xbe8edb84) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/b2g/app/nsBrowserApp.cpp:249
gdb> info threads
[New Thread 109.230]
[New Thread 109.232]
[New Thread 109.233]
[New Thread 109.235]
[New Thread 109.236]
[New Thread 109.237]
[New Thread 109.238]
[New Thread 109.239]
[New Thread 109.240]
[New Thread 109.241]
[New Thread 109.242]
[New Thread 109.243]
[New Thread 109.244]
[New Thread 109.245]
[New Thread 109.246]
[New Thread 109.247]
[New Thread 109.248]
[New Thread 109.249]
[New Thread 109.250]
[New Thread 109.251]
[New Thread 109.252]
[New Thread 109.253]
[New Thread 109.254]
[New Thread 109.255]
[New Thread 109.256]
[New Thread 109.257]
[New Thread 109.264]
[New Thread 109.323]
[New Thread 109.326]
[New Thread 109.327]
[New Thread 109.331]
[New Thread 109.333]
[New Thread 109.376]
[New Thread 109.379]
[New Thread 109.489]
[New Thread 109.493]
[New Thread 109.494]
  39 Thread 109.494  0x4072e77e in yy_find_reduce_action (yyp=0x4ad1a808, yymajor=<value optimized out>, yyminor=..., pParse=0x4cbf9408) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/db/sqlite3/src/sqlite3.c:108580
  38 Thread 109.493  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:183
  37 Thread 109.489  poll () at bionic/libc/arch-arm/syscalls/poll.S:10
  36 Thread 109.379  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  35 Thread 109.376  0xffff0520 in ?? ()
  34 Thread 109.333  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  33 Thread 109.331  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  32 Thread 109.327  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  31 Thread 109.326  __ioctl () at bionic/libc/arch-arm/syscalls/__ioctl.S:9
  30 Thread 109.323  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  29 Thread 109.264  poll () at bionic/libc/arch-arm/syscalls/poll.S:10
  28 Thread 109.257  syscall () at bionic/libc/arch-arm/bionic/syscall.S:50
  27 Thread 109.256  read () at bionic/libc/arch-arm/syscalls/read.S:9
  26 Thread 109.255  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  25 Thread 109.254  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  24 Thread 109.253  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  23 Thread 109.252  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  22 Thread 109.251  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  21 Thread 109.250  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  20 Thread 109.249  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  19 Thread 109.248  0xffff0520 in ?? ()
  18 Thread 109.247  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  17 Thread 109.246  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  16 Thread 109.245  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  15 Thread 109.244  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  14 Thread 109.243  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:183
  13 Thread 109.242  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  12 Thread 109.241  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  11 Thread 109.240  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  10 Thread 109.239  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  9 Thread 109.238  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:183
  8 Thread 109.237  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  7 Thread 109.236  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  6 Thread 109.235  0xffff0520 in ?? ()
  5 Thread 109.233  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  4 Thread 109.232  syscall () at bionic/libc/arch-arm/bionic/syscall.S:50
  3 Thread 109.230  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
  2 Thread 109.461  __futex_syscall3 () at bionic/libc/arch-arm/bionic/atomics_arm.S:182
* 1 Thread 109.109  0x4118ca86 in RunDBusCallback (aMsg=0x449bcf20, aBluetoothReplyRunnable=0x497f1af0, aFunc=0x4118ed01 <UnpackVoidMessage(DBusMessage*, DBusError*, mozilla::dom::bluetooth::BluetoothValue&, nsAString_internal&)>) at /home/tdz/Projects/mozilla/src/B2G-unagi/gecko/dom/bluetooth/linux/BluetoothDBusService.cpp:892
gdb> info registers
r0             0x99	0x99
r1             0xbe8ea020	0xbe8ea020
r2             0x7b	0x7b
r3             0x0	0x0
r4             0x497f1af0	0x497f1af0
r5             0x497f1b20	0x497f1b20
r6             0x449bcf20	0x449bcf20
r7             0xbe8ea478	0xbe8ea478
r8             0x4118ed01	0x4118ed01
r9             0x4118cb69	0x4118cb69
r10            0x0	0x0
r11            0x497f1af0	0x497f1af0
r12            0x40066108	0x40066108
sp             0xbe8ea470	0xbe8ea470
lr             0x4118ca83	0x4118ca83
pc             0x4118ca86	0x4118ca86 <RunDBusCallback(DBusMessage*, void*, void (*)(DBusMessage*, DBusError*, mozilla::dom::bluetooth::BluetoothValue&, nsAString_internal&))+54>
cpsr           0x20000030	0x20000030
gdb>

Comment 1

[Thomas Zimmermann [:tzimmermann] [:tdz]]

Oops, I mean something is running in the main thread that isn't supposed to run there.

Comment 2

[Thomas Zimmermann [:tzimmermann] [:tdz]]

And I know what's happening here: this bug get's triggered by the workaround I added for bug 827888, where the callback for a message gets executed immediately if the message's reply has already been received.

The actual fix for this problem is in bug 830290. However these patches are quite intrusive.

As the code seems to work in practice (as a nearby comment indicates), I suggest we remove the failed assertion for now and concentrate on getting the patches from bug 830290 into the repository.

Comment 3

[Eric Chou [:ericchou] [:echou]]

It(In reply to Thomas Zimmermann [:tzimmermann] from comment #2)
> And I know what's happening here: this bug get's triggered by the workaround
> I added for bug 827888, where the callback for a message gets executed
> immediately if the message's reply has already been received.
> 
> The actual fix for this problem is in bug 830290. However these patches are
> quite intrusive.
> 
> As the code seems to work in practice (as a nearby comment indicates), I
> suggest we remove the failed assertion for now and concentrate on getting
> the patches from bug 830290 into the repository.

I don't know if this is a good idea to just remove the assertion. Basically, it's confusing that the callback function may be called on the main thread
(call dbus_func_args_async_callback directly) and on non-main threads(via dbus_pending_call_set_notify). Since bug 830290 should resolve this, I would suggest that we should let this bug open until bug 830290 landed, then we can check if this will still happen.

Comment 4

[Eric Chou [:ericchou] [:echou]]

ok, I changed my mind since this could be reproduced easily. I'd say it's ok to remove the assertion for now, but we have to make sure it will not cause regressions and remember to put it back in bug 830290.

Comment 5

[Wayne Chang [:wchang]]

Hi Shawn, can you help on this one? Thanks

Comment 6

[Shawn Huang [:shawnjohnjr][:shuang] (as a happy gecko contributor)]

I believe bug 830290 patch can resolve this problem. We shall concentrate on bug 830290 patch first.

Comment 7

[Gregor Wagner [:gwagner]]

I think we should get a fix here without relying on bug 830290 since the big change of bug 830290 is unlikely to be uplifted.

Comment 8

[Eric Chou [:ericchou] [:echou]]

(In reply to Gregor Wagner [:gwagner] from comment #7)
> I think we should get a fix here without relying on bug 830290 since the big
> change of bug 830290 is unlikely to be uplifted.

I think several patches of bug 830290 would still be merged into b2g18, and currently I can't tell if this problem will be fixed. So I would suggest that we work on this issue again after b2g18 version of bug 830290 landed.

Comment 9

[Shawn Huang [:shawnjohnjr][:shuang] (as a happy gecko contributor)]

To avoid a dramatic change, for b2g18 branch, we probably go for removing assertion. And focus on bug 830290 on central which is proper solution.

Comment 10

[Shawn Huang [:shawnjohnjr][:shuang] (as a happy gecko contributor)]

https://tbpl.mozilla.org/?tree=Try&rev=4a8dd76644e6

Comment 11

[Shawn Huang [:shawnjohnjr][:shuang] (as a happy gecko contributor)]

Attachment: Remove the assertion

Comment 12

[Eric Chou [:ericchou] [:echou]]

Comment on attachment 728923 [details] [diff] [review]
Remove the assertion

Review of attachment 728923 [details] [diff] [review]:
-----------------------------------------------------------------

Looks good. Please remember to revise the patch summary.

Comment 13

[Shawn Huang [:shawnjohnjr][:shuang] (as a happy gecko contributor)]

Attachment: bug 841336 patch

Comment 14

[Shawn Huang [:shawnjohnjr][:shuang] (as a happy gecko contributor)]

Attachment: Bug 841336-Remove assertion in RunDBusCallback if platform is gonk, r=echou

Comment 15

[Eric Chou [:ericchou] [:echou]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/94de0fb8fbed

Comment 16

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/94de0fb8fbed

Comment 17

[Ryan VanderMeulen [:RyanVM]]

This is going to need a b2g18-specific patch for uplift.

Comment 18

[Eric Chou [:ericchou] [:echou]]

Attachment: patch 1: for b2g18, r=echou

The patch for b2g18.

Comment 19

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-b2g18/rev/882497f1bbe7

Comment 20

[Walter Chen[:ypwalter][:wachen]]

verified fixed in v1train pub 2013/04/17

Comment 21

[Thomas Zimmermann [:tzimmermann] [:tdz]]

Sorry, I just messed up the status flags. This should be VERIFIED FIXED.