Merge lp:~andreserl/maas/lp1604962_lp1604987 into lp:~maas-committers/maas/trunk

[Andres Rodriguez]

Fixes to correctly log cloud-init/curtin FAIL events in the node event log.

Fixes to correctly log "mark_failed" events. We did this by combining the mark_failed with _mark_failed functions, provided that the latter wasn't really storing anything in the event log and it should. It now differentiates between a user driven "Mark Failed" vs a system driven.

[Gavin Panella (allenap)]

Looks good, with a few minor comments.

review: Approve

[MAAS Lander (maas-lander)]

The attempt to merge lp:~andreserl/maas/lp1604962_lp1604987 into lp:maas failed. Below is the output from the failed tests.

Hit:1 http://security.ubuntu.com/ubuntu xenial-security InRelease
Hit:2 http://prodstack-zone-2.clouds.archive.ubuntu.com/ubuntu xenial InRelease
Get:3 http://prodstack-zone-2.clouds.archive.ubuntu.com/ubuntu xenial-updates InRelease [95.7 kB]
Hit:4 http://prodstack-zone-2.clouds.archive.ubuntu.com/ubuntu xenial-backports InRelease
Fetched 95.7 kB in 0s (193 kB/s)
Reading package lists...
sudo DEBIAN_FRONTEND=noninteractive apt-get -y \
    --no-install-recommends install apache2 archdetect-deb authbind bash bind9 bind9utils build-essential bzr bzr-builddeb chromium-browser chromium-chromedriver curl daemontools debhelper dh-apport dh-systemd distro-info dnsutils firefox freeipmi-tools git gjs ipython isc-dhcp-common libjs-angularjs libjs-jquery libjs-jquery-hotkeys libjs-yui3-full libjs-yui3-min libpq-dev make nodejs-legacy npm postgresql pxelinux python3-all python3-apt python3-bson python3-convoy python3-crochet python3-cssselect python3-curtin python3-dev python3-distro-info python3-django python3-django-nose python3-django-piston3 python3-dnspython python3-docutils python3-formencode python3-hivex python3-httplib2 python3-jinja2 python3-jsonschema python3-lxml python3-netaddr python3-netifaces python3-novaclient python3-oauth python3-oauthlib python3-openssl python3-paramiko python3-petname python3-pexpect python3-psycopg2 python3-pyinotify python3-pyparsing python3-pyvmomi python3-requests python3-seamicroclient python3-setuptools python3-simplestreams python3-sphinx python3-tempita python3-twisted python3-txtftp python3-tz python3-yaml python3-zope.interface python-bson python-crochet python-django python-django-piston python-djorm-ext-pgarray python-formencode python-lxml python-netaddr python-netifaces python-pocket-lint python-psycopg2 python-simplejson python-tempita python-twisted python-yaml socat syslinux-common tgt ubuntu-cloudimage-keyring wget xvfb
Reading package lists...
Building dependency tree...
Reading state information...
archdetect-deb is already the newest version (1.117ubuntu2).
authbind is already the newest version (2.1.1+nmu1).
build-essential is already the newest version (12.1ubuntu2).
curl is already the newest version (7.47.0-1ubuntu2).
debhelper is already the newest version (9.20160115ubuntu3).
distro-info is already the newest version (0.14build1).
freeipmi-tools is already the newest version (1.4.11-1ubuntu1).
git is already the newest version (1:2.7.4-0ubuntu1).
libjs-angularjs is already the newest version (1.2.28-1ubuntu2).
libjs-jquery is already the newest version (1.11.3+dfsg-4).
libjs-yui3-full is already the newest version (3.5.1-1ubuntu3).
libjs-yui3-min is already the newest version (3.5.1-1ubuntu3).
make is already the newest version (4.1-6).
postgresql is already the newest version (9.5+173).
pxelinux is already the newest version (3:6.03+dfsg-11ubuntu1).
python-formencode is already the newest version (1.3.0-0ubuntu5).
python-lxml is already the newest version (3.5.0-1build1).
python-netaddr is already the newest version (0.7.18-1).
python-netifaces is already the newes...

[MAAS Lander (maas-lander)]

The attempt to merge lp:~andreserl/maas/lp1604962_lp1604987 into lp:maas failed. Below is the output from the failed tests.

Get:1 http://security.ubuntu.com/ubuntu xenial-security InRelease [94.5 kB]
Hit:2 http://prodstack-zone-2.clouds.archive.ubuntu.com/ubuntu xenial InRelease
Get:3 http://prodstack-zone-2.clouds.archive.ubuntu.com/ubuntu xenial-updates InRelease [95.7 kB]
Hit:4 http://prodstack-zone-2.clouds.archive.ubuntu.com/ubuntu xenial-backports InRelease
Get:5 http://security.ubuntu.com/ubuntu xenial-security/universe Sources [8,948 B]
Get:6 http://security.ubuntu.com/ubuntu xenial-security/universe amd64 Packages [36.4 kB]
Get:7 http://security.ubuntu.com/ubuntu xenial-security/universe Translation-en [22.0 kB]
Fetched 257 kB in 0s (529 kB/s)
Reading package lists...
sudo DEBIAN_FRONTEND=noninteractive apt-get -y \
    --no-install-recommends install apache2 archdetect-deb authbind bash bind9 bind9utils build-essential bzr bzr-builddeb chromium-browser chromium-chromedriver curl daemontools debhelper dh-apport dh-systemd distro-info dnsutils firefox freeipmi-tools git gjs ipython isc-dhcp-common libjs-angularjs libjs-jquery libjs-jquery-hotkeys libjs-yui3-full libjs-yui3-min libpq-dev make nodejs-legacy npm postgresql pxelinux python3-all python3-apt python3-bson python3-convoy python3-crochet python3-cssselect python3-curtin python3-dev python3-distro-info python3-django python3-django-nose python3-django-piston3 python3-dnspython python3-docutils python3-formencode python3-hivex python3-httplib2 python3-jinja2 python3-jsonschema python3-lxml python3-netaddr python3-netifaces python3-novaclient python3-oauth python3-oauthlib python3-openssl python3-paramiko python3-petname python3-pexpect python3-psycopg2 python3-pyinotify python3-pyparsing python3-pyvmomi python3-requests python3-seamicroclient python3-setuptools python3-simplestreams python3-sphinx python3-tempita python3-twisted python3-txtftp python3-tz python3-yaml python3-zope.interface python-bson python-crochet python-django python-django-piston python-djorm-ext-pgarray python-formencode python-lxml python-netaddr python-netifaces python-pocket-lint python-psycopg2 python-simplejson python-tempita python-twisted python-yaml socat syslinux-common tgt ubuntu-cloudimage-keyring wget xvfb
Reading package lists...
Building dependency tree...
Reading state information...
archdetect-deb is already the newest version (1.117ubuntu2).
authbind is already the newest version (2.1.1+nmu1).
build-essential is already the newest version (12.1ubuntu2).
curl is already the newest version (7.47.0-1ubuntu2).
debhelper is already the newest version (9.20160115ubuntu3).
distro-info is already the newest version (0.14build1).
freeipmi-tools is already the newest version (1.4.11-1ubuntu1).
git is already the newest version (1:2.7.4-0ubuntu1).
libjs-angularjs is already the newest version (1.2.28-1ubuntu2).
libjs-jquery is already the newest version (1.11.3+dfsg-4).
libjs-yui3-full is already the newest version (3.5.1-1ubuntu3).
libjs-yui3-min is already the newest version (3.5.1-1ubuntu3).
make is already the newest version (4.1-6).
postgresql is already the newest version (9.5+173).
pxelinux is...

[MAAS Lander (maas-lander)]

There are additional revisions which have not been approved in review. Please seek review and approval of these new revisions.

[Andres Rodriguez (andreserl)]

review: Approve

=== modified file 'src/maasserver/models/node.py'
--- src/maasserver/models/node.py	2016-07-21 23:33:35 +0000
+++ src/maasserver/models/node.py	2016-07-25 22:18:24 +0000
@@ -1132,20 +1132,29 @@
 
     def _register_request_event(
             self, user, type_name, action='', comment=None):
-        """Register a node user request event."""
-        # don't register system generated non-user requests
+        """Register a node request event.
+
+        It registers events like start_commission (started by a user),
+        or mark_failed (started by the system)"""
+
+        # the description will be the comment, if any.
+        description = comment if comment else ''
+        # if the user exists, we need to construct the description with
+        # the user. as it would be a user-driven request.
         if user is not None:
-            event_details = EVENT_DETAILS[type_name]
-            description = "(%s)" % user.username
-            if comment:
-                description = "%s - %s" % (description, comment)
-            # Avoid circular imports.
-            from maasserver.models.event import Event
-            Event.objects.register_event_and_event_type(
-                self.system_id, type_name, type_level=event_details.level,
-                type_description=event_details.description,
-                event_action=action,
-                event_description=description)
+            if len(description) == 0:
+                description = "(%s)" % user
+            else:
+                description = "(%s) - %s" % (user, description)
+        event_details = EVENT_DETAILS[type_name]
+
+        # Avoid circular imports.
+        from maasserver.models.event import Event
+        Event.objects.register_event_and_event_type(
+            self.system_id, type_name, type_level=event_details.level,
+            type_description=event_details.description,
+            event_action=action,
+            event_description=description)
 
     def storage_layout_issues(self):
         """Return any errors with the storage layout.
@@ -2408,18 +2417,22 @@
         arch, subarch = self.architecture.split('/')
         return (arch, subarch)
 
-    def mark_failed(self, user, comment=None):
-        self._register_request_event(
-            user, EVENT_TYPES.REQUEST_NODE_MARK_FAILED, action='mark_failed',
-            comment=comment)
-        self._mark_failed(user, comment)
-
-    def _mark_failed(self, user, comment=None, commit=True):
+    def mark_failed(self, user=None, comment=None, commit=True):
         """Mark this node as failed.
 
         The actual 'failed' state depends on the current status of the
         node.
         """
+        if user is None:
+            # This is a system-driven event. Log level is ERROR.
+            event_type = EVENT_TYPES.REQUEST_NODE_MARK_FAILED_SYSTEM
+        else:
+            # This is a user-driven event. Log level is INFO.
+            event_type = EVENT_TYPES.REQUEST_NODE_MARK_FAILED
+        self._register_request_event(
+            user, event_type, action='mark_failed',
+            comment=comment)
+
         new_status = get_failed_status(self.status)
         if new_status is not None:
             self.status = new_status
 
=== modified file 'src/maasserver/models/tests/test_node.py'
--- src/maasserver/models/tests/test_node.py	2016-07-18 20:06:21 +0000
+++ src/maasserver/models/tests/test_node.py	2016-07-25 22:18:24 +0000
@@ -3148,14 +3148,23 @@
             event_action=event_action,
             event_description=event_description))
 
-    def test__register_request_event_with_none_user_saves_no_event(self):
+    def test__register_request_event_none_user_saves_comment_not_user(self):
         node = factory.make_Node()
         log_mock = self.patch_autospec(
             Event.objects, 'register_event_and_event_type')
         event_name = EVENT_TYPES.REQUEST_NODE_START
+        event_action = factory.make_name('action')
+        event_details = EVENT_DETAILS[event_name]
         comment = factory.make_name("comment")
-        node._register_request_event(None, event_name, comment)
-        self.assertThat(log_mock, MockNotCalled())
+        event_description = "%s" % (comment)
+        node._register_request_event(None, event_name, event_action, comment)
+        self.assertThat(log_mock, MockCalledOnceWith(
+            node.system_id,
+            EVENT_TYPES.REQUEST_NODE_START,
+            type_level=event_details.level,
+            type_description=event_details.description,
+            event_action=event_action,
+            event_description=event_description))
 
     def test__status_message_returns_most_recent_event(self):
         # The first event won't be returned.
 
=== modified file 'src/maasserver/rpc/nodes.py'
--- src/maasserver/rpc/nodes.py	2016-05-11 00:25:14 +0000
+++ src/maasserver/rpc/nodes.py	2016-07-25 22:18:24 +0000
@@ -49,7 +49,7 @@
     except Node.DoesNotExist:
         raise NoSuchNode.from_system_id(system_id)
     try:
-        node.mark_failed(None, error_description)
+        node.mark_failed(comment=error_description)
     except exceptions.NodeStateViolation as e:
         raise NodeStateViolation(e)
 
 
=== modified file 'src/maasserver/status_monitor.py'
--- src/maasserver/status_monitor.py	2016-07-22 14:41:58 +0000
+++ src/maasserver/status_monitor.py	2016-07-25 22:18:24 +0000
@@ -43,7 +43,7 @@
             NODE_STATUS_CHOICES_DICT[node.status],
             NODE_FAILURE_MONITORED_STATUS_TIMEOUTS[node.status],
             )
-        node._mark_failed(None, commit=False, comment=comment)
+        node.mark_failed(commit=False, comment=comment)
         node.status_expires = None
         node.save()
 
 
=== modified file 'src/metadataserver/api.py'
--- src/metadataserver/api.py	2016-07-22 00:41:50 +0000
+++ src/metadataserver/api.py	2016-07-25 22:18:24 +0000
@@ -157,12 +157,19 @@
         raise UnknownMetadataVersion("Unknown metadata version: %s" % version)
 
 
-def add_event_to_node_event_log(node, origin, action, description):
+def add_event_to_node_event_log(
+        node, origin, action, description, result=None):
     """Add an entry to the node's event log."""
     if node.status == NODE_STATUS.COMMISSIONING:
-        type_name = EVENT_TYPES.NODE_COMMISSIONING_EVENT
+        if result in ['SUCCESS', None]:
+            type_name = EVENT_TYPES.NODE_COMMISSIONING_EVENT
+        else:
+            type_name = EVENT_TYPES.NODE_COMMISSIONING_EVENT_FAILED
     elif node.status == NODE_STATUS.DEPLOYING:
-        type_name = EVENT_TYPES.NODE_INSTALL_EVENT
+        if result in ['SUCCESS', None]:
+            type_name = EVENT_TYPES.NODE_INSTALL_EVENT
+        else:
+            type_name = EVENT_TYPES.NODE_INSTALL_EVENT_FAILED
     elif node.node_type in [
             NODE_TYPE.RACK_CONTROLLER,
             NODE_TYPE.REGION_AND_RACK_CONTROLLER]:
@@ -327,7 +334,8 @@
         result = message.get('result')
 
         # Add this event to the node event log.
-        add_event_to_node_event_log(node, origin, activity_name, description)
+        add_event_to_node_event_log(
+            node, origin, activity_name, description, result)
 
         # Save attached files, if any.
         for sent_file in message.get('files', []):
@@ -358,12 +366,11 @@
             elif node.status == NODE_STATUS.DEPLOYING:
                 if result in ['FAIL', 'FAILURE']:
                     node.mark_failed(
-                        None,
-                        "Installation failed (refer to the "
-                        "installation log for more information).")
+                        comment="Installation failed (refer to the "
+                                "installation log for more information).")
             elif node.status == NODE_STATUS.DISK_ERASING:
                 if result in ['FAIL', 'FAILURE']:
-                    node.mark_failed(None, "Failed to erase disks.")
+                    node.mark_failed(comment="Failed to erase disks.")
 
             # Deallocate the node if we enter any terminal state.
             if node.node_type == NODE_TYPE.MACHINE and node.status in [
@@ -530,16 +537,15 @@
             self._store_installation_results(node, request)
             if status == SIGNAL_STATUS.FAILED:
                 node.mark_failed(
-                    None,
-                    "Installation failed (refer to the "
-                    "installation log for more information).")
+                    comment="Installation failed (refer to the "
+                            "installation log for more information).")
             target_status = None
         elif node.status == NODE_STATUS.DISK_ERASING:
             if status == SIGNAL_STATUS.OK:
                 # disk erasing complete, release node
                 node.release()
             elif status == SIGNAL_STATUS.FAILED:
-                node.mark_failed(None, "Failed to erase disks.")
+                node.mark_failed(comment="Failed to erase disks.")
             target_status = None
 
         if target_status in (None, node.status):
 
=== modified file 'src/metadataserver/tests/test_api_status.py'
--- src/metadataserver/tests/test_api_status.py	2016-06-11 23:58:38 +0000
+++ src/metadataserver/tests/test_api_status.py	2016-07-25 22:18:24 +0000
@@ -193,7 +193,8 @@
             NODE_STATUS.FAILED_DEPLOYMENT, reload_object(node).status)
         # Check last node event.
         self.assertEqual(
-            "'curtin' Command Install",
+            "Installation failed (refer to the installation"
+            " log for more information).",
             Event.objects.filter(node=node).last().description)
 
     def test_status_installation_fail_leaves_node_failed(self):
@@ -212,7 +213,8 @@
             NODE_STATUS.FAILED_DEPLOYMENT, reload_object(node).status)
         # Check last node event.
         self.assertEqual(
-            "'curtin' Command Install",
+            "Installation failed (refer to the installation"
+            " log for more information).",
             Event.objects.filter(node=node).last().description)
 
     def test_status_installation_failure_doesnt_clear_owner(self):
@@ -270,7 +272,7 @@
             NODE_STATUS.FAILED_DISK_ERASING, reload_object(node).status)
         # Check last node event.
         self.assertEqual(
-            "'curtin' Erasing disk",
+            "Failed to erase disks.",
             Event.objects.filter(node=node).last().description)
 
     def test_status_erasure_failure_does_not_populate_tags(self):
 
=== modified file 'src/provisioningserver/events.py'
--- src/provisioningserver/events.py	2016-07-13 19:03:15 +0000
+++ src/provisioningserver/events.py	2016-07-25 22:18:24 +0000
@@ -66,7 +66,9 @@
     # Node status events
     NODE_STATUS_EVENT = "NODE_STATUS_EVENT"
     NODE_COMMISSIONING_EVENT = "NODE_COMMISSIONING_EVENT"
+    NODE_COMMISSIONING_EVENT_FAILED = "NODE_COMMISSIONING_EVENT_FAILED"
     NODE_INSTALL_EVENT = "NODE_INSTALL_EVENT"
+    NODE_INSTALL_EVENT_FAILED = "NODE_INSTALL_EVENT_FAILED"
     # Node user request events
     REQUEST_NODE_START_COMMISSIONING = "REQUEST_NODE_START_COMMISSIONING"
     REQUEST_NODE_ABORT_COMMISSIONING = "REQUEST_NODE_ABORT_COMMISSIONING"
@@ -76,6 +78,7 @@
     REQUEST_NODE_ABORT_ERASE_DISK = "REQUEST_NODE_ABORT_ERASE_DISK"
     REQUEST_NODE_RELEASE = "REQUEST_NODE_RELEASE"
     REQUEST_NODE_MARK_FAILED = "REQUEST_NODE_MARK_FAILED"
+    REQUEST_NODE_MARK_FAILED_SYSTEM = "REQUEST_NODE_MARK_FAILED_SYSTEM"
     REQUEST_NODE_MARK_BROKEN = "REQUEST_NODE_MARK_BROKEN"
     REQUEST_NODE_MARK_FIXED = "REQUEST_NODE_MARK_FIXED"
     REQUEST_NODE_START_DEPLOYMENT = "REQUEST_NODE_START_DEPLOYMENT"
@@ -151,10 +154,18 @@
         description="Node commissioning",
         level=DEBUG,
     ),
+    EVENT_TYPES.NODE_COMMISSIONING_EVENT_FAILED: EventDetail(
+        description="Node commissioning failure",
+        level=ERROR,
+    ),
     EVENT_TYPES.NODE_INSTALL_EVENT: EventDetail(
         description="Node installation",
         level=DEBUG,
     ),
+    EVENT_TYPES.NODE_INSTALL_EVENT_FAILED: EventDetail(
+        description="Node installation failure",
+        level=ERROR,
+    ),
     EVENT_TYPES.REQUEST_NODE_START_COMMISSIONING: EventDetail(
         description="User starting node commissioning",
         level=INFO,
@@ -187,6 +198,10 @@
         description="User marking node failed",
         level=INFO,
     ),
+    EVENT_TYPES.REQUEST_NODE_MARK_FAILED_SYSTEM: EventDetail(
+        description="Marking node failed",
+        level=ERROR,
+    ),
     EVENT_TYPES.REQUEST_NODE_MARK_BROKEN: EventDetail(
         description="User marking node broken",
         level=INFO,