Revisiting XenD / XenStored performance / scalability issues

["Daniel P. Berrange" <berrange@redhat.com>]

[-- Attachment #1: Type: text/plain, Size: 3804 bytes --]

Waay back at the end of 3.0.3 dev cycle I brought up the issue of XenD
running far too many xenstore transactions per-request

http://lists.xensource.com/archives/html/xen-devel/2006-10/msg00487.html

Short summary:  

   # nc -U /var/lib/xend/xend-socket 
   GET /xend/domain/test

Resulted in approx 16 xenstore transactions for a domain with one disk and
one NIC - this increases as # of devices increases.

Since there was major XenAPI work about to be done which would refactor a
large portion of XenD code it was anticipated this situation would improve.
I've just tested again with Xen 3.0.5 rc2, but we seem to have got worse,
now doing approx 30 xenstore transactions for a domain with one disk and
one NIC. Again this figure of 30 increases as you add more devices to
the guest.

As a test case I'm using

  time for i in `seq 1 1000` ; do virsh list > /dev/null  ; done

Which takes approx  1m 45 seconds to complete. During this test run the
CPU usage shown by top gives xenstored 70% utilization and xend about 15%.
As noted before xenstored is bottlenecked doing disk I/O, since each txn
requires a copy of the tdb database - 30 txns * 200 kb =~ 6 MB of I/O.

As a quick 'hack' I changed xend init script to have

     mkdir /dev/shm/xenstored
     mount --bind /dev/shm/xenstored /var/lib/xenstored

Which puts xenstored's database on tmpfs (ie RAM). This reduced the runtime
of the test to 55 seconds on average. OProfile still showed that most of
xenstored's time was spent doing I/O - even though that I/O was to a RAM
disk there was still the data copying overheads between kernel/userspace.
This validated that reducing the xenstored I/O overhead is the way to 
address the performance problem. 

The core problem is that XenD does lots of 'singleton' transactions - ie it
has each individual xenstore read within its own transaction. So I've put
together a proof of concept patch which pulls the transactions up in the
call stack for several key places inside XenD. With this patch applied, a
single 'GET /xend/domain/test' now only does 2 transactions regardless of
how many devices exist in the guest.

This reduced the runtime from the test from 1m 45s, to average of 30s - so
even much better than the tmpfs results. CPU usage from top now shows that 
xenstored is taking <  1% CPU time during the test, and XenD is taking about
25% CPU time. 

The one remaining puzzle is why I can't get XenD to max out a single CPU.
This is a dual core box, so I'd expect XenD CPU time to hit 50%, but it
never went above 25%. I can only imagine there is some kind of 'sleep' state,
or synchronization overhead hiding in the code somewhere, because there
was no I/O wait time reported and no other processes had any CPU time 
against them.

Finally this test case is obviously using the legacy SEXPR API, so a
simple 'virsh list' shoudl be much faster with XenAPI - however, there
do seem to be a number of places where even the new XenAPI ends up doing
huge numbers of 'singleton' transactions - 'xm create' is one - about 80
transactions to create a single domain. 

I'd really like to see all the 'convenience' methods in the object
 xen.xend.xenstore.xstransact removed, and have the caller be responsible
for managing transactions. The convenience APIs are making it very unclear
just where the overhead is coming from since the are a number of call-chains
which can ultimately trigger these transactions.

Attaching the patch against 3.0.5/unstable as reference. 

Dan.
-- 
|=- Red Hat, Engineering, Emerging Technologies, Boston.  +1 978 392 2496 -=|
|=-           Perl modules: http://search.cpan.org/~danberr/              -=|
|=-               Projects: http://freshmeat.net/~danielpb/               -=|
|=-  GnuPG: 7D3B9505   F3C9 553F A1DA 4AC2 5648 23C1 B3DF F742 7D3B 9505  -=| 

[-- Attachment #2: xen-xs-transactions.patch --]
[-- Type: text/plain, Size: 18489 bytes --]

diff -r 8ca89a9e54a7 tools/python/xen/xend/XendConfig.py
--- a/tools/python/xen/xend/XendConfig.py	Wed Apr 25 09:44:20 2007 +0100
+++ b/tools/python/xen/xend/XendConfig.py	Wed Apr 25 12:52:29 2007 -0400
@@ -26,6 +26,7 @@ from xen.xend.XendDevices import XendDev
 from xen.xend.XendDevices import XendDevices
 from xen.xend.PrettyPrint import prettyprintstring
 from xen.xend.XendConstants import DOM_STATE_HALTED
+from xen.xend.xenstore.xstransact import xstransact
 
 log = logging.getLogger("xend.XendConfig")
 log.setLevel(logging.WARN)
@@ -884,36 +885,43 @@ class XendConfig(dict):
 
         # Marshall devices (running or from configuration)
         if not ignore_devices:
-            for cls in XendDevices.valid_devices():
-                found = False
+            txn = xstransact()
+            try:
+                for cls in XendDevices.valid_devices():
+                    found = False
                 
-                # figure if there is a dev controller is valid and running
-                if domain and domain.getDomid() != None:
-                    try:
-                        controller = domain.getDeviceController(cls)
-                        configs = controller.configurations()
-                        for config in configs:
-                            if sxp.name(config) in ('vbd', 'tap'):
-                                # The bootable flag is never written to the
-                                # store as part of the device config.
-                                dev_uuid = sxp.child_value(config, 'uuid')
-                                dev_type, dev_cfg = self['devices'][dev_uuid]
-                                is_bootable = dev_cfg.get('bootable', 0)
-                                config.append(['bootable', int(is_bootable)])
-
-                            sxpr.append(['device', config])
-
-                        found = True
-                    except:
-                        log.exception("dumping sxp from device controllers")
-                        pass
+                    # figure if there is a dev controller is valid and running
+                    if domain and domain.getDomid() != None:
+                        try:
+                            controller = domain.getDeviceController(cls)
+                            configs = controller.configurations(txn)
+                            for config in configs:
+                                if sxp.name(config) in ('vbd', 'tap'):
+                                    # The bootable flag is never written to the
+                                    # store as part of the device config.
+                                    dev_uuid = sxp.child_value(config, 'uuid')
+                                    dev_type, dev_cfg = self['devices'][dev_uuid]
+                                    is_bootable = dev_cfg.get('bootable', 0)
+                                    config.append(['bootable', int(is_bootable)])
+
+                                sxpr.append(['device', config])
+
+                            found = True
+                        except:
+                            log.exception("dumping sxp from device controllers")
+                            pass
                     
-                # if we didn't find that device, check the existing config
-                # for a device in the same class
-                if not found:
-                    for dev_type, dev_info in self.all_devices_sxpr():
-                        if dev_type == cls:
-                            sxpr.append(['device', dev_info])
+                    # if we didn't find that device, check the existing config
+                    # for a device in the same class
+                    if not found:
+                        for dev_type, dev_info in self.all_devices_sxpr():
+                            if dev_type == cls:
+                                sxpr.append(['device', dev_info])
+
+                txn.commit()
+            except:
+                txn.abort()
+                raise
 
         return sxpr    
     
diff -r 8ca89a9e54a7 tools/python/xen/xend/XendDomain.py
--- a/tools/python/xen/xend/XendDomain.py	Wed Apr 25 09:44:20 2007 +0100
+++ b/tools/python/xen/xend/XendDomain.py	Wed Apr 25 12:53:38 2007 -0400
@@ -391,13 +391,22 @@ class XendDomain:
         @rtype: None
         """
 
+        txn = xstransact()
+        try:
+            self._refreshTxn(txn, refresh_shutdown)
+            txn.commit()
+        except:
+            txn.abort()
+            raise
+
+    def _refreshTxn(self, transaction, refresh_shutdown):
         running = self._running_domains()
         # Add domains that are not already tracked but running in Xen,
         # and update domain state for those that are running and tracked.
         for dom in running:
             domid = dom['domid']
             if domid in self.domains:
-                self.domains[domid].update(dom, refresh_shutdown)
+                self.domains[domid].update(dom, refresh_shutdown, transaction)
             elif domid not in self.domains and dom['dying'] != 1:
                 try:
                     new_dom = XendDomainInfo.recreate(dom, False)
diff -r 8ca89a9e54a7 tools/python/xen/xend/XendDomainInfo.py
--- a/tools/python/xen/xend/XendDomainInfo.py	Wed Apr 25 09:44:20 2007 +0100
+++ b/tools/python/xen/xend/XendDomainInfo.py	Wed Apr 25 12:55:05 2007 -0400
@@ -704,12 +704,15 @@ class XendDomainInfo:
 
         self._update_consoles()
 
-    def _update_consoles(self):
+    def _update_consoles(self, transaction = None):
         if self.domid == None or self.domid == 0:
             return
 
         # Update VT100 port if it exists
-        self.console_port = self.readDom('console/port')
+        if transaction is None:
+            self.console_port = self.readDom('console/port')
+        else:
+            self.console_port = self.readDomTxn(transaction, 'console/port')
         if self.console_port is not None:
             serial_consoles = self.info.console_get_all('vt100')
             if not serial_consoles:
@@ -722,7 +725,10 @@ class XendDomainInfo:
                 
 
         # Update VNC port if it exists and write to xenstore
-        vnc_port = self.readDom('console/vnc-port')
+        if transaction is None:
+            vnc_port = self.readDom('console/vnc-port')
+        else:
+            vnc_port = self.readDomTxn(transaction, 'console/vnc-port')
         if vnc_port is not None:
             for dev_uuid, (dev_type, dev_info) in self.info['devices'].items():
                 if dev_type == 'vfb':
@@ -757,6 +763,27 @@ class XendDomainInfo:
     def storeVm(self, *args):
         return xstransact.Store(self.vmpath, *args)
 
+
+    def _readVmTxn(self, transaction,  *args):
+        paths = map(lambda x: self.vmpath + "/" + x, args)
+        return transaction.read(*paths)
+
+    def _writeVmTxn(self, transaction,  *args):
+        paths = map(lambda x: self.vmpath + "/" + x, args)
+        return transaction.write(*paths)
+
+    def _removeVmTxn(self, transaction,  *args):
+        paths = map(lambda x: self.vmpath + "/" + x, args)
+        return transaction.remove(*paths)
+
+    def _gatherVmTxn(self, transaction,  *args):
+        paths = map(lambda x: self.vmpath + "/" + x, args)
+        return transaction.gather(paths)
+
+    def storeVmTxn(self, transaction,  *args):
+        paths = map(lambda x: self.vmpath + "/" + x, args)
+        return transaction.store(*paths)
+
     #
     # Function to update xenstore /dom/*
     #
@@ -775,6 +802,28 @@ class XendDomainInfo:
 
     def storeDom(self, *args):
         return xstransact.Store(self.dompath, *args)
+
+
+    def readDomTxn(self, transaction, *args):
+        paths = map(lambda x: self.vmpath + "/" + x, args)
+        return transaction.read(*paths)
+
+    def gatherDomTxn(self, transaction, *args):
+        paths = map(lambda x: self.vmpath + "/" + x, args)
+        return transaction.gather(*paths)
+
+    def _writeDomTxn(self, transaction, *args):
+        paths = map(lambda x: self.vmpath + "/" + x, args)
+        return transaction.write(*paths)
+
+    def _removeDomTxn(self, transaction, *args):
+        paths = map(lambda x: self.vmpath + "/" + x, args)
+        return transaction.remove(*paths)
+
+    def storeDomTxn(self, transaction, *args):
+        paths = map(lambda x: self.vmpath + "/" + x, args)
+        return transaction.store(*paths)
+
 
     def _recreateDom(self):
         complete(self.dompath, lambda t: self._recreateDomFunc(t))
@@ -2062,7 +2111,7 @@ class XendDomainInfo:
                            (" as domain %s" % str(dom.domid)) or ""))
         
 
-    def update(self, info = None, refresh = True):
+    def update(self, info = None, refresh = True, transaction = None):
         """Update with info from xc.domain_getinfo().
         """
         log.trace("XendDomainInfo.update(%s) on domain %s", info,
@@ -2094,7 +2143,7 @@ class XendDomainInfo:
         # TODO: we should eventually get rid of old_dom_states
 
         self.info.update_config(info)
-        self._update_consoles()
+        self._update_consoles(transaction)
         
         if refresh:
             self.refreshShutdown(info)
diff -r 8ca89a9e54a7 tools/python/xen/xend/server/ConsoleController.py
--- a/tools/python/xen/xend/server/ConsoleController.py	Wed Apr 25 09:44:20 2007 +0100
+++ b/tools/python/xen/xend/server/ConsoleController.py	Wed Apr 25 12:57:05 2007 -0400
@@ -19,9 +19,12 @@ class ConsoleController(DevController):
         return (self.allocateDeviceID(), back, {})
 
 
-    def getDeviceConfiguration(self, devid):
-        result = DevController.getDeviceConfiguration(self, devid)
-        devinfo = self.readBackend(devid, *self.valid_cfg)
+    def getDeviceConfiguration(self, devid, transaction = None):
+        result = DevController.getDeviceConfiguration(self, devid, transaction)
+        if transaction is None:
+            devinfo = self.readBackend(devid, *self.valid_cfg)
+        else:
+            devinfo = self.readBackendTxn(transaction, devid, *self.valid_cfg)
         config = dict(zip(self.valid_cfg, devinfo))
         config = dict([(key, val) for key, val in config.items()
                        if val != None])
diff -r 8ca89a9e54a7 tools/python/xen/xend/server/DevController.py
--- a/tools/python/xen/xend/server/DevController.py	Wed Apr 25 09:44:20 2007 +0100
+++ b/tools/python/xen/xend/server/DevController.py	Wed Apr 25 12:57:05 2007 -0400
@@ -225,15 +225,15 @@ class DevController:
 
         self.vm._removeVm("device/%s/%d" % (self.deviceClass, devid))
 
-    def configurations(self):
-        return map(self.configuration, self.deviceIDs())
-
-
-    def configuration(self, devid):
+    def configurations(self, transaction = None):
+        return map(lambda x: self.configuration(x, transaction), self.deviceIDs(transaction))
+
+
+    def configuration(self, devid, transaction = None):
         """@return an s-expression giving the current configuration of the
         specified device.  This would be suitable for giving to {@link
         #createDevice} in order to recreate that device."""
-        configDict = self.getDeviceConfiguration(devid)
+        configDict = self.getDeviceConfiguration(devid, transaction)
         sxpr = [self.deviceClass]
         for key, val in configDict.items():
             if isinstance(val, (types.ListType, types.TupleType)):
@@ -259,13 +259,16 @@ class DevController:
                                    'id', devid]]
 
 
-    def getDeviceConfiguration(self, devid):
+    def getDeviceConfiguration(self, devid, transaction = None):
         """Returns the configuration of a device.
 
         @note: Similar to L{configuration} except it returns a dict.
         @return: dict
         """
-        backdomid = xstransact.Read(self.frontendPath(devid), "backend-id")
+        if transaction is None:
+            backdomid = xstransact.Read(self.frontendPath(devid), "backend-id")
+        else:
+            backdomid = transaction.read(self.frontendPath(devid) + "/backend-id")
         if backdomid is None:
             raise VmError("Device %s not connected" % devid)
 
@@ -393,14 +396,28 @@ class DevController:
         else:
             raise VmError("Device %s not connected" % devid)
 
+    def readBackendTxn(self, transaction, devid, *args):
+        frontpath = self.frontendPath(devid)
+        backpath = transaction.read(frontpath + "/backend")
+        if backpath:
+            paths = map(lambda x: backpath + "/" + x, args)
+            return transaction.read(*paths)
+        else:
+            raise VmError("Device %s not connected" % devid)
+
     def readFrontend(self, devid, *args):
         return xstransact.Read(self.frontendPath(devid), *args)
+
+    def readFrontendTxn(self, transaction, devid, *args):
+        paths = map(lambda x: self.frontendPath(devid) + "/" + x, args)
+        return transaction.read(*paths)
 
     def deviceIDs(self, transaction = None):
         """@return The IDs of each of the devices currently configured for
         this instance's deviceClass.
         """
         fe = self.backendRoot()
+
         if transaction:
             return map(lambda x: int(x.split('/')[-1]), transaction.list(fe))
         else:
diff -r 8ca89a9e54a7 tools/python/xen/xend/server/blkif.py
--- a/tools/python/xen/xend/server/blkif.py	Wed Apr 25 09:44:20 2007 +0100
+++ b/tools/python/xen/xend/server/blkif.py	Wed Apr 25 12:57:05 2007 -0400
@@ -107,19 +107,26 @@ class BlkifController(DevController):
                           (self.deviceClass, devid, config))
 
 
-    def getDeviceConfiguration(self, devid):
+    def getDeviceConfiguration(self, devid, transaction = None):
         """Returns the configuration of a device.
 
         @note: Similar to L{configuration} except it returns a dict.
         @return: dict
         """
-        config = DevController.getDeviceConfiguration(self, devid)
-        devinfo = self.readBackend(devid, 'dev', 'type', 'params', 'mode',
-                                   'uuid')
+        config = DevController.getDeviceConfiguration(self, devid, transaction)
+        if transaction is None:
+            devinfo = self.readBackend(devid, 'dev', 'type', 'params', 'mode',
+                                       'uuid')
+        else:
+            devinfo = self.readBackendTxn(transaction, devid,
+                                          'dev', 'type', 'params', 'mode', 'uuid')
         dev, typ, params, mode, uuid = devinfo
         
         if dev:
-            dev_type = self.readFrontend(devid, 'device-type')
+            if transaction is None:
+                dev_type = self.readFrontend(devid, 'device-type')
+            else:
+                dev_type = self.readFrontendTxn(transaction, devid, 'device-type')
             if dev_type:
                 dev += ':' + dev_type
             config['dev'] = dev
diff -r 8ca89a9e54a7 tools/python/xen/xend/server/netif.py
--- a/tools/python/xen/xend/server/netif.py	Wed Apr 25 09:44:20 2007 +0100
+++ b/tools/python/xen/xend/server/netif.py	Wed Apr 25 12:57:05 2007 -0400
@@ -149,16 +149,19 @@ class NetifController(DevController):
         return (devid, back, front)
 
 
-    def getDeviceConfiguration(self, devid):
+    def getDeviceConfiguration(self, devid, transaction = None):
         """@see DevController.configuration"""
 
-        result = DevController.getDeviceConfiguration(self, devid)
+        result = DevController.getDeviceConfiguration(self, devid, transaction)
 
         config_path = "device/%s/%d/" % (self.deviceClass, devid)
         devinfo = ()
         for x in ( 'script', 'ip', 'bridge', 'mac',
                    'type', 'vifname', 'rate', 'uuid', 'model' ):
-            y = self.vm._readVm(config_path + x)
+            if transaction is None:
+                y = self.vm._readVm(config_path + x)
+            else:
+                y = self.vm._readVmTxn(transaction, config_path + x)
             devinfo += (y,)
         (script, ip, bridge, mac, typ, vifname, rate, uuid, model) = devinfo
 
diff -r 8ca89a9e54a7 tools/python/xen/xend/server/pciif.py
--- a/tools/python/xen/xend/server/pciif.py	Wed Apr 25 09:44:20 2007 +0100
+++ b/tools/python/xen/xend/server/pciif.py	Wed Apr 25 12:57:05 2007 -0400
@@ -78,8 +78,8 @@ class PciController(DevController):
         back['uuid'] = config.get('uuid','')
         return (0, back, {})
 
-    def getDeviceConfiguration(self, devid):
-        result = DevController.getDeviceConfiguration(self, devid)
+    def getDeviceConfiguration(self, devid, transaction = None):
+        result = DevController.getDeviceConfiguration(self, devid, transaction)
         num_devs = self.readBackend(devid, 'num_devs')
         pci_devs = []
         
diff -r 8ca89a9e54a7 tools/python/xen/xend/server/tpmif.py
--- a/tools/python/xen/xend/server/tpmif.py	Wed Apr 25 09:44:20 2007 +0100
+++ b/tools/python/xen/xend/server/tpmif.py	Wed Apr 25 12:57:05 2007 -0400
@@ -67,9 +67,9 @@ class TPMifController(DevController):
 
         return (devid, back, front)
 
-    def getDeviceConfiguration(self, devid):
+    def getDeviceConfiguration(self, devid, transaction = None):
         """Returns the configuration of a device"""
-        result = DevController.getDeviceConfiguration(self, devid)
+        result = DevController.getDeviceConfiguration(self, devid, transaction)
 
         (instance, uuid, type) = \
                            self.readBackend(devid, 'instance',
diff -r 8ca89a9e54a7 tools/python/xen/xend/server/vfbif.py
--- a/tools/python/xen/xend/server/vfbif.py	Wed Apr 25 09:44:20 2007 +0100
+++ b/tools/python/xen/xend/server/vfbif.py	Wed Apr 25 12:57:05 2007 -0400
@@ -35,10 +35,13 @@ class VfbifController(DevController):
         return (devid, back, {})
 
 
-    def getDeviceConfiguration(self, devid):
-        result = DevController.getDeviceConfiguration(self, devid)
+    def getDeviceConfiguration(self, devid, transaction = None):
+        result = DevController.getDeviceConfiguration(self, devid, transaction)
 
-        devinfo = self.readBackend(devid, *CONFIG_ENTRIES)
+        if transaction is None:
+            devinfo = self.readBackend(devid, *CONFIG_ENTRIES)
+        else:
+            devinfo = self.readBackendTxn(transaction, devid, *CONFIG_ENTRIES)
         return dict([(CONFIG_ENTRIES[i], devinfo[i])
                      for i in range(len(CONFIG_ENTRIES))
                      if devinfo[i] is not None])

[-- Attachment #3: Type: text/plain, Size: 138 bytes --]

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xensource.com
http://lists.xensource.com/xen-devel