Merge lp:~jk0/nova/diagnostics-per-instance into lp:~hudson-openstack/nova/trunk

[Josh Kearney]

Log all XenAPI actions to InstanceActions.

[lp:~jk0/nova/diagnostics-per-instance]

475. By Josh Kearney on 2010-12-21

Filter templates and dom0 from list_instances()

476. By Josh Kearney on 2010-12-21

Style correction

477. By Josh Kearney on 2010-12-21

Merged trunk

478. By Josh Kearney on 2010-12-22

Merged trunk

[Ed Leafe (ed-leafe)]

Looks good.

review: Approve

[Rick Clark (dendrobates)]

lgtm and tests pass

review: Approve

[Eric Day (eday)]

How is the diagnostics data intended to be pulled out and analyzed? Right now it looks like it's only being stored, but there is no API or tools to read it.

Part of my concern with this and the previous branch sticking it into the same core database is that this seems like more of a logging hook, where you could push to some plugin interface, and then write implementations to a queue, another DB with monitoring, etc. It would be great to see more design details around how this data will be accessed and the use cases behind them before we start sticking it all in the DB.

review: Needs Information

[Josh Kearney (jk0)]

> How is the diagnostics data intended to be pulled out and analyzed? Right now
> it looks like it's only being stored, but there is no API or tools to read it.

Currently there is no way to retrieve the data short of making calls directly in SQL (that is my project today -- making this available via the API). My thoughts were to propose these merges in small steps instead of one big chunk, getting lots of good feedback along the way.

> Part of my concern with this and the previous branch sticking it into the same
> core database is that this seems like more of a logging hook, where you could
> push to some plugin interface, and then write implementations to a queue,
> another DB with monitoring, etc. It would be great to see more design details
> around how this data will be accessed and the use cases behind them before we
> start sticking it all in the DB.

I'm just going off of what the blueprint wants for now. I agree that this might not be the best way to store the data, but it's easy enough to change once the distributed data store design is in place. Otherwise I just don't see this getting done in time for Bexar.

[Sandy Walsh (sandy-walsh)]

Would like to see tests around _poll_task calling done.send_exception(XenAPI.Failure(error_info)) to ensure the action gets logged. This is independent of the pending xenserver tests.

If the len(action) > 255, will this bust the operation? Shouldn't just the logging fail, but the action complete?

Perhaps more of general question, but should there be an error code on failures?

=== modified file 'nova/db/api.py'
--- nova/db/api.py	2010-11-03 22:06:00 +0000
+++ nova/db/api.py	2010-12-22 16:46:27 +0000
@@ -334,6 +334,11 @@
                                             security_group_id)
 
 
+def instance_action_create(context, values):
+    """Create an instance action from the values dictionary."""
+    return IMPL.instance_action_create(context, values)
+
+
 ###################
 
 

=== modified file 'nova/db/sqlalchemy/api.py'
--- nova/db/sqlalchemy/api.py	2010-12-21 15:25:39 +0000
+++ nova/db/sqlalchemy/api.py	2010-12-22 16:46:27 +0000
@@ -749,6 +749,18 @@
         instance_ref.save(session=session)
 
 
+@require_context
+def instance_action_create(context, values):
+    """Create an instance action from the values dictionary."""
+    action_ref = models.InstanceActions()
+    action_ref.update(values)
+
+    session = get_session()
+    with session.begin():
+        action_ref.save(session=session)
+    return action_ref
+
+
 ###################
 
 

=== modified file 'nova/db/sqlalchemy/models.py'
--- nova/db/sqlalchemy/models.py	2010-12-20 20:21:01 +0000
+++ nova/db/sqlalchemy/models.py	2010-12-22 16:46:27 +0000
@@ -248,7 +248,6 @@
     instance_id = Column(Integer, ForeignKey('instances.id'))
 
     action = Column(String(255))
-    result = Column(Boolean)
     error = Column(Text)
 
 

=== modified file 'nova/tests/virt_unittest.py'
--- nova/tests/virt_unittest.py	2010-12-17 12:07:43 +0000
+++ nova/tests/virt_unittest.py	2010-12-22 16:46:27 +0000
@@ -129,43 +129,45 @@
                 check_list.append(check)
             else:
                 if expect_kernel:
-                    check = (lambda t: t.find('./os/kernel').text.split('/'
-                                       )[1], 'kernel')
+                    check = (lambda t: t.find('./os/kernel').text.split(
+                        '/')[1], 'kernel')
                 else:
                     check = (lambda t: t.find('./os/kernel'), None)
                 check_list.append(check)
 
                 if expect_ramdisk:
-                    check = (lambda t: t.find('./os/initrd').text.split('/'
-                                       )[1], 'ramdisk')
+                    check = (lambda t: t.find('./os/initrd').text.split(
+                        '/')[1], 'ramdisk')
                 else:
                     check = (lambda t: t.find('./os/initrd'), None)
                 check_list.append(check)
 
         common_checks = [
             (lambda t: t.find('.').tag, 'domain'),
-            (lambda t: t.find('./devices/interface/filterref/parameter'
-                        ).get('name'), 'IP'),
-            (lambda t: t.find('./devices/interface/filterref/parameter'
-                       ).get('value'), '10.11.12.13'),
-            (lambda t: t.findall('./devices/interface/filterref/parameter'
-                        )[1].get('name'), 'DHCPSERVER'),
-            (lambda t: t.findall('./devices/interface/filterref/parameter'
-                       )[1].get('value'), '10.0.0.1'),
-            (lambda t: t.find('./devices/serial/source').get('path'
-                       ).split('/')[1], 'console.log'),
+            (lambda t: t.find(
+                './devices/interface/filterref/parameter').get('name'), 'IP'),
+            (lambda t: t.find(
+                './devices/interface/filterref/parameter').get(
+                    'value'), '10.11.12.13'),
+            (lambda t: t.findall(
+                './devices/interface/filterref/parameter')[1].get(
+                    'name'), 'DHCPSERVER'),
+            (lambda t: t.findall(
+                './devices/interface/filterref/parameter')[1].get(
+                    'value'), '10.0.0.1'),
+            (lambda t: t.find('./devices/serial/source').get(
+                'path').split('/')[1], 'console.log'),
             (lambda t: t.find('./memory').text, '2097152')]
 
         if rescue:
-            common_checks += [(lambda t: t.findall('./devices/disk/source'
-                                         )[0].get('file').split('/')[1],
-                               'rescue-disk'),
-                              (lambda t: t.findall('./devices/disk/source'
-                                         )[1].get('file').split('/')[1],
-                               'disk')]
+            common_checks += [
+                (lambda t: t.findall('./devices/disk/source')[0].get(
+                    'file').split('/')[1], 'rescue-disk'),
+                (lambda t: t.findall('./devices/disk/source')[1].get(
+                    'file').split('/')[1], 'disk')]
         else:
-            common_checks += [(lambda t: t.findall('./devices/disk/source'
-                                         )[0].get('file').split('/')[1],
+            common_checks += [(lambda t: t.findall(
+                './devices/disk/source')[0].get('file').split('/')[1],
                                'disk')]
 
         for (libvirt_type, (expected_uri, checks)) in type_uri_map.iteritems():

=== modified file 'nova/virt/xenapi/vmops.py'
--- nova/virt/xenapi/vmops.py	2010-12-15 18:19:39 +0000
+++ nova/virt/xenapi/vmops.py	2010-12-22 16:46:27 +0000
@@ -44,12 +44,16 @@
         VMHelper.late_import()
 
     def list_instances(self):
-        """ List VM instances """
-        return [self._session.get_xenapi().VM.get_name_label(vm) \
-                for vm in self._session.get_xenapi().VM.get_all()]
+        """List VM instances"""
+        vms = []
+        for vm in self._session.get_xenapi().VM.get_all():
+            rec = self._session.get_xenapi().VM.get_record(vm)
+            if not rec["is_a_template"] and not rec["is_control_domain"]:
+                vms.append(rec["name_label"])
+        return vms
 
     def spawn(self, instance):
-        """ Create VM instance """
+        """Create VM instance"""
         vm = VMHelper.lookup(self._session, instance.name)
         if vm is not None:
             raise Exception('Attempted to create non-unique name %s' %
@@ -81,16 +85,16 @@
                      vm_ref)
 
     def reboot(self, instance):
-        """ Reboot VM instance """
+        """Reboot VM instance"""
         instance_name = instance.name
         vm = VMHelper.lookup(self._session, instance_name)
         if vm is None:
             raise Exception('instance not present %s' % instance_name)
         task = self._session.call_xenapi('Async.VM.clean_reboot', vm)
-        self._session.wait_for_task(task)
+        self._session.wait_for_task(instance.id, task)
 
     def destroy(self, instance):
-        """ Destroy VM instance """
+        """Destroy VM instance"""
         vm = VMHelper.lookup(self._session, instance.name)
         if vm is None:
             # Don't complain, just return.  This lets us clean up instances
@@ -101,7 +105,7 @@
         try:
             task = self._session.call_xenapi('Async.VM.hard_shutdown',
                                                    vm)
-            self._session.wait_for_task(task)
+            self._session.wait_for_task(instance.id, task)
         except XenAPI.Failure, exc:
             logging.warn(exc)
         # Disk clean-up
@@ -109,43 +113,43 @@
             for vdi in vdis:
                 try:
                     task = self._session.call_xenapi('Async.VDI.destroy', vdi)
-                    self._session.wait_for_task(task)
+                    self._session.wait_for_task(instance.id, task)
                 except XenAPI.Failure, exc:
                     logging.warn(exc)
         try:
             task = self._session.call_xenapi('Async.VM.destroy', vm)
-            self._session.wait_for_task(task)
+            self._session.wait_for_task(instance.id, task)
         except XenAPI.Failure, exc:
             logging.warn(exc)
 
-    def _wait_with_callback(self, task, callback):
+    def _wait_with_callback(self, instance_id, task, callback):
         ret = None
         try:
-            ret = self._session.wait_for_task(task)
+            ret = self._session.wait_for_task(instance_id, task)
         except XenAPI.Failure, exc:
             logging.warn(exc)
         callback(ret)
 
     def pause(self, instance, callback):
-        """ Pause VM instance """
+        """Pause VM instance"""
         instance_name = instance.name
         vm = VMHelper.lookup(self._session, instance_name)
         if vm is None:
             raise Exception('instance not present %s' % instance_name)
         task = self._session.call_xenapi('Async.VM.pause', vm)
-        self._wait_with_callback(task, callback)
+        self._wait_with_callback(instance.id, task, callback)
 
     def unpause(self, instance, callback):
-        """ Unpause VM instance """
+        """Unpause VM instance"""
         instance_name = instance.name
         vm = VMHelper.lookup(self._session, instance_name)
         if vm is None:
             raise Exception('instance not present %s' % instance_name)
         task = self._session.call_xenapi('Async.VM.unpause', vm)
-        self._wait_with_callback(task, callback)
+        self._wait_with_callback(instance.id, task, callback)
 
     def get_info(self, instance_id):
-        """ Return data about VM instance """
+        """Return data about VM instance"""
         vm = VMHelper.lookup_blocking(self._session, instance_id)
         if vm is None:
             raise Exception('instance not present %s' % instance_id)
@@ -161,6 +165,6 @@
         return VMHelper.compile_diagnostics(self._session, rec)
 
     def get_console_output(self, instance):
-        """ Return snapshot of console """
+        """Return snapshot of console"""
         # TODO: implement this to fix pylint!
         return 'FAKE CONSOLE OUTPUT of instance'

=== modified file 'nova/virt/xenapi_conn.py'
--- nova/virt/xenapi_conn.py	2010-12-21 15:25:39 +0000
+++ nova/virt/xenapi_conn.py	2010-12-22 16:46:27 +0000
@@ -54,6 +54,8 @@
 from eventlet import event
 from eventlet import tpool
 
+from nova import context
+from nova import db
 from nova import utils
 from nova import flags
 from nova.virt.xenapi.vmops import VMOps
@@ -101,7 +103,7 @@
 
 
 class XenAPIConnection(object):
-    """ A connection to XenServer or Xen Cloud Platform """
+    """A connection to XenServer or Xen Cloud Platform"""
 
     def __init__(self, url, user, pw):
         session = XenAPISession(url, user, pw)
@@ -109,31 +111,31 @@
         self._volumeops = VolumeOps(session)
 
     def list_instances(self):
-        """ List VM instances """
+        """List VM instances"""
         return self._vmops.list_instances()
 
     def spawn(self, instance):
-        """ Create VM instance """
+        """Create VM instance"""
         self._vmops.spawn(instance)
 
     def reboot(self, instance):
-        """ Reboot VM instance """
+        """Reboot VM instance"""
         self._vmops.reboot(instance)
 
     def destroy(self, instance):
-        """ Destroy VM instance """
+        """Destroy VM instance"""
         self._vmops.destroy(instance)
 
     def pause(self, instance, callback):
-        """ Pause VM instance """
+        """Pause VM instance"""
         self._vmops.pause(instance, callback)
 
     def unpause(self, instance, callback):
-        """ Unpause paused VM instance """
+        """Unpause paused VM instance"""
         self._vmops.unpause(instance, callback)
 
     def get_info(self, instance_id):
-        """ Return data about VM instance """
+        """Return data about VM instance"""
         return self._vmops.get_info(instance_id)
 
     def get_diagnostics(self, instance_id):
@@ -141,33 +143,33 @@
         return self._vmops.get_diagnostics(instance_id)
 
     def get_console_output(self, instance):
-        """ Return snapshot of console """
+        """Return snapshot of console"""
         return self._vmops.get_console_output(instance)
 
     def attach_volume(self, instance_name, device_path, mountpoint):
-        """ Attach volume storage to VM instance """
+        """Attach volume storage to VM instance"""
         return self._volumeops.attach_volume(instance_name,
                                                device_path,
                                                mountpoint)
 
     def detach_volume(self, instance_name, mountpoint):
-        """ Detach volume storage to VM instance """
+        """Detach volume storage to VM instance"""
         return self._volumeops.detach_volume(instance_name, mountpoint)
 
 
 class XenAPISession(object):
-    """ The session to invoke XenAPI SDK calls """
+    """The session to invoke XenAPI SDK calls"""
 
     def __init__(self, url, user, pw):
         self._session = XenAPI.Session(url)
         self._session.login_with_password(user, pw)
 
     def get_xenapi(self):
-        """ Return the xenapi object """
+        """Return the xenapi object"""
         return self._session.xenapi
 
     def get_xenapi_host(self):
-        """ Return the xenapi host """
+        """Return the xenapi host"""
         return self._session.xenapi.session.get_this_host(self._session.handle)
 
     def call_xenapi(self, method, *args):
@@ -183,42 +185,53 @@
                              self._session.xenapi.Async.host.call_plugin,
                              self.get_xenapi_host(), plugin, fn, args)
 
-    def wait_for_task(self, task):
+    def wait_for_task(self, instance_id, task):
         """Return a Deferred that will give the result of the given task.
         The task is polled until it completes."""
 
         done = event.Event()
-        loop = utils.LoopingCall(self._poll_task, task, done)
+        loop = utils.LoopingCall(self._poll_task, instance_id, task, done)
         loop.start(FLAGS.xenapi_task_poll_interval, now=True)
         rv = done.wait()
         loop.stop()
         return rv
 
-    def _poll_task(self, task, done):
+    def _poll_task(self, instance_id, task, done):
         """Poll the given XenAPI task, and fire the given Deferred if we
         get a result."""
         try:
-            #logging.debug('Polling task %s...', task)
+            name = self._session.xenapi.task.get_name_label(task)
             status = self._session.xenapi.task.get_status(task)
-            if status == 'pending':
+            action = dict(
+                instance_id=int(instance_id),
+                action=name,
+                error=None)
+            if status == "pending":
                 return
-            elif status == 'success':
+            elif status == "success":
                 result = self._session.xenapi.task.get_result(task)
-                logging.info(_('Task %s status: success.  %s'), task, result)
+                logging.info(_("Task [%s] %s status: success    %s") % (
+                    name,
+                    task,
+                    result))
                 done.send(_parse_xmlrpc_value(result))
             else:
                 error_info = self._session.xenapi.task.get_error_info(task)
-                logging.warn(_('Task %s status: %s.  %s'), task, status,
-                             error_info)
+                action["error"] = str(error_info)
+                logging.warn(_("Task [%s] %s status: %s    %s") % (
+                    name,
+                    task,
+                    status,
+                    error_info))
                 done.send_exception(XenAPI.Failure(error_info))
-                #logging.debug('Polling task %s done.', task)
+            db.instance_action_create(context.get_admin_context(), action)
         except XenAPI.Failure, exc:
             logging.warn(exc)
             done.send_exception(*sys.exc_info())
 
 
 def _unwrap_plugin_exceptions(func, *args, **kwargs):
-    """ Parse exception details """
+    """Parse exception details"""
     try:
         return func(*args, **kwargs)
     except XenAPI.Failure, exc: