After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 570193 - Mounting phone connected via Bluetooth fails
Mounting phone connected via Bluetooth fails
Status: RESOLVED FIXED
Product: gvfs
Classification: Core
Component: [obsolete] obexftp backend
git master
Other Linux
: Normal normal
: ---
Assigned To: gvfs-maint
gvfs-maint
Depends on:
Blocks:
 
 
Reported: 2009-02-02 10:36 UTC by Tomas Bzatek
Modified: 2009-02-03 13:44 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
Valgrind log when it crashes (53.10 KB, text/plain)
2009-02-02 12:51 UTC, Tomas Bzatek
  Details
gvfs-obexftp-dbus-crasher.patch (1.09 KB, patch)
2009-02-02 17:41 UTC, Bastien Nocera
none Details | Review
gdb trace with the patch (4.42 KB, text/plain)
2009-02-03 10:02 UTC, Tomas Bzatek
  Details
gvfs-obexftp-dbus-crasher-2.patch (1.72 KB, patch)
2009-02-03 10:31 UTC, Bastien Nocera
none Details | Review
gvfs-obexftp-dbus-crasher-3.patch (1.93 KB, patch)
2009-02-03 11:35 UTC, Bastien Nocera
none Details | Review
gvfs-obexftp-dbus-crasher-4.patch (2.97 KB, patch)
2009-02-03 12:03 UTC, Bastien Nocera
committed Details | Review
gdb backtrace with latest trunk + updated patch (2.91 KB, text/plain)
2009-02-03 13:12 UTC, Tomas Bzatek
  Details

Description Tomas Bzatek 2009-02-02 10:36:39 UTC
Mounting obex locations sometimes fail (hit rate about 50%). 

Fedora rawhide, BT USB stick, connecting to the Sony Ericsson K750i phone.
gvfs-1.1.4-2.fc11.i386 - package contains obexfs write support patch from #519071
dbus-1.2.4.4permissive-1.fc11.i386


(gdb) r host=[00:16:20:D1:B7:65]
Starting program: /usr/libexec/gvfsd-obexftp host=[00:16:20:D1:B7:65]
[Thread debugging using libthread_db enabled]
setting 'host' to '[00:16:20:D1:B7:65]'
Added new job source 0x8077848 (GVfsBackendObexftp)
Queued new job 0x8079c18 (GVfsJobMount)
[New Thread 0xb7de4b70 (LWP 5387)]
+ do_mount
  do_mount: 00:16:20:D1:B7:65 mounted
process 5386: arguments to dbus_pending_call_block() were incorrect, assertion "pending != NULL" failed in file dbus-pending-call.c line 705.
This is normally a bug in some application using the D-Bus library.
  D-Bus not built with -rdynamic so unable to print a backtrace

Program received signal SIGABRT, Aborted.
0x00130416 in __kernel_vsyscall ()
(gdb) thread apply all bt


Comment 1 Tomas Bzatek 2009-02-02 10:39:32 UTC
Another occurrence:

(gdb) r host=[00:16:20:D1:B7:65]
Starting program: /usr/libexec/gvfsd-obexftp host=[00:16:20:D1:B7:65]
[Thread debugging using libthread_db enabled]
setting 'host' to '[00:16:20:D1:B7:65]'
Added new job source 0x8077848 (GVfsBackendObexftp)
Queued new job 0x8079c18 (GVfsJobMount)
[New Thread 0xb7de4b70 (LWP 5609)]
+ do_mount
  do_mount: 00:16:20:D1:B7:65 mounted

** ERROR **: Out of memory
aborting...

Program received signal SIGTRAP, Trace/breakpoint trap.
[Switching to Thread 0xb7de4b70 (LWP 5609)]
IA__g_logv (log_domain=0x0, log_level=G_LOG_LEVEL_ERROR, format=0x14a968 "Out of memory", args1=0xb7de40fc "������\a\blA޷") at gmessages.c:503
503		  g_private_set (g_log_depth, GUINT_TO_POINTER (depth));
(gdb) thread apply all bt

Thread 2 (Thread 0xb7de4b70 (LWP 5609))

  • #0 IA__g_logv
    at gmessages.c line 503
  • #1 IA__g_log
    at gmessages.c line 517
  • #2 dbus_g_proxy_begin_call_internal
    at dbus-gproxy.c line 2232
  • #3 dbus_g_proxy_call
    at dbus-gproxy.c line 2586
  • #4 _get_device_properties
    at gvfsbackendobexftp.c line 188
  • #5 do_mount
    at gvfsbackendobexftp.c line 607
  • #6 run
    at gvfsjobmount.c line 113
  • #7 g_vfs_job_run
    at gvfsjob.c line 198
  • #8 job_handler_callback
    at gvfsdaemon.c line 142
  • #9 g_thread_pool_thread_proxy
    at gthreadpool.c line 265
  • #10 g_thread_create_proxy
    at gthread.c line 635
  • #11 start_thread
    at pthread_create.c line 297
  • #12 clone
    at ../sysdeps/unix/sysv/linux/i386/clone.S line 130

Comment 2 Tomas Bzatek 2009-02-02 12:50:03 UTC
Caught this log from Valgrind, no crash in this case though. Normal pass is clean, this happens in 5% of cases.

+ do_mount
  do_mount: 00:16:20:D1:B7:65 mounted
==21062== Thread 2:
==21062== Invalid read of size 1
==21062==    at 0x4173E29: _dbus_pending_call_set_timeout_added_unlocked (dbus-pending-call.c:250)
==21062==    by 0x416724F: _dbus_connection_queue_received_message_link (dbus-connection.c:472)
==21062==    by 0x417A9D1: _dbus_transport_queue_messages (dbus-transport.c:1129)
==21062==    by 0x417B9AC: do_reading (dbus-transport-socket.c:788)
==21062==    by 0x417BF4C: socket_do_iteration (dbus-transport-socket.c:1083)
==21062==    by 0x4179F8E: _dbus_transport_do_iteration (dbus-transport.c:956)
==21062==    by 0x41649BD: _dbus_connection_do_iteration_unlocked (dbus-connection.c:1150)
==21062==    by 0x4166F51: _dbus_connection_block_pending_call (dbus-connection.c:2309)
==21062==    by 0x4174300: dbus_pending_call_block (dbus-pending-call.c:707)
==21062==    by 0x404DB2E: dbus_g_proxy_end_call_internal (dbus-gproxy.c:2264)
==21062==    by 0x404E56D: dbus_g_proxy_call (dbus-gproxy.c:2593)
==21062==    by 0x80501AD: do_mount (gvfsbackendobexftp.c:174)
==21062==  Address 0x449dccc is 36 bytes inside a block of size 40 free'd
==21062==    at 0x402790A: free (vg_replace_malloc.c:323)
==21062==    by 0x41801B0: dbus_free (dbus-memory.c:644)
==21062==    by 0x417443A: _dbus_pending_call_last_unref (dbus-pending-call.c:413)
==21062==    by 0x416417D: complete_pending_call_and_unlock (dbus-connection.c:2213)
==21062==    by 0x4164E6B: dbus_connection_dispatch (dbus-connection.c:4352)
==21062==    by 0x404815C: message_queue_dispatch (dbus-gmain.c:101)
==21062==    by 0x41E27F7: g_main_context_dispatch (gmain.c:1814)
==21062==    by 0x41E5EA2: g_main_context_iterate (gmain.c:2448)
==21062==    by 0x41E63C1: g_main_loop_run (gmain.c:2656)
==21062==    by 0x80529C2: daemon_main (daemon-main.c:270)
==21062==    by 0x8052C94: main (daemon-main-generic.c:39)
==21062== 
==21062== Invalid write of size 1
==21062==    at 0x4173E37: _dbus_pending_call_set_timeout_added_unlocked (dbus-pending-call.c:250)
==21062==    by 0x416724F: _dbus_connection_queue_received_message_link (dbus-connection.c:472)
==21062==    by 0x417A9D1: _dbus_transport_queue_messages (dbus-transport.c:1129)
==21062==    by 0x417B9AC: do_reading (dbus-transport-socket.c:788)
==21062==    by 0x417BF4C: socket_do_iteration (dbus-transport-socket.c:1083)
==21062==    by 0x4179F8E: _dbus_transport_do_iteration (dbus-transport.c:956)
==21062==    by 0x41649BD: _dbus_connection_do_iteration_unlocked (dbus-connection.c:1150)
==21062==    by 0x4166F51: _dbus_connection_block_pending_call (dbus-connection.c:2309)
==21062==    by 0x4174300: dbus_pending_call_block (dbus-pending-call.c:707)
==21062==    by 0x404DB2E: dbus_g_proxy_end_call_internal (dbus-gproxy.c:2264)
==21062==    by 0x404E56D: dbus_g_proxy_call (dbus-gproxy.c:2593)
==21062==    by 0x80501AD: do_mount (gvfsbackendobexftp.c:174)
==21062==  Address 0x449dccc is 36 bytes inside a block of size 40 free'd
==21062==    at 0x402790A: free (vg_replace_malloc.c:323)
==21062==    by 0x41801B0: dbus_free (dbus-memory.c:644)
==21062==    by 0x417443A: _dbus_pending_call_last_unref (dbus-pending-call.c:413)
==21062==    by 0x416417D: complete_pending_call_and_unlock (dbus-connection.c:2213)
==21062==    by 0x4164E6B: dbus_connection_dispatch (dbus-connection.c:4352)
==21062==    by 0x404815C: message_queue_dispatch (dbus-gmain.c:101)
==21062==    by 0x41E27F7: g_main_context_dispatch (gmain.c:1814)
==21062==    by 0x41E5EA2: g_main_context_iterate (gmain.c:2448)
==21062==    by 0x41E63C1: g_main_loop_run (gmain.c:2656)
==21062==    by 0x80529C2: daemon_main (daemon-main.c:270)
==21062==    by 0x8052C94: main (daemon-main-generic.c:39)
Comment 3 Tomas Bzatek 2009-02-02 12:51:49 UTC
Created attachment 127756 [details]
Valgrind log when it crashes
Comment 4 Bastien Nocera 2009-02-02 17:41:33 UTC
Created attachment 127772 [details] [review]
gvfs-obexftp-dbus-crasher.patch

This should avoid the problems, let me know how it goes.
Comment 5 Tomas Bzatek 2009-02-03 10:02:49 UTC
Created attachment 127823 [details]
gdb trace with the patch

(In reply to comment #4)
> Created an attachment (id=127772) [edit]
> gvfs-obexftp-dbus-crasher.patch
> 
> This should avoid the problems, let me know how it goes.
> 

Something is broken with your patch, looks like the dbus connection is not set up properly -- see the attachment. This happens all the time.
Comment 6 Tomas Bzatek 2009-02-03 10:04:15 UTC
Removing all dbus_g_connection_unref(connection) gives me old error again:

Thread 2 (Thread 0xb7de4b70 (LWP 18711))

  • #0 IA__g_logv
    at gmessages.c line 503
  • #1 IA__g_log
    at gmessages.c line 517
  • #2 dbus_g_proxy_begin_call_internal
    at dbus-gproxy.c line 2232
  • #3 dbus_g_proxy_call
    at dbus-gproxy.c line 2586
  • #4 do_mount
    at gvfsbackendobexftp.c line 879
  • #5 run
    at gvfsjobmount.c line 113
  • #6 g_vfs_job_run
    at gvfsjob.c line 198
  • #7 job_handler_callback
    at gvfsdaemon.c line 142
  • #8 g_thread_pool_thread_proxy
    at gthreadpool.c line 265
  • #9 g_thread_create_proxy
    at gthread.c line 635
  • #10 start_thread
    at pthread_create.c line 297
  • #11 clone
    at ../sysdeps/unix/sysv/linux/i386/clone.S line 130

Thread 1 (LWP 18709)

  • #0 IA__g_hash_table_lookup
    at ghash.c line 787
  • #1 daemon_message_func
    at gvfsdaemon.c line 978
  • #2 dbus_connection_dispatch
    at dbus-connection.c line 4406
  • #3 message_queue_dispatch
    at dbus-gmain.c line 101
  • #4 g_main_dispatch
    at gmain.c line 1814
  • #5 IA__g_main_context_dispatch
    at gmain.c line 2367
  • #6 g_main_context_iterate
    at gmain.c line 2448
  • #7 IA__g_main_loop_run
    at gmain.c line 2656
  • #8 daemon_main
    at daemon-main.c line 270
  • #9 main
    at daemon-main-generic.c line 39

Comment 7 Bastien Nocera 2009-02-03 10:31:59 UTC
Created attachment 127824 [details] [review]
gvfs-obexftp-dbus-crasher-2.patch

This should fix the FindDevice problems (could you please check that valgrind is now clean?).

For the OOM problems on creating the obex session, could you please launch obex-data-server on its own using "obex-data-server -n" after having killed it? This should show whether the OOM is caused by obex-data-server or not.
Comment 8 Tomas Bzatek 2009-02-03 10:43:28 UTC
Still occasional OOM errors.

Normally the log from obex-data-server looks like:
** Message: obex-data-server 0.4.1
** Message: Using Session bus
** Message: Parsed[0]: ftp, Parsed[1]: (null)
** Message: Connected SDP session
** Message: SDP search process
** Message: SDP search completed
** Message: getting RFCOMM channel
** Message: Connect in progress
** Message: Failed to connect
** Message: session closed
** Message: Removing listened DBUS name :1.153 (object: /org/openobex/session0)
** Message: Removed from listened DBUS names list

while when gvfsd-obexftp crashes, I only get the following:

** Message: Parsed[0]: ftp, Parsed[1]: (null)
** (obex-data-server:19837): WARNING **: DBUS NAME REMOVED: :1.160
** (obex-data-server:19837): WARNING **: Finalizing session
** Message: attempting to close session
** Message: session closed
** Message: Removing listened DBUS name :1.160 (object: /org/openobex/session7)
** Message: Removed from listened DBUS names list

Note that obex-data-server keeps running and another mount attempt is working fine.
Comment 9 Bastien Nocera 2009-02-03 11:35:08 UTC
Created attachment 127825 [details] [review]
gvfs-obexftp-dbus-crasher-3.patch

Fix the potential crasher on FindDevice again. We shouldn't set it up with the main loop, otherwise we might get other threads taking over the messages (again).
Comment 10 Bastien Nocera 2009-02-03 12:03:46 UTC
Created attachment 127826 [details] [review]
gvfs-obexftp-dbus-crasher-4.patch

And with help from Alex...
Comment 11 Bastien Nocera 2009-02-03 12:12:51 UTC
I can see that it fails to connect on the OOM case:
** Message: Failed to connect

But I'm not sure how to reproduce it here. Could you please test with the latest trunk and the patch from comment 10 applied?
Comment 12 Tomas Bzatek 2009-02-03 13:12:10 UTC
Created attachment 127832 [details]
gdb backtrace with latest trunk + updated patch

Still no luck. This is latest trunk plus the latest patch (-4).
Comment 13 Bastien Nocera 2009-02-03 13:44:01 UTC
The double-free is now fixed. Could you please open a new bug for the OOM when calling CreateBluetoothSession?

2009-02-03  Bastien Nocera  <hadess@hadess.net>

        Bug 570193 – Mounting phone connected via Bluetooth fails

        * daemon/gvfsbackendobexftp.c (_get_bluetooth_device_properties):
        Use a private connection to connect to the system D-Bus, thanks
        to Alexander Larsson