Repository: Azure/WALinuxAgent
Pull request #2313 (2021-07-21 20:22:02)

Query vmSettings only on new Goal State
Fast Track will be implemented in 3 phases. 

In the first phase Fast Track will not be enabled, so all goal states will come thru Fabric. The agent will query the vmSettings and compare it against the Fabric goal state from the Wireserver reporting any differences, or any errors from the HostGAPlugin.

This PR starts the work for Phase 1:

* Query vmSettings only when a new goal state is retrieved from the WireServer
* Don't report HTTP NOT_MODIFIED (304) as an error when retrieving vmSettings
* Save vmSettings to /var/lib/waagent/vmSettings.etag.json and to the history folder
* Pick up vmSettings.etag.json in the log collector
* vmSettings (HostGAPlugin) is not deployed to all regions yet so added Debug.FetchVmSettings to waagent.conf to disable the new code (it will be enabled only on DCR)

codecov[bot]: # [Codecov](https://codecov.io/gh/Azure/WALinuxAgent/pull/2313?src=pr&el=h1&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) Report
> Merging [#2313](https://codecov.io/gh/Azure/WALinuxAgent/pull/2313?src=pr&el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) (50364a8) into [fast-track](https://codecov.io/gh/Azure/WALinuxAgent/commit/fcd0b238b89e09f800d1ca6d29429412a3d4b188?el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) (fcd0b23) will **decrease** coverage by `0.16%`.
> The diff coverage is `56.25%`.

[![Impacted file tree graph](https://codecov.io/gh/Azure/WALinuxAgent/pull/2313/graphs/tree.svg?width=650&height=150&src=pr&token=ae90E2KYCw&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure)](https://codecov.io/gh/Azure/WALinuxAgent/pull/2313?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure)

```diff
@@              Coverage Diff               @@
##           fast-track    #2313      +/-   ##
==============================================
- Coverage       70.71%   70.54%   -0.17%     
==============================================
  Files              97       97              
  Lines           13993    14002       +9     
  Branches         2007     2009       +2     
==============================================
- Hits             9895     9878      -17     
- Misses           3653     3681      +28     
+ Partials          445      443       -2     
```


| [Impacted Files](https://codecov.io/gh/Azure/WALinuxAgent/pull/2313?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) | Coverage Δ | |
|---|---|---|
| [azurelinuxagent/common/logcollector\_manifests.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2313/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi9sb2djb2xsZWN0b3JfbWFuaWZlc3RzLnB5) | `100.00% <ø> (ø)` | |
| [azurelinuxagent/common/utils/archive.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2313/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi91dGlscy9hcmNoaXZlLnB5) | `84.35% <ø> (ø)` | |
| [azurelinuxagent/ga/update.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2313/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2dhL3VwZGF0ZS5weQ==) | `87.65% <ø> (-0.02%)` | :arrow_down: |
| [azurelinuxagent/common/protocol/wire.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2313/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi9wcm90b2NvbC93aXJlLnB5) | `75.71% <45.45%> (-2.27%)` | :arrow_down: |
| [...inuxagent/common/protocol/extensions\_goal\_state.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2313/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi9wcm90b2NvbC9leHRlbnNpb25zX2dvYWxfc3RhdGUucHk=) | `57.14% <66.66%> (-42.86%)` | :arrow_down: |
| [azurelinuxagent/common/conf.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2313/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi9jb25mLnB5) | `77.25% <100.00%> (+0.21%)` | :arrow_up: |
| [azurelinuxagent/common/protocol/hostplugin.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2313/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi9wcm90b2NvbC9ob3N0cGx1Z2luLnB5) | `84.54% <0.00%> (-1.45%)` | :arrow_down: |

------

[Continue to review full report at Codecov](https://codecov.io/gh/Azure/WALinuxAgent/pull/2313?src=pr&el=continue&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure).
> **Legend** - [Click here to learn more](https://docs.codecov.io/docs/codecov-delta?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure)
> `Δ = absolute <relative> (impact)`, `ø = not affected`, `? = missing data`
> Powered by [Codecov](https://codecov.io/gh/Azure/WALinuxAgent/pull/2313?src=pr&el=footer&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure). Last update [fcd0b23...50364a8](https://codecov.io/gh/Azure/WALinuxAgent/pull/2313?src=pr&el=lastupdated&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure). Read the [comment docs](https://docs.codecov.io/docs/pull-request-comments?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure).

narrieta: FYI @jscalev 

Patch:
diff --git a/azurelinuxagent/common/conf.py b/azurelinuxagent/common/conf.py
index 67798a47..f79a80b2 100644
--- a/azurelinuxagent/common/conf.py
+++ b/azurelinuxagent/common/conf.py
@@ -118,6 +118,7 @@ __SWITCH_OPTIONS__ = {
     "Debug.CgroupLogMetrics": False,
     "Debug.CgroupDisableOnProcessCheckFailure": True,
     "Debug.CgroupDisableOnQuotaCheckFailure": True,
+    "Debug.FetchVmSettings": False,
 }
 
 
@@ -507,3 +508,11 @@ def get_cgroup_disable_on_quota_check_failure(conf=__conf__):
     NOTE: This option is experimental and may be removed in later versions of the Agent.
     """
     return conf.get_switch("Debug.CgroupDisableOnQuotaCheckFailure", True)
+
+def get_fetch_vm_settings(conf=__conf__):
+    """
+    If True, the agent will query the extensions goal state (via the vmSettings API)
+
+    NOTE: This option is experimental and may be removed in later versions of the Agent.
+    """
+    return conf.get_switch("Debug.FetchVmSettings", False)
diff --git a/azurelinuxagent/common/logcollector_manifests.py b/azurelinuxagent/common/logcollector_manifests.py
index f022c656..27eba6ed 100644
--- a/azurelinuxagent/common/logcollector_manifests.py
+++ b/azurelinuxagent/common/logcollector_manifests.py
@@ -40,6 +40,7 @@ echo,
 
 echo,### Gathering Extension Files ###
 copy,$LIB_DIR/*.xml
+copy,$LIB_DIR/VmSettings.*.json
 copy,$LIB_DIR/waagent_status.*.json
 copy,$LIB_DIR/*/status/*.status
 copy,$LIB_DIR/*/config/*.settings
diff --git a/azurelinuxagent/common/protocol/extensions_goal_state.py b/azurelinuxagent/common/protocol/extensions_goal_state.py
index 6e20117a..39ca5d42 100644
--- a/azurelinuxagent/common/protocol/extensions_goal_state.py
+++ b/azurelinuxagent/common/protocol/extensions_goal_state.py
@@ -16,7 +16,14 @@
 #
 # Requires Python 2.6+ and Openssl 1.0+
 
+import re
+
+
 class ExtensionsGoalState(object):
     def __init__(self, etag, vm_settings):
         self.etag = etag
         self.vm_settings = vm_settings
+
+    def get_redacted_vm_settings(self):
+        return re.sub(r'("protectedSettings"\s*:\s*)"[^"]+"', r'\1"***REDACTED***"', self.vm_settings, flags=re.IGNORECASE)
+
diff --git a/azurelinuxagent/common/protocol/wire.py b/azurelinuxagent/common/protocol/wire.py
index acc38437..bd56fed2 100644
--- a/azurelinuxagent/common/protocol/wire.py
+++ b/azurelinuxagent/common/protocol/wire.py
@@ -57,6 +57,7 @@ TELEMETRY_URI = "http://{0}/machine?comp=telemetrydata"
 WIRE_SERVER_ADDR_FILE_NAME = "WireServer"
 INCARNATION_FILE_NAME = "Incarnation"
 GOAL_STATE_FILE_NAME = "GoalState.{0}.xml"
+VM_SETTINGS_FILE_NAME = "VmSettings.{0}.json"
 HOSTING_ENV_FILE_NAME = "HostingEnvironmentConfig.xml"
 SHARED_CONF_FILE_NAME = "SharedConfig.xml"
 REMOTE_ACCESS_FILE_NAME = "RemoteAccess.{0}.xml"
@@ -715,7 +716,7 @@ class WireClient(object):
 
         return success
 
-    def fetch(self, uri, headers=None, use_proxy=None, decode=True, max_retry=None):
+    def fetch(self, uri, headers=None, use_proxy=None, decode=True, max_retry=None, ok_codes=None):
         """
         max_retry indicates the maximum number of retries for the HTTP request; None indicates that the default value should be used
 
@@ -723,13 +724,13 @@ class WireClient(object):
         """
         logger.verbose("Fetch [{0}] with headers [{1}]", uri, headers)
         content = None
-        response = self._fetch_response(uri, headers, use_proxy, max_retry=max_retry)
+        response = self._fetch_response(uri, headers, use_proxy, max_retry=max_retry, ok_codes=ok_codes)
         if response is not None and not restutil.request_failed(response):
             response_content = response.read()
             content = self.decode_config(response_content) if decode else response_content
         return content, response.getheaders()
 
-    def _fetch_response(self, uri, headers=None, use_proxy=None, max_retry=None):
+    def _fetch_response(self, uri, headers=None, use_proxy=None, max_retry=None, ok_codes=None):
         """
         max_retry indicates the maximum number of retries for the HTTP request; None indicates that the default value should be used
         """
@@ -744,7 +745,7 @@ class WireClient(object):
 
             host_plugin = self.get_host_plugin()
 
-            if restutil.request_failed(resp):
+            if restutil.request_failed(resp, ok_codes=ok_codes):
                 error_response = restutil.read_response_error(resp)
                 msg = "Fetch failed from [{0}]: {1}".format(uri, error_response)
                 logger.warn(msg)
@@ -792,6 +793,8 @@ class WireClient(object):
 
             if new_goal_state is not None:
                 self._goal_state = new_goal_state
+                if conf.get_fetch_vm_settings():
+                    self.update_extensions_goal_state()
                 self._save_goal_state()
                 self._update_host_plugin(new_goal_state.container_id, new_goal_state.role_config_name)
 
@@ -806,7 +809,7 @@ class WireClient(object):
             if etag is not None:
                 headers['if-none-match'] = etag
 
-            vm_settings, response_headers = self.fetch(url, headers)
+            vm_settings, response_headers = self.fetch(url, headers, ok_codes=[httpclient.OK, httpclient.NOT_MODIFIED])
 
             # The response includes an etag if and only if the VM settings change.
             response_etag = None
@@ -817,11 +820,12 @@ class WireClient(object):
             if response_etag is None:
                 return
 
-            # TODO - We need to archive the ExtensionsGoalState to the history folder (as well as save the current value to /var/lib/waagent)
             self._extensions_goal_state = ExtensionsGoalState(response_etag, vm_settings)
 
         except Exception as exception:
-            raise ProtocolError("Error fetching extension goal state (correlation id: {0}): {1}".format(correlation_id, ustr(exception)))
+            # TODO: report HostGAPlugin failure
+            # TODO: raise ProtocolError instead of logging a warning
+            logger.warn("Error fetching extension goal state (correlation id: {0}): {1}".format(correlation_id, ustr(exception)))
 
     def _update_host_plugin(self, container_id, role_config_name):
         if self._host_plugin is not None:
@@ -848,6 +852,9 @@ class WireClient(object):
             if self._goal_state.ext_conf is not None and self._goal_state.ext_conf.xml_text is not None:
                 self._save_cache(self._goal_state.ext_conf.get_redacted_xml_text(), EXT_CONF_FILE_NAME.format(self._goal_state.incarnation))
 
+            if self._extensions_goal_state is not None:
+                self._save_cache(self._extensions_goal_state.get_redacted_vm_settings(), VM_SETTINGS_FILE_NAME.format(self._extensions_goal_state.etag))  # TODO: need to redact settings
+
         except Exception as e:
             logger.warn("Failed to save the goal state to disk: {0}", ustr(e))
 
diff --git a/azurelinuxagent/common/utils/archive.py b/azurelinuxagent/common/utils/archive.py
index 2ef80103..8e484577 100644
--- a/azurelinuxagent/common/utils/archive.py
+++ b/azurelinuxagent/common/utils/archive.py
@@ -41,6 +41,7 @@ ARCHIVE_DIRECTORY_NAME = 'history'
 _MAX_ARCHIVED_STATES = 50
 
 _CACHE_PATTERNS = [
+    re.compile(r"^VmSettings.\d+\.json$"),
     re.compile(r"^(.*)\.(\d+)\.(agentsManifest)$", re.IGNORECASE),
     re.compile(r"^(.*)\.(\d+)\.(manifest\.xml)$", re.IGNORECASE),
     re.compile(r"^(.*)\.(\d+)\.(xml)$", re.IGNORECASE),
diff --git a/azurelinuxagent/ga/update.py b/azurelinuxagent/ga/update.py
index 54e90cfa..06a24ecd 100644
--- a/azurelinuxagent/ga/update.py
+++ b/azurelinuxagent/ga/update.py
@@ -359,13 +359,13 @@ class UpdateHandler(object):
         """
         try:
             protocol.update_goal_state()
-            protocol.update_extensions_goal_state()
 
             if self._last_try_update_goal_state_failed:
                 self._last_try_update_goal_state_failed = False
                 message = u"Retrieving the goal state recovered from previous errors"
                 add_event(AGENT_NAME, op=WALAEventOperation.FetchGoalState, version=CURRENT_VERSION, is_success=True, message=message, log_event=False)
                 logger.info(message)
+
         except Exception as e:
             if not self._last_try_update_goal_state_failed:
                 self._last_try_update_goal_state_failed = True


Test patch:
diff --git a/tests/ga/test_update.py b/tests/ga/test_update.py
index a95aba73..8e790a24 100644
--- a/tests/ga/test_update.py
+++ b/tests/ga/test_update.py
@@ -45,7 +45,7 @@ from azurelinuxagent.ga.update import GuestAgent, GuestAgentError, MAX_FAILURE,
 from tests.protocol.mocks import mock_wire_protocol
 from tests.protocol.mockwiredata import DATA_FILE, DATA_FILE_MULTIPLE_EXT
 from tests.tools import AgentTestCase, data_dir, DEFAULT, patch, load_bin_data, load_data, Mock, MagicMock, \
-    clear_singleton_instances, mock_sleep
+    clear_singleton_instances, mock_sleep, skip_if_predicate_true
 from tests.protocol import mockwiredata
 from tests.protocol.mocks import HttpRequestPredicates
 
@@ -1915,6 +1915,7 @@ class TryUpdateGoalStateTestCase(HttpRequestPredicates, AgentTestCase):
             update_handler = get_update_handler()
             self.assertFalse(update_handler._try_update_goal_state(protocol), "try_update_goal_state should have failed")
 
+    @skip_if_predicate_true(lambda: True, "TODO: Enable this test once we start retrieving the ExtensionsGoalState (vmSettings)")
     def test_it_should_update_the_goal_state(self):
         update_handler = get_update_handler()
         with mock_wire_protocol(mockwiredata.DATA_FILE) as protocol:
diff --git a/tests/test_agent.py b/tests/test_agent.py
index 5d449267..01f2b4b8 100644
--- a/tests/test_agent.py
+++ b/tests/test_agent.py
@@ -33,6 +33,7 @@ Debug.CgroupCheckPeriod = 300
 Debug.CgroupDisableOnProcessCheckFailure = True
 Debug.CgroupDisableOnQuotaCheckFailure = True
 Debug.CgroupLogMetrics = False
+Debug.FetchVmSettings = False
 DetectScvmmEnv = False
 EnableOverProvisioning = True
 Extension.LogDir = /var/log/azure