From mboxrd@z Thu Jan 1 00:00:00 1970 From: tupeng212 Subject: Big Bug:Time in VM running on xen goes slower Date: Tue, 7 Aug 2012 23:44:45 +0800 Message-ID: <201208070018394210381@gmail.com> Reply-To: tupeng212 Mime-Version: 1.0 Content-Type: multipart/mixed; boundary="===============1615201137309538416==" Return-path: List-Unsubscribe: , List-Post: List-Help: List-Subscribe: , Sender: xen-devel-bounces@lists.xen.org Errors-To: xen-devel-bounces@lists.xen.org To: xen-devel List-Id: xen-devel@lists.xenproject.org This is a multi-part message in MIME format. --===============1615201137309538416== Content-Type: multipart/alternative; boundary="----=_001_NextPart421446275566_=----" This is a multi-part message in MIME format. ------=_001_NextPart421446275566_=---- Content-Type: text/plain; charset="gb2312" Content-Transfer-Encoding: base64 RGVhciBhbGw6DQpJIGhhdmUgZm91bmQgYSBiaWcgYnVnIG9uIHhlbiBjb25jZXJuaW5nIHRpbWUg dmlydHVhbGl6YXRpb24uIFBsZWFzZSBsZXQgbWUgc2hvdyB5b3UgdGhlIHdob2xlIHByb2Nlc3M6 DQoNCjEgUGhlbm9tZW5vbg0Kd2hlbiBJIHJ1biBhIEpWTSBiYXNlZCBwcm9ncmFtIGluIElFIGJy b3dzZXIgaW4gbXkgVmlydHVhbCBNYWNoaW5lLCBJIGhhdmUgZm91bmQgY2xlYXJseSB0aGF0IHRp bWUgYXQgdGhlIHJpZ2h0IGJvdHRvbSBjb3JuZXIgaW4gbXkgVk0gZ2V0cyBtb3JlIHNsb3dlciBh bmQgc2xvd2VyLg0KSSBzdHVkaWVkIHRoZSBidWcgZGVlcGx5LCBhbmQgZm91bmQgc29tZXRoaW5n IGJlbG93Lg0KDQoyIFhlbg0Kdm14X3ZtZXhpdF9oYW5kbGVyICAtLT4gLi4uLi4uLi4uIC0tPiBo YW5kbGVfcnRjX2lvICAtLT4gcnRjX2lvcG9ydF93cml0ZSAgLS0+IHJ0Y190aW1lcl91cGRhdGUg LS0+IHNldCBSVEMncyBSRUdfQSB0byBhIGhpZ2ggcmF0ZS0tPiBjcmVhdGVfcGVyaW9kaWNfdGlt ZShkaXNhYmxlIHRoZSBmb3JtZXIgdGltZXIsIGFuZCBpbml0IGEgbmV3IG9uZSkNCldpbjcgaXMg aW5zdGFsbGVkIGluIHRoZSB2bS4gVGhpcyBjYWxsaW5nIHBhdGggaXMgZXhlY3V0ZWQgc28gZnJl cXVlbnQgdGhhdCBtYXkgY29tZSBkb3duIHRvIHNldCB0aGUgUlRDJ3MgUkVHX0EgaHVuZHJlZHMg b2YgdGltZXMgZXZlcnkgc2Vjb25kIGJ1dCB3aXRoIHRoZSBzYW1lIHJhdGUoOTc2LjU2MnVzKDEw MjRIWikpLCBpdCBpcyBzbyBhYm5vcm1hbCB0byBtZSB0byBzZWUgc3VjaCBiZWhhdmlvci4NCg0K MyBPUw0KSSBoYXZlIHRyaWVkIHRvIGZpbmQgd2h5IHRoZSB3aW43IHNldHRlZCBSVEMncyByZWdB IHNvIGZyZXF1ZW50bHkuIGZpbmFsbHkgZ290IHRoZSByZXN1bHQsIGFsbCB0aGF0IGNvbWVzIGZy b20gYSBmdW5jdGlvbjogTnRTZXRUaW1lclJlc29sdXRpb24gLS0+IDB4NzAsMHg3MQ0Kd2hlbiBJ IGF0dGFjaGVkIHdpbmRiZyBpbnRvIHRoZSBndWVzdCBPUywgSSBhbHNvIGZvdW5kIHRoZSBzb3Vy Y2UsIHRoZXkgYXJlIGFsbCBjYWxsZWQgZnJvbSBhIHVwcGVyIHN5c3RlbSBjYWxsIHRoYXQgY29t ZXMgZnJvbSBKVk0oSmF2YSBWaXJ0dWFsIE1hY2hpbmUpLg0KDQo0IEpWTQ0KSSBkb24ndCBrbm93 IHdoeSBKVk0gY2FsbHMgTnRTZXRUaW1lclJlc29sdXRpb24gdG8gc2V0IHRoZSBzYW1lIFJUQydz IHJhdGUgZG93biAoOTc2LjU2MnVzKDEwMjRIWikpIHNvIGZyZXF1ZW50bHkuIA0KQnV0IGZvdW5k IHNvbWV0aGluZyB1c2VmdWwsIGluIHRoZSBqYXZhIHNvdXJjZSBjb2RlLCBJIGZvdW5kIG1hbnkg cGFsYWNlcyB3cml0dGVuIHdpdGggdGltZS5zY2hlZHVsZUF0Rml4ZWRSYXRlKCksIEluZm9ybWF0 aW9ucyBmcm9tIEludGVybmV0IHRvbGQgbWUgdGhpcyBmdW5jdGlvbiBzY2hlZHVsZUF0Rml4ZWRS YXRlIGRlbWFuZHMgYSBoaWdoZXIgdGltZSByZXNvbHV0aW9uLiBzbyBJIGd1ZXNzIHRoZSB3aG9s ZSBwcm9jZXNzIG1heSBiZSB0aGlzOiANCmphdmEgd2FudHMgYSBoaWdoZXIgdGltZSByZXNvbHV0 aW9uIHRpbWVyLCBzbyBpdCBjaGFuZ2VzIHRoZSBSVEMncyByYXRlIGZyb20gMTUuNjI1bXMoNjRI WikgdG8gOTc2LjU2MnVzKDEwMjRIWiksIGFmdGVyIHRoYXQsIGl0IHJlY29uZmlybXMgd2hldGhl ciB0aGUgdGltZSBpcyBhY2N1cmF0ZSBhcyBleHBlY3RlZCwgYnV0IGl0J3Mgc29ycnkgdG8gZ2V0 IHNvbWUgbm90aWNlIGl0ICdzIG5vdCBhY2N1cmF0ZSBlaXRoZXIuIHNvIGl0IHNldHMgIHRoZSBS VEMncyByYXRlIGZyb20gMTUuNjI1bXMoNjRIWikgdG8gOTc2LjU2MnVzKDEwMjRIWikgYWdhaW4g YW5kIGFnYWluLi4uLCBhdCBsYXN0LCByZXN1bHRzIGluIGEgc2xvdyBzeXN0ZW0gdGltZXIgaW4g dm0uDQp0aGVyZSBpcyBhbHNvIGEgZnJlcXVlbnRseSBjYWxsZWQgZnVuY3Rpb24gZ29pbmcgaW50 byBteSBleWVzOiBRdWVyeVBlcmZvcm1hbmNlQ291bnRlci4NCg0KDQp3aGF0IG15IHByb2JsZW1z IGFyZToNCjEgd2h5IHRoZSBKVk0gc2V0cyB0aGUgc2FtZSBSVEMncyByYXRlIDk3NjU2MiBkb3du IHRvIHRoZSBjb21zIGFnYWluIGFuZCBhZ2Fpbj8gd2hhdCBoZSBmb3VuZCAgaXMgYWJub3JtYWw/ DQoyIGV2ZW4gYSBhYm5vcm1hbCB1c2VyIHByb2dyYW0gY2FsbHMgY3JlYXRlX3BlcmlvZGljX3Rp bWUgdG8gc2V0IHRoZSByYXRlIGFnYWluIGFuZCBhZ2FpbiwgaG93IGRvIHdlIGF2b2lkIHRoZSBp bmZsdWVuY2UgdXBvbiBvdXIgdGltZSBpbiB2bT8gaG93IGRvIHdlIGNvbXBlbnNhdGUgdGhlIGVs YXBzZWQgdGltZSBhdCB0aGUgc3dpdGNoaW5nIHBvaW50PyBlc3BlY2lhbGx5IHdoZW4gdGhlIHN3 aXRjaCBpcyBzbyBmcmVxdWVudC4NCg0KY2FuIHNvbWUgYmlnIGZpZ3VyZXMgZ2l2ZSBtZSBzb21l IGFkdmljZXMgb24gdGhpcz8NCnRoYW5rcyENCg0KDQoNCnR1cGVuZzIxMg== ------=_001_NextPart421446275566_=---- Content-Type: text/html; charset="gb2312" Content-Transfer-Encoding: quoted-printable
Dear all:
I have found a big bug on xen concerning t= ime=20 virtualization. Please let me show you the whole process:
 
1 Phenomenon
when I run a JVM base= d program in=20 IE browser in my Virtual Machine, I have found clearly that time at the ri= ght=20 bottom corner in my VM gets more slower and=20 slower.
I studied the bug dee= ply, and=20 found something below.
 <= /DIV>
2 Xen
vmx_vmexit_handler&nb= sp; -->=20 ......... --> handle_rtc_io  --> rtc_ioport_write  -->=20 rtc_timer_update --> set RTC's REG_A to a high rate-->=20 create_periodic_time(disable the former timer, and init a new=20 one)
Win7 is installed in = the vm. This=20 calling path is executed so frequent that may come down to set the RTC's R= EG_A=20 hundreds of times every second but with the same rate(976.562us(1024HZ)), it is so abnormal to me to see such=20 behavior.
 <= /DIV>
3 OS
I have tried to find = why the win7=20 setted RTC's regA so frequently. finally got the result, all that com= es=20 from a function: NtSetTimerResolution -->=20 0x70,0x71
when I= attached=20 windbg into the guest OS, I also found the source, they are all called fro= m a=20 upper system call that comes from JVM(Java Virtual=20 Machine).
 
4=20 JVM
I don'= t know why JVM=20 calls NtSetTimerResolution to set the same RT= C's rate=20 down (976.562us(1024HZ)) so frequently.
But fo= und something=20 useful, in the java source code, I found= many=20 palaces written with time.scheduleAtFixedRate(), Informations from Interne= t told=20 me this function scheduleAtFixedRate demands a higher time resolution= .=20 so I=20 guess the whole process may be this:
java w= ants a higher=20 time resolution timer, so it changes the RTC's rate from 15.625ms(64HZ) to= =20 976.562us(1024HZ), after that, it reconfirms whether the time is accurate = as=20 expected, but it's sorry to get some notice it 's not accurate either. so = it=20 sets  the RTC's rate from 15.625ms(64HZ) to 976.562us(1024HZ) again a= nd=20 again..., at last, results in a slow system timer in=20 vm.
there = is also a=20 frequently called function going into my eyes:=20 QueryPerformanceCounter.
 
 
what my problems are:
1 why the JVM sets the same RTC's rate 976562 down to the coms again = and=20 again? what he found  is abnormal?
2 even a abnormal user program calls create_periodic_time to set the = rate=20 again and again, how do we avoid the influence upon our time in vm? how do= we=20 compensate the elapsed time at the switching point? especially when the sw= itch=20 is so frequent.
 
can some big figures give me some advices on this?
thanks!
tupeng212
 
 
 
------=_001_NextPart421446275566_=------ --===============1615201137309538416== Content-Type: text/plain; charset="us-ascii" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit Content-Disposition: inline _______________________________________________ Xen-devel mailing list Xen-devel@lists.xen.org http://lists.xen.org/xen-devel --===============1615201137309538416==--