Merge ~newell-jensen/maas:curtin-cloud-init-status-message-events into maas:master

[Newell Jensen]

Add new event types and events for cloud-init and curtin messages that we want to user in conjunction with status messages for a more granular boot process.

[Blake Rouse (blake-rouse)]

Overall this looks good, just a question. More about the code not about how it was implemented. Implementation seems correct, just as we discussed.

review: Needs Information

[Newell Jensen (newell-jensen)]

Replied inline.

c2cc50a... by Newell Jensen on 2019-04-11

Fix typos.

100c1ef... by Newell Jensen on 2019-04-11

Key off the action instead of the curtin and cloudinit description. Update unit tests.

[Blake Rouse (blake-rouse)]

Looks good, thanks for the fixes.

review: Approve

diff --git a/src/metadataserver/api.py b/src/metadataserver/api.py
index 3470a29..59c12fa 100644
--- a/src/metadataserver/api.py
+++ b/src/metadataserver/api.py
@@ -1,4 +1,4 @@
-# Copyright 2012-2018 Canonical Ltd.  This software is licensed under the
+# Copyright 2012-2019 Canonical Ltd.  This software is licensed under the
 # GNU Affero General Public License version 3 (see the file LICENSE).
 
 """Metadata API."""
@@ -102,6 +102,7 @@ from metadataserver.vendor_data import get_vendor_data
 from piston3.utils import rc
 from provisioningserver.events import (
     EVENT_DETAILS,
+    EVENT_STATUS_MESSAGES,
     EVENT_TYPES,
 )
 from provisioningserver.logger import LegacyLogger
@@ -190,7 +191,8 @@ def check_version(version):
 
 
 def add_event_to_node_event_log(
-        node, origin, action, description, result=None, created=None):
+        node, origin, action, description,
+        event_type, result=None, created=None):
     """Add an entry to the node's event log."""
     if node.status == NODE_STATUS.COMMISSIONING:
         if result in ['SUCCESS', None]:
@@ -216,10 +218,27 @@ def add_event_to_node_event_log(
     else:
         type_name = EVENT_TYPES.NODE_STATUS_EVENT
 
-    event_details = EVENT_DETAILS[type_name]
+    # Create an extra event for the machine status messages.
+    if action in EVENT_STATUS_MESSAGES:
+        # cloud-init sends the action 'modules-final' for
+        # both commissioning and deployment but we are only interested
+        # in setting the message for deployment.
+        if ((action == 'modules-final' and
+             node.status == NODE_STATUS.DEPLOYING and
+             event_type == 'finish') or (
+                 action != 'modules-final' and event_type == 'start')):
+                Event.objects.register_event_and_event_type(
+                    EVENT_STATUS_MESSAGES[action],
+                    type_level=EVENT_DETAILS[
+                        EVENT_STATUS_MESSAGES[action]].level,
+                    type_description=EVENT_DETAILS[
+                        EVENT_STATUS_MESSAGES[action]].description,
+                    event_action=action, event_description='',
+                    system_id=node.system_id, created=created)
+
     return Event.objects.register_event_and_event_type(
-        type_name, type_level=event_details.level,
-        type_description=event_details.description,
+        type_name, type_level=EVENT_DETAILS[type_name].level,
+        type_description=EVENT_DETAILS[type_name].description,
         event_action=action,
         event_description="'%s' %s" % (origin, description),
         system_id=node.system_id, created=created)
diff --git a/src/metadataserver/api_twisted.py b/src/metadataserver/api_twisted.py
index 0659d30..ddad25e 100644
--- a/src/metadataserver/api_twisted.py
+++ b/src/metadataserver/api_twisted.py
@@ -1,4 +1,4 @@
-# Copyright 2017-2018 Canonical Ltd.  This software is licensed under the
+# Copyright 2017-2019 Canonical Ltd.  This software is licensed under the
 # GNU Affero General Public License version 3 (see the file LICENSE).
 
 """Metadata API that runs in the Twisted reactor."""
@@ -33,6 +33,7 @@ from metadataserver.api import (
 )
 from metadataserver.enum import SCRIPT_STATUS
 from metadataserver.models import NodeKey
+from provisioningserver.events import EVENT_STATUS_MESSAGES
 from provisioningserver.logger import LegacyLogger
 from provisioningserver.utils.twisted import deferred
 from twisted.application.internet import TimerService
@@ -307,7 +308,7 @@ class StatusWorkerService(TimerService, object):
 
         # Add this event to the node event log.
         add_event_to_node_event_log(
-            node, origin, activity_name, description, result,
+            node, origin, activity_name, description, event_type, result,
             message['timestamp'])
 
         # Group files together with the ScriptResult they belong.
@@ -494,8 +495,18 @@ class StatusWorkerService(TimerService, object):
                 ] and
             message['event_type'] in ['start', 'finish'] and
             message['origin'] == 'curtin')
+        is_status_message_event = (
+            message['name'] in EVENT_STATUS_MESSAGES and
+            message['event_type'] == 'start')
+        # modules-final is a cloudinit event that is part of
+        # EVENT_STATUS_MESSAGES but we want to create an event for
+        # the 'finish' event_type.
+        is_modules_final_event = (
+            message['name'] == 'modules-final' and
+            message['event_type'] == 'finish')
         if (is_starting_event or is_final_event or has_files or
-                is_curtin_early_late):
+                is_curtin_early_late or is_status_message_event or
+                is_modules_final_event):
             d = deferToDatabase(
                 self._processMessageNow, authorization, message)
             d.addErrback(
diff --git a/src/metadataserver/tests/test_api.py b/src/metadataserver/tests/test_api.py
index 68d8b2f..1c48a98 100644
--- a/src/metadataserver/tests/test_api.py
+++ b/src/metadataserver/tests/test_api.py
@@ -1,4 +1,4 @@
-# Copyright 2012-2018 Canonical Ltd.  This software is licensed under the
+# Copyright 2012-2019 Canonical Ltd.  This software is licensed under the
 # GNU Affero General Public License version 3 (see the file LICENSE).
 
 """Tests for the metadata API."""
@@ -103,6 +103,7 @@ from netaddr import IPNetwork
 from provisioningserver.events import (
     EVENT_DETAILS,
     EVENT_TYPES,
+    EVENT_STATUS_MESSAGES,
 )
 from provisioningserver.refresh.node_info_scripts import (
     NODE_INFO_SCRIPTS,
@@ -227,7 +228,8 @@ class TestHelpers(MAASServerTestCase):
             origin = factory.make_name('origin')
             action = factory.make_name('action')
             description = factory.make_name('description')
-            add_event_to_node_event_log(node, origin, action, description)
+            add_event_to_node_event_log(
+                node, origin, action, description, event_type='')
             event = Event.objects.get(node=node)
 
             self.assertEqual(node, event.node)
@@ -236,12 +238,28 @@ class TestHelpers(MAASServerTestCase):
             self.assertIn(description, event.description)
             self.assertEqual(expected_type[node.status], event.type.name)
 
+    def test_add_event_to_node_event_log_creates_events_status_messages(self):
+        for action in EVENT_STATUS_MESSAGES.keys():
+            node = factory.make_Node(status=NODE_STATUS.DEPLOYING)
+            origin = factory.make_name('origin')
+            description = factory.make_name('description')
+            add_event_to_node_event_log(
+                node, origin, action, description,
+                event_type='start' if action != 'modules-final' else 'finish')
+            event = Event.objects.filter(node=node).first()
+
+            self.assertEqual(node, event.node)
+            self.assertEqual(action, event.action)
+            self.assertEqual(EVENT_DETAILS[EVENT_STATUS_MESSAGES[
+                action]].description, event.type.description)
+            self.assertEqual('', event.description)
+
     def test_add_event_to_node_event_log_logs_rack_refresh(self):
         rack = factory.make_RackController()
         origin = factory.make_name('origin')
         action = factory.make_name('action')
         description = factory.make_name('description')
-        add_event_to_node_event_log(rack, origin, action, description)
+        add_event_to_node_event_log(rack, origin, action, description, '')
         event = Event.objects.get(node=rack)
 
         self.assertEqual(rack, event.node)
diff --git a/src/metadataserver/tests/test_api_twisted.py b/src/metadataserver/tests/test_api_twisted.py
index 65e5014..81b6fbf 100644
--- a/src/metadataserver/tests/test_api_twisted.py
+++ b/src/metadataserver/tests/test_api_twisted.py
@@ -1,4 +1,4 @@
-# Copyright 2017-2018 Canonical Ltd.  This software is licensed under the
+# Copyright 2017-2019 Canonical Ltd.  This software is licensed under the
 # GNU Affero General Public License version 3 (see the file LICENSE).
 
 """Tests for the twisted metadata API."""
@@ -64,6 +64,7 @@ from metadataserver.enum import (
     SCRIPT_STATUS,
 )
 from metadataserver.models import NodeKey
+from provisioningserver.events import EVENT_STATUS_MESSAGES
 from testtools import ExpectedException
 from testtools.matchers import (
     Equals,
@@ -299,6 +300,23 @@ class TestStatusWorkerServiceTransactional(MAASTransactionServerTestCase):
 
     @wait_for_reactor
     @inlineCallbacks
+    def test_queueMessages_processes_top_level_status_messages_instantly(self):
+        for name in EVENT_STATUS_MESSAGES.keys():
+            worker = StatusWorkerService(sentinel.dbtasks)
+            mock_processMessage = self.patch(worker, "_processMessage")
+            message = self.make_message()
+            message['event_type'] = 'start'
+            message['name'] = name
+            nodes_with_tokens = yield deferToDatabase(
+                self.make_nodes_with_tokens)
+            node, token = nodes_with_tokens[0]
+            yield worker.queueMessage(token.key, message)
+            self.assertThat(
+                mock_processMessage,
+                MockCalledOnceWith(node, message))
+
+    @wait_for_reactor
+    @inlineCallbacks
     def test_queueMessages_processes_files_message_instantly(self):
         worker = StatusWorkerService(sentinel.dbtasks)
         mock_processMessage = self.patch(worker, "_processMessage")
diff --git a/src/provisioningserver/events.py b/src/provisioningserver/events.py
index a1e2415..e72f281 100644
--- a/src/provisioningserver/events.py
+++ b/src/provisioningserver/events.py
@@ -1,10 +1,11 @@
-# Copyright 2014-2018 Canonical Ltd.  This software is licensed under the
+# Copyright 2014-2019 Canonical Ltd.  This software is licensed under the
 # GNU Affero General Public License version 3 (see the file LICENSE).
 
 """Event catalog."""
 
 __all__ = [
     'EVENT_DETAILS',
+    'EVENT_STATUS_MESSAGES',
     'EVENT_TYPES',
     'send_node_event',
     'send_node_event_mac_address',
@@ -141,6 +142,24 @@ class EVENT_TYPES:
     NETWORKING = "NETWORKING"
     # Zones events
     ZONES = "ZONES"
+    # Status message events
+    CONFIGURING_STORAGE = "CONFIGURING_STORAGE"
+    CONFIGURING_NETWORKING = "CONFIGURING_NETWORKING"
+    INSTALLING_OS = "INSTALLING_OS"
+    CONFIGURING_OS = "CONFIGURING_OS"
+    APPLYING_POST_INSTALLATION_CONFIG = "APPLYING_POST_INSTALLATION_CONFIG"
+    REBOOTING_MACHINE = "REBOOTING_MACHINE"
+
+# Used to create new events used for the machine's status.
+# The keys are the messages sent from cloud-init and curtin
+# to the metadataserver.
+EVENT_STATUS_MESSAGES = {
+    'cmd-install/stage-partitioning': EVENT_TYPES.CONFIGURING_STORAGE,
+    'cmd-install/stage-network': EVENT_TYPES.CONFIGURING_NETWORKING,
+    'cmd-install/stage-extract': EVENT_TYPES.INSTALLING_OS,
+    'cmd-install/stage-curthooks': EVENT_TYPES.CONFIGURING_OS,
+    'modules-final': EVENT_TYPES.APPLYING_POST_INSTALLATION_CONFIG,
+}
 
 
 EventDetail = namedtuple("EventDetail", ("description", "level"))
@@ -401,6 +420,30 @@ EVENT_DETAILS = {
         description=("Zones"),
         level=AUDIT,
     ),
+    EVENT_TYPES.CONFIGURING_STORAGE: EventDetail(
+        description=("Configuring storage"),
+        level=INFO,
+    ),
+    EVENT_TYPES.CONFIGURING_NETWORKING: EventDetail(
+        description=("Configuring networking"),
+        level=INFO,
+    ),
+    EVENT_TYPES.INSTALLING_OS: EventDetail(
+        description=("Installing OS"),
+        level=INFO,
+    ),
+    EVENT_TYPES.CONFIGURING_OS: EventDetail(
+        description=("Configuring OS"),
+        level=INFO,
+    ),
+    EVENT_TYPES.APPLYING_POST_INSTALLATION_CONFIG: EventDetail(
+        description=("Applying post installation config"),
+        level=INFO,
+    ),
+    EVENT_TYPES.REBOOTING_MACHINE: EventDetail(
+        description=("Rebooting machine"),
+        level=INFO,
+    ),
 }