test_timeo fail with Assertion `elapsed > 440000 && elapsed < 550000' failed. when system is under load

Description

When running "make check" we sometimes observe the following:

test_timeo running...
lt-test_timeo: test_timeo.cpp:77: int main(): Assertion `elapsed > 440000 && elapsed < 550000' failed.
/bin/sh: line 5: 32248 Aborted (core dumped) ${dir}$tst
FAIL: test_timeo

zeromq-3.2.1$ gdb tests/.libs/lt-test_timeo tests/core.32248
GNU gdb (GDB) Red Hat Enterprise Linux (7.0.1-23.el5_5.2)
Copyright (C) 2009 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /tmp/zeromq-3.2.1/tests/.libs/lt-test_timeo...done.
[New Thread 32268]
[New Thread 32267]
Reading symbols from /tmp/zeromq-3.2.1/src/.libs/libzmq.so.3...done.
Loaded symbols for /tmp/zeromq-3.2.1/src/.libs/libzmq.so.3
Reading symbols from /lib64/librt.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib64/librt.so.1
Reading symbols from /lib64/libpthread.so.0...(no debugging symbols found)...done.
Loaded symbols for /lib64/libpthread.so.0
Reading symbols from /usr/lib64/libstdc++.so.6...(no debugging symbols found)...done.
Loaded symbols for /usr/lib64/libstdc++.so.6
Reading symbols from /lib64/libm.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib64/libm.so.6
Reading symbols from /lib64/libgcc_s.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib64/libgcc_s.so.1
Reading symbols from /lib64/libc.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib64/libc.so.6
Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib64/ld-linux-x86-64.so.2

warning: no loadable sections found in added symbol-file system-supplied DSO at 0x7fff5b8bc000
Core was generated by `/tmp/zeromq-3.2.1/tests/.libs/lt-test_timeo'.
Program terminated with signal 6, Aborted.
#0 0x00002b945d9de285 in raise () from /lib64/libc.so.6
(gdb) bt
#0 0x00002b945d9de285 in raise () from /lib64/libc.so.6
#1 0x00002b945d9dfd30 in abort () from /lib64/libc.so.6
#2 0x00002b945d9d7706 in __assert_fail () from /lib64/libc.so.6
#3 0x0000000000400f66 in main () at test_timeo.cpp:77
(gdb) frame 3
#3 0x0000000000400f66 in main () at test_timeo.cpp:77
77 assert (elapsed > 440000 && elapsed < 550000);
(gdb) list
72 void *watch = zmq_stopwatch_start ();
73 rc = zmq_recv (sb, buf, 32, 0);
74 assert (rc == -1);
75 assert (zmq_errno () == EAGAIN);
76 unsigned long elapsed = zmq_stopwatch_stop (watch);
77 assert (elapsed > 440000 && elapsed < 550000);
78
79 // Check whether connection during the wait doesn't distort the timeout.
80 timeout = 2000;
81 rc = zmq_setsockopt(sb, ZMQ_RCVTIMEO, &timeout, timeout_size);

This is zeromq-3.2.1-rc2 plus the patch from c05a1b1f26497adf0f4adce2d62cc37c4349bba3. I can reproduce the problem consistently regardless of that patch in my environment (CentOS 5 Xen domU) when I run yes(1) in the background and run the test with a nice level of +10:

zeromq-3.2.1/tests$ yes > /dev/null & while true ;do nice ./test_timeo || echo FAIL; done
[1] 7841
test_timeo running...
lt-test_timeo: test_timeo.cpp:77: int main(): Assertion `elapsed > 440000 && elapsed < 550000' failed.
Aborted (core dumped)
FAIL
test_timeo running...
lt-test_timeo: test_timeo.cpp:77: int main(): Assertion `elapsed > 440000 && elapsed < 550000' failed.
Aborted (core dumped)
FAIL
test_timeo running...
lt-test_timeo: test_timeo.cpp:77: int main(): Assertion `elapsed > 440000 && elapsed < 550000' failed.
Aborted (core dumped)
FAIL
test_timeo running...
[...]

This also happens without running yes(1) if the system is otherwise under load.

Environment

CentOS 5 x86_64 Xen domU

Activity

Show:

Details

Assignee

Reporter

Labels

Components

Affects versions

Priority

Created November 16, 2012 at 12:01 PM
Updated November 16, 2012 at 12:01 PM