Control: tags -1 + confirmed
On Mon, 18 Dec 2017 at 09:17:46 +0000, Simon McVittie wrote:
> The failure on the buildd is new, although I think I might have seen it
> before in local testing (but never reproducibly). It's probably some
> rarely-hit race condition?
I can reproduce this by running the gdbus-peer test in a loop (this is
with GLib git master, not Debian's GLib, but that's close enough). I'm
not convinced it's RC, but I'll leave it at serious severity for now.
(gdb) thread apply all bt
Thread 7 (Thread 0x7f4576854700 (LWP 19643)):
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1 0x00007f457aa3cadd in g_cond_wait_until (cond=cond@entry=0x5617ef3f0be8,
mutex=mutex@entry=0x5617ef3f0be0, end_time=end_time@entry=280830465587) at
/home/smcv/src/glib/glib/gthread-posix.c:1449
#2 0x00007f457a9c9a8e in g_async_queue_pop_intern_unlocked
(queue=queue@entry=0x5617ef3f0be0, wait=wait@entry=1, end_time=280830465587) at
/home/smcv/src/glib/glib/gasyncqueue.c:422
#3 0x00007f457a9ca119 in g_async_queue_timeout_pop_unlocked
(queue=0x5617ef3f0be0, timeout=timeout@entry=500000) at
/home/smcv/src/glib/glib/gasyncqueue.c:570
#4 0x00007f457aa1ef01 in g_thread_pool_wait_for_new_task
(pool=pool@entry=0x5617ef4072a0) at /home/smcv/src/glib/glib/gthreadpool.c:262
#5 0x00007f457aa1f10b in g_thread_pool_thread_proxy (data=<optimized out>) at
/home/smcv/src/glib/glib/gthreadpool.c:296
#6 0x00007f457aa1e5fd in g_thread_proxy (data=0x5617ef3f8d40) at
/home/smcv/src/glib/glib/gthread.c:784
#7 0x00007f457a51a519 in start_thread (arg=0x7f4576854700) at
pthread_create.c:456
#8 0x00007f45799afa4f in clone () at
../sysdeps/unix/sysv/linux/x86_64/clone.S:97
Thread 6 (Thread 0x7f4578a6a700 (LWP 19641)):
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1 0x00007f457aa3c9ce in g_cond_wait (cond=cond@entry=0x7f457b8dd2b0
<cancellable_cond>, mutex=mutex@entry=0x7f457b8dd2c0 <cancellable_mutex>) at
/home/smcv/src/glib/glib/gthread-posix.c:1402
#2 0x00007f457b574975 in g_cancellable_disconnect (cancellable=0x5617ef3fca80,
handler_id=59) at /home/smcv/src/glib/gio/gcancellable.c:632
#3 0x00007f457b5749ae in cancellable_source_finalize (source=0x5617ef407e00)
at /home/smcv/src/glib/gio/gcancellable.c:675
#4 0x00007f457a9f3af9 in g_source_unref_internal
(source=source@entry=0x5617ef407e00, context=context@entry=0x5617ef3f2000,
have_lock=have_lock@entry=1) at /home/smcv/src/glib/glib/gmain.c:2119
#5 0x00007f457a9f3ef3 in g_child_source_remove_internal
(child_source=0x5617ef407e00, context=context@entry=0x5617ef3f2000) at
/home/smcv/src/glib/glib/gmain.c:1510
#6 0x00007f457a9f3e5b in g_source_destroy_internal (source=0x5617ef4082f0,
context=0x5617ef3f2000, have_lock=have_lock@entry=0) at
/home/smcv/src/glib/glib/gmain.c:1273
#7 0x00007f457a9f4e79 in g_source_destroy (source=source@entry=0x5617ef4082f0)
at /home/smcv/src/glib/glib/gmain.c:1304
#8 0x00007f457b5bf1b7 in free_sources (sources=0x0) at
/home/smcv/src/glib/gio/gsocketlistener.c:616
#9 0x00007f457b5c6003 in g_task_finalize (object=0x5617ef3e80e0) at
/home/smcv/src/glib/gio/gtask.c:641
#10 0x00007f457b2ea752 in g_object_unref (_object=_object@entry=0x5617ef3e80e0)
at /home/smcv/src/glib/gobject/gobject.c:3338
#11 0x00007f457b5bf308 in accept_ready (accept_socket=<optimized out>,
condition=<optimized out>, user_data=0x5617ef3e80e0) at
/home/smcv/src/glib/gio/gsocketlistener.c:786
#12 0x00007f457b5b6bd5 in socket_source_dispatch
(source=source@entry=0x5617ef4082f0, callback=0x7f457b5bf259 <accept_ready>,
user_data=0x5617ef3e80e0) at /home/smcv/src/glib/gio/gsocket.c:3818
#13 0x00007f457a9f459c in g_main_dispatch
(context=context@entry=0x5617ef3f2000) at /home/smcv/src/glib/glib/gmain.c:3183
#14 0x00007f457a9f6de0 in g_main_context_dispatch
(context=context@entry=0x5617ef3f2000) at /home/smcv/src/glib/glib/gmain.c:3848
#15 0x00007f457a9f6f39 in g_main_context_iterate (context=0x5617ef3f2000,
block=block@entry=1, dispatch=dispatch@entry=1, self=self@entry=0x5617ef3f8b70)
at /home/smcv/src/glib/glib/gmain.c:3921
#16 0x00007f457a9f72d8 in g_main_loop_run (loop=0x5617ef3f0b40) at
/home/smcv/src/glib/glib/gmain.c:4117
#17 0x00005617edf15430 in run_service_loop (service_context=0x5617ef3f2000) at
/home/smcv/src/glib/gio/tests/gdbus-peer.c:365
#18 0x00005617edf16b72 in nonce_tcp_service_thread_func
(user_data=0x7fff9d4ed060) at /home/smcv/src/glib/gio/tests/gdbus-peer.c:1235
#19 0x00007f457aa1e5fd in g_thread_proxy (data=0x5617ef3f8b70) at
/home/smcv/src/glib/glib/gthread.c:784
#20 0x00007f457a51a519 in start_thread (arg=0x7f4578a6a700) at
pthread_create.c:456
#21 0x00007f45799afa4f in clone () at
../sysdeps/unix/sysv/linux/x86_64/clone.S:97
Thread 5 (Thread 0x7f4577267700 (LWP 19642)):
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1 0x00007f457aa3cadd in g_cond_wait_until (cond=cond@entry=0x5617ef3ce578,
mutex=mutex@entry=0x5617ef3ce570, end_time=end_time@entry=280830465124) at
/home/smcv/src/glib/glib/gthread-posix.c:1449
#2 0x00007f457a9c9a8e in g_async_queue_pop_intern_unlocked
(queue=queue@entry=0x5617ef3ce570, wait=wait@entry=1, end_time=280830465124) at
/home/smcv/src/glib/glib/gasyncqueue.c:422
#3 0x00007f457a9ca119 in g_async_queue_timeout_pop_unlocked
(queue=0x5617ef3ce570, timeout=timeout@entry=500000) at
/home/smcv/src/glib/glib/gasyncqueue.c:570
#4 0x00007f457aa1ef01 in g_thread_pool_wait_for_new_task
(pool=pool@entry=0x5617ef3d2800) at /home/smcv/src/glib/glib/gthreadpool.c:262
#5 0x00007f457aa1f10b in g_thread_pool_thread_proxy (data=<optimized out>) at
/home/smcv/src/glib/glib/gthreadpool.c:296
#6 0x00007f457aa1e5fd in g_thread_proxy (data=0x5617ef3f8de0) at
/home/smcv/src/glib/glib/gthread.c:784
#7 0x00007f457a51a519 in start_thread (arg=0x7f4577267700) at
pthread_create.c:456
#8 0x00007f45799afa4f in clone () at
../sysdeps/unix/sysv/linux/x86_64/clone.S:97
Thread 4 (Thread 0x7f4577a68700 (LWP 19639)):
#0 0x00007f45799a5a5d in poll () at ../sysdeps/unix/syscall-template.S:84
#1 0x00007f457aa06ddc in g_poll (fds=fds@entry=0x5617ef3f0bb0,
nfds=nfds@entry=1, timeout=timeout@entry=-1) at
/home/smcv/src/glib/glib/gpoll.c:124
#2 0x00007f457a9f46e3 in g_main_context_poll
(context=context@entry=0x5617ef3f0800, timeout=-1, priority=<optimized out>,
fds=fds@entry=0x5617ef3f0bb0, n_fds=n_fds@entry=1) at
/home/smcv/src/glib/glib/gmain.c:4222
#3 0x00007f457a9f6ef6 in g_main_context_iterate (context=0x5617ef3f0800,
block=block@entry=1, dispatch=dispatch@entry=1, self=self@entry=0x5617ef3d2cf0)
at /home/smcv/src/glib/glib/gmain.c:3916
#4 0x00007f457a9f72d8 in g_main_loop_run (loop=0x5617ef3f2120) at
/home/smcv/src/glib/glib/gmain.c:4117
#5 0x00007f457b60be61 in gdbus_shared_thread_func (user_data=0x5617ef3f2160)
at /home/smcv/src/glib/gio/gdbusprivate.c:275
#6 0x00007f457aa1e5fd in g_thread_proxy (data=0x5617ef3d2cf0) at
/home/smcv/src/glib/glib/gthread.c:784
#7 0x00007f457a51a519 in start_thread (arg=0x7f4577a68700) at
pthread_create.c:456
#8 0x00007f45799afa4f in clone () at
../sysdeps/unix/sysv/linux/x86_64/clone.S:97
Thread 3 (Thread 0x7f4578269700 (LWP 19638)):
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1 0x00007f457aa3cadd in g_cond_wait_until (cond=cond@entry=0x5617ef3edf08,
mutex=mutex@entry=0x5617ef3edf00, end_time=end_time@entry=280830358684) at
/home/smcv/src/glib/glib/gthread-posix.c:1449
#2 0x00007f457a9c9a8e in g_async_queue_pop_intern_unlocked
(queue=queue@entry=0x5617ef3edf00, wait=wait@entry=1, end_time=280830358684) at
/home/smcv/src/glib/glib/gasyncqueue.c:422
#3 0x00007f457a9ca119 in g_async_queue_timeout_pop_unlocked
(queue=0x5617ef3edf00, timeout=timeout@entry=500000) at
/home/smcv/src/glib/glib/gasyncqueue.c:570
#4 0x00007f457aa1ef01 in g_thread_pool_wait_for_new_task
(pool=pool@entry=0x5617ef3e6720) at /home/smcv/src/glib/glib/gthreadpool.c:262
#5 0x00007f457aa1f10b in g_thread_pool_thread_proxy (data=<optimized out>) at
/home/smcv/src/glib/glib/gthreadpool.c:296
#6 0x00007f457aa1e5fd in g_thread_proxy (data=0x5617ef3d3280) at
/home/smcv/src/glib/glib/gthread.c:784
#7 0x00007f457a51a519 in start_thread (arg=0x7f4578269700) at
pthread_create.c:456
#8 0x00007f45799afa4f in clone () at
../sysdeps/unix/sysv/linux/x86_64/clone.S:97
Thread 2 (Thread 0x7f457926b700 (LWP 19635)):
#0 0x00007f45799a5a5d in poll () at ../sysdeps/unix/syscall-template.S:84
#1 0x00007f457aa06ddc in g_poll (fds=fds@entry=0x5617ef3d26f0,
nfds=nfds@entry=1, timeout=timeout@entry=-1) at
/home/smcv/src/glib/glib/gpoll.c:124
#2 0x00007f457a9f46e3 in g_main_context_poll
(context=context@entry=0x5617ef3d2960, timeout=-1, priority=<optimized out>,
fds=fds@entry=0x5617ef3d26f0, n_fds=n_fds@entry=1) at
/home/smcv/src/glib/glib/gmain.c:4222
#3 0x00007f457a9f6ef6 in g_main_context_iterate
(context=context@entry=0x5617ef3d2960, block=block@entry=1,
dispatch=dispatch@entry=1, self=<optimized out>) at
/home/smcv/src/glib/glib/gmain.c:3916
#4 0x00007f457a9f6fb7 in g_main_context_iteration (context=0x5617ef3d2960,
may_block=may_block@entry=1) at /home/smcv/src/glib/glib/gmain.c:3982
#5 0x00007f457a9f6fe9 in glib_worker_main (data=<optimized out>) at
/home/smcv/src/glib/glib/gmain.c:5791
#6 0x00007f457aa1e5fd in g_thread_proxy (data=0x5617ef3d2c00) at
/home/smcv/src/glib/glib/gthread.c:784
#7 0x00007f457a51a519 in start_thread (arg=0x7f457926b700) at
pthread_create.c:456
#8 0x00007f45799afa4f in clone () at
../sysdeps/unix/sysv/linux/x86_64/clone.S:97
Thread 1 (Thread 0x7f457baba840 (LWP 19620)):
#0 _g_log_abort (breakpoint=breakpoint@entry=1) at
/home/smcv/src/glib/glib/gmessages.c:583
#1 0x00007f457a9fde07 in g_logv (log_domain=0x7f457aa3f40e "GLib",
log_level=G_LOG_LEVEL_CRITICAL, format=<optimized out>,
args=args@entry=0x7fff9d4ecaa8) at /home/smcv/src/glib/glib/gmessages.c:1391
#2 0x00007f457a9fdff3 in g_log (log_domain=log_domain@entry=0x7f457aa3f40e
"GLib", log_level=log_level@entry=G_LOG_LEVEL_CRITICAL,
format=format@entry=0x7f457aa49398 "%s: assertion '%s' failed") at
/home/smcv/src/glib/glib/gmessages.c:1432
#3 0x00007f457a9fe3e9 in g_return_if_fail_warning
(log_domain=log_domain@entry=0x7f457aa3f40e "GLib",
pretty_function=pretty_function@entry=0x7f457aa47a70 <__func__.12136>
"g_source_set_ready_time", expression=expression@entry=0x7f457aa4749e
"source->ref_count > 0") at /home/smcv/src/glib/glib/gmessages.c:2752
#4 0x00007f457a9f5663 in g_source_set_ready_time (source=0x5617ef407e00,
ready_time=ready_time@entry=0) at /home/smcv/src/glib/glib/gmain.c:1845
#5 0x00007f457b5740ee in cancellable_source_cancelled
(cancellable=cancellable@entry=0x5617ef3fca80, user_data=<optimized out>) at
/home/smcv/src/glib/gio/gcancellable.c:653
#6 0x00007f457b2e77d9 in g_cclosure_marshal_VOID__VOID
(closure=0x5617ef407220, return_value=<optimized out>,
n_param_values=<optimized out>, param_values=<optimized out>,
invocation_hint=<optimized out>, marshal_data=<optimized out>) at
/home/smcv/src/glib/gobject/gmarshal.c:875
#7 0x00007f457b2e59ba in g_closure_invoke (closure=0x5617ef407220,
return_value=return_value@entry=0x0, n_param_values=1,
param_values=param_values@entry=0x7fff9d4ecd90,
invocation_hint=invocation_hint@entry=0x7fff9d4ecd30) at
/home/smcv/src/glib/gobject/gclosure.c:804
#8 0x00007f457b2f9a6f in signal_emit_unlocked_R
(node=node@entry=0x5617ef3e6d50, detail=detail@entry=0,
instance=instance@entry=0x5617ef3fca80,
emission_return=emission_return@entry=0x0,
instance_and_params=instance_and_params@entry=0x7fff9d4ecd90) at
/home/smcv/src/glib/gobject/gsignal.c:3635
#9 0x00007f457b3029d0 in g_signal_emit_valist (instance=0x5617ef3fca80,
signal_id=<optimized out>, detail=0, var_args=var_args@entry=0x7fff9d4ecf08) at
/home/smcv/src/glib/gobject/gsignal.c:3391
#10 0x00007f457b302c24 in g_signal_emit
(instance=instance@entry=0x5617ef3fca80, signal_id=<optimized out>,
detail=detail@entry=0) at /home/smcv/src/glib/gobject/gsignal.c:3447
#11 0x00007f457b5747da in g_cancellable_cancel (cancellable=0x5617ef3fca80) at
/home/smcv/src/glib/gio/gcancellable.c:508
#12 0x00007f457b5c43d1 in set_active (service=service@entry=0x5617ef3f9d50,
active=active@entry=0) at /home/smcv/src/glib/gio/gsocketservice.c:163
#13 0x00007f457b5c48a5 in g_socket_service_stop (service=0x5617ef3f9d50) at
/home/smcv/src/glib/gio/gsocketservice.c:299
#14 0x00007f457b61343c in g_dbus_server_stop (server=0x5617ef3e4810) at
/home/smcv/src/glib/gio/gdbusserver.c:613
#15 0x00005617edf16784 in test_nonce_tcp () at
/home/smcv/src/glib/gio/tests/gdbus-peer.c:1355
#16 0x00007f457aa1d26e in test_case_run (tc=tc@entry=0x5617ef3d0660) at
/home/smcv/src/glib/glib/gtestutils.c:2255
#17 0x00007f457aa1d47f in g_test_run_suite_internal
(suite=suite@entry=0x5617ef3ceae0, path=path@entry=0x0) at
/home/smcv/src/glib/glib/gtestutils.c:2339
#18 0x00007f457aa1d49a in g_test_run_suite_internal
(suite=suite@entry=0x5617ef3ceb40, path=path@entry=0x0) at
/home/smcv/src/glib/glib/gtestutils.c:2351
#19 0x00007f457aa1d5ee in g_test_run_suite (suite=0x5617ef3ceb40) at
/home/smcv/src/glib/glib/gtestutils.c:2426
#20 0x00007f457aa1d603 in g_test_run () at
/home/smcv/src/glib/glib/gtestutils.c:1692
#21 0x00005617edf190f1 in main (argc=<optimized out>, argv=<optimized out>) at
/home/smcv/src/glib/gio/tests/gdbus-peer.c:1759
Regards,
smcv
