Repository: Azure/WALinuxAgent
Pull request #2913 (2023-08-31 23:11:13)

Download certs on FT GS after check_certificates only when missing fr…
…om disk (#2907)

* Download certs on FT GS only when missing from disk

* Improve telemetry for inconsistent GS

* Fix string format

(cherry picked from commit c13f7500c4e3c93f081d0ff6cdb46c6ffdcdd43a)

<!-- DO NOT DELETE THIS TEMPLATE -->

## Description

Issue # <!-- if any -->
<!--
Please add an informative description that covers that changes made by the pull request. 
This checklist is used to make sure that common issues in a pull request are addressed.
This will expedite the process of getting your pull request merged and avoid extra work on your part to fix issues discovered during the review process.
-->

---

### PR information
- [ ] The title of the PR is clear and informative.
- [ ] There are a small number of commits, each of which has an informative message. This means that previously merged commits do not appear in the history of the PR. For information on cleaning up the commits in your pull request, [see this page](https://github.com/Azure/azure-powershell/blob/master/documentation/development-docs/cleaning-up-commits.md).
- [ ] If applicable, the PR references the bug/issue that it fixes in the description.
- [ ] New Unit tests were added for the changes made

### Quality of Code and Contribution Guidelines
- [ ] I have read the [contribution guidelines](https://github.com/Azure/WALinuxAgent/blob/master/.github/CONTRIBUTING.md).

codecov[bot]: ## [Codecov](https://app.codecov.io/gh/Azure/WALinuxAgent/pull/2913?src=pr&el=h1&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) Report
> Merging [#2913](https://app.codecov.io/gh/Azure/WALinuxAgent/pull/2913?src=pr&el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) (b922747) into [develop](https://app.codecov.io/gh/Azure/WALinuxAgent/commit/ae01d59f2d43314f4c8cb2d8120a3c5892086de6?el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) (ae01d59) will **increase** coverage by `0.01%`.
> The diff coverage is `82.14%`.

```diff
@@             Coverage Diff             @@
##           develop    #2913      +/-   ##
===========================================
+ Coverage    71.98%   72.00%   +0.01%     
===========================================
  Files          106      106              
  Lines        16038    16061      +23     
  Branches      2300     2303       +3     
===========================================
+ Hits         11545    11564      +19     
- Misses        3959     3963       +4     
  Partials       534      534              
```


| [Files Changed](https://app.codecov.io/gh/Azure/WALinuxAgent/pull/2913?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) | Coverage Δ | |
|---|---|---|
| [azurelinuxagent/common/protocol/goal\_state.py](https://app.codecov.io/gh/Azure/WALinuxAgent/pull/2913?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi9wcm90b2NvbC9nb2FsX3N0YXRlLnB5) | `94.84% <82.14%> (-0.61%)` | :arrow_down: |



Patch:
diff --git a/azurelinuxagent/common/protocol/goal_state.py b/azurelinuxagent/common/protocol/goal_state.py
index 3d02268c..267b01c5 100644
--- a/azurelinuxagent/common/protocol/goal_state.py
+++ b/azurelinuxagent/common/protocol/goal_state.py
@@ -208,9 +208,15 @@ class GoalState(object):
         try:
             self._update(force_update=False)
         except GoalStateInconsistentError as e:
-            self.logger.warn("Detected an inconsistency in the goal state: {0}", ustr(e))
+            message = "Detected an inconsistency in the goal state: {0}".format(ustr(e))
+            self.logger.warn(message)
+            add_event(op=WALAEventOperation.GoalState, is_success=False, message=message)
+
             self._update(force_update=True)
-            self.logger.info("The goal state is consistent")
+
+            message = "The goal state is consistent"
+            self.logger.info(message)
+            add_event(op=WALAEventOperation.GoalState, message=message)
 
     def _update(self, force_update):
         #
@@ -219,7 +225,9 @@ class GoalState(object):
         timestamp = datetime.datetime.utcnow()
 
         if force_update:
-            self.logger.info("Refreshing goal state and vmSettings")
+            message = "Refreshing goal state and vmSettings"
+            self.logger.info(message)
+            add_event(op=WALAEventOperation.GoalState, message=message)
 
         incarnation, xml_text, xml_doc = GoalState._fetch_goal_state(self._wire_client)
         goal_state_updated = force_update or incarnation != self._incarnation
@@ -292,11 +300,9 @@ class GoalState(object):
         #
         if self._extensions_goal_state.source == GoalStateSource.FastTrack and self._goal_state_properties & GoalStateProperties.Certificates:
             self._check_certificates()
+            self._check_and_download_missing_certs_on_disk()
 
     def _check_certificates(self):
-        # Re-download certificates in case they have been removed from disk since last download
-        if self._certs_uri is not None:
-            self._download_certificates(self._certs_uri)
         # Check that certificates needed by extensions are in goal state certs.summary
         for extension in self.extensions_goal_state.extensions:
             for settings in extension.settings:
@@ -321,6 +327,32 @@ class GoalState(object):
         self._history.save_certificates(json.dumps(certs.summary))
         return certs
 
+    def _check_and_download_missing_certs_on_disk(self):
+        # Re-download certificates if any have been removed from disk since last download
+        if self._certs_uri is not None:
+            certificates = self.certs.summary
+            certs_missing_from_disk = False
+
+            for c in certificates:
+                cert_path = os.path.join(conf.get_lib_dir(), c['thumbprint'] + '.crt')
+                if not os.path.isfile(cert_path):
+                    certs_missing_from_disk = True
+                    message = "Certificate required by goal state is not on disk: {0}".format(cert_path)
+                    self.logger.info(message)
+                    add_event(op=WALAEventOperation.GoalState, message=message)
+            if certs_missing_from_disk:
+                # Try to re-download certs. Sometimes download may fail if certs_uri is outdated/contains wrong
+                # container id (for example, when the VM is moved to a new container after resuming from
+                # hibernation). If download fails we should report and continue with goal state processing, as some
+                # extensions in the goal state may succeed.
+                try:
+                    self._download_certificates(self._certs_uri)
+                except Exception as e:
+                    message = "Unable to download certificates. Goal state processing will continue, some " \
+                              "extensions requiring certificates may fail. Error: {0}".format(ustr(e))
+                    self.logger.warn(message)
+                    add_event(op=WALAEventOperation.GoalState, is_success=False, message=message)
+
     def _restore_wire_server_goal_state(self, incarnation, xml_text, xml_doc, vm_settings_support_stopped_error):
         msg = 'The HGAP stopped supporting vmSettings; will fetched the goal state from the WireServer.'
         self.logger.info(msg)


Test patch:
diff --git a/tests/common/protocol/test_goal_state.py b/tests/common/protocol/test_goal_state.py
index 3f00a62d..c33851e9 100644
--- a/tests/common/protocol/test_goal_state.py
+++ b/tests/common/protocol/test_goal_state.py
@@ -157,7 +157,7 @@ class GoalStateTestCase(AgentTestCase, HttpRequestPredicates):
             protocol.set_http_handlers(http_get_handler=None)
             goal_state.update()
             self._assert_directory_contents(
-                self._find_history_subdirectory("234-987"), ["VmSettings.json", "Certificates.json"])
+                self._find_history_subdirectory("234-987"), ["VmSettings.json"])
 
     def test_it_should_redact_the_protected_settings_when_saving_to_the_history_directory(self):
         with mock_wire_protocol(wire_protocol_data.DATA_FILE_VM_SETTINGS) as protocol:
@@ -464,7 +464,7 @@ class GoalStateTestCase(AgentTestCase, HttpRequestPredicates):
             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(4, http_get_handler.certificate_requests, "There should have been exactly 4 requests for the goal state certificates (2x original + 2x 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]