On Wed, 18 Mar 2020 at 08:29:06 +0000, Simon McVittie wrote:
> https://gitlab.gnome.org/GNOME/gegl/issues/226 appears to be the same thing
> on x86_64. I suspect it might be a race condition or otherwise
> intermittent: in the past this test also timed out on armel, but my recent
> upload worked fine on armel. Perhaps there is something about the ARM
> family of architectures that makes this more likely to happen there.
I reproduced this on the arm64 porterbox 'amdahl' by running that test
1000 times in a loop. After a while, output stopped.
>From the backtrace below it appears that there is a deadlock between
threads 1 and 6, which are both waiting for the same mutex. This might
be a GLib bug.
smcv
Thread 6 (Thread 0xffff95366ce0 (LWP 1856)):
#0 syscall () at ../sysdeps/unix/sysv/linux/aarch64/syscall.S:38
#1 0x0000ffff97f6f588 in g_mutex_lock_slowpath (mutex=0xffff97cee280
<g.inotify_lock_lock>) at ../../../glib/gthread-posix.c:1457
#2 0x0000ffff97f700b8 in g_mutex_lock (mutex=<optimized out>) at
../../../glib/gthread-posix.c:1482
#3 0x0000ffff97c4c00c in _ih_sub_cancel (sub=0xaaaac48fad60) at
../../../gio/inotify/inotify-helper.c:121
#4 0x0000ffff97c4c2a8 in g_inotify_file_monitor_cancel (monitor=<optimized
out>) at ../../../gio/inotify/ginotifyfilemonitor.c:75
#5 0x0000ffff97b6b474 in g_file_monitor_cancel (monitor=0xaaaac48fd410
[GInotifyFileMonitor]) at ../../../gio/gfilemonitor.c:241
#6 g_file_monitor_cancel (monitor=0xaaaac48fd410 [GInotifyFileMonitor]) at
../../../gio/gfilemonitor.c:235
#7 0x0000ffff97b6b51c in g_file_monitor_dispose (object=0xaaaac48fd410
[GInotifyFileMonitor]) at ../../../gio/gfilemonitor.c:123
#8 0x0000ffff97c409d4 in g_local_file_monitor_dispose (object=0xaaaac48fd410
[GInotifyFileMonitor]) at ../../../gio/glocalfilemonitor.c:814
#9 0x0000ffff97e784f8 in g_object_unref (_object=<optimized out>) at
../../../gobject/gobject.c:3461
#10 g_object_unref (_object=0xaaaac48fd410) at ../../../gobject/gobject.c:3391
#11 0x0000ffff97c40358 in g_file_monitor_source_handle_event
(fms=0xaaaac48faa50,
event_type=event_type@entry=G_FILE_MONITOR_EVENT_CHANGES_DONE_HINT,
child=0xffff84001470 "buf_a.gegl", rename_to=rename_to@entry=0x0,
other=other@entry=0x0, event_time=<optimized out>) at
../../../gio/glocalfilemonitor.c:455
#12 0x0000ffff97c4bbe4 in ih_event_callback (event=0xffff84001430,
sub=0xaaaac48fad60, file_event=<optimized out>) at
../../../gio/inotify/inotify-helper.c:206
#13 0x0000ffff97c4b13c in ip_event_dispatch
(dir_list=dir_list@entry=0xaaaac48f7d80 = {...}, file_list=0x0,
event=event@entry=0xffff84001430) at ../../../gio/inotify/inotify-path.c:492
#14 0x0000ffff97c4b2f4 in ip_event_dispatch (event=0xffff84001430,
file_list=<optimized out>, dir_list=0xaaaac48f7d80 = {...}) at
../../../gio/inotify/inotify-path.c:547
#15 ip_event_callback (event=0xffff84001430) at
../../../gio/inotify/inotify-path.c:547
#16 ip_event_callback (event=0xffff84001430) at
../../../gio/inotify/inotify-path.c:529
#17 0x0000ffff97c4a4f8 in ik_source_dispatch (source=0xaaaac48fa5f0,
func=0xffff97c4b210 <ip_event_callback>, user_data=<optimized out>) at
../../../gio/inotify/inotify-kernel.c:327
#18 0x0000ffff97f2235c in g_main_dispatch (context=0xaaaac48fa6b0) at
../../../glib/gmain.c:3309
#19 g_main_context_dispatch (context=context@entry=0xaaaac48fa6b0) at
../../../glib/gmain.c:3974
#20 0x0000ffff97f22708 in g_main_context_iterate
(context=context@entry=0xaaaac48fa6b0, block=block@entry=1,
dispatch=dispatch@entry=1, self=<optimized out>) at ../../../glib/gmain.c:4047
#21 0x0000ffff97f227ac in g_main_context_iteration (context=0xaaaac48fa6b0,
may_block=may_block@entry=1) at ../../../glib/gmain.c:4108
#22 0x0000ffff97f227fc in glib_worker_main (data=<optimized out>) at
../../../glib/gmain.c:5996
#23 0x0000ffff97f4bcec in g_thread_proxy (data=0xaaaac48fbd20) at
../../../glib/gthread.c:807
#24 0x0000ffff97a0b998 in start_thread (arg=0xfffffc63b24f) at
pthread_create.c:479
#25 0x0000ffff97dc16ac in thread_start () at
../sysdeps/unix/sysv/linux/aarch64/clone.S:78
Thread 5 (Thread 0xffff95b67ce0 (LWP 1855)):
#0 syscall () at ../sysdeps/unix/sysv/linux/aarch64/syscall.S:38
#1 0x0000ffff97f701dc in g_cond_wait (cond=cond@entry=0xffff981bf9d0
<queue_cond>, mutex=mutex@entry=0xffff981bf998 <mutex>) at
../../../glib/gthread-posix.c:1540
#2 0x0000ffff98149d70 in gegl_tile_backend_file_writer_thread
(ignored=<optimized out>) at ../gegl/buffer/gegl-tile-backend-file-async.c:257
#3 0x0000ffff97f4bcec in g_thread_proxy (data=0xaaaac4865120) at
../../../glib/gthread.c:807
#4 0x0000ffff97a0b998 in start_thread (arg=0xfffffc63b5ff) at
pthread_create.c:479
#5 0x0000ffff97dc16ac in thread_start () at
../sysdeps/unix/sysv/linux/aarch64/clone.S:78
Thread 4 (Thread 0xffff96368ce0 (LWP 1854)):
#0 syscall () at ../sysdeps/unix/sysv/linux/aarch64/syscall.S:38
#1 0x0000ffff97f701dc in g_cond_wait (cond=cond@entry=0xffff981bd228
<gegl_parallel_distribute_threads+128>, mutex=mutex@entry=0xffff981bd220
<gegl_parallel_distribute_threads+120>) at ../../../glib/gthread-posix.c:1540
#2 0x0000ffff9811d4e0 in gegl_parallel_distribute_thread_func
(thread=0xffff981bd218 <gegl_parallel_distribute_threads+112>) at
../gegl/gegl-parallel.c:508
#3 0x0000ffff97f4bcec in g_thread_proxy (data=0xaaaac4864b60) at
../../../glib/gthread.c:807
#4 0x0000ffff97a0b998 in start_thread (arg=0xfffffc63bccf) at
pthread_create.c:479
#5 0x0000ffff97dc16ac in thread_start () at
../sysdeps/unix/sysv/linux/aarch64/clone.S:78
Thread 3 (Thread 0xffff96b69ce0 (LWP 1853)):
#0 syscall () at ../sysdeps/unix/sysv/linux/aarch64/syscall.S:38
#1 0x0000ffff97f701dc in g_cond_wait (cond=cond@entry=0xffff981bd1f0
<gegl_parallel_distribute_threads+72>, mutex=mutex@entry=0xffff981bd1e8
<gegl_parallel_distribute_threads+64>) at ../../../glib/gthread-posix.c:1540
#2 0x0000ffff9811d4e0 in gegl_parallel_distribute_thread_func
(thread=0xffff981bd1e0 <gegl_parallel_distribute_threads+56>) at
../gegl/gegl-parallel.c:508
#3 0x0000ffff97f4bcec in g_thread_proxy (data=0xaaaac4864b00) at
../../../glib/gthread.c:807
#4 0x0000ffff97a0b998 in start_thread (arg=0xfffffc63bccf) at
pthread_create.c:479
#5 0x0000ffff97dc16ac in thread_start () at
../sysdeps/unix/sysv/linux/aarch64/clone.S:78
Thread 2 (Thread 0xffff9736ace0 (LWP 1852)):
#0 syscall () at ../sysdeps/unix/sysv/linux/aarch64/syscall.S:38
#1 0x0000ffff97f701dc in g_cond_wait (cond=cond@entry=0xffff981bd1b8
<gegl_parallel_distribute_threads+16>, mutex=mutex@entry=0xffff981bd1b0
<gegl_parallel_distribute_threads+8>) at ../../../glib/gthread-posix.c:1540
#2 0x0000ffff9811d4e0 in gegl_parallel_distribute_thread_func
(thread=0xffff981bd1a8 <gegl_parallel_distribute_threads>) at
../gegl/gegl-parallel.c:508
#3 0x0000ffff97f4bcec in g_thread_proxy (data=0xaaaac4864aa0) at
../../../glib/gthread.c:807
#4 0x0000ffff97a0b998 in start_thread (arg=0xfffffc63bccf) at
pthread_create.c:479
#5 0x0000ffff97dc16ac in thread_start () at
../sysdeps/unix/sysv/linux/aarch64/clone.S:78
Thread 1 (Thread 0xffff976efbe0 (LWP 1851)):
#0 syscall () at ../sysdeps/unix/sysv/linux/aarch64/syscall.S:38
#1 0x0000ffff97f6f588 in g_mutex_lock_slowpath
(mutex=mutex@entry=0xffff97cee280 <g.inotify_lock_lock>) at
../../../glib/gthread-posix.c:1457
#2 0x0000ffff97f700b8 in g_mutex_lock (mutex=mutex@entry=0xffff97cee280
<g.inotify_lock_lock>) at ../../../glib/gthread-posix.c:1482
#3 0x0000ffff97c4bf14 in _ih_startup () at
../../../gio/inotify/inotify-helper.c:74
#4 0x0000ffff97c4c308 in g_inotify_file_monitor_start
(local_monitor=<optimized out>, dirname=0xaaaac48f62c0
"/tmp/test-backend-file-PI3NH0", basename=0xaaaac48fe550 "buf_a.gegl",
filename=0x0, source=0xaaaac48fe700) at
../../../gio/inotify/ginotifyfilemonitor.c:61
#5 0x0000ffff97c40e5c in g_local_file_monitor_new_for_path
(pathname=0xaaaac48b3bb0 "/tmp/test-backend-file-PI3NH0/buf_a.gegl",
is_directory=0, flags=G_FILE_MONITOR_NONE, error=<optimized out>) at
../../../gio/glocalfilemonitor.c:886
#6 0x0000ffff97b5e6dc in g_file_monitor_file (file=0xaaaac48f80c0,
flags=flags@entry=G_FILE_MONITOR_NONE, cancellable=cancellable@entry=0x0,
error=error@entry=0x0) at ../../../gio/gfile.c:5447
#7 0x0000ffff9814abec in gegl_tile_backend_file_constructed
(object=0xaaaac48f00a0 [GeglTileBackendFile]) at
../gegl/buffer/gegl-tile-backend-file-async.c:1170
#8 0x0000ffff97e78d88 in g_object_new_internal (class=0xaaaac48ee750,
class@entry=0xaaaac48b5140, params=params@entry=0xfffffc63b928,
n_params=n_params@entry=4) at ../../../gobject/gobject.c:1977
#9 0x0000ffff97e7ab8c in g_object_new_valist (object_type=0xaaaac48ee5a0
[GeglTileBackendFile/GeglTileBackend/GeglTileSource],
first_property_name=first_property_name@entry=0xffff98177638 "tile-width",
var_args=...) at ../../../gobject/gobject.c:2262
#10 0x0000ffff97e7ae14 in g_object_new (object_type=<optimized out>,
first_property_name=first_property_name@entry=0xffff98177638 "tile-width") at
../../../gobject/gobject.c:1780
#11 0x0000ffff9813c9e0 in gegl_buffer_constructor (type=<optimized out>,
n_params=<optimized out>, params=<optimized out>) at
../gegl/buffer/gegl-buffer.c:549
#12 0x0000ffff97e78b40 in g_object_new_with_custom_constructor (n_params=2,
params=0xfffffc63be18, class=0xaaaac48b4400) at ../../../gobject/gobject.c:1855
#13 g_object_new_internal (class=0xaaaac48b4400, class@entry=0xaaaac48724d0,
params=params@entry=0xfffffc63be18, n_params=n_params@entry=2) at
../../../gobject/gobject.c:1935
#14 0x0000ffff97e7ab8c in g_object_new_valist (object_type=0xaaaac48b4160
[GeglBuffer/GeglTileHandler/GeglTileSource], first_property_name=<optimized
out>, var_args=...) at ../../../gobject/gobject.c:2262
#15 0x0000ffff97e7ae14 in g_object_new (object_type=<optimized out>,
first_property_name=<optimized out>) at ../../../gobject/gobject.c:1780
#16 0x0000aaaac3179808 in test_buffer_open () at
../tests/simple/test-backend-file.c:306
#17 main (argc=<optimized out>, argv=<optimized out>) at
../tests/simple/test-backend-file.c:443
