GNOME Bugzilla – Bug 774578
test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time)
Last modified: 2016-11-18 16:25:33 UTC
dev@unstable:~/source/git/gnome/grilo/tests$ make check Making check in . make[1]: Entering directory '/local/packages/source/git/gnome/grilo/tests' make check-local make[2]: Entering directory '/local/packages/source/git/gnome/grilo/tests' TEST: registry... (pid=3274) /registry/init: OK /registry/load: OK /registry/unregister: OK PASS: registry TEST: lib-net... (pid=3297) /net/throttling/small-delay: ** ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (58257943343 >= 58257991378) FAIL GTester: last random seed: R02Sedbbc85f5195cd7939bacb39bb99b04e
The failure is random. Happens in roughly 1 in 20 runs.
Another failure instance: ------------------------- dev@unstable:~/source/git/gnome/grilo/tests$ make check Making check in . make[1]: Entering directory '/local/packages/source/git/gnome/grilo/tests' make check-local make[2]: Entering directory '/local/packages/source/git/gnome/grilo/tests' TEST: registry... (pid=4192) /registry/init: OK /registry/load: OK /registry/unregister: OK PASS: registry TEST: lib-net... (pid=4214) /net/throttling/small-delay: ** ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (58438942221 >= 58439046375) FAIL GTester: last random seed: R02Sc6bd01202c97704787265fb93d008e4c
(In reply to vrishab from comment #2) <snip> > TEST: lib-net... (pid=4214) > /net/throttling/small-delay: ** > ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed > (received_time >= op->expected_time): (58438942221 >= 58439046375) That's only just above 0.1 sec. For 100 runs, I got 18 failures with 0.1 sec as the threshold, 1 with 0.15 sec, and 0 with 0.2. commit a176b9a03d04d3f1657ffeaff51bd72a2e6ae21e Author: Bastien Nocera <hadess@hadess.net> Date: Fri Nov 18 14:12:12 2016 +0100 tests: Fix common test failures in GrlNet tests The small-delay test fails fairly often, about 20% of the time for a 100 runs on a non-loaded machine. We're lucky it doesn't happen more often, as g_timeout_add_seconds() as used by grl-net-wc.c will ultimately use g_timeout_set_expiration() which might round up timeouts to the above second: " /* We want the microseconds part of the timeout to land on the * 'timer_perturb' mark, but we need to make sure we don't try to * set the timeout in the past. We do this by ensuring that we * always only *increase* the expiration time by adding a full * second in the case that the microsecond portion decreases. */ " Bump the threshold to a full second, and verify by raising the delay in the grl_net_wc_set_throttling() call. https://bugzilla.gnome.org/show_bug.cgi?id=774578
With the above fix: dev@unstable:~/source/git/gnome/grilo/tests$ total=0; fail=0; while [ 1 ] ; do make check || ((fail++)); ((total++)); echo "$fail fail in $total runs"; done 23 fail in 233 runs ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18121943107 >= 18122099136) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18123943032 >= 18124186825) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18125943091 >= 18126118039) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18127943127 >= 18128111251) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18129943396 >= 18130120345) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18131943797 >= 18132115575) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18133943504 >= 18134119327) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18135942010 >= 18136132256) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18137942953 >= 18138126287) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18139943836 >= 18140124765) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18141941800 >= 18142126294) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18143943247 >= 18144127503) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18145943675 >= 18146126188) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18147943209 >= 18148148373) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18149942868 >= 18150127581) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18151942229 >= 18152125535) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18153943069 >= 18154107279) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18155943463 >= 18156121831) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18157943573 >= 18158117464) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18159943621 >= 18160111836) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18161943351 >= 18162126465) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18163943324 >= 18164141091) ERROR:lib-net.c:114:test_net_wc_throttling_cb: assertion failed (received_time >= op->expected_time): (18165943628 >= 18166134159)
One interesting point is that failures happen in succession.
If the machine is loaded, this might happen. I'll leave it at that, best we can do for now.