On Thu, Jun 04, 2009 at 07:55:43PM +0000, Frederik Himpe 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 I think is happening is that poll() is returning much sooner than
>> we anticipate. When you give it a timeout, it'll return upto 1
>> timeslice before the timeout is due. I suspect that this is what is
>> tripping up the test case on Mandriva. Could you apply the following
>> patch, and re-build & run LIBVIRT_DEBUG=1 ./eventtest again, and also
>> re-run with the 'strace -ttt -f ./eventtest' (i forgot to ask for -f
>> last time).
$ LIBVIRT_DEBUG=1 ./eventtest
OK
21:52:03.838: debug : virEventUpdateTimeoutImpl:247 : Updating timer 2 timeout with 100
ms freq
21:52:03.838: debug : virEventInterruptLocked:637 : Skip interrupt, 0 -1210193008
6: Firing a timer 21:52:03.838: debug : virEventMakePollFDs:365 : Prepare n=0 w=1, f=13
e=1
21:52:03.838: debug : virEventMakePollFDs:365 : Prepare n=1 w=6, f=11 e=1
21:52:03.838: debug : virEventCalculateTimeout:313 : Calculate expiry of 5 timers
21:52:03.838: debug : virEventCalculateTimeout:319 : Got a timeout scheduled for
1244145123938
21:52:03.838: debug : virEventCalculateTimeout:343 : Timeout at 1244145123938 due in 100
ms
21:52:03.838: debug : virEventRunOnce:566 : Poll on 2 handles 0x8068098 timeout 100
21:52:03.931: debug : virEventRunOnce:568 : Poll got 0 event
21:52:03.931: info : virEventDispatchTimeouts:405 : Check timeout 1244145123938 against
current 1244145123931
FAIL Timer 1 should have fired, but didn't
$ strace -ttt -f ./eventtest
[pid 32197] 1244145232.605696 <... clock_gettime resumed>
{1244145232, 605606509}) = 0
[pid 32198] 1244145232.605779 poll([{fd=13, events=POLLIN}, {fd=11, events=POLLIN}], 2,
99 <unfinished ...>
[pid 32197] 1244145232.605840 clock_gettime(CLOCK_REALTIME, {1244145232, 605855562}) = 0
Great, this confirms my thought. We asked for a 99 ms timeout, but poll
returned significantly sooner than we asked for - approx 60-80 ms. So
when we then ncompare the elapsed time, with scheduled timer, we don't
see the expiry.
I suspect that Mandriva is either using a lower HZ for the kernel, or do
not have the hi-res timers or tickless feature. Not Mandriva's fault if
this is correct - we'll just have to take account of this potential for
early return of poll in our tests, since it is clearly allowed by the API
spec.
"The timeout argument specifies an upper limit on the time for which
poll() will block, in milliseconds.:
so by definition, it must return at least 1 timeslice before the expiry.
Daniel
--
|: Red Hat, Engineering, London -o-
http://people.redhat.com/berrange/ :|
|:
http://libvirt.org -o-
http://virt-manager.org -o-
http://ovirt.org :|
|:
http://autobuild.org -o-
http://search.cpan.org/~danberr/ :|
|: GnuPG: 7D3B9505 -o- F3C9 553F A1DA 4AC2 5648 23C1 B3DF F742 7D3B 9505 :|