Bug#884661: glib2.0: sometimes FTBFS on reproducible-builds: gmenumodel test: assertion failed (items_changed_count == 1): (0 == 1)

[Simon McVittie]

On Mon, 18 Dec 2017 at 09:17:46 +0000, Simon McVittie wrote:
> [#884661] might be new, or just rare.

https://tests.reproducible-builds.org/debian/logs/unstable/amd64/glib2.0_2.54.2-2.build2.log.gz
1..11
# Start of gmenu tests
ok 1 /gmenu/equality
PASS: gmenumodel 1 /gmenu/equality
ok 2 /gmenu/random
PASS: gmenumodel 2 /gmenu/random
ok 3 /gmenu/attributes
PASS: gmenumodel 3 /gmenu/attributes
ok 4 /gmenu/links
PASS: gmenumodel 4 /gmenu/links
ok 5 /gmenu/mutable
PASS: gmenumodel 5 /gmenu/mutable
ok 6 /gmenu/convenience
PASS: gmenumodel 6 /gmenu/convenience
ok 7 /gmenu/menuitem
PASS: gmenumodel 7 /gmenu/menuitem
# Start of dbus tests
ok 8 /gmenu/dbus/roundtrip
PASS: gmenumodel 8 /gmenu/dbus/roundtrip
# GLib-GIO:ERROR:../../../../../gio/tests/gmenumodel.c:850:test_dbus_subscriptions: assertion failed (items_changed_count == 1): (0 == 1)
ERROR: gmenumodel - too few tests run (expected 11, got 8)
ERROR: gmenumodel - exited with status 134 (terminated by signal 6?)

This is in test /gmenu/dbus/subscriptions, which connects to the
items-changed signal, appends 3 items to an empty menu, runs the main
loop for 200ms, and asserts that there has been one items-changed event
and the menu now has 3 items.

So this looks like some timing issue: something (another parallel
build?) is slowing down the test enough that 200ms is not long enough
to wait.

This test should ideally wait for the expected events to happen (and
optionally assert that the time elapsed is less than some arbitrary
maximum) instead of waiting an arbitrary time and asserting that the
expected events happened. That would often be quicker, too.

    smcv