From 02d7f45aa1aec6d2f6749da6a4cf29183b75d2eb Mon Sep 17 00:00:00 2001
From: narrieta <narrieta>
Date: Thu, 24 Feb 2022 20:57:17 -0800
Subject: [PATCH 1/5] Reorganize the history directory

---
 .../extensions_goal_state_from_vm_settings.py |  6 +-
 azurelinuxagent/common/protocol/goal_state.py | 73 ++++++++--------
 azurelinuxagent/common/utils/archive.py       | 11 +--
 azurelinuxagent/common/utils/time.py          | 10 +++
 azurelinuxagent/ga/exthandlers.py             | 11 +--
 azurelinuxagent/ga/update.py                  | 25 ++++--
 tests/protocol/test_goal_state.py             | 87 +++++++++++++------
 7 files changed, 136 insertions(+), 87 deletions(-)
 create mode 100644 azurelinuxagent/common/utils/time.py

diff --git a/azurelinuxagent/common/protocol/extensions_goal_state_from_vm_settings.py b/azurelinuxagent/common/protocol/extensions_goal_state_from_vm_settings.py
index c107aa14fc..7d2657e5da 100644
--- a/azurelinuxagent/common/protocol/extensions_goal_state_from_vm_settings.py
+++ b/azurelinuxagent/common/protocol/extensions_goal_state_from_vm_settings.py
@@ -126,7 +126,11 @@ def extensions(self):
         return self._extensions
 
     def get_redacted_text(self):
-        return re.sub(r'("protectedSettings"\s*:\s*)"[^"]+"', r'\1"*** REDACTED ***"', self._text)
+        return ExtensionsGoalStateFromVmSettings.redact(self._text)
+
+    @staticmethod
+    def redact(text):
+        return re.sub(r'("protectedSettings"\s*:\s*)"[^"]+"', r'\1"*** REDACTED ***"', text)
 
     def _parse_vm_settings(self, json_text):
         vm_settings = _CaseFoldedDict.from_dict(json.loads(json_text))
diff --git a/azurelinuxagent/common/protocol/goal_state.py b/azurelinuxagent/common/protocol/goal_state.py
index ee8b15fcd2..676b314c2c 100644
--- a/azurelinuxagent/common/protocol/goal_state.py
+++ b/azurelinuxagent/common/protocol/goal_state.py
@@ -27,12 +27,14 @@
 from azurelinuxagent.common.exception import ProtocolError, ResourceGoneError, VmSettingsError
 from azurelinuxagent.common.future import ustr
 from azurelinuxagent.common.protocol.extensions_goal_state_factory import ExtensionsGoalStateFactory
+from azurelinuxagent.common.protocol.extensions_goal_state_from_vm_settings import ExtensionsGoalStateFromVmSettings
 from azurelinuxagent.common.protocol.hostplugin import VmSettingsNotSupported
 from azurelinuxagent.common.protocol.restapi import Cert, CertList, RemoteAccessUser, RemoteAccessUsersList
 from azurelinuxagent.common.utils import fileutil
 from azurelinuxagent.common.utils.archive import GoalStateHistory
 from azurelinuxagent.common.utils.cryptutil import CryptUtil
 from azurelinuxagent.common.utils.textutil import parse_doc, findall, find, findtext, getattrib
+from azurelinuxagent.common.utils.time import create_timestamp
 
 GOAL_STATE_URI = "http://{0}/machine/?comp=goalstate"
 CERTS_FILE_NAME = "Certificates.xml"
@@ -60,28 +62,24 @@ def __init__(self, wire_client):
             self._wire_client = wire_client
 
             # These "basic" properties come from the initial request to WireServer's goalstate API
-            self._timestamp = None
             self._incarnation = None
             self._role_instance_id = None
             self._role_config_name = None
             self._container_id = None
 
-            xml_text, xml_doc = GoalState._fetch_goal_state(self._wire_client)
-
-            self._initialize_basic_properties(xml_doc)
-
-            # The goal state for extensions can come from vmSettings when using FastTrack or from extensionsConfig otherwise, self._fetch_extended_goal_state
-            # populates the '_extensions_goal_state' property.
+            # These "extended" properties come from additional HTTP requests to the URIs included in the basic goal state, or to the HostGAPlugin
             self._extensions_goal_state = None
-            vm_settings = self._fetch_vm_settings()
-
-            # These "extended" properties come from additional HTTP requests to the URIs included in the basic goal state
             self._hosting_env = None
             self._shared_conf = None
             self._certs = None
             self._remote_access = None
 
-            self._fetch_extended_goal_state(xml_text, xml_doc, vm_settings)
+            timestamp = create_timestamp()
+            xml_text, xml_doc, incarnation = GoalState._fetch_goal_state(self._wire_client)
+            self._history = GoalStateHistory(timestamp, incarnation)
+
+            self._initialize_basic_properties(xml_doc)
+            self._fetch_extended_goal_state(xml_text, xml_doc)
 
         except Exception as exception:
             # We don't log the error here since fetching the goal state is done every few seconds
@@ -139,26 +137,31 @@ def update(self, force_update=False):
         """
         Updates the current GoalState instance fetching values from the WireServer/HostGAPlugin as needed
         """
-        xml_text, xml_doc = GoalState._fetch_goal_state(self._wire_client)
+        timestamp = create_timestamp()
+        xml_text, xml_doc, incarnation = GoalState._fetch_goal_state(self._wire_client)
 
-        vm_settings = self._fetch_vm_settings(force_update=force_update)
-
-        if force_update or self._incarnation != findtext(xml_doc, "Incarnation"):
-            # update the extended goal state, using vm_settings for the extensions (unless they are None, then use extensionsConfig)
+        if force_update or self._incarnation != incarnation:
+            # If we are fetching a new goal state
+            self._history = GoalStateHistory(timestamp, incarnation)
             self._initialize_basic_properties(xml_doc)
-            self._fetch_extended_goal_state(xml_text, xml_doc,  vm_settings)
+            self._fetch_extended_goal_state(xml_text, xml_doc, force_vm_settings_update=force_update)
         else:
-            # else just ensure the extensions are using the latest vm_settings
-            if vm_settings is not None:
+            # else ensure the extensions are using the latest vm_settings
+            timestamp = create_timestamp()
+            vm_settings, vm_settings_updated = self._fetch_vm_settings(force_update=force_update)
+            if vm_settings_updated:
+                self._history = GoalStateHistory(timestamp, vm_settings.etag)
                 self._extensions_goal_state = vm_settings
+                self._history.save_vm_settings(vm_settings.get_redacted_text())
 
     def save_to_history(self, data, file_name):
         self._history.save(data, file_name)
 
+    def add_file_to_history(self, file_name):
+        self._history.add_file(file_name)
+
     def _initialize_basic_properties(self, xml_doc):
-        self._timestamp = datetime.datetime.utcnow().isoformat()
         self._incarnation = findtext(xml_doc, "Incarnation")
-        self._history = GoalStateHistory(self._timestamp, self._incarnation)  # history for the WireServer goal state; vmSettings are separate
         role_instance = find(xml_doc, "RoleInstance")
         self._role_instance_id = findtext(role_instance, "InstanceId")
         role_config = find(role_instance, "Configuration")
@@ -175,16 +178,17 @@ def _fetch_goal_state(wire_client):
 
         # In some environments a few goal state requests return a missing RoleInstance; these retries are used to work around that issue
         # TODO: Consider retrying on 410 (ResourceGone) as well
+        incarnation = "unknown"
         for _ in range(0, _GET_GOAL_STATE_MAX_ATTEMPTS):
             xml_text = wire_client.fetch_config(uri, wire_client.get_header())
             xml_doc = parse_doc(xml_text)
+            incarnation = findtext(xml_doc, "Incarnation")
 
             role_instance = find(xml_doc, "RoleInstance")
             if role_instance:
                 break
             time.sleep(0.5)
         else:
-            incarnation = findtext(xml_doc, "Incarnation")
             raise ProtocolError("Fetched goal state without a RoleInstance [incarnation {inc}]".format(inc=incarnation))
 
         # Telemetry and the HostGAPlugin depend on the container id/role config; keep them up-to-date each time we fetch the goal state
@@ -198,7 +202,7 @@ def _fetch_goal_state(wire_client):
 
         wire_client.update_host_plugin(container_id, role_config_name)
 
-        return xml_text, xml_doc
+        return xml_text, xml_doc, incarnation
 
     def _fetch_vm_settings(self, force_update=False):
         """
@@ -207,30 +211,23 @@ def _fetch_vm_settings(self, force_update=False):
         vm_settings, vm_settings_updated = (None, False)
 
         if conf.get_enable_fast_track():
-            def save_to_history(etag, text):
-                # The vmSettings are updated independently of the WireServer goal state and they are saved to a separate directory
-                history = GoalStateHistory(datetime.datetime.utcnow().isoformat(), etag)
-                history.save_vm_settings(text)
-
             try:
                 vm_settings, vm_settings_updated = self._wire_client.get_host_plugin().fetch_vm_settings(force_update=force_update)
 
             except VmSettingsNotSupported:
                 pass
             except VmSettingsError as exception:
-                save_to_history(exception.etag, exception.vm_settings_text)
+                # ensure we save the vmSettings if there were parsing errors
+                self._history.save_vm_settings(ExtensionsGoalStateFromVmSettings.redact(exception.vm_settings_text))
                 raise
             except ResourceGoneError:
                 # retry after refreshing the HostGAPlugin
                 GoalState.update_host_plugin_headers(self._wire_client)
                 vm_settings, vm_settings_updated = self._wire_client.get_host_plugin().fetch_vm_settings(force_update=force_update)
 
-            if vm_settings_updated:
-                save_to_history(vm_settings.etag, vm_settings.get_redacted_text())
-
-        return vm_settings
+        return vm_settings, vm_settings_updated
 
-    def _fetch_extended_goal_state(self, xml_text, xml_doc, vm_settings):
+    def _fetch_extended_goal_state(self, xml_text, xml_doc, force_vm_settings_update=False):
         """
         Issues HTTP requests (WireServer) for each of the URIs in the goal state (ExtensionsConfig, Certificate, Remote Access users, etc)
         and populates the corresponding properties. If the given 'vm_settings' are not None they are used for the extensions goal state,
@@ -241,8 +238,8 @@ def _fetch_extended_goal_state(self, xml_text, xml_doc, vm_settings):
 
             self._history.save_goal_state(xml_text)
 
-            # TODO: at this point we always fetch the extensionsConfig, even if it is not needed, and save it for debugging purposes. Once
-            #       FastTrack is stable this code can be updated to fetch it only when actually needed.
+            # Always fetch the ExtensionsConfig, even if it is not needed, and save it for debugging purposes. Once FastTrack is stable this code could be updated to
+            # fetch it only when actually needed.
             extensions_config_uri = findtext(xml_doc, "ExtensionsConfig")
 
             if extensions_config_uri is None:
@@ -252,8 +249,12 @@ def _fetch_extended_goal_state(self, xml_text, xml_doc, vm_settings):
                 extensions_config = ExtensionsGoalStateFactory.create_from_extensions_config(self._incarnation, xml_text, self._wire_client)
                 self._history.save_extensions_config(extensions_config.get_redacted_text())
 
+            vm_settings, vm_settings_updated = self._fetch_vm_settings(force_update=force_vm_settings_update)
+
             if vm_settings is not None:
                 self._extensions_goal_state = vm_settings
+                if vm_settings_updated:
+                    self._history.save_vm_settings(vm_settings.get_redacted_text())
             else:
                 self._extensions_goal_state = extensions_config
 
diff --git a/azurelinuxagent/common/utils/archive.py b/azurelinuxagent/common/utils/archive.py
index b40da7964d..edde7842bc 100644
--- a/azurelinuxagent/common/utils/archive.py
+++ b/azurelinuxagent/common/utils/archive.py
@@ -38,7 +38,7 @@
 
 ARCHIVE_DIRECTORY_NAME = 'history'
 
-_MAX_ARCHIVED_STATES = 100
+_MAX_ARCHIVED_STATES = 50
 
 _CACHE_PATTERNS = [
     re.compile(r"^VmSettings.\d+\.json$"),
@@ -214,9 +214,6 @@ def write_to_file(d, f):
 
         self._save(write_to_file, data, file_name)
 
-    def _save_file(self, source_file, target_name):
-        self._save(shutil.move, source_file, target_name)
-
     def _save(self, function, source, target_name):
         try:
             if not os.path.exists(self._root):
@@ -228,6 +225,9 @@ def _save(self, function, source, target_name):
                 self._errors = True
                 logger.warn("Failed to save goal state file {0}: {1} [no additional errors saving the goal state will be reported]".format(target_name, e))
 
+    def add_file(self, source_file):
+        self._save(shutil.move, source_file, self._root)
+
     def save_goal_state(self, text):
         self.save(text, _GOAL_STATE_FILE_NAME)
 
@@ -245,6 +245,3 @@ def save_hosting_env(self, text):
 
     def save_shared_conf(self, text):
         self.save(text, _SHARED_CONF_FILE_NAME)
-
-    def save_status_file(self, status_file):
-        self._save_file(status_file, AGENT_STATUS_FILE)
diff --git a/azurelinuxagent/common/utils/time.py b/azurelinuxagent/common/utils/time.py
new file mode 100644
index 0000000000..baf311ca7a
--- /dev/null
+++ b/azurelinuxagent/common/utils/time.py
@@ -0,0 +1,10 @@
+# Copyright (c) Microsoft Corporation. All rights reserved.
+# Licensed under the Apache License.
+import datetime
+
+
+def create_timestamp():
+    """
+    Returns a string with current UTC time in iso format
+    """
+    return datetime.datetime.utcnow().isoformat()
diff --git a/azurelinuxagent/ga/exthandlers.py b/azurelinuxagent/ga/exthandlers.py
index f848d2d329..73a8fa52dc 100644
--- a/azurelinuxagent/ga/exthandlers.py
+++ b/azurelinuxagent/ga/exthandlers.py
@@ -945,7 +945,7 @@ def report_ext_handlers_status(self, incarnation_changed=False, vm_agent_update_
 
                 self.report_status_error_state.reset()
 
-            self.write_ext_handlers_status_to_info_file(vm_status, incarnation_changed)
+            self.write_ext_handlers_status_to_info_file(vm_status)
 
             return vm_status
 
@@ -959,16 +959,9 @@ def report_ext_handlers_status(self, incarnation_changed=False, vm_agent_update_
                       message=msg)
             return None
 
-    def write_ext_handlers_status_to_info_file(self, vm_status, incarnation_changed):
+    def write_ext_handlers_status_to_info_file(self, vm_status):
         status_file = os.path.join(conf.get_lib_dir(), AGENT_STATUS_FILE)
 
-        if os.path.exists(status_file) and incarnation_changed:
-            # On new goal state, move the last status report for the previous goal state to the history folder
-            last_modified = os.path.getmtime(status_file)
-            timestamp = datetime.datetime.utcfromtimestamp(last_modified).isoformat()
-            GoalStateHistory(timestamp, "status").save_status_file(status_file)
-
-        # Now create/overwrite the status file; this file is kept for debugging purposes only
         status_blob_text = self.protocol.get_status_blob_data()
         if status_blob_text is None:
             status_blob_text = ""
diff --git a/azurelinuxagent/ga/update.py b/azurelinuxagent/ga/update.py
index ab1950d934..2ddcbb24f0 100644
--- a/azurelinuxagent/ga/update.py
+++ b/azurelinuxagent/ga/update.py
@@ -51,7 +51,7 @@
     VERSION_0
 from azurelinuxagent.common.protocol.util import get_protocol_util
 from azurelinuxagent.common.utils import shellutil
-from azurelinuxagent.common.utils.archive import StateArchiver
+from azurelinuxagent.common.utils.archive import StateArchiver, AGENT_STATUS_FILE
 from azurelinuxagent.common.utils.flexible_version import FlexibleVersion
 from azurelinuxagent.common.utils.networkutil import AddFirewallRules
 from azurelinuxagent.common.utils.shellutil import CommandError
@@ -590,16 +590,21 @@ def _process_goal_state(self, exthandlers_handler, remote_access_handler):
 
             # report status always, even if the goal state did not change
             # do it before processing the remote access, since that operation can take a long time
+            if self._processing_new_extensions_goal_state():
+                # Before reporting status for the new goal state, move the status report for the previous goal state to the history folder.
+                status_file = os.path.join(conf.get_lib_dir(), AGENT_STATUS_FILE)
+                if os.path.exists(status_file):
+                    self._goal_state.add_file_to_history(status_file)
+
             self._report_status(exthandlers_handler)
 
+            # now process remote access
             if self._processing_new_incarnation():
                 remote_access_handler.run()
 
+            # and lastly, cleanup the goal state history (but do it only on new goal states - no need to do it on every iteration)
             if self._processing_new_extensions_goal_state():
-                try:
-                    UpdateHandler._cleanup_goal_state_history()
-                except Exception as exception:
-                    logger.warn("Error cleaning up the goal state history: {0}", ustr(exception))
+                UpdateHandler._cleanup_goal_state_history()
 
         finally:
             if self._goal_state is not None:
@@ -608,9 +613,12 @@ def _process_goal_state(self, exthandlers_handler, remote_access_handler):
 
     @staticmethod
     def _cleanup_goal_state_history():
-        archiver = StateArchiver(conf.get_lib_dir())
-        archiver.purge()
-        archiver.archive()
+        try:
+            archiver = StateArchiver(conf.get_lib_dir())
+            archiver.purge()
+            archiver.archive()
+        except Exception as exception:
+            logger.warn("Error cleaning up the goal state history: {0}", ustr(exception))
 
     @staticmethod
     def _cleanup_legacy_goal_state_history():
@@ -666,6 +674,7 @@ def _report_status(self, exthandlers_handler):
             supports_fast_track = False
         else:
             supports_fast_track = self._goal_state.extensions_goal_state.source_channel == GoalStateChannel.HostGAPlugin
+
         vm_status = exthandlers_handler.report_ext_handlers_status(
             incarnation_changed=self._processing_new_extensions_goal_state(),
             vm_agent_update_status=vm_agent_update_status,
diff --git a/tests/protocol/test_goal_state.py b/tests/protocol/test_goal_state.py
index 4e8dd4f737..af818e845e 100644
--- a/tests/protocol/test_goal_state.py
+++ b/tests/protocol/test_goal_state.py
@@ -2,6 +2,7 @@
 # Licensed under the Apache License.
 
 import glob
+import http.client as httpclient
 import os
 import re
 
@@ -9,8 +10,9 @@
 from azurelinuxagent.common.exception import ProtocolError
 from azurelinuxagent.common.utils import fileutil
 from azurelinuxagent.common.utils.archive import ARCHIVE_DIRECTORY_NAME
-from tests.protocol.mocks import mock_wire_protocol
+from tests.protocol.mocks import mock_wire_protocol, MockHttpResponse
 from tests.protocol import mockwiredata
+from tests.protocol.HttpRequestPredicates import HttpRequestPredicates
 from tests.tools import AgentTestCase, patch, load_data
 
 
@@ -27,34 +29,64 @@ def test_fetch_goal_state_should_raise_on_incomplete_goal_state(self):
                 self.assertEqual(_GET_GOAL_STATE_MAX_ATTEMPTS, mock_sleep.call_count, "Unexpected number of retries")
 
     @patch("azurelinuxagent.common.conf.get_enable_fast_track", return_value=True)
-    def test_fetch_full_goal_state_should_save_goal_state_to_history_directory(self, _):
+    def test_instantiating_goal_state_should_save_the_goal_state_to_the_history_directory(self, _):
         with mock_wire_protocol(mockwiredata.DATA_FILE_VM_SETTINGS) as protocol:
-            # use a new goal state with a specific test incarnation and etag
             protocol.mock_wire_data.set_incarnation(999)
-            protocol.mock_wire_data.set_etag(888)
-            goal_state = GoalState(protocol.client)
 
-            matches = glob.glob(os.path.join(self.tmp_dir, ARCHIVE_DIRECTORY_NAME, "*_999"))
-            self.assertTrue(len(matches) == 1, "Expected one history directory for incarnation 999. Got: {0}".format(matches))
+            _ = GoalState(protocol.client)
 
-            history_directory = matches[0]
-            extensions_config_file = os.path.join(history_directory, "ExtensionsConfig.xml")
-            expected_files = [
-                os.path.join(history_directory, "GoalState.xml"),
-                os.path.join(history_directory, "SharedConfig.xml"),
-                os.path.join(history_directory, "HostingEnvironmentConfig.xml"),
-                extensions_config_file,
-            ]
+            self._assert_directory_contents(
+                self._find_history_subdirectory("999"),
+                ["GoalState.xml", "ExtensionsConfig.xml", "VmSettings.json", "SharedConfig.xml", "HostingEnvironmentConfig.xml"])
 
-            matches = glob.glob(os.path.join(self.tmp_dir, ARCHIVE_DIRECTORY_NAME, "*_888"))
-            self.assertTrue(len(matches) == 1, "Expected one history directory for etag 888. Got: {0}".format(matches))
+    def _find_history_subdirectory(self, tag):
+        matches = glob.glob(os.path.join(self.tmp_dir, ARCHIVE_DIRECTORY_NAME, "*_{0}".format(tag)))
+        self.assertTrue(len(matches) == 1, "Expected one history directory for tag {0}. Got: {1}".format(tag, matches))
+        return matches[0]
 
-            history_directory = matches[0]
-            vm_settings_file = os.path.join(history_directory, "VmSettings.json")
-            expected_files.append(vm_settings_file)
+    def _assert_directory_contents(self, directory, expected_files):
+        actual_files = os.listdir(directory)
+
+        expected_files.sort()
+        actual_files.sort()
+
+        self.assertEqual(expected_files, actual_files, "The expected files were not saved to {0}".format(directory))
 
-            for f in expected_files:
-                self.assertTrue(os.path.exists(f), "{0} was not saved".format(f))
+    @patch("azurelinuxagent.common.conf.get_enable_fast_track", return_value=True)
+    def test_update_should_create_new_history_subdirectories(self, _):
+        with mock_wire_protocol(mockwiredata.DATA_FILE_VM_SETTINGS) as protocol:
+            protocol.mock_wire_data.set_incarnation(123)
+            protocol.mock_wire_data.set_etag(654)
+
+            goal_state = GoalState(protocol.client)
+            self._assert_directory_contents(
+                self._find_history_subdirectory("123"),
+                ["GoalState.xml", "ExtensionsConfig.xml", "VmSettings.json", "SharedConfig.xml", "HostingEnvironmentConfig.xml"])
+
+            def http_get_handler(url, *_, **__):
+                if HttpRequestPredicates.is_host_plugin_vm_settings_request(url):
+                    return MockHttpResponse(status=httpclient.NOT_MODIFIED)
+                return None
+
+            protocol.mock_wire_data.set_incarnation(234)
+            protocol.set_http_handlers(http_get_handler=http_get_handler)
+            goal_state.update()
+            self._assert_directory_contents(
+                self._find_history_subdirectory("234"),
+                ["GoalState.xml", "ExtensionsConfig.xml", "SharedConfig.xml", "HostingEnvironmentConfig.xml"])
+
+            protocol.mock_wire_data.set_etag(987)
+            protocol.set_http_handlers(http_get_handler=None)
+            goal_state.update()
+            self._assert_directory_contents(
+                self._find_history_subdirectory("987"), ["VmSettings.json"])
+
+    @patch("azurelinuxagent.common.conf.get_enable_fast_track", return_value=True)
+    def test_it_should_redact_the_protected_settings_when_saving_to_the_history_directory(self, _):
+        with mock_wire_protocol(mockwiredata.DATA_FILE_VM_SETTINGS) as protocol:
+            protocol.mock_wire_data.set_incarnation(888)
+
+            goal_state = GoalState(protocol.client)
 
             extensions_goal_state = goal_state.extensions_goal_state
             protected_settings = []
@@ -65,6 +97,9 @@ def test_fetch_full_goal_state_should_save_goal_state_to_history_directory(self,
             if len(protected_settings) == 0:
                 raise Exception("The test goal state does not include any protected settings")
 
+            history_directory = self._find_history_subdirectory("888")
+            extensions_config_file = os.path.join(history_directory, "ExtensionsConfig.xml")
+            vm_settings_file = os.path.join(history_directory, "VmSettings.json")
             for file_name in extensions_config_file, vm_settings_file:
                 with open(file_name, "r") as stream:
                     file_contents = stream.read()
@@ -88,13 +123,13 @@ def test_it_should_save_vm_settings_on_parse_errors(self, _):
             data_file = mockwiredata.DATA_FILE_VM_SETTINGS.copy()
             data_file["vm_settings"] = invalid_vm_settings_file
             protocol.mock_wire_data = mockwiredata.WireProtocolData(data_file)
-            protocol.mock_wire_data.set_etag(888)
+            protocol.mock_wire_data.set_incarnation(888)
 
-            with self.assertRaises(ProtocolError):
-                GoalState(protocol.client)
+            with self.assertRaises(ProtocolError):  # the parsing error will cause an exception
+                goal_state = GoalState(protocol.client)
 
             matches = glob.glob(os.path.join(self.tmp_dir, ARCHIVE_DIRECTORY_NAME, "*_888"))
-            self.assertTrue(len(matches) == 1, "Expected one history directory for etag 888. Got: {0}".format(matches))
+            self.assertTrue(len(matches) == 1, "Expected one history directory for incarnation 888. Got: {0}".format(matches))
 
             history_directory = matches[0]
             vm_settings_file = os.path.join(history_directory, "VmSettings.json")

From 35b3f5ae16400505eae4b05ffc182bdcc8d0bcb0 Mon Sep 17 00:00:00 2001
From: narrieta <narrieta>
Date: Thu, 24 Feb 2022 22:14:55 -0800
Subject: [PATCH 2/5] pylint

---
 azurelinuxagent/common/protocol/goal_state.py | 5 -----
 azurelinuxagent/ga/exthandlers.py             | 2 +-
 tests/protocol/test_goal_state.py             | 2 +-
 3 files changed, 2 insertions(+), 7 deletions(-)

diff --git a/azurelinuxagent/common/protocol/goal_state.py b/azurelinuxagent/common/protocol/goal_state.py
index 676b314c2c..de2e79b6dc 100644
--- a/azurelinuxagent/common/protocol/goal_state.py
+++ b/azurelinuxagent/common/protocol/goal_state.py
@@ -15,7 +15,6 @@
 # limitations under the License.
 #
 # Requires Python 2.6+ and Openssl 1.0+
-import datetime
 import os
 import re
 import time
@@ -85,10 +84,6 @@ def __init__(self, wire_client):
             # We don't log the error here since fetching the goal state is done every few seconds
             raise ProtocolError(msg="Error fetching goal state", inner=exception)
 
-    @property
-    def timestamp(self):
-        return self._timestamp
-
     @property
     def incarnation(self):
         return self._incarnation
diff --git a/azurelinuxagent/ga/exthandlers.py b/azurelinuxagent/ga/exthandlers.py
index 73a8fa52dc..9e2f3bed60 100644
--- a/azurelinuxagent/ga/exthandlers.py
+++ b/azurelinuxagent/ga/exthandlers.py
@@ -50,7 +50,7 @@
 from azurelinuxagent.common.protocol.restapi import ExtensionStatus, ExtensionSubStatus, Extension, ExtHandlerStatus, \
     VMStatus, GoalStateAggregateStatus, ExtensionState, ExtensionRequestedState, ExtensionSettings
 from azurelinuxagent.common.utils import textutil
-from azurelinuxagent.common.utils.archive import ARCHIVE_DIRECTORY_NAME, AGENT_STATUS_FILE, GoalStateHistory
+from azurelinuxagent.common.utils.archive import ARCHIVE_DIRECTORY_NAME, AGENT_STATUS_FILE
 from azurelinuxagent.common.utils.flexible_version import FlexibleVersion
 from azurelinuxagent.common.version import AGENT_NAME, CURRENT_VERSION, \
     PY_VERSION_MAJOR, PY_VERSION_MICRO, PY_VERSION_MINOR
diff --git a/tests/protocol/test_goal_state.py b/tests/protocol/test_goal_state.py
index af818e845e..b464fc7660 100644
--- a/tests/protocol/test_goal_state.py
+++ b/tests/protocol/test_goal_state.py
@@ -126,7 +126,7 @@ def test_it_should_save_vm_settings_on_parse_errors(self, _):
             protocol.mock_wire_data.set_incarnation(888)
 
             with self.assertRaises(ProtocolError):  # the parsing error will cause an exception
-                goal_state = GoalState(protocol.client)
+                _ = GoalState(protocol.client)
 
             matches = glob.glob(os.path.join(self.tmp_dir, ARCHIVE_DIRECTORY_NAME, "*_888"))
             self.assertTrue(len(matches) == 1, "Expected one history directory for incarnation 888. Got: {0}".format(matches))

From 7f7d128923153e747d8041d7f8d9f74e91bc192c Mon Sep 17 00:00:00 2001
From: narrieta <narrieta>
Date: Thu, 24 Feb 2022 22:39:35 -0800
Subject: [PATCH 3/5] python2

---
 azurelinuxagent/common/protocol/goal_state.py         | 2 +-
 azurelinuxagent/common/utils/{time.py => timeutil.py} | 0
 tests/protocol/test_goal_state.py                     | 2 +-
 3 files changed, 2 insertions(+), 2 deletions(-)
 rename azurelinuxagent/common/utils/{time.py => timeutil.py} (100%)

diff --git a/azurelinuxagent/common/protocol/goal_state.py b/azurelinuxagent/common/protocol/goal_state.py
index de2e79b6dc..9eaa017b59 100644
--- a/azurelinuxagent/common/protocol/goal_state.py
+++ b/azurelinuxagent/common/protocol/goal_state.py
@@ -33,7 +33,7 @@
 from azurelinuxagent.common.utils.archive import GoalStateHistory
 from azurelinuxagent.common.utils.cryptutil import CryptUtil
 from azurelinuxagent.common.utils.textutil import parse_doc, findall, find, findtext, getattrib
-from azurelinuxagent.common.utils.time import create_timestamp
+from azurelinuxagent.common.utils.timeutil import create_timestamp
 
 GOAL_STATE_URI = "http://{0}/machine/?comp=goalstate"
 CERTS_FILE_NAME = "Certificates.xml"
diff --git a/azurelinuxagent/common/utils/time.py b/azurelinuxagent/common/utils/timeutil.py
similarity index 100%
rename from azurelinuxagent/common/utils/time.py
rename to azurelinuxagent/common/utils/timeutil.py
diff --git a/tests/protocol/test_goal_state.py b/tests/protocol/test_goal_state.py
index b464fc7660..dfa2ccb4f1 100644
--- a/tests/protocol/test_goal_state.py
+++ b/tests/protocol/test_goal_state.py
@@ -2,10 +2,10 @@
 # Licensed under the Apache License.
 
 import glob
-import http.client as httpclient
 import os
 import re
 
+from azurelinuxagent.common.future import httpclient
 from azurelinuxagent.common.protocol.goal_state import GoalState, _GET_GOAL_STATE_MAX_ATTEMPTS
 from azurelinuxagent.common.exception import ProtocolError
 from azurelinuxagent.common.utils import fileutil

From 5b8ce71fa0650c51088a274016fe608ef8cd2473 Mon Sep 17 00:00:00 2001
From: narrieta <narrieta>
Date: Fri, 25 Feb 2022 11:28:39 -0800
Subject: [PATCH 4/5] write agent status directly to history

---
 azurelinuxagent/common/protocol/goal_state.py |  3 --
 azurelinuxagent/common/utils/archive.py       | 16 ++-----
 azurelinuxagent/ga/exthandlers.py             | 45 +++++++------------
 azurelinuxagent/ga/update.py                  | 29 ++++++------
 tests/ga/test_extension.py                    |  7 +--
 tests/ga/test_report_status.py                |  3 +-
 tests/ga/test_update.py                       | 18 ++++++++
 7 files changed, 53 insertions(+), 68 deletions(-)

diff --git a/azurelinuxagent/common/protocol/goal_state.py b/azurelinuxagent/common/protocol/goal_state.py
index 9eaa017b59..d4429085d7 100644
--- a/azurelinuxagent/common/protocol/goal_state.py
+++ b/azurelinuxagent/common/protocol/goal_state.py
@@ -152,9 +152,6 @@ def update(self, force_update=False):
     def save_to_history(self, data, file_name):
         self._history.save(data, file_name)
 
-    def add_file_to_history(self, file_name):
-        self._history.add_file(file_name)
-
     def _initialize_basic_properties(self, xml_doc):
         self._incarnation = findtext(xml_doc, "Incarnation")
         role_instance = find(xml_doc, "RoleInstance")
diff --git a/azurelinuxagent/common/utils/archive.py b/azurelinuxagent/common/utils/archive.py
index edde7842bc..1c39dd498e 100644
--- a/azurelinuxagent/common/utils/archive.py
+++ b/azurelinuxagent/common/utils/archive.py
@@ -208,25 +208,15 @@ def __init__(self, timestamp, tag=None):
         self._root = os.path.join(conf.get_lib_dir(), ARCHIVE_DIRECTORY_NAME, "{0}_{1}".format(timestamp, tag) if tag is not None else timestamp)
 
     def save(self, data, file_name):
-        def write_to_file(d, f):
-            with open(f, "w") as h:
-                h.write(d)
-
-        self._save(write_to_file, data, file_name)
-
-    def _save(self, function, source, target_name):
         try:
             if not os.path.exists(self._root):
                 fileutil.mkdir(self._root, mode=0o700)
-            target = os.path.join(self._root, target_name)
-            function(source, target)
+            with open(os.path.join(self._root, file_name), "w") as handle:
+                handle.write(data)
         except Exception as e:
             if not self._errors:  # report only 1 error per directory
                 self._errors = True
-                logger.warn("Failed to save goal state file {0}: {1} [no additional errors saving the goal state will be reported]".format(target_name, e))
-
-    def add_file(self, source_file):
-        self._save(shutil.move, source_file, self._root)
+                logger.warn("Failed to save goal state file {0}: {1} [no additional errors saving the goal state will be reported]".format(file_name, e))
 
     def save_goal_state(self, text):
         self.save(text, _GOAL_STATE_FILE_NAME)
diff --git a/azurelinuxagent/ga/exthandlers.py b/azurelinuxagent/ga/exthandlers.py
index 9e2f3bed60..209f2c57ed 100644
--- a/azurelinuxagent/ga/exthandlers.py
+++ b/azurelinuxagent/ga/exthandlers.py
@@ -50,7 +50,7 @@
 from azurelinuxagent.common.protocol.restapi import ExtensionStatus, ExtensionSubStatus, Extension, ExtHandlerStatus, \
     VMStatus, GoalStateAggregateStatus, ExtensionState, ExtensionRequestedState, ExtensionSettings
 from azurelinuxagent.common.utils import textutil
-from azurelinuxagent.common.utils.archive import ARCHIVE_DIRECTORY_NAME, AGENT_STATUS_FILE
+from azurelinuxagent.common.utils.archive import ARCHIVE_DIRECTORY_NAME
 from azurelinuxagent.common.utils.flexible_version import FlexibleVersion
 from azurelinuxagent.common.version import AGENT_NAME, CURRENT_VERSION, \
     PY_VERSION_MAJOR, PY_VERSION_MICRO, PY_VERSION_MINOR
@@ -945,8 +945,6 @@ def report_ext_handlers_status(self, incarnation_changed=False, vm_agent_update_
 
                 self.report_status_error_state.reset()
 
-            self.write_ext_handlers_status_to_info_file(vm_status)
-
             return vm_status
 
         except Exception as error:
@@ -959,45 +957,32 @@ def report_ext_handlers_status(self, incarnation_changed=False, vm_agent_update_
                       message=msg)
             return None
 
-    def write_ext_handlers_status_to_info_file(self, vm_status):
-        status_file = os.path.join(conf.get_lib_dir(), AGENT_STATUS_FILE)
-
+    def get_ext_handlers_status_debug_info(self, vm_status):
         status_blob_text = self.protocol.get_status_blob_data()
         if status_blob_text is None:
             status_blob_text = ""
 
-        debug_info = ExtHandlersHandler._get_status_debug_info(vm_status)
-
-        status_file_text = \
-'''{{
-    "__comment__": "The __status__ property is the actual status reported to CRP",
-    "__status__": {0},
-    "__debug__": {1}
-}}
-'''.format(status_blob_text, debug_info)
-
-        fileutil.write_file(status_file, status_file_text)
-
-    @staticmethod
-    def _get_status_debug_info(vm_status):
         support_multi_config = dict()
+        vm_status_data = get_properties(vm_status)
+        vm_handler_statuses = vm_status_data.get('vmAgent', dict()).get('extensionHandlers')
+        for handler_status in vm_handler_statuses:
+            if handler_status.get('name') is not None:
+                support_multi_config[handler_status.get('name')] = handler_status.get('supports_multi_config')
 
-        if vm_status is not None:
-            vm_status_data = get_properties(vm_status)
-            vm_handler_statuses = vm_status_data.get('vmAgent', dict()).get('extensionHandlers')
-            for handler_status in vm_handler_statuses:
-                if handler_status.get('name') is not None:
-                    support_multi_config[handler_status.get('name')] = handler_status.get('supports_multi_config')
-
-        debug_info = {
+        debug_text = json.dumps({
             "agentName": AGENT_NAME,
             "daemonVersion": str(version.get_daemon_version()),
             "pythonVersion": "Python: {0}.{1}.{2}".format(PY_VERSION_MAJOR, PY_VERSION_MINOR, PY_VERSION_MICRO),
             "extensionSupportedFeatures": [name for name, _ in get_agent_supported_features_list_for_extensions().items()],
             "supportsMultiConfig": support_multi_config
-        }
+        })
 
-        return json.dumps(debug_info)
+        return '''{{
+    "__comment__": "The __status__ property is the actual status reported to CRP",
+    "__status__": {0},
+    "__debug__": {1}
+}}
+'''.format(status_blob_text, debug_text)
 
     def report_ext_handler_status(self, vm_status, ext_handler, incarnation_changed):
         ext_handler_i = ExtHandlerInstance(ext_handler, self.protocol)
diff --git a/azurelinuxagent/ga/update.py b/azurelinuxagent/ga/update.py
index 2ddcbb24f0..0e87586565 100644
--- a/azurelinuxagent/ga/update.py
+++ b/azurelinuxagent/ga/update.py
@@ -170,7 +170,7 @@ def __init__(self):
         # these members are used to avoid reporting errors too frequently
         self._heartbeat_update_goal_state_error_count = 0
         self._last_try_update_goal_state_failed = False
-        self._report_status_last_failed_incarnation = -1
+        self._report_status_last_failed_goal_state = None
 
         # incarnation of the last goal state that has been fully processed
         # (None if no goal state has been processed)
@@ -588,21 +588,14 @@ def _process_goal_state(self, exthandlers_handler, remote_access_handler):
                 self._extensions_summary = ExtensionsSummary()
                 exthandlers_handler.run()
 
-            # report status always, even if the goal state did not change
+            # always report status, even if the goal state did not change
             # do it before processing the remote access, since that operation can take a long time
-            if self._processing_new_extensions_goal_state():
-                # Before reporting status for the new goal state, move the status report for the previous goal state to the history folder.
-                status_file = os.path.join(conf.get_lib_dir(), AGENT_STATUS_FILE)
-                if os.path.exists(status_file):
-                    self._goal_state.add_file_to_history(status_file)
-
             self._report_status(exthandlers_handler)
 
-            # now process remote access
             if self._processing_new_incarnation():
                 remote_access_handler.run()
 
-            # and lastly, cleanup the goal state history (but do it only on new goal states - no need to do it on every iteration)
+            # lastly, cleanup the goal state history (but do it only on new goal states - no need to do it on every iteration)
             if self._processing_new_extensions_goal_state():
                 UpdateHandler._cleanup_goal_state_history()
 
@@ -679,9 +672,14 @@ def _report_status(self, exthandlers_handler):
             incarnation_changed=self._processing_new_extensions_goal_state(),
             vm_agent_update_status=vm_agent_update_status,
             vm_agent_supports_fast_track=supports_fast_track)
-        if vm_status is None:
-            return
 
+        if vm_status is not None:
+            self._report_extensions_summary(vm_status)
+            if self._goal_state is not None:
+                agent_status = exthandlers_handler.get_ext_handlers_status_debug_info(vm_status)
+                self._goal_state.save_to_history(agent_status, AGENT_STATUS_FILE)
+
+    def _report_extensions_summary(self, vm_status):
         try:
             extensions_summary = ExtensionsSummary(vm_status)
             if self._extensions_summary != extensions_summary:
@@ -696,10 +694,9 @@ def _report_status(self, exthandlers_handler):
                     if self._is_initial_goal_state:
                         self._on_initial_goal_state_completed(self._extensions_summary)
         except Exception as error:
-            # report errors only once per incarnation
-            goal_state = exthandlers_handler.protocol.get_goal_state()
-            if self._report_status_last_failed_incarnation != goal_state.incarnation:
-                self._report_status_last_failed_incarnation = goal_state.incarnation
+            # report errors only once per goal state
+            if self._report_status_last_failed_goal_state != self._goal_state.extensions_goal_state.id:
+                self._report_status_last_failed_goal_state = self._goal_state.extensions_goal_state.id
                 msg = u"Error logging the goal state summary: {0}".format(textutil.format_exception(error))
                 logger.warn(msg)
                 add_event(op=WALAEventOperation.GoalState, is_success=False, message=msg)
diff --git a/tests/ga/test_extension.py b/tests/ga/test_extension.py
index 9ad8297b06..5967031293 100644
--- a/tests/ga/test_extension.py
+++ b/tests/ga/test_extension.py
@@ -33,7 +33,6 @@
 from azurelinuxagent.common.datacontract import get_properties
 from azurelinuxagent.common.event import WALAEventOperation
 from azurelinuxagent.common.utils import fileutil
-from azurelinuxagent.common.utils.archive import AGENT_STATUS_FILE
 from azurelinuxagent.common.utils.fileutil import read_file
 from azurelinuxagent.common.utils.flexible_version import FlexibleVersion
 from azurelinuxagent.common.version import PY_VERSION_MAJOR, PY_VERSION_MINOR, PY_VERSION_MICRO, AGENT_NAME, \
@@ -3425,10 +3424,8 @@ def mock_http_put(url, *args, **_):
 
 
             exthandlers_handler.run()
-            exthandlers_handler.report_ext_handlers_status()
-
-            status_path = os.path.join(conf.get_lib_dir(), AGENT_STATUS_FILE.format(1))
-            actual_status_json = json.loads(fileutil.read_file(status_path))
+            vm_status = exthandlers_handler.report_ext_handlers_status()
+            actual_status_json = json.loads(exthandlers_handler.get_ext_handlers_status_debug_info(vm_status))
 
             # Don't compare the guestOSInfo
             status_property = actual_status_json.get("__status__")
diff --git a/tests/ga/test_report_status.py b/tests/ga/test_report_status.py
index dd26845fe9..df1776d31b 100644
--- a/tests/ga/test_report_status.py
+++ b/tests/ga/test_report_status.py
@@ -109,11 +109,12 @@ def test_report_status_should_log_errors_only_once_per_goal_state(self):
             with patch("azurelinuxagent.common.conf.get_autoupdate_enabled", return_value=False):  # skip agent update
                 with patch("azurelinuxagent.ga.update.logger.warn") as logger_warn:
                     update_handler = get_update_handler()
+                    update_handler._goal_state = protocol.get_goal_state()  # these tests skip the initialization of the goal state. so do that here
                     exthandlers_handler = ExtHandlersHandler(protocol)
                     update_handler._report_status(exthandlers_handler)
                     self.assertEqual(0, logger_warn.call_count, "UpdateHandler._report_status() should not report WARNINGS when there are no errors")
 
-                    with patch("azurelinuxagent.ga.update.ExtensionsSummary.__init__", return_value=Exception("TEST EXCEPTION")):  # simulate an error during _report_status()
+                    with patch("azurelinuxagent.ga.update.ExtensionsSummary.__init__", side_effect=Exception("TEST EXCEPTION")):  # simulate an error during _report_status()
                         update_handler._report_status(exthandlers_handler)
                         update_handler._report_status(exthandlers_handler)
                         update_handler._report_status(exthandlers_handler)
diff --git a/tests/ga/test_update.py b/tests/ga/test_update.py
index b9d9e29642..6f587d3c53 100644
--- a/tests/ga/test_update.py
+++ b/tests/ga/test_update.py
@@ -41,6 +41,7 @@
 from azurelinuxagent.common.protocol.util import ProtocolUtil
 from azurelinuxagent.common.protocol.wire import WireProtocol
 from azurelinuxagent.common.utils import fileutil, restutil, textutil
+from azurelinuxagent.common.utils.archive import ARCHIVE_DIRECTORY_NAME, AGENT_STATUS_FILE
 from azurelinuxagent.common.utils.flexible_version import FlexibleVersion
 from azurelinuxagent.common.utils.networkutil import FirewallCmdDirectCommands, AddFirewallRules
 from azurelinuxagent.common.version import AGENT_PKG_GLOB, AGENT_DIR_GLOB, AGENT_NAME, AGENT_DIR_PATTERN, \
@@ -2780,6 +2781,7 @@ def create_vm_status(extension_status):
             exthandlers_handler.report_ext_handlers_status = Mock(return_value=create_vm_status(ExtensionStatusValue.success))
         else:
             exthandlers_handler.report_ext_handlers_status = Mock(side_effect=[create_vm_status(s) for s in extension_statuses])
+        exthandlers_handler.get_ext_handlers_status_debug_info = Mock(return_value='')
         yield exthandlers_handler
 
 
@@ -2813,6 +2815,22 @@ def test_it_should_process_goal_state_only_on_new_goal_state(self):
             self.assertEqual(3, exthandlers_handler.report_ext_handlers_status.call_count, "exthandlers_handler.report_ext_handlers_status() should have been called on a new goal state")
             self.assertEqual(2, remote_access_handler.run.call_count, "remote_access_handler.run() should have been called on a new goal state")
 
+    def test_it_should_write_the_agent_status_to_the_history_folder(self):
+        with _mock_exthandlers_handler() as exthandlers_handler:
+            update_handler = _create_update_handler()
+            remote_access_handler = Mock()
+            remote_access_handler.run = Mock()
+
+            update_handler._process_goal_state(exthandlers_handler, remote_access_handler)
+
+            incarnation = exthandlers_handler.protocol.get_goal_state().incarnation
+            matches = glob.glob(os.path.join(conf.get_lib_dir(), ARCHIVE_DIRECTORY_NAME, "*_{0}".format(incarnation)))
+            self.assertTrue(len(matches) == 1, "Could not find the history directory for the goal state. Got: {0}".format(matches))
+
+            status_file = os.path.join(matches[0], AGENT_STATUS_FILE)
+            self.assertTrue(os.path.exists(status_file), "Could not find {0}".format(status_file))
+
+
 class HeartbeatTestCase(AgentTestCase):
 
     @patch("azurelinuxagent.common.logger.info")

From 7faa811489c5ca06e3a3e18d9c4ff041793e5154 Mon Sep 17 00:00:00 2001
From: narrieta <narrieta>
Date: Mon, 28 Feb 2022 20:34:59 -0800
Subject: [PATCH 5/5] update message

---
 azurelinuxagent/common/utils/archive.py | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/azurelinuxagent/common/utils/archive.py b/azurelinuxagent/common/utils/archive.py
index 1c39dd498e..807b5dca73 100644
--- a/azurelinuxagent/common/utils/archive.py
+++ b/azurelinuxagent/common/utils/archive.py
@@ -216,7 +216,7 @@ def save(self, data, file_name):
         except Exception as e:
             if not self._errors:  # report only 1 error per directory
                 self._errors = True
-                logger.warn("Failed to save goal state file {0}: {1} [no additional errors saving the goal state will be reported]".format(file_name, e))
+                logger.warn("Failed to save {0} to the goal state history: {1} [no additional errors saving the goal state will be reported]".format(file_name, e))
 
     def save_goal_state(self, text):
         self.save(text, _GOAL_STATE_FILE_NAME)