tupeng212 at gmail
Aug 10, 2012, 8:17 AM
Post #3 of 7
(93 views)
Permalink
|
|
Re: Big Bug:Time in VM goes slower; foud Solution but demand Judgement! A Interesting Story!
[In reply to]
|
|
Dear Jan Beulich:
Thanks for reply! You are a very clever man, you have sensed some thing immediately as I found lately. Please forgive my so lately reply!
1 why JVM set the same rate down so frequently ?
the first achievement I will show is I found the action in JVM and the reason by debugging disassembly code.
it seems to me like this in JVM:
======================================== 1 what happened in JVM ====================================
while (loop)//or a frequent call
{
timeBeginPeriod() --> NtSetTimerResolution(1(enble))
rc = WaitForMultipleObjects(5, 0x2222222, 0, 1); //the last parameter demands 1ms timer resolution
if (rc = TIMEOUT){
break;
}
else{
call 0x44444444;
}
timeEndPeriod() --> NtSetTimerResolution(0(disable))
}
====================================================================================================
so its behavior is totally legal, for it demands higher timer resolution (here 1ms), so it calls NtSetTimerResolution to improve the resolution.
it is not as I guessed "unaccurate"
I also wrote a tester below, which confirms my suppose. if you are interested in it , you can build it by MS's compiler, and after running the tester in VM about 1 minutes, VM's time will slow.
=========================== 2 a test which will lead to trigger slowing VM's inner time========
#include <stdio.h>
#include <windows.h>
typedef int (__stdcall *NTSETTIMER)(IN ULONG RequestedResolution, IN BOOLEAN Set, OUT PULONG ActualResolution );
typedef int (__stdcall *NTQUERYTIMER)(OUT PULONG MinimumResolution, OUT PULONG MaximumResolution, OUT PULONG CurrentResolution );
int main()
{
DWORD min_res = 0, max_res = 0, cur_res = 0, ret = 0;
HMODULE hdll = NULL;
hdll = GetModuleHandle("ntdll.dll");
NTSETTIMER AddrNtSetTimer = 0;
NTQUERYTIMER AddrNtQueyTimer = 0;
AddrNtSetTimer = (NTSETTIMER) GetProcAddress(hdll, "NtSetTimerResolution");
AddrNtQueyTimer = (NTQUERYTIMER)GetProcAddress(hdll, "NtQueryTimerResolution");
while (1)
{
ret = AddrNtQueyTimer(&min_res, &max_res, &cur_res);
printf("min_res = %d, max_res = %d, cur_res = %d\n",min_res, max_res, cur_res);
Sleep(10);
ret = AddrNtSetTimer(10000, 1, &cur_res);
Sleep(10);
ret = AddrNtSetTimer(10000, 0, &cur_res);
Sleep(10);
}
return 0;
}
==============================================================================================
2 Bug in xen
JVM is OK, so left the bug to xen, I have found both the reason and solution. As Jan mentioned avoiding call create_periodic_time, it got much better. so I modified it like this, if the pt timer is created before, setting RegA down is just changing the period value, so I do nothing except just setting period to pt's field. it is OK!
I thought pt->scheduled is responsible for Accuracy of pt_process_missed_ticks, so we should not interfere it at any outer invading or interruption, so I let create_periodic_time changed everything but reserved only one filed pt->scheduled as setted before, I am very happy to find the bug disappear. After I rechecked your mail I found you are really a very smart man, you have predicted something!
Did you further check whether the adjustments done to the
scheduled time in create_periodic_time() are responsible for this
conclusion of the JVM (could be effectively doubling the first
interval if HVM_PARAM_VPT_ALIGN is set, and with the high rate
of re-sets this could certainly have a more visible effect than
intended)?
After I tracked pt->scheduled, more and more truth surfaced. I will show you the RTC's spotting as I observed.
normal spot is like this:
0 1 2 3 4 5
. . . . . . (normal spot)
|(pt->scheduled at 2)
when create_periodic_time interfere pt->schedule at NOW
0 1 2 3 4 5
. . . . . .
|(NOW) | (new pt->scheduled is moved to 3 after ALIGN)
so it real spot is like this:
. . . . .
0 1 2 3 4 5
|(here we missed one spot at 2)
the original pt->scheduled is at 2 before create_periodic_time will be executed, but after it, pt->scheduled is moved to 3, so missed one spot to GuestWin.
3 who is wrong?
I doubt align_timer worth suspected:
s_time_t align_timer(s_time_t firsttick, uint64_t period)
{
if ( !period )
return firsttick;
return firsttick + (period - 1) - ((firsttick - 1) % period); //in xen4.x
return firsttick - ((firsttick - 1) % period);//it should be aligned like this.
}
I have also found another updating RTC's RegA in tools\ioemu-qemu-xen\hw\MCc146818rtc.c:
if (period_code != 0 && (s->cmos_data[RTC_REG_B] & REG_B_PIE)) {
#endif
if (period_code <= 2)
period_code += 7;
/* period in 32 Khz cycles */
period = 1 << (period_code - 1);
#ifdef IRQ_COALESCE_HACK
if(period != s->period)
s->irq_coalesced = (s->irq_coalesced * s->period) / period;
s->period = period;
#endif
/* compute 32 khz clock */
cur_clock = muldiv64(current_time, 32768, ticks_per_sec); //here I don't make sense it ......
next_irq_clock = (cur_clock & ~(period - 1)) + period;
s->next_periodic_time = muldiv64(next_irq_clock, ticks_per_sec, 32768) + 1;
qemu_mod_timer(s->periodic_timer, s->next_periodic_time);
I don't know what happened in real RTC, the most popular RTC chip is MC146818, I have checked its datasheet but found nothing I want. What I want to know is When a real outer 0x71 come down to set RTC's RegA, who does it change or spot the next periodic interrupt time ? In my case, the period doesn't change, it misses one spot, even if the period changes how will it spot the next scheduled time?
I need the man who knows the details deeply concerning when updating a real RTC's regA, how will it take it into effect, and make the transition smoothly in a real RTC.
I have been very anxious in another aspect, in our virtual environment, at create_periodic_time, NOW() may be far more later than pt->scheduled setted before, at this point, the new pt->scheduled may be far more behind the one after executing create_periodic_time. So the interval between both which should be treated by pt_process_missed_ticks to the former pt->scheduled's period is now all thrown away as nothing missed. So I think how to handle the interval between both pt->scheduled worth consideration in create_periodic_time.
Thanks!
tupeng212
From: Jan Beulich
Date: 2012-08-08 17:20
To: tupeng212
CC: xen-devel
Subject: Re: [Xen-devel] Big Bug:Time in VM running on xen goes slower
>>> On 07.08.12 at 17:44, tupeng212 <tupeng212 [at] gmail> wrote:
> 2 Xen
> vmx_vmexit_handler --> ......... --> handle_rtc_io --> rtc_ioport_write -->
> rtc_timer_update --> set RTC's REG_A to a high rate--> create_periodic_time(disable
> the former timer, and init a new one)
> Win7 is installed in the vm. This calling path is executed so frequent that
> may come down to set the RTC's REG_A hundreds of times every second but with
> the same rate(976.562us(1024HZ)), it is so abnormal to me to see such
> behavior.
_If_ the problem is merely with the high rate of calls to
create_periodic_time(), I think this could be taken care of by
avoiding the call (and perhaps the call to rtc_timer_update() in
the first place) by checking whether anything actually changes
due to the current write. I don't think, however, that this would
help much, as the high rate of port accesses (and hence traps
into the hypervisor) would remain. It might, nevertheless, get
your immediate problem of the time slowing down taken care of
if that is caused inside Xen (but the cause here may as well be in
the Windows kernel).
> 3 OS
> I have tried to find why the win7 setted RTC's regA so frequently. finally
> got the result, all that comes from a function: NtSetTimerResolution -->
> 0x70,0x71
> when I attached windbg into the guest OS, I also found the source, they are
> all called from a upper system call that comes from JVM(Java Virtual
> Machine).
Getting Windows to be a little smarter and avoid the port I/O when
doing redundant writes would of course be even better, but is
clearly a difficult to achieve goal.
> 4 JVM
> I don't know why JVM calls NtSetTimerResolution to set the same RTC's rate
> down (976.562us(1024HZ)) so frequently.
> But found something useful, in the java source code, I found many palaces
> written with time.scheduleAtFixedRate(), Informations from Internet told me
> this function scheduleAtFixedRate demands a higher time resolution. so I
> guess the whole process may be this:
> java wants a higher time resolution timer, so it changes the RTC's rate from
> 15.625ms(64HZ) to 976.562us(1024HZ), after that, it reconfirms whether the
> time is accurate as expected, but it's sorry to get some notice it 's not
> accurate either. so it sets the RTC's rate from 15.625ms(64HZ) to
> 976.562us(1024HZ) again and again..., at last, results in a slow system timer
> in vm.
Now that's really the fundamental thing to find out - what makes it
think the clock isn't accurate? Is this an artifact of scheduling (as
the scheduler tick certainly is several milliseconds, whereas
"accurate" here appears to require below 1ms granularity), perhaps
as a result of the box being overloaded (i.e. the VM not being able
to get scheduled quickly enough when the timer expires)? For that,
did you try lowering the scheduler time slice and/or its rate limit
(possible via command line option)? Of course doing so may have
other undesirable side effects, but it would be worth a try.
Did you further check whether the adjustments done to the
scheduled time in create_periodic_time() are responsible for this
conclusion of the JVM (could be effectively doubling the first
interval if HVM_PARAM_VPT_ALIGN is set, and with the high rate
of re-sets this could certainly have a more visible effect than
intended)?
Jan
|
x86-hvm-rtc.patch
