Limit Inspection->Lookup->Heartbeat lag

Caches hardware information collected during inspection
so that the initial lookup can occur without any delay.

Also adds logging to track how long inventory collection takes.

Conflicts:
	ironic_python_agent/hardware.py
	ironic_python_agent/tests/unit/base.py
	ironic_python_agent/tests/unit/test_hardware.py
	ironic_python_agent/tests/unit/test_inspector.py

Co-Authored-By: Dmitry Tantsur <dtantsur@protonmail.com>
Change-Id: I3e0d237d37219e783d81913fa6cc490492b3f96a
(cherry picked from commit c76b8b2c217d57680baec977b374e821304198f9)

8 files changed, 66 insertions, 6 deletions

diff --git a/ironic_python_agent/agent.py b/ironic_python_agent/agent.py
index c9fe2acc..813c6c7b 100644
--- a/ironic_python_agent/agent.py
+++ b/ironic_python_agent/agent.py
@@ -387,6 +387,10 @@ class IronicPythonAgent(base.ExecuteCommandMixin):
             # Inspection should be started before call to lookup, otherwise
             # lookup will fail due to unknown MAC.
             uuid = None
+            # We can't try to inspect or heartbeat until we have valid
+            # interfaces to perform those actions over.
+            self._wait_for_interface()
+
             if cfg.CONF.inspection_callback_url:
                 try:
                     # Attempt inspection. This may fail, and previously
@@ -396,10 +400,8 @@ class IronicPythonAgent(base.ExecuteCommandMixin):
                     LOG.error('Failed to perform inspection: %s', e)
 
             if self.api_url:
-                self._wait_for_interface()
                 content = self.api_client.lookup_node(
-                    hardware_info=hardware.dispatch_to_managers(
-                        'list_hardware_info'),
+                    hardware_info=hardware.list_hardware_info(use_cache=True),
                     timeout=self.lookup_timeout,
                     starting_interval=self.lookup_interval,
                     node_uuid=uuid)
@@ -423,6 +425,9 @@ class IronicPythonAgent(base.ExecuteCommandMixin):
                 LOG.info('No ipa-api-url configured, Heartbeat and lookup '
                          'skipped for inspector.')
             else:
+                # NOTE(TheJulia): Once communication flow capability is
+                # able to be driven solely from the conductor, this is no
+                # longer a major issue.
                 LOG.error('Neither ipa-api-url nor inspection_callback_url'
                           'found, please check your pxe append parameters.')
 
diff --git a/ironic_python_agent/hardware.py b/ironic_python_agent/hardware.py
index 8e5dbc09..e5cadf50 100644
--- a/ironic_python_agent/hardware.py
+++ b/ironic_python_agent/hardware.py
@@ -653,6 +653,8 @@ class HardwareManager(object):
 
         :return: a dictionary representing inventory
         """
+        start = time.time()
+        LOG.info('Collecting full inventory')
         # NOTE(dtantsur): don't forget to update docs when extending inventory
         hardware_info = {}
         hardware_info['interfaces'] = self.list_network_interfaces()
@@ -664,6 +666,7 @@ class HardwareManager(object):
         hardware_info['system_vendor'] = self.get_system_vendor_info()
         hardware_info['boot'] = self.get_boot_info()
         hardware_info['hostname'] = netutils.get_hostname()
+        LOG.info('Inventory collected in %.2f second(s)', time.time() - start)
         return hardware_info
 
     def get_clean_steps(self, node, ports):
@@ -2014,6 +2017,23 @@ def load_managers():
     _get_managers()
 
 
+_CACHED_HW_INFO = None
+
+
+def list_hardware_info(use_cache=True):
+    """List hardware information with caching."""
+    global _CACHED_HW_INFO
+
+    if _CACHED_HW_INFO is None:
+        _CACHED_HW_INFO = dispatch_to_managers('list_hardware_info')
+        return _CACHED_HW_INFO
+
+    if use_cache:
+        return _CACHED_HW_INFO
+    else:
+        return dispatch_to_managers('list_hardware_info')
+
+
 def cache_node(node):
     """Store the node object in the hardware module.
 
diff --git a/ironic_python_agent/inspector.py b/ironic_python_agent/inspector.py
index 6b645861..4fbe4d3e 100644
--- a/ironic_python_agent/inspector.py
+++ b/ironic_python_agent/inspector.py
@@ -200,7 +200,7 @@ def collect_default(data, failures):
     :param failures: AccumulatedFailures object
     """
     wait_for_dhcp()
-    inventory = hardware.dispatch_to_managers('list_hardware_info')
+    inventory = hardware.list_hardware_info()
 
     data['inventory'] = inventory
     # Replicate the same logic as in deploy. We need to make sure that when
diff --git a/ironic_python_agent/tests/unit/base.py b/ironic_python_agent/tests/unit/base.py
index 033c39cb..143c1366 100644
--- a/ironic_python_agent/tests/unit/base.py
+++ b/ironic_python_agent/tests/unit/base.py
@@ -23,6 +23,7 @@ from oslo_config import cfg
 from oslo_config import fixture as config_fixture
 from oslotest import base as test_base
 
+from ironic_python_agent import hardware
 from ironic_python_agent import utils
 
 CONF = cfg.CONF
@@ -58,6 +59,8 @@ class IronicAgentTest(test_base.BaseTestCase):
             self.patch(subprocess, 'check_output', do_not_call)
             self.patch(utils, 'execute', do_not_call)
 
+        hardware._CACHED_HW_INFO = None
+
     def _set_config(self):
         self.cfg_fixture = self.useFixture(config_fixture.Config(CONF))
 
diff --git a/ironic_python_agent/tests/unit/test_agent.py b/ironic_python_agent/tests/unit/test_agent.py
index 869b7b88..9b2d6ca0 100644
--- a/ironic_python_agent/tests/unit/test_agent.py
+++ b/ironic_python_agent/tests/unit/test_agent.py
@@ -486,7 +486,7 @@ class TestBaseAgent(ironic_agent_base.IronicAgentTest):
 
         mock_inspector.assert_called_once_with()
 
-        self.assertFalse(mock_wait.called)
+        self.assertTrue(mock_wait.called)
         self.assertFalse(mock_dispatch.called)
 
     @mock.patch('ironic_lib.mdns.get_endpoint', autospec=True)
@@ -542,7 +542,7 @@ class TestBaseAgent(ironic_agent_base.IronicAgentTest):
         self.assertTrue(wsgi_server.handle_request.called)
 
         self.assertFalse(mock_inspector.called)
-        self.assertFalse(mock_wait.called)
+        self.assertTrue(mock_wait.called)
         self.assertFalse(mock_dispatch.called)
 
     @mock.patch.object(time, 'time', autospec=True)
diff --git a/ironic_python_agent/tests/unit/test_hardware.py b/ironic_python_agent/tests/unit/test_hardware.py
index dbe2fc3a..5671d452 100644
--- a/ironic_python_agent/tests/unit/test_hardware.py
+++ b/ironic_python_agent/tests/unit/test_hardware.py
@@ -3728,3 +3728,22 @@ def create_hdparm_info(supported=False, enabled=False, locked=False,
     update_values(values, enhanced_erase, 'enhanced_erase')
 
     return HDPARM_INFO_TEMPLATE % values
+
+
+@mock.patch('ironic_python_agent.hardware.dispatch_to_managers',
+            autospec=True)
+class TestListHardwareInfo(base.IronicAgentTest):
+
+    def test_caching(self, mock_dispatch):
+        fake_info = {'I am': 'hardware'}
+        mock_dispatch.return_value = fake_info
+
+        self.assertEqual(fake_info, hardware.list_hardware_info())
+        self.assertEqual(fake_info, hardware.list_hardware_info())
+        mock_dispatch.assert_called_once_with('list_hardware_info')
+
+        self.assertEqual(fake_info,
+                         hardware.list_hardware_info(use_cache=False))
+        self.assertEqual(fake_info, hardware.list_hardware_info())
+        mock_dispatch.assert_called_with('list_hardware_info')
+        self.assertEqual(2, mock_dispatch.call_count)
diff --git a/ironic_python_agent/tests/unit/test_inspector.py b/ironic_python_agent/tests/unit/test_inspector.py
index 10f9f9e4..fd7622d4 100644
--- a/ironic_python_agent/tests/unit/test_inspector.py
+++ b/ironic_python_agent/tests/unit/test_inspector.py
@@ -244,6 +244,14 @@ class TestCollectDefault(BaseDiscoverTest):
         mock_dispatch.assert_called_once_with('list_hardware_info')
         mock_wait_for_dhcp.assert_called_once_with()
 
+    def test_cache_hardware_info(self, mock_dispatch, mock_wait_for_dhcp):
+        mock_dispatch.return_value = self.inventory
+
+        inspector.collect_default(self.data, self.failures)
+        inspector.collect_default(self.data, self.failures)
+        # Hardware is cached, so only one call is made
+        mock_dispatch.assert_called_once_with('list_hardware_info')
+
     def test_no_root_disk(self, mock_dispatch, mock_wait_for_dhcp):
         mock_dispatch.return_value = self.inventory
         self.inventory['disks'] = []
diff --git a/releasenotes/notes/inspect-to-clean-b3616d843775c187.yaml b/releasenotes/notes/inspect-to-clean-b3616d843775c187.yaml
new file mode 100644
index 00000000..a07c8bb3
--- /dev/null
+++ b/releasenotes/notes/inspect-to-clean-b3616d843775c187.yaml
@@ -0,0 +1,5 @@
+---
+fixes:
+  - |
+    Speeds up going from inspection to cleaning with fast-track enabled by
+    caching hardware information between the steps.