2018-05-25 15:41:15

by Chris Murphy

[permalink] [raw]
Subject: bluetoothd: segfault at error 4 in libc-2.27.so

I'm not able to find a reference in the FAQ for where to file bugs, so
for now I'm posting it here.

kernel 4.17.0-0.rc6.git1.1.fc29.x86_64
bluez-5.49-3.fc28.x86_64

At the time of the bluetoothd crash, I'm trying to manually reconnect
laptop to a mouse, and then see coredumpctl capture crash information.
So I installed debuginfos and...

[chris@f28h ~]$ sudo coredumpctl gdb 755
PID: 755 (bluetoothd)
UID: 0 (root)
GID: 0 (root)
Signal: 11 (SEGV)
Timestamp: Fri 2018-05-25 09:10:40 MDT (4min 47s ago)
Command Line: /usr/libexec/bluetooth/bluetoothd -d
Executable: /usr/libexec/bluetooth/bluetoothd
Control Group: /system.slice/bluetooth.service
Unit: bluetooth.service
Slice: system.slice
Boot ID: 7319e09cac754e09b51ecdb68933976b
Machine ID: bbe68372db9f4c589a1f67f008e70864
Hostname: f28h.local
Storage:
/var/lib/systemd/coredump/core.bluetoothd.0.7319e09cac754e09b51ecdb68933976b.755.1527261040000000.lz4
Message: Process 755 (bluetoothd) of user 0 dumped core.

Stack trace of thread 755:
#0 0x00007f276376ef38 n/a (libc.so.6)
#1 0x00007f2763771cd0 n/a (libc.so.6)
#2 0x00007f2763774222 __libc_calloc (libc.so.6)
#3 0x00007f27637674e3 open_memstream (libc.so.6)
#4 0x00007f27637e3270 __vsyslog_chk (libc.so.6)
#5 0x000055fada987ef1 btd_debug (bluetoothd)
#6 0x000055fada99b437 start_discovery_timeout (bluetoothd)
#7 0x00007f2764159371 n/a (libglib-2.0.so.0)
#8 0x00007f27641588ad g_main_context_dispatch
(libglib-2.0.so.0)
#9 0x00007f2764158c78 n/a (libglib-2.0.so.0)
#10 0x00007f2764158fa2 g_main_loop_run (libglib-2.0.so.0)
#11 0x000055fada952564 main (bluetoothd)
#12 0x00007f276371218b __libc_start_main (libc.so.6)
#13 0x000055fada952eba _start (bluetoothd)

GNU gdb (GDB) Fedora 8.1-15.fc28
Copyright (C) 2018 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 "x86_64-redhat-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/libexec/bluetooth/bluetoothd...Reading
symbols from /usr/lib/debug/usr/libexec/bluetooth/bluetoothd-5.49-3.fc28.x86_64.debug...done.
done.
[New LWP 755]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/libexec/bluetooth/bluetoothd -d'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 malloc_consolidate (av=av@entry=0x7f2763aa8c40 <main_arena>) at
malloc.c:4439
4439 unsigned int idx = fastbin_index (chunksize (p));
(gdb) thread apply all bt full

Thread 1 (Thread 0x7f2764622540 (LWP 755)):
#0 malloc_consolidate (av=av@entry=0x7f2763aa8c40 <main_arena>) at
malloc.c:4439
idx = <optimized out>
fb = 0x7f2763aa8c80 <main_arena+64>
maxfb = 0x7f2763aa8c98 <main_arena+88>
p = 0xffffffff
nextp = <optimized out>
unsorted_bin = 0x7f2763aa8ca0 <main_arena+96>
first_unsorted = <optimized out>
nextchunk = <optimized out>
size = <optimized out>
nextsize = <optimized out>
prevsize = <optimized out>
nextinuse = <optimized out>
bck = <optimized out>
fwd = <optimized out>
#1 0x00007f2763771cd0 in _int_malloc (av=av@entry=0x7f2763aa8c40
<main_arena>, bytes=bytes@entry=8192) at malloc.c:3703
nb = 8208
idx = 107
bin = <optimized out>
victim = <optimized out>
size = <optimized out>
victim_index = <optimized out>
remainder = <optimized out>
remainder_size = <optimized out>
block = <optimized out>
bit = <optimized out>
map = <optimized out>
fwd = <optimized out>
bck = <optimized out>
tcache_unsorted_count = <optimized out>
tcache_nb = <optimized out>
tc_idx = <optimized out>
return_cached = <optimized out>
__PRETTY_FUNCTION__ = "_int_malloc"
#2 0x00007f2763774222 in __libc_calloc (n=n@entry=1,
elem_size=elem_size@entry=8192) at malloc.c:3436
av = <optimized out>
oldtop = 0x55fadb8cd4d0
---Type <return> to continue, or q <return> to quit---
p = <optimized out>
bytes = 8192
sz = 8192
csz = <optimized out>
oldtopsize = 133936
mem = <optimized out>
clearsize = <optimized out>
nclears = <optimized out>
d = <optimized out>
hook = <optimized out>
__PRETTY_FUNCTION__ = "__libc_calloc"
#3 0x00007f27637674e3 in __GI___open_memstream
(bufloc=bufloc@entry=0x7ffd59f097d0,
sizeloc=sizeloc@entry=0x7ffd59f097d8) at memstream.c:83
new_f = 0x55fadb8c0660
buf = <optimized out>
#4 0x00007f27637e3270 in __vsyslog_chk () at ../misc/syslog.c:167
now_tm = {tm_sec = 1508940240, tm_min = 32765, tm_hour =
1669791698, tm_mday = 32551, tm_mon = -611539488, tm_year = 22010,
tm_wday = -627542654, tm_yday = 22010,
tm_isdst = -611672912, tm_gmtoff = 94535913430448, tm_zone =
0x55fadb8b38f0 "\b"}
now = 94535898036858
fd = <optimized out>
f = <optimized out>
buf = 0x0
bufsize = 0
msgoff = <optimized out>
saved_errno = 0
failbuf =
"\360\070\213\333\372U\000\000\000\000\000\000\000\000\000\000\220\070\213\333\372U\000\000\000\260\212\333",
<incomplete sequence \372>
clarg = <optimized out>
#5 0x000055fada987ef1 in vsyslog (__ap=0x7ffd59f098c0,
__fmt=0x55fada9e63ed "%s:%s() ", __pri=7) at
/usr/include/bits/syslog.h:47
No locals.
#6 btd_debug (index=index@entry=65535,
format=format@entry=0x55fada9e63ed "%s:%s() ") at src/log.c:252
ap = {{gp_offset = 16, fp_offset = 48, overflow_arg_area =
0x7ffd59f099b0, reg_save_area = 0x7ffd59f098e0}}
#7 0x000055fada99b437 in start_discovery_timeout
(user_data=user_data@entry=0x55fadb8b0c20) at src/adapter.c:1510
__btd_debug_desc = {file = 0x55fada9f2ded "src/adapter.c", flags = 1}
adapter = 0x55fadb8b0c20
sd_cp = <optimized out>
new_type = <optimized out>
__func__ = "start_discovery_timeout"
#8 0x00007f2764159371 in g_timeout_dispatch (source=0x55fadb8c58d0,
callback=0x55fada99b2a0 <start_discovery_timeout>,
user_data=0x55fadb8b0c20) at gmain.c:4650
timeout_source = 0x55fadb8c58d0
again = <optimized out>
---Type <return> to continue, or q <return> to quit---
#9 0x00007f27641588ad in g_main_dispatch (context=0x55fadb89ddb0) at
gmain.c:3177
dispatch = 0x7f2764159350 <g_timeout_dispatch>
prev_source = 0x0
was_in_call = 0
user_data = 0x55fadb8b0c20
callback = 0x55fada99b2a0 <start_discovery_timeout>
cb_funcs = 0x7f2764422280 <g_source_callback_funcs>
cb_data = 0x55fadb8c2690
need_destroy = <optimized out>
source = 0x55fadb8c58d0
current = 0x55fadb8a80a0
i = 0
current = <optimized out>
i = <optimized out>
__func__ = "g_main_dispatch"
source = <optimized out>
_g_boolean_var_ = <optimized out>
was_in_call = <optimized out>
user_data = <optimized out>
callback = <optimized out>
cb_funcs = <optimized out>
cb_data = <optimized out>
need_destroy = <optimized out>
dispatch = <optimized out>
prev_source = <optimized out>
_g_boolean_var_ = <optimized out>
#10 g_main_context_dispatch (context=context@entry=0x55fadb89ddb0) at
gmain.c:3830
No locals.
#11 0x00007f2764158c78 in g_main_context_iterate
(context=0x55fadb89ddb0, block=block@entry=1,
dispatch=dispatch@entry=1, self=<optimized out>) at gmain.c:3903
max_priority = 2147483647
timeout = 4912
some_ready = 1
nfds = <optimized out>
allocated_nfds = 29
fds = 0x55fadb8a98d0
#12 0x00007f2764158fa2 in g_main_loop_run (loop=0x55fadb89def0) at gmain.c:4099
self = <optimized out>
__func__ = "g_main_loop_run"
#13 0x000055fada952564 in main (argc=<optimized out>, argv=<optimized
out>) at src/main.c:770
---Type <return> to continue, or q <return> to quit---
context = <optimized out>
err = 0x0
sdp_flags = <optimized out>
gdbus_flags = <optimized out>
signal = 1
watchdog = 0
watchdog_usec = <optimized out>
__func__ = "main"
(gdb)
(gdb) quit


Possibly related events in the journal leading up to the crash...


[16605.110142] f28h.local kernel: xhci_hcd 0000:00:14.0: Root hub is
not suspended
[16606.787745] f28h.local bluetoothd[755]:
src/adapter.c:device_found_callback() hci0 addr 9C:20:7B:7C:F6:98,
rssi -95 flags 0x0000 eir_len 15
[16606.789357] f28h.local bluetoothd[755]:
src/device.c:device_set_legacy() legacy 0
[16606.789753] f28h.local bluetoothd[755]:
src/device.c:device_set_flags() flags 26
[16605.211477] f28h.local kernel: Bluetooth: hci0: last event is not
cmd complete (0x0f)
[16632.021515] f28h.local bluetoothd[755]:
src/device.c:btd_device_set_temporary() temporary 1
[16632.024133] f28h.local bluetoothd[755]:
src/service.c:change_state() 0x55fadb8bcef0: device 58:1F:AA:EB:B4:6A
profile input-hid state changed: connecting -> disconnecting (0)
[16632.024450] f28h.local bluetoothd[755]:
profiles/input/device.c:input_device_disconnect()
[16632.024731] f28h.local bluetoothd[755]: Can't get HIDP connection info
[16632.024993] f28h.local bluetoothd[755]:
src/service.c:change_state() 0x55fadb8bcef0: device 58:1F:AA:EB:B4:6A
profile input-hid state changed: disconnecting -> disconnected (0)
[16632.025320] f28h.local bluetoothd[755]:
src/adapter.c:remove_whitelist_complete() 58:1F:AA:EB:B4:6A removed
from kernel whitelist
[16632.425334] f28h.local kernel: xhci_hcd 0000:00:14.0: Root hub is
not suspended
[16634.067223] f28h.local bluetoothd[755]:
src/adapter.c:discovering_callback() hci0 type 7 discovering 0 method
0
[16634.069110] f28h.local bluetoothd[755]:
src/adapter.c:trigger_start_discovery()
[16634.069602] f28h.local bluetoothd[755]:
src/adapter.c:cancel_passive_scanning()
[16634.070084] f28h.local bluetoothd[755]:
src/adapter.c:dev_disconnected() Device 58:1F:AA:EB:B4:6A
disconnected, reason 2
[16634.070512] f28h.local bluetoothd[755]:
src/adapter.c:adapter_remove_connection()
[16634.070892] f28h.local bluetoothd[755]:
src/adapter.c:adapter_remove_connection() Removing temporary device
/org/bluez/hci0/dev_58_1F_AA_EB_B4_6A
[16634.071333] f28h.local bluetoothd[755]:
src/device.c:device_remove() Removing device
/org/bluez/hci0/dev_58_1F_AA_EB_B4_6A
[16634.071738] f28h.local bluetoothd[755]:
src/service.c:change_state() 0x55fadb8bcef0: device 58:1F:AA:EB:B4:6A
profile input-hid state changed: disconnected -> unavailable (0)
[16634.072139] f28h.local bluetoothd[755]:
profiles/input/device.c:input_device_unregister()
/org/bluez/hci0/dev_58_1F_AA_EB_B4_6A
[16634.072614] f28h.local bluetoothd[755]:
src/service.c:btd_service_unref() 0x55fadb8bcef0: ref=1
[16634.073032] f28h.local bluetoothd[755]:
src/service.c:btd_service_unref() 0x55fadb8bcef0: ref=0
[16634.073470] f28h.local bluetoothd[755]:
src/device.c:btd_device_unref() Freeing device
/org/bluez/hci0/dev_58_1F_AA_EB_B4_6A
[16634.073857] f28h.local bluetoothd[755]: src/device.c:device_free()
0x55fadb8b23e0
[16634.074298] f28h.local bluetoothd[755]:
plugins/policy.c:disconnect_cb() reason 2
[16634.074695] f28h.local bluetoothd[755]:
src/adapter.c:bonding_attempt_complete() hci0 bdaddr 58:1F:AA:EB:B4:6A
type 0 status 0xe
[16634.075098] f28h.local bluetoothd[755]: src/adapter.c:resume_discovery()
[16634.075507] f28h.local bluetoothd[755]:
src/adapter.c:trigger_start_discovery()
[16634.075864] f28h.local bluetoothd[755]:
src/adapter.c:cancel_passive_scanning()
[16634.076263] f28h.local bluetoothd[755]: connect error: Connection
timed out (110)

[16637.422684] f28h.local kernel: bluetoothd[755]: segfault at
100000007 ip 00007f276376ef38 sp 00007ffd59f09660 error 4 in
libc-2.27.so[7f27636ef000+1b5000]


Thanks,

Chris Murphy