IBMCloud: recognize provisioning environment during debug boots.

When images are deployed from template in a production environment
the artifacts of the provisioning stage (provisioningConfiguration.cfg)
that cloud-init referenced are cleaned up.  However, when provisioned
in "debug" mode (internal to IBM) the artifacts are left.

This changes the 'is_ibm_provisioning' implementations in both
ds-identify and in the IBM datasource to identify the provisioning
stage more correctly.  The change is to consider provisioning only
if the provisioing file existed and there was no log file or
the log file was older than this boot.

LP: #1767166

5 files changed, 175 insertions, 23 deletions

diff --git a/cloudinit/sources/DataSourceIBMCloud.py b/cloudinit/sources/DataSourceIBMCloud.py
index cfa724bf..01106ec0 100644
--- a/cloudinit/sources/DataSourceIBMCloud.py
+++ b/cloudinit/sources/DataSourceIBMCloud.py
@@ -8,17 +8,11 @@ There are 2 different api exposed launch methods.
  * template: This is the legacy method of launching instances.
    When booting from an image template, the system boots first into
    a "provisioning" mode.  There, host <-> guest mechanisms are utilized
-   to execute code in the guest and provision it.
+   to execute code in the guest and configure it.  The configuration
+   includes configuring the system network and possibly installing
+   packages and other software stack.
 
-   Cloud-init will disable itself when it detects that it is in the
-   provisioning mode.  It detects this by the presence of
-   a file '/root/provisioningConfiguration.cfg'.
-
-   When provided with user-data, the "first boot" will contain a
-   ConfigDrive-like disk labeled with 'METADATA'.  If there is no user-data
-   provided, then there is no data-source.
-
-   Cloud-init never does any network configuration in this mode.
+   After the provisioning is finished, the system reboots.
 
  * os_code: Essentially "launch by OS Code" (Operating System Code).
    This is a more modern approach.  There is no specific "provisioning" boot.
@@ -200,8 +194,30 @@ def _is_xen():
     return os.path.exists("/proc/xen")
 
 
-def _is_ibm_provisioning():
-    return os.path.exists("/root/provisioningConfiguration.cfg")
+def _is_ibm_provisioning(
+        prov_cfg="/root/provisioningConfiguration.cfg",
+        inst_log="/root/swinstall.log",
+        boot_ref="/proc/1/environ"):
+    """Return boolean indicating if this boot is ibm provisioning boot."""
+    if os.path.exists(prov_cfg):
+        msg = "config '%s' exists." % prov_cfg
+        result = True
+        if os.path.exists(inst_log):
+            if os.path.exists(boot_ref):
+                result = (os.stat(inst_log).st_mtime >
+                          os.stat(boot_ref).st_mtime)
+                msg += (" log '%s' from %s boot." %
+                        (inst_log, "current" if result else "previous"))
+            else:
+                msg += (" log '%s' existed, but no reference file '%s'." %
+                        (inst_log, boot_ref))
+                result = False
+        else:
+            msg += " log '%s' did not exist." % inst_log
+    else:
+        result, msg = (False, "config '%s' did not exist." % prov_cfg)
+    LOG.debug("ibm_provisioning=%s: %s", result, msg)
+    return result
 
 
 def get_ibm_platform():
@@ -251,7 +267,7 @@ def get_ibm_platform():
         else:
             return (Platforms.TEMPLATE_LIVE_METADATA, metadata_path)
     elif _is_ibm_provisioning():
-            return (Platforms.TEMPLATE_PROVISIONING_NODATA, None)
+        return (Platforms.TEMPLATE_PROVISIONING_NODATA, None)
     return not_found
 
 
diff --git a/cloudinit/tests/helpers.py b/cloudinit/tests/helpers.py
index 4999f1f6..117a9cfe 100644
--- a/cloudinit/tests/helpers.py
+++ b/cloudinit/tests/helpers.py
@@ -8,6 +8,7 @@ import os
 import shutil
 import sys
 import tempfile
+import time
 import unittest
 
 import mock
@@ -263,7 +264,8 @@ class FilesystemMockingTestCase(ResourceUsingTestCase):
             os.path: [('isfile', 1), ('exists', 1),
                       ('islink', 1), ('isdir', 1), ('lexists', 1)],
             os: [('listdir', 1), ('mkdir', 1),
-                 ('lstat', 1), ('symlink', 2)]
+                 ('lstat', 1), ('symlink', 2),
+                 ('stat', 1)]
         }
 
         if hasattr(os, 'scandir'):
@@ -349,6 +351,15 @@ def populate_dir(path, files):
     return ret
 
 
+def populate_dir_with_ts(path, data):
+    """data is {'file': ('contents', mtime)}.  mtime relative to now."""
+    populate_dir(path, dict((k, v[0]) for k, v in data.items()))
+    btime = time.time()
+    for fpath, (_contents, mtime) in data.items():
+        ts = btime + mtime if mtime else btime
+        os.utime(os.path.sep.join((path, fpath)), (ts, ts))
+
+
 def dir2dict(startdir, prefix=None):
     flist = {}
     if prefix is None:
diff --git a/tests/unittests/test_datasource/test_ibmcloud.py b/tests/unittests/test_datasource/test_ibmcloud.py
index 621cfe49..e639ae47 100644
--- a/tests/unittests/test_datasource/test_ibmcloud.py
+++ b/tests/unittests/test_datasource/test_ibmcloud.py
@@ -259,4 +259,54 @@ class TestReadMD(test_helpers.CiTestCase):
                          ret['metadata'])
 
 
+class TestIsIBMProvisioning(test_helpers.FilesystemMockingTestCase):
+    """Test the _is_ibm_provisioning method."""
+    inst_log = "/root/swinstall.log"
+    prov_cfg = "/root/provisioningConfiguration.cfg"
+    boot_ref = "/proc/1/environ"
+    with_logs = True
+
+    def _call_with_root(self, rootd):
+        self.reRoot(rootd)
+        return ibm._is_ibm_provisioning()
+
+    def test_no_config(self):
+        """No provisioning config means not provisioning."""
+        self.assertFalse(self._call_with_root(self.tmp_dir()))
+
+    def test_config_only(self):
+        """A provisioning config without a log means provisioning."""
+        rootd = self.tmp_dir()
+        test_helpers.populate_dir(rootd, {self.prov_cfg: "key=value"})
+        self.assertTrue(self._call_with_root(rootd))
+
+    def test_config_with_old_log(self):
+        """A config with a log from previous boot is not provisioning."""
+        rootd = self.tmp_dir()
+        data = {self.prov_cfg: ("key=value\nkey2=val2\n", -10),
+                self.inst_log: ("log data\n", -30),
+                self.boot_ref: ("PWD=/", 0)}
+        test_helpers.populate_dir_with_ts(rootd, data)
+        self.assertFalse(self._call_with_root(rootd=rootd))
+        self.assertIn("from previous boot", self.logs.getvalue())
+
+    def test_config_with_new_log(self):
+        """A config with a log from this boot is provisioning."""
+        rootd = self.tmp_dir()
+        data = {self.prov_cfg: ("key=value\nkey2=val2\n", -10),
+                self.inst_log: ("log data\n", 30),
+                self.boot_ref: ("PWD=/", 0)}
+        test_helpers.populate_dir_with_ts(rootd, data)
+        self.assertTrue(self._call_with_root(rootd=rootd))
+        self.assertIn("from current boot", self.logs.getvalue())
+
+    def test_config_and_log_no_reference(self):
+        """If the config and log existed, but no reference, assume not."""
+        rootd = self.tmp_dir()
+        test_helpers.populate_dir(
+            rootd, {self.prov_cfg: "key=value", self.inst_log: "log data\n"})
+        self.assertFalse(self._call_with_root(rootd=rootd))
+        self.assertIn("no reference file", self.logs.getvalue())
+
+
 # vi: ts=4 expandtab
diff --git a/tests/unittests/test_ds_identify.py b/tests/unittests/test_ds_identify.py
index 53643989..ad7fe41e 100644
--- a/tests/unittests/test_ds_identify.py
+++ b/tests/unittests/test_ds_identify.py
@@ -1,5 +1,6 @@
 # This file is part of cloud-init. See LICENSE file for license information.
 
+from collections import namedtuple
 import copy
 import os
 from uuid import uuid4
@@ -7,7 +8,7 @@ from uuid import uuid4
 from cloudinit import safeyaml
 from cloudinit import util
 from cloudinit.tests.helpers import (
-    CiTestCase, dir2dict, populate_dir)
+    CiTestCase, dir2dict, populate_dir, populate_dir_with_ts)
 
 from cloudinit.sources import DataSourceIBMCloud as dsibm
 
@@ -66,7 +67,6 @@ P_SYS_VENDOR = "sys/class/dmi/id/sys_vendor"
 P_SEED_DIR = "var/lib/cloud/seed"
 P_DSID_CFG = "etc/cloud/ds-identify.cfg"
 
-IBM_PROVISIONING_CHECK_PATH = "/root/provisioningConfiguration.cfg"
 IBM_CONFIG_UUID = "9796-932E"
 
 MOCK_VIRT_IS_KVM = {'name': 'detect_virt', 'RET': 'kvm', 'ret': 0}
@@ -74,11 +74,17 @@ MOCK_VIRT_IS_VMWARE = {'name': 'detect_virt', 'RET': 'vmware', 'ret': 0}
 MOCK_VIRT_IS_XEN = {'name': 'detect_virt', 'RET': 'xen', 'ret': 0}
 MOCK_UNAME_IS_PPC64 = {'name': 'uname', 'out': UNAME_PPC64EL, 'ret': 0}
 
+shell_true = 0
+shell_false = 1
 
-class TestDsIdentify(CiTestCase):
+CallReturn = namedtuple('CallReturn',
+                        ['rc', 'stdout', 'stderr', 'cfg', 'files'])
+
+
+class DsIdentifyBase(CiTestCase):
     dsid_path = os.path.realpath('tools/ds-identify')
 
-    def call(self, rootd=None, mocks=None, args=None, files=None,
+    def call(self, rootd=None, mocks=None, func="main", args=None, files=None,
              policy_dmi=DI_DEFAULT_POLICY,
              policy_no_dmi=DI_DEFAULT_POLICY_NO_DMI,
              ec2_strict_id=DI_EC2_STRICT_ID_DEFAULT):
@@ -135,7 +141,7 @@ class TestDsIdentify(CiTestCase):
                 mocklines.append(write_mock(d))
 
         endlines = [
-            'main %s' % ' '.join(['"%s"' % s for s in args])
+            func + ' ' + ' '.join(['"%s"' % s for s in args])
         ]
 
         with open(wrap, "w") as fp:
@@ -159,7 +165,7 @@ class TestDsIdentify(CiTestCase):
                 cfg = {"_INVALID_YAML": contents,
                        "_EXCEPTION": str(e)}
 
-        return rc, out, err, cfg, dir2dict(rootd)
+        return CallReturn(rc, out, err, cfg, dir2dict(rootd))
 
     def _call_via_dict(self, data, rootd=None, **kwargs):
         # return output of self.call with a dict input like VALID_CFG[item]
@@ -190,6 +196,8 @@ class TestDsIdentify(CiTestCase):
                 _print_run_output(rc, out, err, cfg, files)
         return rc, out, err, cfg, files
 
+
+class TestDsIdentify(DsIdentifyBase):
     def test_wb_print_variables(self):
         """_print_info reports an array of discovered variables to stderr."""
         data = VALID_CFG['Azure-dmi-detection']
@@ -250,7 +258,10 @@ class TestDsIdentify(CiTestCase):
         Template provisioning with user-data has METADATA disk,
         datasource should return not found."""
         data = copy.deepcopy(VALID_CFG['IBMCloud-metadata'])
-        data['files'] = {IBM_PROVISIONING_CHECK_PATH: 'xxx'}
+        # change the 'is_ibm_provisioning' mock to return 1 (false)
+        isprov_m = [m for m in data['mocks']
+                    if m["name"] == "is_ibm_provisioning"][0]
+        isprov_m['ret'] = shell_true
         return self._check_via_dict(data, RC_NOT_FOUND)
 
     def test_ibmcloud_template_userdata(self):
@@ -265,7 +276,8 @@ class TestDsIdentify(CiTestCase):
 
         no disks attached.  Datasource should return not found."""
         data = copy.deepcopy(VALID_CFG['IBMCloud-nodisks'])
-        data['files'] = {IBM_PROVISIONING_CHECK_PATH: 'xxx'}
+        data['mocks'].append(
+            {'name': 'is_ibm_provisioning', 'ret': shell_true})
         return self._check_via_dict(data, RC_NOT_FOUND)
 
     def test_ibmcloud_template_no_userdata(self):
@@ -446,6 +458,47 @@ class TestDsIdentify(CiTestCase):
         self._test_ds_found('Hetzner')
 
 
+class TestIsIBMProvisioning(DsIdentifyBase):
+    """Test the is_ibm_provisioning method in ds-identify."""
+
+    inst_log = "/root/swinstall.log"
+    prov_cfg = "/root/provisioningConfiguration.cfg"
+    boot_ref = "/proc/1/environ"
+    funcname = "is_ibm_provisioning"
+
+    def test_no_config(self):
+        """No provisioning config means not provisioning."""
+        ret = self.call(files={}, func=self.funcname)
+        self.assertEqual(shell_false, ret.rc)
+
+    def test_config_only(self):
+        """A provisioning config without a log means provisioning."""
+        ret = self.call(files={self.prov_cfg: "key=value"}, func=self.funcname)
+        self.assertEqual(shell_true, ret.rc)
+
+    def test_config_with_old_log(self):
+        """A config with a log from previous boot is not provisioning."""
+        rootd = self.tmp_dir()
+        data = {self.prov_cfg: ("key=value\nkey2=val2\n", -10),
+                self.inst_log: ("log data\n", -30),
+                self.boot_ref: ("PWD=/", 0)}
+        populate_dir_with_ts(rootd, data)
+        ret = self.call(rootd=rootd, func=self.funcname)
+        self.assertEqual(shell_false, ret.rc)
+        self.assertIn("from previous boot", ret.stderr)
+
+    def test_config_with_new_log(self):
+        """A config with a log from this boot is provisioning."""
+        rootd = self.tmp_dir()
+        data = {self.prov_cfg: ("key=value\nkey2=val2\n", -10),
+                self.inst_log: ("log data\n", 30),
+                self.boot_ref: ("PWD=/", 0)}
+        populate_dir_with_ts(rootd, data)
+        ret = self.call(rootd=rootd, func=self.funcname)
+        self.assertEqual(shell_true, ret.rc)
+        self.assertIn("from current boot", ret.stderr)
+
+
 def blkid_out(disks=None):
     """Convert a list of disk dictionaries into blkid content."""
     if disks is None:
@@ -639,6 +692,7 @@ VALID_CFG = {
         'ds': 'IBMCloud',
         'mocks': [
             MOCK_VIRT_IS_XEN,
+            {'name': 'is_ibm_provisioning', 'ret': shell_false},
             {'name': 'blkid', 'ret': 0,
              'out': blkid_out(
                  [{'DEVNAME': 'xvda1', 'TYPE': 'vfat', 'PARTUUID': uuid4()},
@@ -652,6 +706,7 @@ VALID_CFG = {
         'ds': 'IBMCloud',
         'mocks': [
             MOCK_VIRT_IS_XEN,
+            {'name': 'is_ibm_provisioning', 'ret': shell_false},
             {'name': 'blkid', 'ret': 0,
              'out': blkid_out(
                  [{'DEVNAME': 'xvda1', 'TYPE': 'ext3', 'PARTUUID': uuid4(),
@@ -669,6 +724,7 @@ VALID_CFG = {
         'ds': 'IBMCloud',
         'mocks': [
             MOCK_VIRT_IS_XEN,
+            {'name': 'is_ibm_provisioning', 'ret': shell_false},
             {'name': 'blkid', 'ret': 0,
              'out': blkid_out(
                  [{'DEVNAME': 'xvda1', 'TYPE': 'vfat', 'PARTUUID': uuid4()},
diff --git a/tools/ds-identify b/tools/ds-identify
index 9a2db5c4..7fff5d1e 100755
--- a/tools/ds-identify
+++ b/tools/ds-identify
@@ -125,6 +125,7 @@ DI_ON_NOTFOUND=""
 DI_EC2_STRICT_ID_DEFAULT="true"
 
 _IS_IBM_CLOUD=""
+_IS_IBM_PROVISIONING=""
 
 error() {
     set -- "ERROR:" "$@";
@@ -1006,7 +1007,25 @@ dscheck_Hetzner() {
 }
 
 is_ibm_provisioning() {
-    [ -f "${PATH_ROOT}/root/provisioningConfiguration.cfg" ]
+    local pcfg="${PATH_ROOT}/root/provisioningConfiguration.cfg"
+    local logf="${PATH_ROOT}/root/swinstall.log"
+    local is_prov=false msg="config '$pcfg' did not exist."
+    if [ -f "$pcfg" ]; then
+        msg="config '$pcfg' exists."
+        is_prov=true
+        if [ -f "$logf" ]; then
+            if [ "$logf" -nt "$PATH_PROC_1_ENVIRON" ]; then
+                msg="$msg log '$logf' from current boot."
+            else
+                is_prov=false
+                msg="$msg log '$logf' from previous boot."
+            fi
+        else
+            msg="$msg log '$logf' did not exist."
+        fi
+    fi
+    debug 2 "ibm_provisioning=$is_prov: $msg"
+    [ "$is_prov" = "true" ]
 }
 
 is_ibm_cloud() {