gfvsd-trash unresponsive, appears blocked on inotify mutex
Running glib 2.64.1 and gvfs 1.44.1, I have noticed on at least two occasions that during a running GNOME session, suddenly all Gtk+ file dialogs would start to take 25 seconds to open. This seemed like a D-Bus timeout, so I observed a test application (gedit, running as :1.3800) opening a dialog box and saw that the delay corresponded to method calls to gvfsd-trash (running as :1.193) which are never replied to. gedit-dbus.log
strace confirmed gvfsd-trash is not making any progress on the main thread, and gdb shows the main thread and one worker stuck inside GInotifyFileMonitor.
(gdb) t a a bt
Thread 3 (Thread 0x7efe8ffff700 (LWP 6110)):
#0 0x00007efea255db69 in __GI___poll (fds=0x7efe8800ac30, nfds=6, timeout=-1) at ../sysdeps/unix/sysv/linux/poll.c:29
#1 0x00007efea26808d6 in g_main_context_poll (priority=<optimized out>, n_fds=6, fds=0x7efe8800ac30, timeout=<optimized out>, context=0x5600111b1f70) at ../../../glib/gmain.c:4346
#2 g_main_context_iterate (context=0x5600111b1f70, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../../../glib/gmain.c:4042
#3 0x00007efea2680c2a in g_main_loop_run (loop=0x5600111b2060) at ../../../glib/gmain.c:4241
#4 0x00007efea28c9ca6 in gdbus_shared_thread_func (user_data=0x5600111a4360) at ../../../gio/gdbusprivate.c:279
#5 0x00007efea26a9afd in g_thread_proxy (data=0x5600111a8b60) at ../../../glib/gthread.c:807
#6 0x00007efea2285fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#7 0x00007efea256882f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Thread 2 (Thread 0x7efe94c92700 (LWP 6109)):
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1 0x00007efea26cc27c in g_mutex_lock_slowpath (mutex=mutex@entry=0x7efea2989318 <g.inotify_lock_lock>) at ../../../glib/gthread-posix.c:1458
#2 0x00007efea26ccc92 in g_mutex_lock (mutex=mutex@entry=0x7efea2989318 <g.inotify_lock_lock>) at ../../../glib/gthread-posix.c:1482
#3 0x00007efea28f4000 in _ih_sub_cancel (sub=0x560011224970) at ../../../gio/inotify/inotify-helper.c:121
#4 0x00007efea28f4275 in g_inotify_file_monitor_cancel (monitor=<optimized out>) at ../../../gio/inotify/ginotifyfilemonitor.c:75
#5 0x00007efea2825408 in g_file_monitor_cancel (monitor=0x5600111b49f0) at ../../../gio/gfilemonitor.c:241
#6 g_file_monitor_cancel (monitor=0x5600111b49f0) at ../../../gio/gfilemonitor.c:235
#7 0x00007efea282547c in g_file_monitor_dispose (object=0x5600111b49f0) at ../../../gio/gfilemonitor.c:123
#8 0x00007efea28e8e30 in g_local_file_monitor_dispose (object=0x5600111b49f0) at ../../../gio/glocalfilemonitor.c:814
#9 0x00007efea276f043 in g_object_unref (_object=<optimized out>) at ../../../gobject/gobject.c:3461
#10 g_object_unref (_object=0x5600111b49f0) at ../../../gobject/gobject.c:3391
#11 0x00007efea28e8893 in g_file_monitor_source_handle_event (fms=0x5600112144e0, event_type=event_type@entry=G_FILE_MONITOR_EVENT_UNMOUNTED, child=<optimized out>, rename_to=rename_to@entry=0x0,
other=<optimized out>, other@entry=0x0, event_time=<optimized out>) at ../../../gio/glocalfilemonitor.c:455
#12 0x00007efea28f3b79 in ih_event_callback (event=0x7efe9000a410, sub=0x560011224970, file_event=<optimized out>) at ../../../gio/inotify/inotify-helper.c:206
#13 0x00007efea28f30fc in ip_event_dispatch (dir_list=dir_list@entry=0x7efe9000ace0, file_list=0x0, event=event@entry=0x7efe9000a410) at ../../../gio/inotify/inotify-path.c:492
#14 0x00007efea28f32b6 in ip_event_dispatch (event=0x7efe9000a410, file_list=<optimized out>, dir_list=0x7efe9000ace0) at ../../../gio/inotify/inotify-path.c:547
#15 ip_event_callback (event=0x7efe9000a410) at ../../../gio/inotify/inotify-path.c:547
#16 ip_event_callback (event=event@entry=0x7efe9000a410) at ../../../gio/inotify/inotify-path.c:529
#17 0x00007efea28f2609 in ik_source_dispatch (source=0x7efe900075c0, func=0x7efea28f3200 <ip_event_callback>, user_data=<optimized out>) at ../../../gio/inotify/inotify-kernel.c:327
#18 0x00007efea2680591 in g_main_dispatch (context=0x56001119cd40) at ../../../glib/gmain.c:3309
#19 g_main_context_dispatch (context=context@entry=0x56001119cd40) at ../../../glib/gmain.c:3974
#20 0x00007efea2680968 in g_main_context_iterate (context=context@entry=0x56001119cd40, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../../../glib/gmain.c:4047
#21 0x00007efea26809fc in g_main_context_iteration (context=0x56001119cd40, may_block=may_block@entry=1) at ../../../glib/gmain.c:4108
#22 0x00007efea2680a41 in glib_worker_main (data=<optimized out>) at ../../../glib/gmain.c:5996
#23 0x00007efea26a9afd in g_thread_proxy (data=0x56001118c6a0) at ../../../glib/gthread.c:807
#24 0x00007efea2285fa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#25 0x00007efea256882f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Thread 1 (Thread 0x7efea1ee5a80 (LWP 6108)):
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1 0x00007efea26cc27c in g_mutex_lock_slowpath (mutex=mutex@entry=0x7efea2989318 <g.inotify_lock_lock>) at ../../../glib/gthread-posix.c:1458
#2 0x00007efea26ccc92 in g_mutex_lock (mutex=mutex@entry=0x7efea2989318 <g.inotify_lock_lock>) at ../../../glib/gthread-posix.c:1482
#3 0x00007efea28f4000 in _ih_sub_cancel (sub=0x5600112258d0) at ../../../gio/inotify/inotify-helper.c:121
#4 0x00007efea28f4275 in g_inotify_file_monitor_cancel (monitor=<optimized out>) at ../../../gio/inotify/ginotifyfilemonitor.c:75
#5 0x00007efea2825408 in g_file_monitor_cancel (monitor=0x5600112015a0) at ../../../gio/gfilemonitor.c:241
#6 g_file_monitor_cancel (monitor=0x5600112015a0) at ../../../gio/gfilemonitor.c:235
#7 0x00007efea282547c in g_file_monitor_dispose (object=0x5600112015a0) at ../../../gio/gfilemonitor.c:123
#8 0x00007efea28e8e30 in g_local_file_monitor_dispose (object=0x5600112015a0) at ../../../gio/glocalfilemonitor.c:814
#9 0x00007efea276f043 in g_object_unref (_object=<optimized out>) at ../../../gobject/gobject.c:3461
#10 g_object_unref (_object=0x5600112015a0) at ../../../gobject/gobject.c:3391
#11 0x000056001009dd77 in ?? ()
#12 0x000056001009dd91 in ?? ()
#13 0x000056001009d982 in ?? ()
#14 0x000056001009c998 in ?? ()
#15 0x00007efea276a1e6 in _g_closure_invoke_va (closure=0x5600111d0490, return_value=0x0, instance=0x56001119b380, args=0x7fff65d0f970, n_params=0, param_types=0x0) at ../../../gobject/gclosure.c:873
#16 0x00007efea27880f0 in g_signal_emit_valist (instance=0x56001119b380, signal_id=<optimized out>, detail=0, var_args=var_args@entry=0x7fff65d0f970) at ../../../gobject/gsignal.c:3407
--Type <RET> for more, q to quit, c to continue without paging--
#17 0x00007efea27886cf in g_signal_emit (instance=<optimized out>, signal_id=signal_id@entry=51, detail=detail@entry=0) at ../../../gobject/gsignal.c:3554
#18 0x00007efea280578f in g_context_specific_source_dispatch (source=0x5600111cf6a0, callback=<optimized out>, user_data=<optimized out>) at ../../../gio/gcontextspecificgroup.c:54
#19 0x00007efea26806cd in g_main_dispatch (context=0x5600111a8e70) at ../../../glib/gmain.c:3309
#20 g_main_context_dispatch (context=context@entry=0x5600111a8e70) at ../../../glib/gmain.c:3974
#21 0x00007efea2680968 in g_main_context_iterate (context=0x5600111a8e70, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../../../glib/gmain.c:4047
#22 0x00007efea2680c2a in g_main_loop_run (loop=0x56001119cfd0) at ../../../glib/gmain.c:4241
#23 0x000056001009a678 in ?? ()
#24 0x0000560010099c03 in ?? ()
#25 0x00007efea249309b in __libc_start_main (main=0x560010099bb0, argc=4, argv=0x7fff65d0fd48, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fff65d0fd38)
at ../csu/libc-start.c:308
#26 0x0000560010099c3a in ?? ()