Log changes (#166)

* Log changes

* Addressing feedback for: Log changes #1

* Adding some missing UTs for: Log changes

* Addressing feedback for: Log changes #2

* Addressing more UTs for: Log changes

* Addressing feedback for: Log changes #2

* Minor changes/cleanup for: Log changes

Author: rane-rajasi

src/core/src/CoreMain.py

@@ -13,6 +13,7 @@
 # limitations under the License.
 #
 # Requires Python 2.7+
+import os
 
 from core.src.bootstrap.Bootstrapper import Bootstrapper
 from core.src.bootstrap.Constants import Constants
@@ -27,7 +28,7 @@ def __init__(self, argv):
         composite_logger = bootstrapper.composite_logger
         stdout_file_mirror = bootstrapper.stdout_file_mirror
         telemetry_writer = bootstrapper.telemetry_writer
-        lifecycle_manager = status_handler = None
+        lifecycle_manager = status_handler = execution_config = None
 
         # Init operation statuses
         patch_operation_requested = Constants.UNKNOWN
@@ -59,6 +60,12 @@ def __init__(self, argv):
             telemetry_writer.set_task_name(Constants.TelemetryTaskName.AUTO_ASSESSMENT if execution_config.exec_auto_assess_only else Constants.TelemetryTaskName.EXEC)
             patch_operation_requested = execution_config.operation.lower()
 
+            # clean up temp folder before any operation execution begins from Core
+            if os.path.exists(execution_config.temp_folder):
+                composite_logger.log_debug("Deleting all files of certain format from temp folder [FileFormat={0}][TempFolderLocation={1}]"
+                                           .format(Constants.TEMP_FOLDER_CLEANUP_ARTIFACT_LIST, str(execution_config.temp_folder)))
+                bootstrapper.env_layer.file_system.delete_files_from_dir(execution_config.temp_folder, Constants.TEMP_FOLDER_CLEANUP_ARTIFACT_LIST)
+
             patch_assessor = container.get('patch_assessor')
             package_manager = container.get('package_manager')
             configure_patching_processor = container.get('configure_patching_processor')
@@ -115,6 +122,12 @@ def __init__(self, argv):
             composite_logger.log_debug("Completed exception handling.\n")
 
         finally:
+            # clean up temp folder of files created by Core after execution completes
+            if self.is_temp_folder_available(bootstrapper.env_layer, execution_config):
+                composite_logger.log_debug("Deleting all files of certain format from temp folder [FileFormat={0}][TempFolderLocation={1}]"
+                                           .format(Constants.TEMP_FOLDER_CLEANUP_ARTIFACT_LIST, str(execution_config.temp_folder)))
+                bootstrapper.env_layer.file_system.delete_files_from_dir(execution_config.temp_folder, Constants.TEMP_FOLDER_CLEANUP_ARTIFACT_LIST)
+
             if lifecycle_manager is not None:
                 lifecycle_manager.update_core_sequence(completed=True)
 
@@ -139,3 +152,10 @@ def update_patch_substatus_if_pending(patch_operation_requested, overall_patch_i
             status_handler.set_configure_patching_substatus_json(status=Constants.STATUS_ERROR)
             composite_logger.log_debug('  -- Persisted failed configure patching substatus.')
 
+    @staticmethod
+    def is_temp_folder_available(env_layer, execution_config):
+        return env_layer is not None \
+               and execution_config is not None \
+               and execution_config.temp_folder is not None \
+               and os.path.exists(execution_config.temp_folder)
+

src/core/src/bootstrap/Constants.py

@@ -59,6 +59,7 @@ class EnvSettings(EnumBackport):
         CONFIG_FOLDER = "configFolder"
         STATUS_FOLDER = "statusFolder"
         EVENTS_FOLDER = "eventsFolder"
+        TEMP_FOLDER = "tempFolder"
         TELEMETRY_SUPPORTED = "telemetrySupported"
 
     class ConfigSettings(EnumBackport):
@@ -76,6 +77,9 @@ class ConfigSettings(EnumBackport):
         ASSESSMENT_MODE = 'assessmentMode'
         MAXIMUM_ASSESSMENT_INTERVAL = 'maximumAssessmentInterval'
 
+    TEMP_FOLDER_DIR_NAME = "tmp"
+    TEMP_FOLDER_CLEANUP_ARTIFACT_LIST = ["*.list"]
+
     # File to save default settings for auto OS updates
     IMAGE_DEFAULT_PATCH_CONFIGURATION_BACKUP_PATH = "ImageDefaultPatchConfiguration.bak"
 

src/core/src/bootstrap/EnvLayer.py

@@ -17,6 +17,7 @@
 from __future__ import print_function
 import base64
 import datetime
+import glob
 import json
 import os
 import re
@@ -428,6 +429,27 @@ def write_with_retry_using_temp_file(file_path, data, mode='w'):
                     else:
                         raise Exception("Unable to write to {0} (retries exhausted). Error: {1}.".format(str(file_path), repr(error)))
 
+        @staticmethod
+        def delete_files_from_dir(dir_name, file_identifier_list, raise_if_delete_failed=False):
+            """ Clears all files from given dir. NOTE: Uses file_identifier_list to determine the content to delete """
+            for file_identifier in file_identifier_list:
+                files_to_delete = glob.glob(str(dir_name) + "/" + str(file_identifier))
+
+                for file_to_delete in files_to_delete:
+                    try:
+                        os.remove(file_to_delete)
+                    except Exception as error:
+                        error_message = "Unable to delete files from directory [Dir={0}][File={1}][Error={2}][RaiseIfDeleteFailed={3}].".format(
+                            str(dir_name),
+                            str(file_to_delete),
+                            repr(error),
+                            str(raise_if_delete_failed))
+
+                        if raise_if_delete_failed:
+                            raise Exception(error_message)
+                        else:
+                            print(error_message)
+                            return None
 # endregion - File system emulation and extensions
 
 # region - DateTime emulation and extensions

src/core/src/core_logic/ExecutionConfig.py

@@ -44,6 +44,9 @@ def __init__(self, env_layer, composite_logger, execution_parameters):
         self.config_folder = self.environment_settings[Constants.EnvSettings.CONFIG_FOLDER]
         self.status_folder = self.environment_settings[Constants.EnvSettings.STATUS_FOLDER]
         self.events_folder = self.environment_settings[Constants.EnvSettings.EVENTS_FOLDER]
+        self.temp_folder = self.environment_settings[Constants.EnvSettings.TEMP_FOLDER]
+        self.__check_and_create_temp_folder_if_not_exists()
+
         self.telemetry_supported = self.environment_settings[Constants.EnvSettings.TELEMETRY_SUPPORTED]
 
         # Config Settings
@@ -162,3 +165,16 @@ def __extract_most_significant_unit_from_duration(duration_portion, unit_delimit
         else:  # bad data
             raise Exception("Invalid duration portion: {0}".format(str(duration_portion)))
         return most_significant_unit, remaining_duration_portion
+
+    def __check_and_create_temp_folder_if_not_exists(self):
+        """Verifies temp folder exists, creates new one if not found"""
+        if self.temp_folder is None:
+            par_dir = os.path.dirname(self.config_folder)
+            if not os.path.exists(par_dir):
+                raise Exception("Parent directory for all extension artifacts such as config folder, status folder, etc. not found at [{0}].".format(repr(par_dir)))
+            self.temp_folder = os.path.join(par_dir, Constants.TEMP_FOLDER_DIR_NAME)
+
+        if not os.path.exists(self.temp_folder):
+            self.composite_logger.log_debug("Temp folder does not exist, creating one from extension core. [Path={0}]".format(str(self.temp_folder)))
+            os.mkdir(self.temp_folder)
+

src/core/src/package_managers/AptitudePackageManager.py

@@ -18,6 +18,8 @@
 import json
 import os
 import re
+import uuid
+
 from core.src.package_managers.PackageManager import PackageManager
 from core.src.bootstrap.Constants import Constants
 
@@ -28,12 +30,14 @@ class AptitudePackageManager(PackageManager):
     # For more details, try `man apt-get` on any Debian/Ubuntu based box.
     def __init__(self, env_layer, execution_config, composite_logger, telemetry_writer, status_handler):
         super(AptitudePackageManager, self).__init__(env_layer, execution_config, composite_logger, telemetry_writer, status_handler)
+
+        security_list_guid = str(uuid.uuid4())
         # Repo refresh
         self.repo_refresh = 'sudo apt-get -q update'
 
         # Support to get updates and their dependencies
-        self.security_sources_list = '/tmp/az-update-security.list'
-        self.prep_security_sources_list_cmd = 'sudo grep security /etc/apt/sources.list > ' + self.security_sources_list
+        self.security_sources_list = os.path.join(execution_config.temp_folder, 'msft-patch-security-{0}.list'.format(security_list_guid))
+        self.prep_security_sources_list_cmd = 'sudo grep security /etc/apt/sources.list > ' + os.path.normpath(self.security_sources_list)
         self.dist_upgrade_simulation_cmd_template = 'LANG=en_US.UTF8 sudo apt-get -s dist-upgrade <SOURCES> '  # Dist-upgrade simulation template - <SOURCES> needs to be replaced before use; sudo is used as sometimes the sources list needs sudo to be readable
         self.single_package_check_versions = 'apt-cache madison <PACKAGE-NAME>'
         self.single_package_find_installed_dpkg = 'sudo dpkg -s <PACKAGE-NAME>'

src/core/tests/Test_CoreMain.py

@@ -14,9 +14,11 @@
 #
 # Requires Python 2.7+
 import datetime
+import glob
 import json
 import os
 import re
+import shutil
 import time
 import unittest
 import uuid
@@ -46,6 +48,12 @@ def mock_linux_distribution_to_return_centos(self):
     def mock_linux_distribution_to_return_redhat(self):
         return ['Red Hat Enterprise Linux Server', '7.5', 'Maipo']
 
+    def mock_os_remove(self, file_to_remove):
+        raise Exception("File could not be deleted")
+
+    def mock_os_path_exists(self, patch_to_validate):
+        return False
+
     def test_operation_fail_for_non_autopatching_request(self):
         # Test for non auto patching request
         argument_composer = ArgumentComposer()
@@ -880,7 +888,7 @@ def test_assessment_superseded(self):
         scratch_path = os.path.join(os.path.curdir, "scratch")
 
         # Step 2: Set 1.status to Transitioning
-        with open(os.path.join(scratch_path, "1.status"), 'r+') as f:
+        with open(os.path.join(scratch_path, "status", "1.status"), 'r+') as f:
             status = json.load(f)
             status[0]["status"]["status"] = "transitioning"
             status[0]["status"]["substatus"][0]["status"] = "transitioning"
@@ -919,6 +927,98 @@ def test_assessment_superseded(self):
 
         runtime.stop()
 
+    def test_temp_folder_created_during_execution_config_init(self):
+        # temp_folder is set with a path in environment settings but the dir does not exist
+        argument_composer = ArgumentComposer()
+        shutil.rmtree(argument_composer.temp_folder)
+        argument_composer.operation = Constants.ASSESSMENT
+        runtime = RuntimeCompositor(argument_composer.get_composed_arguments(), True, Constants.APT)
+        # validate temp_folder is created
+        self.assertTrue(runtime.execution_config.temp_folder is not None)
+        self.assertTrue(os.path.exists(runtime.execution_config.temp_folder))
+        runtime.stop()
+
+        # temp_folder is set to None in ExecutionConfig with a valid config_folder location
+        argument_composer = ArgumentComposer()
+        shutil.rmtree(argument_composer.temp_folder)
+        argument_composer.temp_folder = None
+        argument_composer.operation = Constants.ASSESSMENT
+        runtime = RuntimeCompositor(argument_composer.get_composed_arguments(), True, Constants.APT)
+        # validate temp_folder is created
+        self.assertTrue(runtime.execution_config.temp_folder is not None)
+        self.assertTrue(os.path.exists(runtime.execution_config.temp_folder))
+        runtime.stop()
+
+        # temp_folder is set to None in ExecutionConfig with an invalid config_folder location, throws exception
+        argument_composer = ArgumentComposer()
+        shutil.rmtree(argument_composer.temp_folder)
+        argument_composer.temp_folder = None
+        argument_composer.operation = Constants.ASSESSMENT
+        # mock path exists check to return False on config_folder exists check
+        backup_os_path_exists = os.path.exists
+        os.path.exists = self.mock_os_path_exists
+        self.assertRaises(Exception, lambda: RuntimeCompositor(argument_composer.get_composed_arguments(), True, Constants.APT))
+        # validate temp_folder is not created
+        self.assertFalse(os.path.exists(os.path.join(os.path.curdir, "scratch", "tmp")))
+        os.path.exists = backup_os_path_exists
+        runtime.stop()
+
+    def test_delete_temp_folder_contents_success(self):
+        argument_composer = ArgumentComposer()
+        self.assertTrue(argument_composer.temp_folder is not None)
+        self.assertEqual(argument_composer.temp_folder, os.path.abspath(os.path.join(os.path.curdir, "scratch", "tmp")))
+
+        # delete temp content
+        argument_composer.operation = Constants.ASSESSMENT
+        runtime = RuntimeCompositor(argument_composer.get_composed_arguments(), True, Constants.APT)
+        runtime.set_legacy_test_type('HappyPath')
+        CoreMain(argument_composer.get_composed_arguments())
+
+        # validate files are deleted
+        self.assertTrue(argument_composer.temp_folder is not None)
+        files_matched = glob.glob(str(argument_composer.temp_folder) + "/" + str(Constants.TEMP_FOLDER_CLEANUP_ARTIFACT_LIST))
+        self.assertTrue(len(files_matched) == 0)
+        runtime.stop()
+
+    def test_delete_temp_folder_contents_when_none_exists(self):
+        argument_composer = ArgumentComposer()
+        argument_composer.operation = Constants.ASSESSMENT
+        runtime = RuntimeCompositor(argument_composer.get_composed_arguments(), True, Constants.APT)
+        shutil.rmtree(runtime.execution_config.temp_folder)
+
+        # attempt to delete temp content
+        runtime.env_layer.file_system.delete_files_from_dir(runtime.execution_config.temp_folder, Constants.TEMP_FOLDER_CLEANUP_ARTIFACT_LIST)
+
+        # validate files are deleted
+        self.assertTrue(runtime.execution_config.temp_folder is not None)
+        files_matched = glob.glob(str(runtime.execution_config.temp_folder) + "/" + str(Constants.TEMP_FOLDER_CLEANUP_ARTIFACT_LIST))
+        self.assertTrue(len(files_matched) == 0)
+        runtime.stop()
+
+    def test_delete_temp_folder_contents_failure(self):
+        argument_composer = ArgumentComposer()
+        self.assertTrue(argument_composer.temp_folder is not None)
+        self.assertEqual(argument_composer.temp_folder, os.path.abspath(os.path.join(os.path.curdir, "scratch", "tmp")))
+
+        # mock os.remove()
+        self.backup_os_remove = os.remove
+        os.remove = self.mock_os_remove
+
+        argument_composer.operation = Constants.ASSESSMENT
+        runtime = RuntimeCompositor(argument_composer.get_composed_arguments(), True, Constants.APT)
+
+        # delete temp content attempt #1, throws exception
+        self.assertRaises(Exception, lambda: runtime.env_layer.file_system.delete_files_from_dir(runtime.execution_config.temp_folder, Constants.TEMP_FOLDER_CLEANUP_ARTIFACT_LIST, raise_if_delete_failed=True))
+        self.assertTrue(os.path.isfile(os.path.join(runtime.execution_config.temp_folder, "temp1.list")))
+
+        # delete temp content attempt #2, does not throws exception
+        runtime.env_layer.file_system.delete_files_from_dir(runtime.execution_config.temp_folder, Constants.TEMP_FOLDER_CLEANUP_ARTIFACT_LIST)
+        self.assertTrue(os.path.isfile(os.path.join(runtime.execution_config.temp_folder, "temp1.list")))
+
+        # reset os.remove() mock
+        os.remove = self.backup_os_remove
+        runtime.stop()
+
     def __check_telemetry_events(self, runtime):
         all_events = os.listdir(runtime.telemetry_writer.events_folder_path)
         self.assertTrue(len(all_events) > 0)

src/core/tests/library/ArgumentComposer.py

@@ -31,14 +31,22 @@ def __init__(self):
         self.__TESTS_FOLDER = "tests"
         self.__SCRATCH_FOLDER = "scratch"
         self.__ARG_TEMPLATE = "{0} {1} {2} {3} \'{4}\' {5} \'{6}\' {7} {8}"
+        self.__CONFIG_FOLDER = "config"
+        self.__STATUS_FOLDER = "status"
+        self.__LOG_FOLDER = "log"
         self.__EVENTS_FOLDER = "events"
+        self.__TEMP_FOLDER = "tmp"
 
         # sequence number
         self.sequence_number = 1
 
         # environment settings
-        self.__log_folder = self.__config_folder = self.__status_folder = self.__get_scratch_folder()
-        self.events_folder = self.__get_events_folder(self.__log_folder)
+        scratch_folder = self.__get_scratch_folder()
+        self.__log_folder = self.__get_custom_folder(scratch_folder, self.__LOG_FOLDER)
+        self.__config_folder = self.__get_custom_folder(scratch_folder, self.__CONFIG_FOLDER)
+        self.__status_folder = self.__get_custom_folder(scratch_folder, self.__STATUS_FOLDER)
+        self.events_folder = self.__get_custom_folder(self.__log_folder, self.__EVENTS_FOLDER)
+        self.temp_folder = self.__get_custom_folder(scratch_folder, self.__TEMP_FOLDER)
 
         # config settings
         self.operation = Constants.INSTALLATION
@@ -67,6 +75,7 @@ def get_composed_arguments(self, env_settings={}):
             "configFolder": self.__config_folder,
             "statusFolder": self.__status_folder,
             "eventsFolder": self.events_folder,
+            "tempFolder": self.temp_folder,
             "telemetrySupported": True
         }
 
@@ -111,14 +120,15 @@ def __get_scratch_folder(self):
             os.mkdir(scratch_folder)
         return scratch_folder
 
-    def __get_events_folder(self, scratch_folder):
-        """ Returns a predetermined events folder and guarantees it exists and is empty. """
-        events_folder = os.path.join(scratch_folder, self.__EVENTS_FOLDER)
-        if os.path.exists(events_folder):
-            shutil.rmtree(events_folder, ignore_errors=True)
-        if not os.path.exists(events_folder):
-            os.mkdir(events_folder)
-        return events_folder
+    @staticmethod
+    def __get_custom_folder(par_dir, custom_folder_name):
+        """ Returns a predetermined custom folder, and guarantees it exists and is empty. """
+        custom_folder = os.path.join(par_dir, custom_folder_name)
+        if os.path.exists(custom_folder):
+            shutil.rmtree(custom_folder, ignore_errors=True)
+        if not os.path.exists(custom_folder):
+            os.mkdir(custom_folder)
+        return custom_folder
 
     def __try_get_tests_folder(self, path=os.getcwd()):
         """ Returns the current working directory if there's no folder with tests in its name in the absolute path