WARNING - OLD ARCHIVES

This is an archived copy of the Xen.org mailing list, which we have preserved to ensure that existing links to archives are not broken. The live archive, which contains the latest emails, can be found at http://lists.xen.org/
   
 
 
Xen 
 
Home Products Support Community News
 
   
 

xen-devel

[Xen-devel] FYI: xend extremly slow when on nfsroot due to xenstored

To: xen-devel@xxxxxxxxxxxxxxxxxxx
Subject: [Xen-devel] FYI: xend extremly slow when on nfsroot due to xenstored
From: Stefan Berger <stefanb@xxxxxxxxxx>
Date: Fri, 14 Sep 2007 17:01:17 -0400
Delivery-date: Fri, 14 Sep 2007 14:02:11 -0700
Envelope-to: www-data@xxxxxxxxxxxxxxxxxx
List-help: <mailto:xen-devel-request@lists.xensource.com?subject=help>
List-id: Xen developer discussion <xen-devel.lists.xensource.com>
List-post: <mailto:xen-devel@lists.xensource.com>
List-subscribe: <http://lists.xensource.com/cgi-bin/mailman/listinfo/xen-devel>, <mailto:xen-devel-request@lists.xensource.com?subject=subscribe>
List-unsubscribe: <http://lists.xensource.com/cgi-bin/mailman/listinfo/xen-devel>, <mailto:xen-devel-request@lists.xensource.com?subject=unsubscribe>
Sender: xen-devel-bounces@xxxxxxxxxxxxxxxxxxx

Hi!

In case someone is running into the same problem...

I have a Xen system that is configured to boot with 'NFSRoot' ('/' mounted over NFS) and has pretty good performance in terms of access to the filesystem.
What struck me on that system was that 'xm start <domain name>' took more than 40 (!) seconds to start a VM, that means 'xm' blocked the console for this long. After some debugging and profiling I found that the culprit of this was the interaction of xend with the xenstore (see below). So, to make it short, the solution is for now to mount /var/lib/xenstored into ramfs and I am back to ~6 seconds for 'xm start'.

Here some of the output of xend:

[2007-09-14 09:21:46 7811] DEBUG (DevController:115) DevController: writing {'protocol': 'x86_64-abi', 'state': '1', 'backend-id': '0', 'backend': '/local/domain/0/backend/console/1/0'} to /local/domain/1/device/console/0.
[2007-09-14 09:21:46 7811] DEBUG (DevController:117) DevController: writing {'domain': 'fedora1', 'protocol': 'vt100', 'uuid': '37625b64-be2e-a74a-8696-85613af84ceb', 'frontend': '/local/domain/1/device/console/0', 'state': '1', 'location': '2', 'online': '1', 'frontend-id': '1'} to /local/domain/0/backend/console/1/0.
[2007-09-14 09:21:46 7811] DEBUG (DevController:122) --> Beginning with writing
[2007-09-14 09:21:46 7811] DEBUG (DevController:123) ---> Removing frontpath
[2007-09-14 09:21:46 7811] DEBUG (DevController:125) ---> Removing backpath
[2007-09-14 09:21:46 7811] DEBUG (DevController:128) ---> Mkdir backpath
[2007-09-14 09:21:46 7811] DEBUG (DevController:130) ---> Set permissions
[2007-09-14 09:21:47 7811] DEBUG (DevController:135) ---> Mkdir frontpath
[2007-09-14 09:21:47 7811] DEBUG (DevController:137) ---> Set permissions
[2007-09-14 09:21:47 7811] DEBUG (DevController:142) ---> Writing to frontpath
[2007-09-14 09:21:48 7811] DEBUG (DevController:144) ---> Writing to backpath
[2007-09-14 09:21:50 7811] DEBUG (DevController:147) --> Committing.
[2007-09-14 09:21:50 7811] DEBUG (DevController:149) --> Ending the writing. Done.
[2007-09-14 09:21:50 7811] INFO (XendDomainInfo:1347) createDevice: vbd : {'uuid': '8eeeaeb4-5c04-0bc2-8949-a4539dd3055e', 'bootable': 1, 'driver': 'paravirtualised', 'dev': 'sda1:disk', 'uname': 'file:/home/jailtime/fedora1/fedora1.img', 'mode': 'w', 'backend': '0'}
[2007-09-14 09:21:50 7811] INFO (security:617) Resource label for file:/home/jailtime/fedora1/fedora1.img not in file, using DEFAULT.
[2007-09-14 09:21:50 7811] INFO (security:771) Access Control Decision : PERMITTED
[2007-09-14 09:21:50 7811] DEBUG (DevController:115) DevController: writing {'virtual-device': '2049', 'device-type': 'disk', 'protocol': 'x86_64-abi', 'backend-id': '0', 'state': '1', 'backend': '/local/domain/0/backend/vbd/1/2049'} to /local/domain/1/device/vbd/2049.
[2007-09-14 09:21:50 7811] DEBUG (DevController:117) DevController: writing {'domain': 'fedora1', 'frontend': '/local/domain/1/device/vbd/2049', 'uuid': '8eeeaeb4-5c04-0bc2-8949-a4539dd3055e', 'dev': 'sda1', 'state': '1', 'params': '/home/jailtime/fedora1/fedora1.img', 'mode': 'w', 'online': '1', 'frontend-id': '1', 'type': 'file'} to /local/domain/0/backend/vbd/1/2049.
[2007-09-14 09:21:50 7811] DEBUG (DevController:122) --> Beginning with writing
[2007-09-14 09:21:50 7811] DEBUG (DevController:123) ---> Removing frontpath
[2007-09-14 09:21:50 7811] DEBUG (DevController:125) ---> Removing backpath
[2007-09-14 09:21:50 7811] DEBUG (DevController:128) ---> Mkdir backpath
[2007-09-14 09:21:51 7811] DEBUG (DevController:130) ---> Set permissions
[2007-09-14 09:21:51 7811] DEBUG (DevController:135) ---> Mkdir frontpath
[2007-09-14 09:21:51 7811] DEBUG (DevController:137) ---> Set permissions
[2007-09-14 09:21:51 7811] DEBUG (DevController:142) ---> Writing to frontpath
[2007-09-14 09:21:52 7811] DEBUG (DevController:144) ---> Writing to backpath
[2007-09-14 09:21:54 7811] DEBUG (DevController:147) --> Committing.
[2007-09-14 09:21:54 7811] DEBUG (DevController:149) --> Ending the writing. Done.


A couple of those ~4 second transactions are occuring and it adds up to > 40 seconds. I still find it surprising that xenstore internally needs so much more time when running via NFSRoot. When run on ramfs the xenstore transaction all occur in less than one second.

   Stefan
 
_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxxxxxxxx
http://lists.xensource.com/xen-devel
<Prev in Thread] Current Thread [Next in Thread>