Fixed waiting for LPAR status in Lpar.activate()

Details:

* Fixed the waiting for LPAR status in Lpar.activate(). Previously, the method
  was waiting for 'operating' or 'not-operating', so when an auto-load
  happened it already returned when status 'not-operating' was reached, but
  the load was still going on in parallel. Now, the method finds out whether
  the LPAR is expected to auto-load or not and waits for the corresponding
  status.

* Added a debug log entry when Lpar.wait_for_status() is called. This happens
  for example when Lpar.activate/deactivate/load() are called with
  wait_for_completion.

* Added definition of image profiles to unit test cases that perform
  activate or load.

Signed-off-by: Andreas Maier <maiera@de.ibm.com>

docs/changes.rst

@@ -35,6 +35,17 @@ Released: not yet
 
 * Docs: Corrected and improved the description of the Lpar.activate() method.
 
+* Fixed the waiting for LPAR status in Lpar.activate(). Previously, the method
+  was waiting for 'operating' or 'not-operating', so when an auto-load
+  happened it already returned when status 'not-operating' was reached, but
+  the load was still going on in parallel. Now, the method finds out whether
+  the LPAR is expected to auto-load or not and waits for the corresponding
+  status.
+
+* Added a debug log entry when Lpar.wait_for_status() is called. This happens
+  for example when Lpar.activate/deactivate/load() are called with
+  wait_for_completion.
+
 **Enhancements:**
 
 **Cleanup:**

tests/unit/zhmcclient/test_lpar.py

@@ -42,6 +42,12 @@
 LPAR2_OID = 'lpar2-oid'
 LPAR2_NAME = 'lpar 2'
 
+# Object IDs and names of our faked image activation profiles:
+IMAGEPROFILE1_OID = 'imageprofile1-oid'
+IMAGEPROFILE1_NAME = 'imageprofile 1'
+IMAGEPROFILE2_OID = 'imageprofile2-oid'
+IMAGEPROFILE2_NAME = 'imageprofile 2'
+
 CPC_NAME = 'fake-cpc1-name'
 
 
@@ -100,6 +106,23 @@ def add_lpar1(self):
         })
         return faked_lpar
 
+    def add_imageprofile1(self):
+        """Add image profile for lpar 1 (no auto-load)."""
+
+        faked_imageprofile = self.faked_cpc.image_activation_profiles.add({
+            'object-id': IMAGEPROFILE1_OID,
+            # object-uri will be automatically set
+            'parent': self.faked_cpc.uri,
+            'class': 'image-activation-profile',
+            'name': LPAR1_NAME,
+            'description': 'Image profile for LPAR #1 (Linux)',
+            'ipl-address': '00000',
+            'ipl-parameter': '',
+            'ipl-type': 'ipltype-standard',
+            'load-at-activation': False,
+        })
+        return faked_imageprofile
+
     def add_lpar2(self):
         """Add lpar 2 (type ssc)."""
 
@@ -125,6 +148,23 @@ def add_lpar2(self):
         })
         return faked_lpar
 
+    def add_imageprofile2(self):
+        """Add image profile for lpar 2 (auto-load due to SSC)."""
+
+        faked_imageprofile = self.faked_cpc.image_activation_profiles.add({
+            'object-id': IMAGEPROFILE2_OID,
+            # object-uri will be automatically set
+            'parent': self.faked_cpc.uri,
+            'class': 'image-activation-profile',
+            'name': LPAR2_NAME,
+            'description': 'Image profile for LPAR #2 (SSC)',
+            'ipl-address': '00000',
+            'ipl-parameter': '',
+            'ipl-type': 'ipltype-standard',
+            'load-at-activation': False,
+        })
+        return faked_imageprofile
+
     def test_lparmanager_initial_attrs(self):
         """Test initial attributes of LparManager."""
 
@@ -382,6 +422,9 @@ def test_lpar_activate(
         faked_lpar.properties['status'] = initial_status
         faked_lpar.properties['next-activation-profile-name'] = initial_profile
 
+        # Add a faked image profile
+        self.add_imageprofile1()
+
         lpar_mgr = self.cpc.lpars
         lpar = lpar_mgr.find(name=faked_lpar.name)
 
@@ -620,6 +663,9 @@ def test_lpar_load(
         faked_lpar.properties['last-used-load-parameter'] = initial_loadparm
         faked_lpar.properties['memory'] = initial_memory
 
+        # Add a faked image profile
+        self.add_imageprofile1()
+
         lpar_mgr = self.cpc.lpars
         lpar = lpar_mgr.find(name=faked_lpar.name)
 
@@ -838,6 +884,9 @@ def test_lpar_scsi_load(
         faked_lpar = self.add_lpar1()
         faked_lpar.properties['status'] = initial_status
 
+        # Add a faked image profile
+        self.add_imageprofile1()
+
         lpar_mgr = self.cpc.lpars
         lpar = lpar_mgr.find(name=faked_lpar.name)
 
@@ -1026,6 +1075,9 @@ def test_lpar_scsi_dump(
         faked_lpar = self.add_lpar1()
         faked_lpar.properties['status'] = initial_status
 
+        # Add a faked image profile
+        self.add_imageprofile1()
+
         lpar_mgr = self.cpc.lpars
         lpar = lpar_mgr.find(name=faked_lpar.name)
 
@@ -1179,6 +1231,9 @@ def test_lpar_nvme_load(
         faked_lpar = self.add_lpar1()
         faked_lpar.properties['status'] = initial_status
 
+        # Add a faked image profile
+        self.add_imageprofile1()
+
         lpar_mgr = self.cpc.lpars
         lpar = lpar_mgr.find(name=faked_lpar.name)
 
@@ -1330,6 +1385,9 @@ def test_lpar_nvme_dump(
         faked_lpar = self.add_lpar1()
         faked_lpar.properties['status'] = initial_status
 
+        # Add a faked image profile
+        self.add_imageprofile1()
+
         lpar_mgr = self.cpc.lpars
         lpar = lpar_mgr.find(name=faked_lpar.name)
 

zhmcclient/_lpar.py

@@ -33,11 +33,14 @@
 from ._manager import BaseManager
 from ._resource import BaseResource
 from ._exceptions import StatusTimeout
-from ._logging import logged_api_call
+from ._constants import HMC_LOGGER_NAME
+from ._logging import get_logger, logged_api_call
 from ._utils import RC_LOGICAL_PARTITION
 
 __all__ = ['LparManager', 'Lpar']
 
+HMC_LOGGER = get_logger(HMC_LOGGER_NAME)
+
 
 class LparManager(BaseManager):
     """
@@ -349,7 +352,21 @@ def activate(self, wait_for_completion=True,
             wait_for_completion=wait_for_completion,
             operation_timeout=operation_timeout)
         if wait_for_completion:
-            statuses = ["not-operating", "operating"]
+            # If an automatic load is performed, the LPAR status will first go
+            # to 'not-operating' and then later to 'operating'. So we cannot
+            # just wait for any of those two, but need to have an understanding
+            # whether we expect auto-load.
+            image_profile_mgr = self.manager.parent.image_activation_profiles
+            image_profile = image_profile_mgr.find(name=self.name)
+            auto_load = image_profile.get_property('load-at-activation')
+            activation_mode = self.get_property('activation-mode')
+            load_profile_specified = activation_profile_name is not None and \
+                activation_profile_name != self.name
+            is_ssc = activation_mode in ('ssc', 'zaware')
+            if auto_load or load_profile_specified or is_ssc:
+                statuses = ["operating"]
+            else:
+                statuses = ["not-operating"]
             if allow_status_exceptions:
                 statuses.append("exceptions")
             self.wait_for_status(statuses, status_timeout)
@@ -1885,6 +1902,9 @@ def wait_for_status(self, status, status_timeout=None):
             statuses = status
         else:
             statuses = [status]
+        HMC_LOGGER.debug("Waiting for LPAR %r to have status: %s "
+                         "(timeout: %s sec)",
+                         self.name, status, status_timeout)
         while True:
 
             # Fastest way to get actual status value: