Repository: Azure/WALinuxAgent
Pull request #2566 (2022-04-26 20:10:08)

Refresh goal state when certificates are missing (#2562)
* Refresh goal state when certificates are missing

* Improve error reporting

* Fix assert message

Co-authored-by: narrieta <narrieta>
(cherry picked from commit cd03ff2c22c572fcafb74d645ed5a437a2c3bf5d)


codecov[bot]: # [Codecov](https://codecov.io/gh/Azure/WALinuxAgent/pull/2566?src=pr&el=h1&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) Report
> Merging [#2566](https://codecov.io/gh/Azure/WALinuxAgent/pull/2566?src=pr&el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) (540a39e) into [develop](https://codecov.io/gh/Azure/WALinuxAgent/commit/03df04a07c64439b51a20626471fc0ceabecc6a5?el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) (03df04a) will **increase** coverage by `0.04%`.
> The diff coverage is `90.58%`.

```diff
@@             Coverage Diff             @@
##           develop    #2566      +/-   ##
===========================================
+ Coverage    71.87%   71.92%   +0.04%     
===========================================
  Files          102      102              
  Lines        15358    15392      +34     
  Branches      2438     2447       +9     
===========================================
+ Hits         11039    11071      +32     
  Misses        3826     3826              
- Partials       493      495       +2     
```


| [Impacted Files](https://codecov.io/gh/Azure/WALinuxAgent/pull/2566?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) | Coverage Δ | |
|---|---|---|
| [azurelinuxagent/common/logger.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2566/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi9sb2dnZXIucHk=) | `89.83% <33.33%> (-0.98%)` | :arrow_down: |
| [azurelinuxagent/common/protocol/goal\_state.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2566/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi9wcm90b2NvbC9nb2FsX3N0YXRlLnB5) | `95.18% <90.19%> (-0.28%)` | :arrow_down: |
| [azurelinuxagent/ga/update.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2566/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2dhL3VwZGF0ZS5weQ==) | `89.35% <95.65%> (+0.08%)` | :arrow_up: |
| [azurelinuxagent/common/protocol/hostplugin.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2566/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi9wcm90b2NvbC9ob3N0cGx1Z2luLnB5) | `87.66% <100.00%> (ø)` | |
| [azurelinuxagent/common/protocol/wire.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2566/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi9wcm90b2NvbC93aXJlLnB5) | `78.82% <100.00%> (ø)` | |
| [azurelinuxagent/common/utils/cryptutil.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2566/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi91dGlscy9jcnlwdHV0aWwucHk=) | `45.79% <0.00%> (+1.86%)` | :arrow_up: |

------

[Continue to review full report at Codecov](https://codecov.io/gh/Azure/WALinuxAgent/pull/2566?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/2566?src=pr&el=footer&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure). Last update [03df04a...540a39e](https://codecov.io/gh/Azure/WALinuxAgent/pull/2566?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).


Patch:
diff --git a/azurelinuxagent/common/logger.py b/azurelinuxagent/common/logger.py
index 07e3f239..3d0dc617 100644
--- a/azurelinuxagent/common/logger.py
+++ b/azurelinuxagent/common/logger.py
@@ -45,6 +45,7 @@ class Logger(object):
         self.logger = self if logger is None else logger
         self.periodic_messages = {}
         self.prefix = prefix
+        self.silent = False
 
     def reset_periodic(self):
         self.logger.periodic_messages = {}
@@ -124,6 +125,9 @@ class Logger(object):
                 finally:
                     log_appender.appender_lock = False
 
+        if self.silent:
+            return
+
         # if msg_format is not unicode convert it to unicode
         if type(msg_format) is not ustr:
             msg_format = ustr(msg_format, errors="backslashreplace")
diff --git a/azurelinuxagent/common/protocol/goal_state.py b/azurelinuxagent/common/protocol/goal_state.py
index da0de9a0..edfd9d14 100644
--- a/azurelinuxagent/common/protocol/goal_state.py
+++ b/azurelinuxagent/common/protocol/goal_state.py
@@ -48,8 +48,16 @@ TRANSPORT_PRV_FILE_NAME = "TransportPrivate.pem"
 _GET_GOAL_STATE_MAX_ATTEMPTS = 6
 
 
+class GoalStateInconsistentError(ProtocolError):
+    """
+    Indicates an inconsistency in the goal state (e.g. missing tenant certificate)
+    """
+    def __init__(self, msg, inner=None):
+        super(GoalStateInconsistentError, self).__init__(msg, inner)
+
+
 class GoalState(object):
-    def __init__(self, wire_client):
+    def __init__(self, wire_client, silent=False):
         """
         Fetches the goal state using the given wire client.
 
@@ -64,6 +72,8 @@ class GoalState(object):
             self._wire_client = wire_client
             self._history = None
             self._extensions_goal_state = None  # populated from vmSettings or extensionsConfig
+            self.logger = logger.Logger(logger.DEFAULT_LOGGER)
+            self.logger.silent = silent
 
             # These properties hold the goal state from the WireServer and are initialized by self._fetch_full_wire_server_goal_state()
             self._incarnation = None
@@ -75,8 +85,10 @@ class GoalState(object):
             self._certs = None
             self._remote_access = None
 
-            self.update()
+            self.update(silent=silent)
 
+        except ProtocolError:
+            raise
         except Exception as exception:
             # 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)
@@ -125,34 +137,47 @@ class GoalState(object):
         # Fetching the goal state updates the HostGAPlugin so simply trigger the request
         GoalState._fetch_goal_state(wire_client)
 
-    def update(self):
+    def update(self, silent=False):
         """
         Updates the current GoalState instance fetching values from the WireServer/HostGAPlugin as needed
         """
+        self.logger.silent = silent
+
+        try:
+            self._update(force_update=False)
+        except GoalStateInconsistentError as e:
+            self.logger.warn("Detected an inconsistency in the goal state: {0}", ustr(e))
+            self._update(force_update=True)
+            self.logger.info("The goal state is consistent")
+
+    def _update(self, force_update):
         #
         # Fetch the goal state from both the HGAP and the WireServer
         #
         timestamp = datetime.datetime.utcnow()
 
+        if force_update:
+            self.logger.info("Refreshing goal state and vmSettings")
+
         incarnation, xml_text, xml_doc = GoalState._fetch_goal_state(self._wire_client)
-        goal_state_updated = incarnation != self._incarnation
+        goal_state_updated = force_update or incarnation != self._incarnation
         if goal_state_updated:
-            logger.info('Fetched a new incarnation for the WireServer goal state [incarnation {0}]', incarnation)
+            self.logger.info('Fetched a new incarnation for the WireServer goal state [incarnation {0}]', incarnation)
 
         vm_settings, vm_settings_updated = None, False
         try:
-            vm_settings, vm_settings_updated = GoalState._fetch_vm_settings(self._wire_client)
+            vm_settings, vm_settings_updated = GoalState._fetch_vm_settings(self._wire_client, force_update=force_update)
         except VmSettingsSupportStopped as exception:  # If the HGAP stopped supporting vmSettings, we need to use the goal state from the WireServer
             self._restore_wire_server_goal_state(incarnation, xml_text, xml_doc, exception)
             return
 
         if vm_settings_updated:
-            logger.info('')
-            logger.info("Fetched new vmSettings [HostGAPlugin correlation ID: {0} eTag: {1} source: {2}]", vm_settings.hostga_plugin_correlation_id, vm_settings.etag, vm_settings.source)
+            self.logger.info('')
+            self.logger.info("Fetched new vmSettings [HostGAPlugin correlation ID: {0} eTag: {1} source: {2}]", vm_settings.hostga_plugin_correlation_id, vm_settings.etag, vm_settings.source)
         # Ignore the vmSettings if their source is Fabric (processing a Fabric goal state may require the tenant certificate and the vmSettings don't include it.)
         if vm_settings is not None and vm_settings.source == GoalStateSource.Fabric:
             if vm_settings_updated:
-                logger.info("The vmSettings originated via Fabric; will ignore them.")
+                self.logger.info("The vmSettings originated via Fabric; will ignore them.")
             vm_settings, vm_settings_updated = None, False
 
         # If neither goal state has changed we are done with the update
@@ -187,19 +212,30 @@ class GoalState(object):
         if self._extensions_goal_state is None or most_recent.created_on_timestamp > self._extensions_goal_state.created_on_timestamp:
             self._extensions_goal_state = most_recent
 
-        # For Fast Track goal states, verify that the required certificates are in the goal state
+        #
+        # For Fast Track goal states, verify that the required certificates are in the goal state.
+        #
+        # Some scenarios can produce inconsistent goal states. For example, during hibernation/resume, the Fabric goal state changes (the
+        # tenant certificate is re-generated when the VM is restarted) *without* the incarnation necessarily changing (e.g. if the incarnation
+        # is 1 before the hibernation; on resume the incarnation is set to 1 even though the goal state has a new certificate). If a Fast
+        # Track goal state comes after that, the extensions will need the new certificate. The Agent needs to refresh the goal state in that
+        # case, to ensure it fetches the new certificate.
+        #
         if self.extensions_goal_state.source == GoalStateSource.FastTrack:
-            for extension in self.extensions_goal_state.extensions:
-                for settings in extension.settings:
-                    if settings.protectedSettings is None:
-                        continue
-                    certificates = self.certs.summary
-                    if not any(settings.certificateThumbprint == c['thumbprint'] for c in certificates):
-                        message = "Certificate {0} needed by {1} is missing from the goal state".format(settings.certificateThumbprint, extension.name)
-                        add_event(op=WALAEventOperation.VmSettings, message=message, is_success=False)
+            self._check_certificates()
+
+    def _check_certificates(self):
+        for extension in self.extensions_goal_state.extensions:
+            for settings in extension.settings:
+                if settings.protectedSettings is None:
+                    continue
+                certificates = self.certs.summary
+                if not any(settings.certificateThumbprint == c['thumbprint'] for c in certificates):
+                    message = "Certificate {0} needed by {1} is missing from the goal state".format(settings.certificateThumbprint, extension.name)
+                    raise GoalStateInconsistentError(message)
 
     def _restore_wire_server_goal_state(self, incarnation, xml_text, xml_doc, vm_settings_support_stopped_error):
-        logger.info('The HGAP stopped supporting vmSettings; will fetched the goal state from the WireServer.')
+        self.logger.info('The HGAP stopped supporting vmSettings; will fetched the goal state from the WireServer.')
         self._history = GoalStateHistory(datetime.datetime.utcnow(), incarnation)
         self._history.save_goal_state(xml_text)
         self._extensions_goal_state = self._fetch_full_wire_server_goal_state(incarnation, xml_doc)
@@ -207,7 +243,7 @@ class GoalState(object):
             self._extensions_goal_state.is_outdated = True
             msg = "Fetched a Fabric goal state older than the most recent FastTrack goal state; will skip it.\nFabric:    {0}\nFastTrack: {1}".format(
                   self._extensions_goal_state.created_on_timestamp, vm_settings_support_stopped_error.timestamp)
-            logger.info(msg)
+            self.logger.info(msg)
             add_event(op=WALAEventOperation.VmSettings, message=msg, is_success=True)
 
     def save_to_history(self, data, file_name):
@@ -249,7 +285,7 @@ class GoalState(object):
         return incarnation, xml_text, xml_doc
 
     @staticmethod
-    def _fetch_vm_settings(wire_client):
+    def _fetch_vm_settings(wire_client, force_update=False):
         """
         Issues an HTTP request (HostGAPlugin) for the vm settings and returns the response as an ExtensionsGoalState.
         """
@@ -258,11 +294,11 @@ class GoalState(object):
         if conf.get_enable_fast_track():
             try:
                 try:
-                    vm_settings, vm_settings_updated = wire_client.get_host_plugin().fetch_vm_settings()
+                    vm_settings, vm_settings_updated = wire_client.get_host_plugin().fetch_vm_settings(force_update=force_update)
                 except ResourceGoneError:
                     # retry after refreshing the HostGAPlugin
                     GoalState.update_host_plugin_headers(wire_client)
-                    vm_settings, vm_settings_updated = wire_client.get_host_plugin().fetch_vm_settings()
+                    vm_settings, vm_settings_updated = wire_client.get_host_plugin().fetch_vm_settings(force_update=force_update)
 
             except VmSettingsSupportStopped:
                 raise
@@ -284,8 +320,8 @@ class GoalState(object):
         Returns the value of ExtensionsConfig.
         """
         try:
-            logger.info('')
-            logger.info('Fetching full goal state from the WireServer [incarnation {0}]', incarnation)
+            self.logger.info('')
+            self.logger.info('Fetching full goal state from the WireServer [incarnation {0}]', incarnation)
 
             role_instance = find(xml_doc, "RoleInstance")
             role_instance_id = findtext(role_instance, "InstanceId")
@@ -317,7 +353,11 @@ class GoalState(object):
             if certs_uri is not None:
                 xml_text = self._wire_client.fetch_config(certs_uri, self._wire_client.get_header_for_cert())
                 certs = Certificates(xml_text)
-                # Save the certificate summary, which includes only the thumbprint but not the certificate itself, to the goal state history
+                # Log and save the certificates summary (i.e. the thumbprint but not the certificate itself) to the goal state history
+                for c in certs.summary:
+                    logger.info("Downloaded certificate {0}".format(c))
+                if len(certs.warnings) > 0:
+                    logger.warn(certs.warnings)
                 self._history.save_certificates(json.dumps(certs.summary))
 
             remote_access = None
@@ -339,10 +379,10 @@ class GoalState(object):
             return extensions_config
 
         except Exception as exception:
-            logger.warn("Fetching the goal state failed: {0}", ustr(exception))
+            self.logger.warn("Fetching the goal state failed: {0}", ustr(exception))
             raise ProtocolError(msg="Error fetching goal state", inner=exception)
         finally:
-            logger.info('Fetch goal state completed')
+            self.logger.info('Fetch goal state completed')
 
 
 class HostingEnv(object):
@@ -366,6 +406,7 @@ class Certificates(object):
     def __init__(self, xml_text):
         self.cert_list = CertList()
         self.summary = []  # debugging info
+        self.warnings = []
 
         # Save the certificates
         local_file = os.path.join(conf.get_lib_dir(), CERTS_FILE_NAME)
@@ -448,11 +489,10 @@ class Certificates(object):
             else:
                 # Since private key has *no* matching certificate,
                 # it will not be named correctly
-                logger.warn("Found NO matching cert/thumbprint for private key!")
+                self.warnings.append("Found NO matching cert/thumbprint for private key!")
 
         for pubkey, thumbprint in thumbprints.items():
             has_private_key = pubkey in prvs
-            logger.info("Downloaded certificate with thumbprint {0} (has private key: {1})".format(thumbprint, has_private_key))
             self.summary.append({"thumbprint": thumbprint, "hasPrivateKey": has_private_key})
 
         for v1_cert in v1_cert_list:
diff --git a/azurelinuxagent/common/protocol/hostplugin.py b/azurelinuxagent/common/protocol/hostplugin.py
index 81b90625..5f795dca 100644
--- a/azurelinuxagent/common/protocol/hostplugin.py
+++ b/azurelinuxagent/common/protocol/hostplugin.py
@@ -453,7 +453,7 @@ class HostPluginProtocol(object):
                     HostPluginProtocol._get_fast_track_state_file(), ustr(e))
         return timeutil.create_timestamp(datetime.datetime.utcnow())
 
-    def fetch_vm_settings(self):
+    def fetch_vm_settings(self, force_update=False):
         """
         Queries the vmSettings from the HostGAPlugin and returns an (ExtensionsGoalState, bool) tuple with the vmSettings and
         a boolean indicating if they are an updated (True) or a cached value (False).
@@ -491,7 +491,7 @@ class HostPluginProtocol(object):
                 # Raise VmSettingsNotSupported directly instead of using raise_not_supported() to avoid resetting the timestamp for the next check
                 raise VmSettingsNotSupported()
 
-            etag = None if self._cached_vm_settings is None else self._cached_vm_settings.etag
+            etag = None if force_update or self._cached_vm_settings is None else self._cached_vm_settings.etag
             correlation_id = str(uuid.uuid4())
 
             self._vm_settings_error_reporter.report_request()
diff --git a/azurelinuxagent/common/protocol/wire.py b/azurelinuxagent/common/protocol/wire.py
index 40e58cc0..7923bea7 100644
--- a/azurelinuxagent/common/protocol/wire.py
+++ b/azurelinuxagent/common/protocol/wire.py
@@ -83,8 +83,8 @@ class WireProtocol(DataContract):
         logger.info('Initializing goal state during protocol detection')
         self.client.update_goal_state(force_update=True)
 
-    def update_goal_state(self):
-        self.client.update_goal_state()
+    def update_goal_state(self, silent=False):
+        self.client.update_goal_state(silent=silent)
 
     def update_host_plugin_from_goal_state(self):
         self.client.update_host_plugin_from_goal_state()
@@ -759,18 +759,18 @@ class WireClient(object):
             self._host_plugin.update_container_id(container_id)
             self._host_plugin.update_role_config_name(role_config_name)
 
-    def update_goal_state(self, force_update=False):
+    def update_goal_state(self, force_update=False, silent=False):
         """
         Updates the goal state if the incarnation or etag changed or if 'force_update' is True
         """
         try:
             if force_update:
-                logger.info("Forcing an update of the goal state..")
+                logger.info("Forcing an update of the goal state.")
 
             if self._goal_state is None or force_update:
-                self._goal_state = GoalState(self)
+                self._goal_state = GoalState(self, silent=silent)
             else:
-                self._goal_state.update()
+                self._goal_state.update(silent=silent)
 
         except ProtocolError:
             raise
diff --git a/azurelinuxagent/ga/update.py b/azurelinuxagent/ga/update.py
index 1a453c8c..c800ce47 100644
--- a/azurelinuxagent/ga/update.py
+++ b/azurelinuxagent/ga/update.py
@@ -168,7 +168,8 @@ class UpdateHandler(object):
 
         # 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._update_goal_state_error_count = 0
+        self._update_goal_state_last_error_report = datetime.min
         self._report_status_last_failed_goal_state = None
 
         # incarnation of the last goal state that has been fully processed
@@ -481,13 +482,16 @@ class UpdateHandler(object):
         Attempts to update the goal state and returns True on success or False on failure, sending telemetry events about the failures.
         """
         try:
-            protocol.update_goal_state()
+            max_errors_to_log = 3
+
+            protocol.update_goal_state(silent=self._update_goal_state_error_count >= max_errors_to_log)
 
             self._goal_state = protocol.get_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"
+            if self._update_goal_state_error_count > 0:
+                self._update_goal_state_error_count = 0
+                message = u"Fetching the goal state recovered from previous errors. Fetched {0} (certificates: {1})".format(
+                    self._goal_state.extensions_goal_state.id, self._goal_state.certs.summary)
                 add_event(AGENT_NAME, op=WALAEventOperation.FetchGoalState, version=CURRENT_VERSION, is_success=True, message=message, log_event=False)
                 logger.info(message)
 
@@ -497,15 +501,21 @@ class UpdateHandler(object):
                 self._supports_fast_track = False
 
         except Exception as e:
-            if not self._last_try_update_goal_state_failed:
-                self._last_try_update_goal_state_failed = True
-                message = u"An error occurred while retrieving the goal state: {0}".format(textutil.format_exception(e))
-                logger.warn(message)
-                add_event(AGENT_NAME, op=WALAEventOperation.FetchGoalState, version=CURRENT_VERSION, is_success=False, message=message, log_event=False)
-            message = u"Attempts to retrieve the goal state are failing: {0}".format(ustr(e))
-            logger.periodic_warn(logger.EVERY_SIX_HOURS, "[PERIODIC] {0}".format(message))
+            self._update_goal_state_error_count += 1
             self._heartbeat_update_goal_state_error_count += 1
+            if self._update_goal_state_error_count <= max_errors_to_log:
+                message = u"Error fetching the goal state: {0}".format(textutil.format_exception(e))
+                logger.error(message)
+                add_event(op=WALAEventOperation.FetchGoalState, is_success=False, message=message, log_event=False)
+                self._update_goal_state_last_error_report = datetime.now()
+            else:
+                if self._update_goal_state_last_error_report + timedelta(hours=6) > datetime.now():
+                    self._update_goal_state_last_error_report = datetime.now()
+                    message = u"Fetching the goal state is still failing: {0}".format(textutil.format_exception(e))
+                    logger.error(message)
+                    add_event(op=WALAEventOperation.FetchGoalState, is_success=False, message=message, log_event=False)
             return False
+
         return True
 
     def __update_guest_agent(self, protocol):
@@ -559,8 +569,8 @@ class UpdateHandler(object):
             raise AgentUpgradeExitException(
                 "Exiting current process to {0} to the request Agent version {1}".format(prefix, requested_version))
 
-        # Ignore new agents if updating is disabled
-        if not conf.get_autoupdate_enabled():
+        # Skip the update if there is no goal state yet or auto-update is disabled
+        if self._goal_state is None or not conf.get_autoupdate_enabled():
             return False
 
         if self._download_agent_if_upgrade_available(protocol):
@@ -600,11 +610,14 @@ class UpdateHandler(object):
             protocol = exthandlers_handler.protocol
 
             # update self._goal_state
-            self._try_update_goal_state(protocol)
-
-            # Update the Guest Agent if a new version is available
-            if self._goal_state is not None:
+            if not self._try_update_goal_state(protocol):
+                # agent updates and status reporting should be done even when the goal state is not updated
                 self.__update_guest_agent(protocol)
+                self._report_status(exthandlers_handler)
+                return
+
+            # check for agent updates
+            self.__update_guest_agent(protocol)
 
             if self._processing_new_extensions_goal_state():
                 if not self._extensions_summary.converged:
@@ -620,8 +633,7 @@ class UpdateHandler(object):
                 # Note: Monitor thread periodically checks this in addition to here.
                 CGroupConfigurator.get_instance().check_cgroups(cgroup_metrics=[])
 
-            # 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
+            # report status before processing the remote access, since that operation can take a long time
             self._report_status(exthandlers_handler)
 
             if self._processing_new_incarnation():


Test patch:
diff --git a/tests/data/wire/certs-2.xml b/tests/data/wire/certs-2.xml
new file mode 100644
index 00000000..66a231ee
--- /dev/null
+++ b/tests/data/wire/certs-2.xml
@@ -0,0 +1,85 @@
+<?xml version="1.0" encoding="utf-8"?>
+<CertificateFile xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:noNamespaceSchemaLocation="certificates10.xsd">
+  <Version>2012-11-30</Version>
+  <Incarnation>5</Incarnation>
+  <Format>Pkcs7BlobWithPfxContents</Format>
+  <Data>MIIOgwYJKoZIhvcNAQcDoIIOdDCCDnACAQIxggEwMIIBLAIBAoAUiF8ZYMs9mMa8
+QOEMxDaIhGza+0IwDQYJKoZIhvcNAQEBBQAEggEAQW7GyeRVEhHSU1/dzV0IndH0
+rDQk+27MvlsWTcpNcgGFtfRYxu5bzmp0+DoimX3pRBlSFOpMJ34jpg4xs78EsSWH
+FRhCf3EGuEUBHo6yR8FhXDTuS7kZ0UmquiCI2/r8j8gbaGBNeP8IRizcAYrPMA5S
+E8l1uCrw7DHuLscbVni/7UglGaTfFS3BqS5jYbiRt2Qh3p+JPUfm51IG3WCIw/WS
+2QHebmHxvMFmAp8AiBWSQJizQBEJ1lIfhhBMN4A7NadMWAe6T2DRclvdrQhJX32k
+amOiogbW4HJsL6Hphn7Frrw3CENOdWMAvgQBvZ3EjAXgsJuhBA1VIrwofzlDljCC
+DTUGCSqGSIb3DQEHATAUBggqhkiG9w0DBwQIxcvw9qx4y0qAgg0QrINXpC23BWT2
+Fb9N8YS3Be9eO3fF8KNdM6qGf0kKR16l/PWyP2L+pZxCcCPk83d070qPdnJK9qpJ
+6S1hI80Y0oQnY9VBFrdfkc8fGZHXqm5jNS9G32v/AxYpJJC/qrAQnWuOdLtOZaGL
+94GEh3XRagvz1wifv8SRI8B1MzxrpCimeMxHkL3zvJFg9FjLGdrak868feqhr6Nb
+pqH9zL7bMq8YP788qTRELUnL72aDzGAM7HEj7V4yu2uD3i3Ryz3bqWaj9IF38Sa0
+6rACBkiNfZBPgExoMUm2GNVyx8hTis2XKRgz4NLh29bBkKrArK9sYDncE9ocwrrX
+AQ99yn03Xv6TH8bRp0cSj4jzBXc5RFsUQG/LxzJVMjvnkDbwNE41DtFiYz5QVcv1
+cMpTH16YfzSL34a479eNq/4+JAs/zcb2wjBskJipMUU4hNx5fhthvfKwDOQbLTqN
+HcP23iPQIhjdUXf6gpu5RGu4JZ0dAMHMHFKvNL6TNejwx/H6KAPp6rCRsYi6QhAb
+42SXdZmhAyQsFpGD9U5ieJApqeCHfj9Xhld61GqLJA9+WLVhDPADjqHoAVvrOkKH
+OtPegId/lWnCB7p551klAjiEA2/DKxFBIAEhqZpiLl+juZfMXovkdmGxMP4gvNNF
+gbS2k5A0IJ8q51gZcH1F56smdAmi5kvhPnFdy/9gqeI/F11F1SkbPVLImP0mmrFi
+zQD5JGfEu1psUYvhpOdaYDkmAK5qU5xHSljqZFz5hXNt4ebvSlurHAhunJb2ln3g
+AJUHwtZnVBrtYMB0w6fdwYqMxXi4vLeqUiHtIQtbOq32zlSryNPQqG9H0iP9l/G1
+t7oUfr9woI/B0kduaY9jd5Qtkqs1DoyfNMSaPNohUK/CWOTD51qOadzSvK0hJ+At
+033PFfv9ilaX6GmzHdEVEanrn9a+BoBCnGnuysHk/8gdswj9OzeCemyIFJD7iObN
+rNex3SCf3ucnAejJOA0awaLx88O1XTteUjcFn26EUji6DRK+8JJiN2lXSyQokNeY
+ox6Z4hFQDmw/Q0k/iJqe9/Dq4zA0l3Krkpra0DZoWh5kzYUA0g5+Yg6GmRNRa8YG
+tuuD6qK1SBEzmCYff6ivjgsXV5+vFBSjEpx2dPEaKdYxtHMOjkttuTi1mr+19dVf
+hSltbzfISbV9HafX76dhwZJ0QwsUx+aOW6OrnK8zoQc5AFOXpe9BrrOuEX01qrM0
+KX5tS8Zx5HqDLievjir194oi3r+nAiG14kYlGmOTHshu7keGCgJmzJ0iVG/i+TnV
+ZSLyd8OqV1F6MET1ijgR3OPL3kt81Zy9lATWk/DgKbGBkkKAnXO2HUw9U34JFyEy
+vEc81qeHci8sT5QKSFHiP3r8EcK8rT5k9CHpnbFmg7VWSMVD0/wRB/C4BiIw357a
+xyJ/q1NNvOZVAyYzIzf9TjwREtyeHEo5kS6hyWSn7fbFf3sNGO2I30veWOvE6kFA
+HMtF3NplOrTYcM7fAK5zJCBK20oU645TxI8GsICMog7IFidFMdRn4MaXpwAjEZO4
+44m2M+4XyeRCAZhp1Fu4mDiHGqgd44mKtwvLACVF4ygWZnACDpI17X88wMnwL4uU
+vgehLZdAE89gvukSCsET1inVBnn/hVenCRbbZ++IGv2XoYvRfeezfOoNUcJXyawQ
+JFqN0CRB5pliuCesTO2urn4HSwGGoeBd507pGWZmOAjbNjGswlJJXF0NFnNW/zWw
+UFYy+BI9axuhWTSnCXbNbngdNQKHznKe1Lwit6AI3U9jS33pM3W+pwUAQegVdtpG
+XT01YgiMCBX+b8B/xcWTww0JbeUwKXudzKsPhQmaA0lubAo04JACMfON8jSZCeRV
+TyIzgacxGU6YbEKH4PhYTGl9srcWIT9iGSYD53V7Kyvjumd0Y3Qc3JLnuWZT6Oe3
+uJ4xz9jJtoaTDvPJQNK3igscjZnWZSP8XMJo1/f7vbvD57pPt1Hqdirp1EBQNshk
+iX9CUh4fuGFFeHf6MtGxPofbXmvA2GYcFsOez4/2eOTEmo6H3P4Hrya97XHS0dmD
+zFSAjzAlacTrn1uuxtxFTikdOwvdmQJJEfyYWCB1lqWOZi97+7nzqyXMLvMgmwug
+ZF/xHFMhFTR8Wn7puuwf36JpPQiM4oQ/Lp66zkS4UlKrVsmSXIXudLMg8SQ5WqK8
+DjevEZwsHHaMtfDsnCAhAdRc2jCpyHKKnmhCDdkcdJJEymWKILUJI5PJ3XtiMHnR
+Sa35OOICS0lTq4VwhUdkGwGjRoY1GsriPHd6LOt1aom14yJros1h7ta604hSCn4k
+zj9p7wY9gfgkXWXNfmarrZ9NNwlHxzgSva+jbJcLmE4GMX5OFHHGlRj/9S1xC2Wf
+MY9orzlooGM74NtmRi4qNkFj3dQCde8XRR4wh2IvPUCsr4j+XaoCoc3R5Rn/yNJK
+zIkccJ2K14u9X/A0BLXHn5Gnd0tBYcVOqP6dQlW9UWdJC/Xooh7+CVU5cZIxuF/s
+Vvg+Xwiv3XqekJRu3cMllJDp5rwe5EWZSmnoAiGKjouKAIszlevaRiD/wT6Zra3c
+Wn/1U/sGop6zRscHR7pgI99NSogzpVGThUs+ez7otDBIdDbLpMjktahgWoi1Vqhc
+fNZXjA6ob4zTWY/16Ys0YWxHO+MtyWTMP1dnsqePDfYXGUHe8yGxylbcjfrsVYta
+4H6eYR86eU3eXB+MpS/iA4jBq4QYWR9QUkd6FDfmRGgWlMXhisPv6Pfnj384NzEV
+Emeg7tW8wzWR64EON9iGeGYYa2BBl2FVaayMEoUhthhFcDM1r3/Mox5xF0qnlys4
+goWkMzqbzA2t97bC0KDGzkcHT4wMeiJBLDZ7S2J2nDAEhcTLY0P2zvOB4879pEWx
+Bd15AyG1DvNssA5ooaDzKi/Li6NgDuMJ8W7+tmsBwDvwuf2N3koqBeXfKhR4rTqu
+Wg1k9fX3+8DzDf0EjtDZJdfWZAynONi1PhZGbNbaMKsQ+6TflkCACInRdOADR5GM
+rL7JtrgF1a9n0HD9vk2WGZqKI71tfS8zODkOZDD8aAusD2DOSmVZl48HX/t4i4Wc
+3dgi/gkCMrfK3wOujb8tL4zjnlVkM7kzKk0MgHuA1w81zFjeMFvigHes4IWhQVcz
+ek3l4bGifI2kzU7bGIi5e/019ppJzGsVcrOE/3z4GS0DJVk6fy7MEMIFx0LhJPlL
+T+9HMH85sSYb97PTiMWpfBvNw3FSC7QQT9FC3L8d/XtMY3NvZoc7Fz7cSGaj7NXG
+1OgVnAzMunPa3QaduoxMF9346s+4a+FrpRxL/3bb4skojjmmLqP4dsbD1uz0fP9y
+xSifnTnrtjumYWMVi+pEb5kR0sTHl0XS7qKRi3SEfv28uh72KdvcufonIA5rnEb5
++yqAZiqW2OxVsRoVLVODPswP4VIDiun2kCnfkQygPzxlZUeDZur0mmZ3vwC81C1Q
+dZcjlukZcqUaxybUloUilqfNeby+2Uig0krLh2+AM4EqR63LeZ/tk+zCitHeRBW0
+wl3Bd7ShBFg6kN5tCJlHf/G6suIJVr+A9BXfwekO9+//CutKakCwmJTUiNWbQbtN
+q3aNCnomyD3WjvUbitVO0CWYjZrmMLIsPtzyLQydpT7tjXpHgvwm5GYWdUGnNs4y
+NbA262sUl7Ku/GDw1CnFYXbxl+qxbucLtCdSIFR2xUq3rEO1MXlD/txdTxn6ANax
+hi9oBg8tHzuGYJFiCDCvbVVTHgWUSnm/EqfclpJzGmxt8g7vbaohW7NMmMQrLBFP
+G6qBypgvotx1iJWaHVLNNiXvyqQwTtelNPAUweRoNawBp/5KTwwy/tHeF0gsVQ7y
+mFX4umub9YT34Lpe7qUPKNxXzFcUgAf1SA6vyZ20UI7p42S2OT2PrahJ+uO6LQVD
++REhtN0oyS3G6HzAmKkBgw7LcV3XmAr39iSR7mdmoHSJuI9bjveAPhniK+N6uuln
+xf17Qnw5NWfr9MXcLli7zqwMglU/1bNirkwVqf/ogi/zQ3JYCo6tFGf/rnGQAORJ
+hvOq2SEYXnizPPIH7VrpE16+jUXwgpiQ8TDyeLPmpZVuhXTXiCaJO5lIwmLQqkmg
+JqNiT9V44sksNFTGNKgZo5O9rEqfqX4dLjfv6pGJL+MFXD9if4f1JQiXJfhcRcDh
+Ff9B6HukgbJ1H96eLUUNj8sL1+WPOqawkS4wg7tVaERE8CW7mqk15dCysn9shSut
+I+7JU7+dZsxpj0ownrxuPAFuT8ZlcBPrFzPUwTlW1G0CbuEco8ijfy5IfbyGCn5s
+K/0bOfAuNVGoOpLZ1dMki2bGdBwQOQlkLKhAxYcCVQ0/urr1Ab+VXU9kBsIU8ssN
+GogKngYpuUV0PHmpzmobielOHLjNqA2v9vQSV3Ed48wRy5OCwLX1+vYmYlggMDGt
+wfl+7QbXYf+k5WnELf3IqYvh8ZWexa0=
+</Data>
+</CertificateFile>
\ No newline at end of file
diff --git a/tests/data/wire/goal_state.xml b/tests/data/wire/goal_state.xml
index 579b5e87..0ccff211 100644
--- a/tests/data/wire/goal_state.xml
+++ b/tests/data/wire/goal_state.xml
@@ -15,12 +15,12 @@
          <InstanceId>b61f93d0-e1ed-40b2-b067-22c243233448.MachineRole_IN_0</InstanceId>
          <State>Started</State>
          <Configuration>
-         <HostingEnvironmentConfig>http://168.63.129.16:80/hostingenvuri/</HostingEnvironmentConfig>
-         <SharedConfig>http://168.63.129.16:80/sharedconfiguri/</SharedConfig>
-         <Certificates>http://168.63.129.16:80/certificatesuri/</Certificates>
-         <ExtensionsConfig>http://168.63.129.16:80/extensionsconfiguri/</ExtensionsConfig>
-         <FullConfig>http://168.63.129.16:80/fullconfiguri/</FullConfig>
-         <ConfigName>b61f93d0-e1ed-40b2-b067-22c243233448.1.b61f93d0-e1ed-40b2-b067-22c243233448.2.MachineRole_IN_0.xml</ConfigName>
+         <HostingEnvironmentConfig>http://168.63.129.16:80/machine/865a6683-91d8-450f-99ae/bc8b9d47%2Db5ed%2D4704%2D85d9%2Dfd74cc967ec2.%5Fcanary?comp=config&amp;type=hostingEnvironmentConfig&amp;incarnation=1</HostingEnvironmentConfig>
+          <SharedConfig>http://168.63.129.16:80/machine/865a6683-91d8-450f-99ae/bc8b9d47%2Db5ed%2D4704%2D85d9%2Dfd74cc967ec2.%5Fcanary?comp=config&amp;type=sharedConfig&amp;incarnation=1</SharedConfig>
+          <ExtensionsConfig>http://168.63.129.16:80/machine/865a6683-91d8-450f-99ae/bc8b9d47%2Db5ed%2D4704%2D85d9%2Dfd74cc967ec2.%5Fcanary?comp=config&amp;type=extensionsConfig&amp;incarnation=1</ExtensionsConfig>
+          <FullConfig>http://168.63.129.16:80/machine/865a6683-91d8-450f-99ae/bc8b9d47%2Db5ed%2D4704%2D85d9%2Dfd74cc967ec2.%5Fcanary?comp=config&amp;type=fullConfig&amp;incarnation=1</FullConfig>
+          <Certificates>http://168.63.129.16:80/machine/865a6683-91d8-450f-99ae/bc8b9d47%2Db5ed%2D4704%2D85d9%2Dfd74cc967ec2.%5Fcanary?comp=certificates&amp;incarnation=1</Certificates>
+          <ConfigName>bc8b9d47-b5ed-4704-85d9-fd74cc967ec2.5.bc8b9d47-b5ed-4704-85d9-fd74cc967ec2.5._canary.1.xml</ConfigName>
          </Configuration>
        </RoleInstance>
      </RoleInstanceList>
diff --git a/tests/data/wire/goal_state_no_ext.xml b/tests/data/wire/goal_state_no_ext.xml
index ef7e3989..e9048daf 100644
--- a/tests/data/wire/goal_state_no_ext.xml
+++ b/tests/data/wire/goal_state_no_ext.xml
@@ -15,11 +15,11 @@
          <InstanceId>b61f93d0-e1ed-40b2-b067-22c243233448.MachineRole_IN_0</InstanceId>
          <State>Started</State>
          <Configuration>
-         <HostingEnvironmentConfig>http://168.63.129.16:80/hostingenvuri/</HostingEnvironmentConfig>
-         <SharedConfig>http://168.63.129.16:80/sharedconfiguri/</SharedConfig>
-         <Certificates>http://168.63.129.16:80/certificatesuri/</Certificates>
-         <FullConfig>http://168.63.129.16:80/fullconfiguri/</FullConfig>
-         <ConfigName>b61f93d0-e1ed-40b2-b067-22c243233448.1.b61f93d0-e1ed-40b2-b067-22c243233448.2.MachineRole_IN_0.xml</ConfigName>
+          <HostingEnvironmentConfig>http://168.63.129.16:80/machine/865a6683-91d8-450f-99ae/bc8b9d47%2Db5ed%2D4704%2D85d9%2Dfd74cc967ec2.%5Fcanary?comp=config&amp;type=hostingEnvironmentConfig&amp;incarnation=1</HostingEnvironmentConfig>
+          <SharedConfig>http://168.63.129.16:80/machine/865a6683-91d8-450f-99ae/bc8b9d47%2Db5ed%2D4704%2D85d9%2Dfd74cc967ec2.%5Fcanary?comp=config&amp;type=sharedConfig&amp;incarnation=1</SharedConfig>
+          <FullConfig>http://168.63.129.16:80/machine/865a6683-91d8-450f-99ae/bc8b9d47%2Db5ed%2D4704%2D85d9%2Dfd74cc967ec2.%5Fcanary?comp=config&amp;type=fullConfig&amp;incarnation=1</FullConfig>
+          <Certificates>http://168.63.129.16:80/machine/865a6683-91d8-450f-99ae/bc8b9d47%2Db5ed%2D4704%2D85d9%2Dfd74cc967ec2.%5Fcanary?comp=certificates&amp;incarnation=1</Certificates>
+          <ConfigName>bc8b9d47-b5ed-4704-85d9-fd74cc967ec2.5.bc8b9d47-b5ed-4704-85d9-fd74cc967ec2.5._canary.1.xml</ConfigName>
          </Configuration>
        </RoleInstance>
      </RoleInstanceList>
diff --git a/tests/data/wire/goal_state_remote_access.xml b/tests/data/wire/goal_state_remote_access.xml
index c2840645..279006f2 100644
--- a/tests/data/wire/goal_state_remote_access.xml
+++ b/tests/data/wire/goal_state_remote_access.xml
@@ -17,12 +17,13 @@
          <InstanceId>b61f93d0-e1ed-40b2-b067-22c243233448.MachineRole_IN_0</InstanceId>
          <State>Started</State>
          <Configuration>
-         <HostingEnvironmentConfig>http://168.63.129.16:80/hostingenvuri/</HostingEnvironmentConfig>
-         <SharedConfig>http://168.63.129.16:80/sharedconfiguri/</SharedConfig>
-         <Certificates>http://168.63.129.16:80/certificatesuri/</Certificates>
-         <ExtensionsConfig>http://168.63.129.16:80/extensionsconfiguri/</ExtensionsConfig>
-         <FullConfig>http://168.63.129.16:80/fullconfiguri/</FullConfig>
-         <ConfigName>b61f93d0-e1ed-40b2-b067-22c243233448.1.b61f93d0-e1ed-40b2-b067-22c243233448.2.MachineRole_IN_0.xml</ConfigName>
+          <ConfigName>b61f93d0-e1ed-40b2-b067-22c243233448.1.b61f93d0-e1ed-40b2-b067-22c243233448.2.MachineRole_IN_0.xml</ConfigName>
+          <HostingEnvironmentConfig>http://168.63.129.16:80/machine/865a6683-91d8-450f-99ae/bc8b9d47%2Db5ed%2D4704%2D85d9%2Dfd74cc967ec2.%5Fcanary?comp=config&amp;type=hostingEnvironmentConfig&amp;incarnation=1</HostingEnvironmentConfig>
+          <SharedConfig>http://168.63.129.16:80/machine/865a6683-91d8-450f-99ae/bc8b9d47%2Db5ed%2D4704%2D85d9%2Dfd74cc967ec2.%5Fcanary?comp=config&amp;type=sharedConfig&amp;incarnation=1</SharedConfig>
+          <ExtensionsConfig>http://168.63.129.16:80/machine/865a6683-91d8-450f-99ae/bc8b9d47%2Db5ed%2D4704%2D85d9%2Dfd74cc967ec2.%5Fcanary?comp=config&amp;type=extensionsConfig&amp;incarnation=1</ExtensionsConfig>
+          <FullConfig>http://168.63.129.16:80/machine/865a6683-91d8-450f-99ae/bc8b9d47%2Db5ed%2D4704%2D85d9%2Dfd74cc967ec2.%5Fcanary?comp=config&amp;type=fullConfig&amp;incarnation=1</FullConfig>
+          <Certificates>http://168.63.129.16:80/machine/865a6683-91d8-450f-99ae/bc8b9d47%2Db5ed%2D4704%2D85d9%2Dfd74cc967ec2.%5Fcanary?comp=certificates&amp;incarnation=1</Certificates>
+          <ConfigName>bc8b9d47-b5ed-4704-85d9-fd74cc967ec2.5.bc8b9d47-b5ed-4704-85d9-fd74cc967ec2.5._canary.1.xml</ConfigName>
          </Configuration>
        </RoleInstance>
      </RoleInstanceList>
diff --git a/tests/ga/test_update.py b/tests/ga/test_update.py
index 664c78e2..f301a8a7 100644
--- a/tests/ga/test_update.py
+++ b/tests/ga/test_update.py
@@ -1785,7 +1785,7 @@ class TestUpdate(UpdateTestCase):
 
     def test_it_should_wait_to_fetch_first_goal_state(self):
         with _get_update_handler() as (update_handler, protocol):
-            with patch("azurelinuxagent.common.logger.warn") as patch_warn:
+            with patch("azurelinuxagent.common.logger.error") as patch_error:
                 with patch("azurelinuxagent.common.logger.info") as patch_info:
                     # Fail GS fetching for the 1st 5 times the agent asks for it
                     update_handler._fail_gs_count = 5
@@ -1799,13 +1799,15 @@ class TestUpdate(UpdateTestCase):
                     protocol.set_http_handlers(http_get_handler=get_handler)
                     update_handler.run(debug=True)
 
-        self.assertEqual(0, update_handler.get_exit_code(), "Exit code should be 0; List of all warnings logged by the agent: {0}".format(
-            patch_warn.call_args_list))
-        warn_msgs = [args[0] for (args, _) in patch_warn.call_args_list if
-                     "An error occurred while retrieving the goal state" in args[0]]
-        self.assertTrue(len(warn_msgs) > 0, "Error should've been reported when failed to retrieve GS")
+        self.assertEqual(0, update_handler.get_exit_code(), "Exit code should be 0; List of all errors logged by the agent: {0}".format(
+            patch_error.call_args_list))
+
+        error_msgs = [args[0] for (args, _) in patch_error.call_args_list if
+                     "Error fetching the goal state" in args[0]]
+        self.assertTrue(len(error_msgs) > 0, "Error should've been reported when failed to retrieve GS")
+
         info_msgs = [args[0] for (args, _) in patch_info.call_args_list if
-                     "Retrieving the goal state recovered from previous errors" in args[0]]
+                     "Fetching the goal state recovered from previous errors." in args[0]]
         self.assertTrue(len(info_msgs) > 0, "Agent should've logged a message when recovered from GS errors")
 
     def test_it_should_reset_legacy_blacklisted_agents_on_process_start(self):
@@ -2637,9 +2639,9 @@ class TryUpdateGoalStateTestCase(HttpRequestPredicates, AgentTestCase):
             calls_to_strings = lambda calls: (str(c) for c in calls)
             filter_calls = lambda calls, regex=None: (c for c in calls_to_strings(calls) if regex is None or re.match(regex, c))
             logger_calls = lambda regex=None: [m for m in filter_calls(logger.method_calls, regex)]  # pylint: disable=used-before-assignment,unnecessary-comprehension
-            warnings = lambda: logger_calls(r'call.warn\(.*An error occurred while retrieving the goal state.*')
-            periodic_warnings = lambda: logger_calls(r'call.periodic_warn\(.*Attempts to retrieve the goal state are failing.*')
-            success_messages = lambda: logger_calls(r'call.info\(.*Retrieving the goal state recovered from previous errors.*')
+            errors = lambda: logger_calls(r'call.error\(.*Error fetching the goal state.*')
+            periodic_errors = lambda: logger_calls(r'call.error\(.*Fetching the goal state is still failing*')
+            success_messages = lambda: logger_calls(r'call.info\(.*Fetching the goal state recovered from previous errors.*')
             telemetry_calls = lambda regex=None: [m for m in filter_calls(add_event.mock_calls, regex)]  # pylint: disable=used-before-assignment,unnecessary-comprehension
             goal_state_events = lambda: telemetry_calls(r".*op='FetchGoalState'.*")
 
@@ -2664,10 +2666,8 @@ class TryUpdateGoalStateTestCase(HttpRequestPredicates, AgentTestCase):
             with create_log_and_telemetry_mocks() as (logger, add_event):
                 update_handler._try_update_goal_state(protocol)
 
-                w = warnings()
-                pw = periodic_warnings()
-                self.assertEqual(1, len(w), "A failure should have produced a warning: [{0}]".format(w))
-                self.assertEqual(1, len(pw), "A failure should have produced a periodic warning: [{0}]".format(pw))
+                e = errors()
+                self.assertEqual(1, len(e), "A failure should have produced an error: [{0}]".format(e))
 
                 gs = goal_state_events()
                 self.assertTrue(len(gs) == 1 and 'is_success=False' in gs[0], "A failure should produce a telemetry event (success=false): [{0}]".format(gs))
@@ -2676,17 +2676,17 @@ class TryUpdateGoalStateTestCase(HttpRequestPredicates, AgentTestCase):
             # ... and errors continue happening...
             #
             with create_log_and_telemetry_mocks() as (logger, add_event):
-                update_handler._try_update_goal_state(protocol)
-                update_handler._try_update_goal_state(protocol)
-                update_handler._try_update_goal_state(protocol)
+                for _ in range(5):
+                    update_handler._update_goal_state_last_error_report = datetime.now() + timedelta(days=1)
+                    update_handler._try_update_goal_state(protocol)
 
-                w = warnings()
-                pw = periodic_warnings()
-                self.assertTrue(len(w) == 0, "Subsequent failures should not produce warnings: [{0}]".format(w))
-                self.assertEqual(len(pw), 3, "Subsequent failures should produce periodic warnings: [{0}]".format(pw))
+                e = errors()
+                pe = periodic_errors()
+                self.assertEqual(2, len(e), "Two additional errors should have been reported: [{0}]".format(e))
+                self.assertEqual(len(pe), 3, "Subsequent failures should produce periodic errors: [{0}]".format(pe))
 
                 tc = telemetry_calls()
-                self.assertTrue(len(tc) == 0, "Subsequent failures should not produce any telemetry events: [{0}]".format(tc))
+                self.assertTrue(len(tc) == 5, "The failures should have produced telemetry events. Got: [{0}]".format(tc))
 
             #
             # ... until we finally succeed
@@ -2696,10 +2696,10 @@ class TryUpdateGoalStateTestCase(HttpRequestPredicates, AgentTestCase):
                 update_handler._try_update_goal_state(protocol)
 
                 s = success_messages()
-                w = warnings()
-                pw = periodic_warnings()
+                e = errors()
+                pe = periodic_errors()
                 self.assertEqual(len(s), 1, "Recovering after failures should have produced an info message: [{0}]".format(s))
-                self.assertTrue(len(w) == 0 and len(pw) == 0, "Recovering after failures should have not produced any warnings: [{0}] [{1}]".format(w, pw))
+                self.assertTrue(len(e) == 0 and len(pe) == 0, "Recovering after failures should have not produced any errors: [{0}] [{1}]".format(e, pe))
 
                 gs = goal_state_events()
                 self.assertTrue(len(gs) == 1 and 'is_success=True' in gs[0], "Recovering after failures should produce a telemetry event (success=true): [{0}]".format(gs))
diff --git a/tests/protocol/HttpRequestPredicates.py b/tests/protocol/HttpRequestPredicates.py
index 39243d54..db3ab8b2 100644
--- a/tests/protocol/HttpRequestPredicates.py
+++ b/tests/protocol/HttpRequestPredicates.py
@@ -11,6 +11,22 @@ class HttpRequestPredicates(object):
     def is_goal_state_request(url):
         return url.lower() == 'http://{0}/machine/?comp=goalstate'.format(restutil.KNOWN_WIRESERVER_IP)
 
+    @staticmethod
+    def is_certificates_request(url):
+        return re.match(r'http://{0}(:80)?/machine/.*?comp=certificates'.format(restutil.KNOWN_WIRESERVER_IP), url, re.IGNORECASE)
+
+    @staticmethod
+    def is_extensions_config_request(url):
+        return re.match(r'http://{0}(:80)?/machine/.*?comp=config&type=extensionsConfig'.format(restutil.KNOWN_WIRESERVER_IP), url, re.IGNORECASE)
+
+    @staticmethod
+    def is_hosting_environment_config_request(url):
+        return re.match(r'http://{0}(:80)?/machine/.*?comp=config&type=hostingEnvironmentConfig'.format(restutil.KNOWN_WIRESERVER_IP), url, re.IGNORECASE)
+
+    @staticmethod
+    def is_shared_config_request(url):
+        return re.match(r'http://{0}(:80)?/machine/.*?comp=config&type=sharedConfig'.format(restutil.KNOWN_WIRESERVER_IP), url, re.IGNORECASE)
+
     @staticmethod
     def is_telemetry_request(url):
         return url.lower() == 'http://{0}/machine?comp=telemetrydata'.format(restutil.KNOWN_WIRESERVER_IP)
diff --git a/tests/protocol/mockwiredata.py b/tests/protocol/mockwiredata.py
index 218bd293..7ec311af 100644
--- a/tests/protocol/mockwiredata.py
+++ b/tests/protocol/mockwiredata.py
@@ -135,10 +135,10 @@ class WireProtocolData(object):
             "/HealthService": 0,
             "/vmAgentLog": 0,
             "goalstate": 0,
-            "hostingenvuri": 0,
-            "sharedconfiguri": 0,
-            "certificatesuri": 0,
-            "extensionsconfiguri": 0,
+            "hostingEnvironmentConfig": 0,
+            "sharedConfig": 0,
+            "certificates": 0,
+            "extensionsConfig": 0,
             "remoteaccessinfouri": 0,
             "extensionArtifact": 0,
             "agentArtifact": 0,
@@ -198,6 +198,10 @@ class WireProtocolData(object):
         if in_vm_artifacts_profile_file is not None:
             self.in_vm_artifacts_profile = load_data(in_vm_artifacts_profile_file)
 
+    def reset_call_counts(self):
+        for counter in self.call_counts:
+            self.call_counts[counter] = 0
+
     def mock_http_get(self, url, *_, **kwargs):
         content = ''
         response_headers = []
@@ -217,18 +221,18 @@ class WireProtocolData(object):
         elif "goalstate" in url:
             content = self.goal_state
             self.call_counts["goalstate"] += 1
-        elif "hostingenvuri" in url:
+        elif HttpRequestPredicates.is_hosting_environment_config_request(url):
             content = self.hosting_env
-            self.call_counts["hostingenvuri"] += 1
-        elif "sharedconfiguri" in url:
+            self.call_counts["hostingEnvironmentConfig"] += 1
+        elif HttpRequestPredicates.is_shared_config_request(url):
             content = self.shared_config
-            self.call_counts["sharedconfiguri"] += 1
-        elif "certificatesuri" in url:
+            self.call_counts["sharedConfig"] += 1
+        elif HttpRequestPredicates.is_certificates_request(url):
             content = self.certs
-            self.call_counts["certificatesuri"] += 1
-        elif "extensionsconfiguri" in url:
+            self.call_counts["certificates"] += 1
+        elif HttpRequestPredicates.is_extensions_config_request(url):
             content = self.ext_conf
-            self.call_counts["extensionsconfiguri"] += 1
+            self.call_counts["extensionsConfig"] += 1
         elif "remoteaccessinfouri" in url:
             content = self.remote_access
             self.call_counts["remoteaccessinfouri"] += 1
diff --git a/tests/protocol/test_goal_state.py b/tests/protocol/test_goal_state.py
index c54a65f9..c7741715 100644
--- a/tests/protocol/test_goal_state.py
+++ b/tests/protocol/test_goal_state.py
@@ -8,13 +8,12 @@ import os
 import re
 import time
 
-from azurelinuxagent.common.event import WALAEventOperation
 from azurelinuxagent.common.future import httpclient
 from azurelinuxagent.common.protocol.extensions_goal_state import GoalStateSource, GoalStateChannel
 from azurelinuxagent.common.protocol.extensions_goal_state_from_extensions_config import ExtensionsGoalStateFromExtensionsConfig
 from azurelinuxagent.common.protocol.extensions_goal_state_from_vm_settings import ExtensionsGoalStateFromVmSettings
 from azurelinuxagent.common.protocol import hostplugin
-from azurelinuxagent.common.protocol.goal_state import GoalState, _GET_GOAL_STATE_MAX_ATTEMPTS
+from azurelinuxagent.common.protocol.goal_state import GoalState, GoalStateInconsistentError, _GET_GOAL_STATE_MAX_ATTEMPTS
 from azurelinuxagent.common.exception import ProtocolError
 from azurelinuxagent.common.utils import fileutil
 from azurelinuxagent.common.utils.archive import ARCHIVE_DIRECTORY_NAME
@@ -360,17 +359,54 @@ class GoalStateTestCase(AgentTestCase, HttpRequestPredicates):
             self.assertEqual(initial_timestamp, goal_state.extensions_goal_state.created_on_timestamp, "The timestamp of the updated goal state is incorrect")
             self.assertTrue(goal_state.extensions_goal_state.is_outdated, "The updated goal state should be marked as outdated")
 
-    def test_it_should_report_missing_certificates(self):
+    def test_it_should_raise_when_the_tenant_certificate_is_missing(self):
         data_file = mockwiredata.DATA_FILE_VM_SETTINGS.copy()
-        data_file["vm_settings"] = "hostgaplugin/vm_settings-missing_cert.json"
 
         with mock_wire_protocol(data_file) as protocol:
-            with patch("azurelinuxagent.common.protocol.goal_state.add_event") as add_event:
+            data_file["vm_settings"] = "hostgaplugin/vm_settings-missing_cert.json"
+            protocol.mock_wire_data.reload()
+
+            with self.assertRaises(GoalStateInconsistentError) as context:
                 _ = GoalState(protocol.client)
 
-                expected_message = "Certificate 59A10F50FFE2A0408D3F03FE336C8FD5716CF25C needed by Microsoft.OSTCExtensions.VMAccessForLinux is missing from the goal state"
-                events = [kwargs for _, kwargs in add_event.call_args_list if kwargs['op'] == WALAEventOperation.VmSettings and kwargs['message'] == expected_message]
+            expected_message = "Certificate 59A10F50FFE2A0408D3F03FE336C8FD5716CF25C needed by Microsoft.OSTCExtensions.VMAccessForLinux is missing from the goal state"
+            self.assertIn(expected_message, str(context.exception))
+
+    def test_it_should_refresh_the_goal_state_when_it_is_inconsistent(self):
+        #
+        # Some scenarios can produce inconsistent goal states. For example, during hibernation/resume, the Fabric goal state changes (the
+        # tenant certificate is re-generated when the VM is restarted) *without* the incarnation changing. If a Fast Track goal state
+        # comes after that, the extensions will need the new certificate. This test simulates that scenario by mocking the certificates
+        # request and returning first a set of certificates (certs-2.xml) that do not match those needed by the extensions, and then a
+        # set (certs.xml) that does match. The test then ensures that the goal state was refreshed and the correct certificates were
+        # fetched.
+        #
+        data_files = [
+            "wire/certs-2.xml",
+            "wire/certs.xml"
+        ]
+
+        def http_get_handler(url, *_, **__):
+            if HttpRequestPredicates.is_certificates_request(url):
+                http_get_handler.certificate_requests += 1
+                if http_get_handler.certificate_requests < len(data_files):
+                    data = load_data(data_files[http_get_handler.certificate_requests - 1])
+                    return MockHttpResponse(status=200, body=data.encode('utf-8'))
+            return None
+        http_get_handler.certificate_requests = 0
+
+        with mock_wire_protocol(mockwiredata.DATA_FILE_VM_SETTINGS) as protocol:
+            protocol.set_http_handlers(http_get_handler=http_get_handler)
+            protocol.mock_wire_data.reset_call_counts()
+
+            goal_state = GoalState(protocol.client)
+
+            self.assertEqual(2, protocol.mock_wire_data.call_counts['goalstate'], "There should have been exactly 2 requests for the goal state (original + refresh)")
+            self.assertEqual(2, http_get_handler.certificate_requests, "There should have been exactly 2 requests for the goal state certificates (original + refresh)")
+
+            thumbprints = [c.thumbprint for c in goal_state.certs.cert_list.certificates]
 
-                self.assertTrue(
-                    len(events) == 1,
-                    "Missing certificate 59A10F50FFE2A0408D3F03FE336C8FD5716CF25C was not reported. Telemetry: {0}".format([kwargs['message'] for _, kwargs in add_event.call_args_list]))
+            for extension in goal_state.extensions_goal_state.extensions:
+                for settings in extension.settings:
+                    if settings.protectedSettings is not None:
+                        self.assertIn(settings.certificateThumbprint, thumbprints, "Certificate is missing from the goal state.")
diff --git a/tests/protocol/test_hostplugin.py b/tests/protocol/test_hostplugin.py
index 16bb7ef0..9f96f7d5 100644
--- a/tests/protocol/test_hostplugin.py
+++ b/tests/protocol/test_hostplugin.py
@@ -257,9 +257,8 @@ class TestHostPlugin(HttpRequestPredicates, AgentTestCase):
             # assert host plugin route is called
             self.assertEqual(1, patch_put.call_count, "Host plugin was not used")
 
-            # assert update goal state is only called once, non-forced
+            # assert update goal state is only called once
             self.assertEqual(1, wire_protocol.client.update_goal_state.call_count, "Unexpected call count")
-            self.assertEqual(0, len(wire_protocol.client.update_goal_state.call_args[1]), "Unexpected parameters")
 
             # ensure the correct url is used
             self.assertEqual(sas_url, patch_put.call_args[0][0])
@@ -291,9 +290,8 @@ class TestHostPlugin(HttpRequestPredicates, AgentTestCase):
             # assert host plugin route is called
             self.assertEqual(1, patch_put.call_count, "Host plugin was not used")
 
-            # assert update goal state is only called once, non-forced
+            # assert update goal state is only called once
             self.assertEqual(1, wire_protocol.client.update_goal_state.call_count, "Update goal state unexpected call count")
-            self.assertEqual(0, len(wire_protocol.client.update_goal_state.call_args[1]), "Update goal state unexpected call count")
 
             # ensure the correct url is used
             self.assertEqual(sas_url, patch_put.call_args[0][0])
@@ -326,9 +324,8 @@ class TestHostPlugin(HttpRequestPredicates, AgentTestCase):
             # assert host plugin route is called
             self.assertEqual(1, patch_put.call_count, "Host plugin was not used")
 
-            # assert update goal state is called with no arguments (forced=False), then update_host_plugin_from_goal_state is called
+            # assert update goal state is called, then update_host_plugin_from_goal_state is called
             self.assertEqual(1, wire_protocol.client.update_goal_state.call_count, "Update goal state unexpected call count")
-            self.assertEqual(0, len(wire_protocol.client.update_goal_state.call_args[1]), "Update goal state unexpected argument count")
             self.assertEqual(1, patch_refresh_host_plugin.call_count, "Refresh host plugin unexpected call count")
 
             # ensure the correct url is used
@@ -361,9 +358,8 @@ class TestHostPlugin(HttpRequestPredicates, AgentTestCase):
             # assert host plugin route is called
             self.assertEqual(1, patch_put.call_count, "Host plugin was not used")
 
-            # assert update goal state is called twice, forced=True on the second
+            # assert update goal state is called twice
             self.assertEqual(1, wire_protocol.client.update_goal_state.call_count, "Update goal state unexpected call count")
-            self.assertEqual(0, len(wire_protocol.client.update_goal_state.call_args[1]), "Update goal state unexpected call count")
 
             # ensure the correct url is used
             self.assertEqual(sas_url, patch_put.call_args[0][0])
diff --git a/tests/protocol/test_wire.py b/tests/protocol/test_wire.py
index 0cc8a01e..c564af72 100644
--- a/tests/protocol/test_wire.py
+++ b/tests/protocol/test_wire.py
@@ -160,7 +160,7 @@ class TestWireProtocol(AgentTestCase, HttpRequestPredicates):
         # -- Tracking calls to retrieve GoalState is problematic since it is
         #    fetched often; however, the dependent documents, such as the
         #    HostingEnvironmentConfig, will be retrieved the expected number
-        self.assertEqual(1, test_data.call_counts["hostingenvuri"])
+        self.assertEqual(1, test_data.call_counts["hostingEnvironmentConfig"])
         self.assertEqual(1, patch_report.call_count)
 
     def test_call_storage_kwargs(self, *args):  # pylint: disable=unused-argument