Re: gvfsd-dav SIGABRT when using WebDAV

[Adam Tauno Williams <awilliam whitemice org>]

On Tue, 2013-01-08 at 09:27 -0500, Adam Tauno Williams wrote:
> On Tue, 2013-01-08 at 09:09 -0500, Adam Tauno Williams wrote:
> > On Tue, 2013-01-08 at 13:55 +0100, Tomas Bzatek wrote:
> > > On Fri, 2013-01-04 at 09:46 -0500, Adam Tauno Williams wrote:
> > > > DOH!  Ok, got that.   Right click -> New file from template ... CRASH!
> > > Tried to reproduce on two different systems, no luck. A gvfs daemon log
> > > would be useful for this. Try killing all gvfs processes and start
> > > `GVFS_DEBUG=1 GVFS_HTTP_DEBUG=all /usr/libexec/gvfsd -r` in the
> > > terminal, grabbing the output. That would tell us which operations were
> > > in progress.
> > AWESOME, thanks for this.  I've been really looking for a way to get a
> > logfile.
> > Except I've had problems where the DE kind of falls apart if I kill the
> > base gvfsd.  But I'll try.
> Seems to be working.  Here I drag-n-drop a file to the WebDAV folder.
> It works.  I drag-n-drop another and it fails with 'The specified
> location is not mounted' message. But the document is created/saved; a
> refresh shows it is there.

Did a zypper dup to GVFS 0.14 from the openSUSE 12.2 GS36 repositories,
rebooted, put GVFS into logging/debugging and did a drag-n-drop from
local to a remote WebDAV share.  It got to ~65K transferred and then
failed with a not-mounted error.

gvfs-backends-1.14.2-1.2.x86_64
gvfs-1.14.2-1.2.x86_64

Backtrace
---------
(gdb) t a a bt

Thread 4 (Thread 0x7f86d2136700 (LWP 6795)):
#0  0x00007f86d61e500c in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x00007f86d61e0f02 in _L_lock_1125 () from /lib64/libpthread.so.0
#2  0x00007f86d61e0e80 in pthread_mutex_lock ()
from /lib64/libpthread.so.0
#3  0x00007f86d647aaa1 in g_mutex_lock (mutex=mutex@entry=0x776850) at
gthread-posix.c:210
#4  0x00007f86d643bd08 in g_source_attach (source=0x7f86c8112d50,
context=0x776850) at gmain.c:1083
#5  0x00007f86d7678b86 in soup_add_timeout ()
from /usr/lib64/libsoup-2.4.so.1
#6  0x00007f86d7680bcb in ?? () from /usr/lib64/libsoup-2.4.so.1
#7  0x00007f86d66fccd7 in ?? () from /usr/lib64/libgobject-2.0.so.0
#8  0x00007f86d67156d6 in g_signal_emit_valist ()
from /usr/lib64/libgobject-2.0.so.0
#9  0x00007f86d6715f22 in g_signal_emit ()
from /usr/lib64/libgobject-2.0.so.0
#10 0x00007f86d7663978 in soup_connection_set_state ()
from /usr/lib64/libsoup-2.4.so.1
#11 0x00007f86d7681bfe in soup_session_unqueue_item ()
from /usr/lib64/libsoup-2.4.so.1
#12 0x00007f86d76862be in ?? () from /usr/lib64/libsoup-2.4.so.1
#13 0x00007f86d76866b9 in ?? () from /usr/lib64/libsoup-2.4.so.1
#14 0x00007f86d6461355 in g_thread_proxy (data=0x77c4a0) at
gthread.c:797
#15 0x00007f86d61dee0e in start_thread () from /lib64/libpthread.so.0
#16 0x00007f86d5f162cd in clone () from /lib64/libc.so.6

Thread 3 (Thread 0x7f86d2937700 (LWP 5394)):
#0  0x00007f86d5f0e14f in poll () from /lib64/libc.so.6
#1  0x00007f86d643dac4 in g_main_context_poll (n_fds=1,
fds=0x7f86c40010c0, timeout=-1, context=0x7a3310, 
    priority=<optimized out>) at gmain.c:3584
#2  g_main_context_iterate (context=context@entry=0x7a3310,
block=block@entry=1, dispatch=dispatch@entry=1, 
    self=<error reading variable: Unhandled dwarf expression opcode
0xfa>) at gmain.c:3285
#3  0x00007f86d643dbe4 in g_main_context_iteration
(context=context@entry=0x7a3310, may_block=may_block@entry=1) at
gmain.c:3351
#4  0x00007f86d308f90d in dconf_gdbus_worker_thread (user_data=0x7a3310)
at dconf-gdbus-thread.c:81
#5  0x00007f86d6461355 in g_thread_proxy (data=0x78e630) at
gthread.c:797
#6  0x00007f86d61dee0e in start_thread () from /lib64/libpthread.so.0
#7  0x00007f86d5f162cd in clone () from /lib64/libc.so.6

Thread 2 (Thread 0x7f86d3c99700 (LWP 5393)):
#0  0x00007f86d5f0e14f in poll () from /lib64/libc.so.6
#1  0x00007f86d643dac4 in g_main_context_poll (n_fds=23,
fds=0x7f86cc002e10, timeout=-1, context=0x77fd50, 
    priority=<optimized out>) at gmain.c:3584
#2  g_main_context_iterate (context=0x77fd50, block=block@entry=1,
dispatch=dispatch@entry=1, 
    self=<error reading variable: Unhandled dwarf expression opcode
0xfa>) at gmain.c:3285
#3  0x00007f86d643df22 in g_main_loop_run (loop=0x77fce0) at
gmain.c:3484
#4  0x00007f86d6a0bbf6 in gdbus_shared_thread_func (user_data=0x77fd20)
at gdbusprivate.c:277
---Type <return> to continue, or q <return> to quit---
#5  0x00007f86d6461355 in g_thread_proxy (data=0x77c280) at
gthread.c:797
#6  0x00007f86d61dee0e in start_thread () from /lib64/libpthread.so.0
#7  0x00007f86d5f162cd in clone () from /lib64/libc.so.6

Thread 1 (Thread 0x7f86d814d7c0 (LWP 5392)):
#0  0x00007f86d5e66d25 in raise () from /lib64/libc.so.6
#1  0x00007f86d5e681a8 in abort () from /lib64/libc.so.6
#2  0x00007f86d645f887 in g_assertion_message
(domain=domain@entry=0x7f86d647de2e "GLib", file=file@entry=
    0x7f86d64849fa "gmain.c", line=line@entry=2781, func=func@entry=
    0x7f86d6485530 <__PRETTY_FUNCTION__.12117> "g_main_context_acquire",
message=<optimized out>) at gtestutils.c:1877
#3  0x00007f86d645fda4 in g_assertion_message_expr
(domain=domain@entry=0x7f86d647de2e "GLib", file=file@entry=
    0x7f86d64849fa "gmain.c", line=line@entry=2781, func=func@entry=
    0x7f86d6485530 <__PRETTY_FUNCTION__.12117> "g_main_context_acquire",
expr=expr@entry=
    0x7f86d6484abc "context->owner_count == 0") at gtestutils.c:1888
#4  0x00007f86d643cdf3 in g_main_context_acquire (context=<optimized
out>) at gmain.c:2781
#5  g_main_context_acquire (context=0x776850) at gmain.c:2768
#6  0x00007f86d643d9a4 in g_main_context_iterate (context=0x776850,
block=block@entry=1, dispatch=dispatch@entry=1, 
    self=<error reading variable: Unhandled dwarf expression opcode
0xfa>) at gmain.c:3240
#7  0x00007f86d643df22 in g_main_loop_run (loop=0x7819b0) at
gmain.c:3484
#8  0x0000000000413d17 in daemon_main (argc=argc@entry=4,
argv=argv@entry=0x7fff136112f8, max_job_threads=max_job_threads@entry=
    1, default_type=default_type@entry=0x427219 "dav",
mountable_name=mountable_name@entry=0x0, 
    first_type_name=first_type_name@entry=0x427219 "dav") at
daemon-main.c:396
#9  0x000000000040c160 in main (argc=4, argv=0x7fff136112f8) at
daemon-main-generic.c:39

Log Snip
---------
Added new job source 0x81d0c0 (GVfsBackendBurn)
Queued new job 0x8179b0 (GVfsJobMount)
send_reply, failed: 0
backend_dbus_handler org.gtk.vfs.Mount:Enumerate
Queued new job 0x81d220 (GVfsJobEnumerate)
send_reply(0x81d220), failed=0 ()

(process:5392): GLib-CRITICAL **: g_main_context_push_thread_default:
assertion `acquired_context' failed
> PUT /dav/Projects/ME%20Marketing/Documents/CRM%
20Exports/MIEFullCRMExport20130109-955240.ods HTTP/1.1
> Soup-Debug-Timestamp: 1357744310
> Soup-Debug: SoupSessionSync 1 (0x791800), SoupMessage 123 (0x7b6910),
SoupSocket 128 (0x7f86c8130c30)
> Host: coils.mormail.com
> Accept-Encoding: gzip, deflate
> User-Agent: gvfs/1.14.2
> Accept-Language: en-us, en;q=0.9
> Connection: Keep-Alive
> Authorization: Basic [adam:******]
> 
> PK
  
< HTTP/1.1 201 Created
< Soup-Debug-Timestamp: 1357744388
< Soup-Debug: SoupMessage 123 (0x7b6910)
< Date: Wed, 09 Jan 2013 15:11:50 GMT
< Server: BaseHTTP/0.3 Python/2.6.5
< Content-Length: 0
< Content-Type: application/vnd.oasis.opendocument.spreadsheet
< Connection: close
< 
  
job_close_write send reply
**
GLib:ERROR:gmain.c:2781:g_main_context_acquire: assertion failed:
(context->owner_count == 0)


-- 
Adam Tauno Williams  GPG D95ED383
Systems Administrator, Python Developer, LPI / NCLA