On Mon, 01 Jun 2009 10:36:36 +0100, Daniel P. Berrange wrote:
> On Sat, May 30, 2009 at 12:45:21PM +0000, Frederik Himpe wrote:
>> On Fri, 29 May 2009 19:18:05 +0200, Daniel Veillard wrote:
>>
>> > - test case for exercising the event loop (Daniel Berrange)
>>
>> I think this test is failing for me on Mandriva Cooker (both i586 and
>> x86_64):
>> What could be wrong?
>
> Strange, this test case works fine for me on both archs with Fedora
> 9/10/11 and RHEL 5.
>
> Could you run the test manually with debugging turned on, eg
>
> LIBVIRT_DEBUG=1 ./eventtest
>
> And also try and capture an strace log with timings
>
> strace -ttt ./eventtest
Actually I found out the test failure is not 100% reproducible. I have
seen it failing in steps 6, 9 and IIRC also step 10 of eventtest.
Here's a failed execution:
$ LIBVIRT_DEBUG=1 ./eventtest
12:18:52.040: debug : virEventAddHandleImpl:112 : Add handle 13 1 0x404570 (nil)
12:18:52.040: debug : virEventAddHandleImpl:116 : Used 0 handle slots, adding 10 more
12:18:52.040: debug : virEventInterruptLocked:636 : Skip interrupt, 0 0
12:18:52.040: debug : virEventAddHandleImpl:112 : Add handle 3 1 0x403750 0x60f480
12:18:52.040: debug : virEventInterruptLocked:636 : Skip interrupt, 0 0
12:18:52.040: debug : virEventAddHandleImpl:112 : Add handle 5 1 0x403750 0x60f498
12:18:52.040: debug : virEventInterruptLocked:636 : Skip interrupt, 0 0
12:18:52.040: debug : virEventAddHandleImpl:112 : Add handle 7 1 0x403750 0x60f4b0
12:18:52.040: debug : virEventInterruptLocked:636 : Skip interrupt, 0 0
12:18:52.040: debug : virEventAddHandleImpl:112 : Add handle 9 1 0x403750 0x60f4c8
12:18:52.040: debug : virEventInterruptLocked:636 : Skip interrupt, 0 0
12:18:52.040: debug : virEventAddHandleImpl:112 : Add handle 11 1 0x403750 0x60f4e0
12:18:52.040: debug : virEventInterruptLocked:636 : Skip interrupt, 0 0
12:18:52.040: debug : virEventAddTimeoutImpl:209 : Adding timer 1 with -1 ms freq
12:18:52.040: debug : virEventAddTimeoutImpl:217 : Used 0 timeout slots, adding 10 more
12:18:52.040: debug : virEventInterruptLocked:636 : Skip interrupt, 0 0
12:18:52.040: debug : virEventAddTimeoutImpl:209 : Adding timer 2 with -1 ms freq
12:18:52.040: debug : virEventInterruptLocked:636 : Skip interrupt, 0 0
12:18:52.040: debug : virEventAddTimeoutImpl:209 : Adding timer 3 with -1 ms freq
12:18:52.040: debug : virEventInterruptLocked:636 : Skip interrupt, 0 0
12:18:52.040: debug : virEventAddTimeoutImpl:209 : Adding timer 4 with -1 ms freq
12:18:52.040: debug : virEventInterruptLocked:636 : Skip interrupt, 0 0
12:18:52.040: debug : virEventAddTimeoutImpl:209 : Adding timer 5 with -1 ms freq
12:18:52.040: debug : virEventInterruptLocked:636 : Skip interrupt, 0 0
1: Simple write 12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=0 w=1, f=13 e=1
12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=1 w=2, f=3 e=1
12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=2 w=3, f=5 e=1
12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=3 w=4, f=7 e=1
12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=4 w=5, f=9 e=1
12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=5 w=6, f=11 e=1
12:18:52.041: debug : virEventCalculateTimeout:313 : Calculate expiry of 5 timers
12:18:52.041: debug : virEventCalculateTimeout:343 : Timeout at 0 due in -1 ms
12:18:52.041: debug : virEventRunOnce:565 : Poll on 6 handles 0x6202f0 timeout -1
12:18:52.041: debug : virEventRunOnce:567 : Poll got 1 event
12:18:52.041: debug : virEventDispatchHandles:450 : Dispatch n=2 f=5 w=3 e=1 0x60f498
OK
12:18:52.041: debug : virEventRemoveHandleImpl:173 : Remove handle 2
12:18:52.041: debug : virEventRemoveHandleImpl:186 : mark delete 1 3
12:18:52.041: debug : virEventInterruptLocked:636 : Skip interrupt, 0 -565913264
2: Deleted before poll 12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=0 w=1, f=13 e=1
12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=1 w=3, f=5 e=1
12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=2 w=4, f=7 e=1
12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=3 w=5, f=9 e=1
12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=4 w=6, f=11 e=1
12:18:52.041: debug : virEventCalculateTimeout:313 : Calculate expiry of 5 timers
12:18:52.041: debug : virEventCalculateTimeout:343 : Timeout at 0 due in -1 ms
12:18:52.041: debug : virEventRunOnce:565 : Poll on 5 handles 0x6202f0 timeout -1
12:18:52.041: debug : virEventRunOnce:567 : Poll got 1 event
12:18:52.041: debug : virEventDispatchHandles:450 : Dispatch n=1 f=5 w=3 e=1 0x60f498
OK
3: Interrupted during poll 12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=0 w=1, f=13 e=1
12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=1 w=3, f=5 e=1
12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=2 w=4, f=7 e=1
12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=3 w=5, f=9 e=1
12:18:52.041: debug : virEventMakePollFDs:365 : Prepare n=4 w=6, f=11 e=1
12:18:52.041: debug : virEventCalculateTimeout:313 : Calculate expiry of 5 timers
12:18:52.041: debug : virEventCalculateTimeout:343 : Timeout at 0 due in -1 ms
12:18:52.041: debug : virEventRunOnce:565 : Poll on 5 handles 0x620010 timeout -1
12:18:52.147: debug : virEventRemoveHandleImpl:173 : Remove handle 3
12:18:52.147: debug : virEventRemoveHandleImpl:186 : mark delete 1 5
12:18:52.147: debug : virEventInterruptLocked:640 : Interrupting
12:18:52.147: debug : virEventRunOnce:567 : Poll got 1 event
12:18:52.147: debug : virEventDispatchHandles:450 : Dispatch n=0 f=13 w=1 e=1 (nil)
12:18:52.147: debug : virEventDispatchHandles:440 : Skip deleted n=1 w=3 f=5
OK
4: Deleted during dispatch 12:18:52.147: debug : virEventMakePollFDs:365 : Prepare n=0 w=1, f=13 e=1
12:18:52.147: debug : virEventMakePollFDs:365 : Prepare n=1 w=4, f=7 e=1
12:18:52.147: debug : virEventMakePollFDs:365 : Prepare n=2 w=5, f=9 e=1
12:18:52.147: debug : virEventMakePollFDs:365 : Prepare n=3 w=6, f=11 e=1
12:18:52.147: debug : virEventCalculateTimeout:313 : Calculate expiry of 5 timers
12:18:52.147: debug : virEventCalculateTimeout:343 : Timeout at 0 due in -1 ms
12:18:52.147: debug : virEventRunOnce:565 : Poll on 4 handles 0x620010 timeout -1
12:18:52.147: debug : virEventRunOnce:567 : Poll got 1 event
12:18:52.147: debug : virEventDispatchHandles:450 : Dispatch n=1 f=7 w=4 e=1 0x60f4b0
12:18:52.147: debug : virEventRemoveHandleImpl:173 : Remove handle 5
12:18:52.147: debug : virEventRemoveHandleImpl:186 : mark delete 2 9
12:18:52.147: debug : virEventInterruptLocked:636 : Skip interrupt, 1 -565913264
12:18:52.147: debug : virEventDispatchHandles:440 : Skip deleted n=2 w=5 f=9
OK
5: Deleted during dispatch 12:18:52.148: debug : virEventMakePollFDs:365 : Prepare n=0 w=1, f=13 e=1
12:18:52.148: debug : virEventMakePollFDs:365 : Prepare n=1 w=4, f=7 e=1
12:18:52.148: debug : virEventMakePollFDs:365 : Prepare n=2 w=6, f=11 e=1
12:18:52.148: debug : virEventCalculateTimeout:313 : Calculate expiry of 5 timers
12:18:52.148: debug : virEventCalculateTimeout:343 : Timeout at 0 due in -1 ms
12:18:52.148: debug : virEventRunOnce:565 : Poll on 3 handles 0x6202f0 timeout -1
12:18:52.148: debug : virEventRunOnce:567 : Poll got 1 event
12:18:52.148: debug : virEventDispatchHandles:450 : Dispatch n=1 f=7 w=4 e=1 0x60f4b0
12:18:52.148: debug : virEventRemoveHandleImpl:173 : Remove handle 4
12:18:52.148: debug : virEventRemoveHandleImpl:186 : mark delete 1 7
12:18:52.148: debug : virEventInterruptLocked:636 : Skip interrupt, 1 -565913264
OK
12:18:52.148: debug : virEventUpdateTimeoutImpl:247 : Updating timer 2 timeout with 100 ms freq
12:18:52.148: debug : virEventInterruptLocked:636 : Skip interrupt, 0 -565913264
6: Firing a timer 12:18:52.148: debug : virEventMakePollFDs:365 : Prepare n=0 w=1, f=13 e=1
12:18:52.148: debug : virEventMakePollFDs:365 : Prepare n=1 w=6, f=11 e=1
12:18:52.148: debug : virEventCalculateTimeout:313 : Calculate expiry of 5 timers
12:18:52.148: debug : virEventCalculateTimeout:319 : Got a timeout scheduled for 1243851532248
12:18:52.148: debug : virEventCalculateTimeout:343 : Timeout at 1243851532248 due in 100 ms
12:18:52.148: debug : virEventRunOnce:565 : Poll on 2 handles 0x6202f0 timeout 100
12:18:52.247: debug : virEventRunOnce:567 : Poll got 0 event
FAIL Timer 1 should have fired, but didn't
$ strace -ttt ./eventtest
1243851616.289203 execve("./eventtest", ["./eventtest"], [/* 50 vars */]) = 0
1243851616.290638 brk(0) = 0x620000
1243851616.290710 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2add61961000
1243851616.290827 uname({sys="Linux", node="klodia.mandriva.com", ...}) = 0
1243851616.290946 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
1243851616.291034 open("/etc/ld.so.cache", O_RDONLY) = 3
1243851616.291087 fstat(3, {st_mode=S_IFREG|0644, st_size=259381, ...}) = 0
1243851616.291175 mmap(NULL, 259381, PROT_READ, MAP_PRIVATE, 3, 0) = 0x2add61962000
1243851616.291214 close(3) = 0
1243851616.291266 open("/lib64/librt.so.1", O_RDONLY) = 3
1243851616.291310 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\"\0\257;\0\0\0@"..., 832) = 832
1243851616.291381 fstat(3, {st_mode=S_IFREG|0755, st_size=38664, ...}) = 0
1243851616.291447 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2add619a2000
1243851616.291500 mmap(0x3baf000000, 2132976, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3baf000000
1243851616.291547 mprotect(0x3baf007000, 2097152, PROT_NONE) = 0
1243851616.291594 mmap(0x3baf207000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7000) = 0x3baf207000
1243851616.291652 close(3) = 0
1243851616.291700 open("/lib64/libpthread.so.0", O_RDONLY) = 3
1243851616.291754 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200W\0\256;\0\0\0@"..., 832) = 832
1243851616.291833 fstat(3, {st_mode=S_IFREG|0755, st_size=132560, ...}) = 0
1243851616.291902 mmap(0x3bae000000, 2208592, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3bae000000
1243851616.291956 mprotect(0x3bae016000, 2097152, PROT_NONE) = 0
1243851616.291997 mmap(0x3bae216000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16000) = 0x3bae216000
1243851616.292059 mmap(0x3bae218000, 13136, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x3bae218000
1243851616.292102 close(3) = 0
1243851616.292161 open("/lib64/libintl.so.8", O_RDONLY) = 3
1243851616.292210 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0 \35\200\261;\0\0\0@"..., 832) = 832
1243851616.292262 fstat(3, {st_mode=S_IFREG|0644, st_size=39768, ...}) = 0
1243851616.292324 mmap(0x3bb1800000, 2133640, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3bb1800000
1243851616.292365 mprotect(0x3bb1809000, 2093056, PROT_NONE) = 0
1243851616.292407 mmap(0x3bb1a08000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x8000) = 0x3bb1a08000
1243851616.292470 close(3) = 0
1243851616.292537 open("/lib64/libc.so.6", O_RDONLY) = 3
1243851616.292579 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0`\345A\255;\0\0\0@"..., 832) = 832
1243851616.292628 fstat(3, {st_mode=S_IFREG|0755, st_size=1442280, ...}) = 0
1243851616.292701 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2add619a3000
1243851616.292767 mmap(0x3bad400000, 3543672, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3bad400000
1243851616.292805 mprotect(0x3bad559000, 2093056, PROT_NONE) = 0
1243851616.292846 mmap(0x3bad758000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x158000) = 0x3bad758000
1243851616.292915 mmap(0x3bad75d000, 17016, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x3bad75d000
1243851616.292958 close(3) = 0
1243851616.293056 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2add619a4000
1243851616.293217 arch_prctl(ARCH_SET_FS, 0x2add619a4560) = 0
1243851616.293371 mprotect(0x3bad758000, 16384, PROT_READ) = 0
1243851616.293459 mprotect(0x3bae216000, 4096, PROT_READ) = 0
1243851616.293522 mprotect(0x3baf207000, 4096, PROT_READ) = 0
1243851616.293571 mprotect(0x60e000, 4096, PROT_READ) = 0
1243851616.293611 mprotect(0x3bad21b000, 4096, PROT_READ) = 0
1243851616.293649 munmap(0x2add61962000, 259381) = 0
1243851616.293693 set_tid_address(0x2add619a45f0) = 32095
1243851616.293732 set_robust_list(0x2add619a4600, 0x18) = 0
1243851616.293770 futex(0x7fff4914720c, FUTEX_WAKE_PRIVATE, 1) = 0
1243851616.293832 rt_sigaction(SIGRTMIN, {0x3bae005610, [], SA_RESTORER|SA_SIGINFO, 0x3bae00ed30}, NULL, 8) = 0
1243851616.293898 rt_sigaction(SIGRT_1, {0x3bae0056a0, [], SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x3bae00ed30}, NULL, 8) = 0
1243851616.293943 rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
1243851616.293993 getrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM_INFINITY}) = 0
1243851616.294171 pipe([3, 4]) = 0
1243851616.294227 pipe([5, 6]) = 0
1243851616.294274 pipe([7, 8]) = 0
1243851616.294313 pipe([9, 10]) = 0
1243851616.294353 pipe([11, 12]) = 0
1243851616.294399 pipe([13, 14]) = 0
1243851616.294446 fcntl(13, F_GETFL) = 0 (flags O_RDONLY)
1243851616.294483 fcntl(13, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
1243851616.294522 fcntl(14, F_GETFL) = 0x1 (flags O_WRONLY)
1243851616.294559 fcntl(14, F_SETFL, O_WRONLY|O_NONBLOCK) = 0
1243851616.294598 fcntl(13, F_GETFD) = 0
1243851616.294631 fcntl(13, F_SETFD, FD_CLOEXEC) = 0
1243851616.294668 fcntl(14, F_GETFD) = 0
1243851616.294699 fcntl(14, F_SETFD, FD_CLOEXEC) = 0
1243851616.294811 brk(0) = 0x620000
1243851616.294862 brk(0x641000) = 0x641000
1243851616.294935 mmap(NULL, 8392704, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x2add619a5000
1243851616.295023 mprotect(0x2add619a5000, 4096, PROT_NONE) = 0
1243851616.295073 clone(child_stack=0x2add621a5250, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x2add621a59e0, tls=0x2add621a5950, child_tidptr=0x2add621a59e0) = 32096
1243851616.295229 write(2, " 1: Simple write "..., 17 1: Simple write ) = 17
1243851616.295284 futex(0x60f404, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x60f400, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
1243851616.295335 futex(0x60f3c0, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.295394 sched_yield() = 0
1243851616.295436 write(6, "1"..., 1) = 1
1243851616.295507 clock_gettime(CLOCK_REALTIME, {1243851616, 295521816}) = 0
1243851616.295552 futex(0x60f3c0, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.295595 clock_gettime(CLOCK_REALTIME, {1243851616, 295607183}) = 0
1243851616.295644 futex(0x60f440, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.295695 futex(0x60f444, FUTEX_WAIT_PRIVATE, 1, {4, 999914633}) = -1 EAGAIN (Resource temporarily unavailable)
1243851616.295747 write(2, "OK\n"..., 3OK
) = 3
1243851616.295790 write(2, " 2: Deleted before poll "..., 24 2: Deleted before poll ) = 24
1243851616.295838 futex(0x60f404, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x60f400, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
1243851616.295882 futex(0x60f3c0, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.295929 sched_yield() = 0
1243851616.295966 write(6, "1"..., 1) = 1
1243851616.296015 clock_gettime(CLOCK_REALTIME, {1243851616, 296026215}) = 0
1243851616.296062 futex(0x60f3c0, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.296118 clock_gettime(CLOCK_REALTIME, {1243851616, 296128425}) = 0
1243851616.296157 futex(0x60f440, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.296205 futex(0x60f444, FUTEX_WAIT_PRIVATE, 3, {4, 999897790}) = -1 EAGAIN (Resource temporarily unavailable)
1243851616.296255 write(2, "OK\n"..., 3OK
) = 3
1243851616.296298 write(2, " 3: Interrupted during poll "..., 28 3: Interrupted during poll ) = 28
1243851616.296358 futex(0x60f404, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x60f400, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
1243851616.296407 futex(0x60f3c0, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.296455 sched_yield() = 0
1243851616.296489 sched_yield() = 0
1243851616.296525 nanosleep({0, 100000000}, NULL) = 0
1243851616.403482 write(14, "\0"..., 1) = 1
1243851616.403538 futex(0x60f580, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.403590 clock_gettime(CLOCK_REALTIME, {1243851616, 403601045}) = 0
1243851616.403635 futex(0x60f3c0, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.403673 clock_gettime(CLOCK_REALTIME, {1243851616, 403683826}) = 0
1243851616.403717 futex(0x60f440, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.403759 futex(0x60f444, FUTEX_WAIT_PRIVATE, 5, {4, 999917219}) = -1 EAGAIN (Resource temporarily unavailable)
1243851616.403807 write(2, "OK\n"..., 3OK
) = 3
1243851616.403851 write(2, " 4: Deleted during dispatch "..., 28 4: Deleted during dispatch ) = 28
1243851616.403897 futex(0x60f404, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x60f400, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
1243851616.403952 futex(0x60f3c0, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.403992 sched_yield() = 0
1243851616.404025 write(8, "1"..., 1) = 1
1243851616.404073 write(10, "1"..., 1) = 1
1243851616.404113 clock_gettime(CLOCK_REALTIME, {1243851616, 404123651}) = 0
1243851616.404164 futex(0x60f3c0, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.404212 clock_gettime(CLOCK_REALTIME, {1243851616, 404222412}) = 0
1243851616.404251 futex(0x60f440, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.404294 futex(0x60f444, FUTEX_WAIT_PRIVATE, 7, {4, 999901239}) = -1 EAGAIN (Resource temporarily unavailable)
1243851616.404341 write(2, "OK\n"..., 3OK
) = 3
1243851616.404381 write(2, " 5: Deleted during dispatch "..., 28 5: Deleted during dispatch ) = 28
1243851616.404430 futex(0x60f404, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x60f400, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
1243851616.404477 futex(0x60f3c0, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.404519 sched_yield() = 0
1243851616.404558 write(8, "1"..., 1) = 1
1243851616.404616 clock_gettime(CLOCK_REALTIME, {1243851616, 404627378}) = 0
1243851616.404657 futex(0x60f3c0, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.404696 clock_gettime(CLOCK_REALTIME, {1243851616, 404706866}) = 0
1243851616.404736 futex(0x60f440, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.404790 futex(0x60f444, FUTEX_WAIT_PRIVATE, 9, {4, 999920512}) = -1 EAGAIN (Resource temporarily unavailable)
1243851616.404836 write(2, "OK\n"..., 3OK
) = 3
1243851616.404880 write(2, " 6: Firing a timer "..., 19 6: Firing a timer ) = 19
1243851616.404926 futex(0x60f404, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x60f400, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
1243851616.404971 futex(0x60f3c0, FUTEX_WAKE_PRIVATE, 1) = 1
1243851616.405012 sched_yield() = 0
1243851616.405047 clock_gettime(CLOCK_REALTIME, {1243851616, 405060486}) = 0
1243851616.405087 clock_gettime(CLOCK_REALTIME, {1243851616, 405100814}) = 0
1243851616.405130 futex(0x60f444, FUTEX_WAIT_PRIVATE, 11, {4, 999959672}) = 0
1243851616.503505 write(2, "FAIL Timer 1 should have fired, b"..., 43FAIL Timer 1 should have fired, but didn't
) = 43
1243851616.503591 exit_group(1) = ?
--
Frederik Himpe
--
Libvir-list mailing list
Libvir-list@xxxxxxxxxx
https://www.redhat.com/mailman/listinfo/libvir-list