Repository: Azure/WALinuxAgent
Pull request #2496 (2022-02-08 00:42:42)

Do not raise on missing status blob; reduce amount of logging for vmsettings (#2492)
* Do not raise on missing status blob; reduce amount of logging for vmsettings

* remove extra file; fix typo

Co-authored-by: narrieta <narrieta>
(cherry picked from commit 7cce03b271cce9bee8d3c09a6eea3ea75cc3526c)



codecov[bot]: # [Codecov](https://codecov.io/gh/Azure/WALinuxAgent/pull/2496?src=pr&el=h1&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) Report
> Merging [#2496](https://codecov.io/gh/Azure/WALinuxAgent/pull/2496?src=pr&el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) (fe565b8) into [develop](https://codecov.io/gh/Azure/WALinuxAgent/commit/40d98de87566245956f5d056a84e32f83a1eaf9d?el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) (40d98de) will **decrease** coverage by `0.01%`.
> The diff coverage is `71.42%`.

[![Impacted file tree graph](https://codecov.io/gh/Azure/WALinuxAgent/pull/2496/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/2496?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure)

```diff
@@             Coverage Diff             @@
##           develop    #2496      +/-   ##
===========================================
- Coverage    71.93%   71.92%   -0.02%     
===========================================
  Files          101      101              
  Lines        15128    15131       +3     
  Branches      2408     2409       +1     
===========================================
  Hits         10883    10883              
- Misses        3759     3760       +1     
- Partials       486      488       +2     
```


| [Impacted Files](https://codecov.io/gh/Azure/WALinuxAgent/pull/2496?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure) | Coverage Δ | |
|---|---|---|
| [...protocol/extensions\_goal\_state\_from\_vm\_settings.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2496/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi9wcm90b2NvbC9leHRlbnNpb25zX2dvYWxfc3RhdGVfZnJvbV92bV9zZXR0aW5ncy5weQ==) | `81.67% <60.00%> (+0.87%)` | :arrow_up: |
| [azurelinuxagent/common/protocol/wire.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2496/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi9wcm90b2NvbC93aXJlLnB5) | `81.61% <100.00%> (+0.04%)` | :arrow_up: |
| [azurelinuxagent/ga/collect\_telemetry\_events.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2496/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure#diff-YXp1cmVsaW51eGFnZW50L2dhL2NvbGxlY3RfdGVsZW1ldHJ5X2V2ZW50cy5weQ==) | `89.72% <0.00%> (-1.72%)` | :arrow_down: |

------

[Continue to review full report at Codecov](https://codecov.io/gh/Azure/WALinuxAgent/pull/2496?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/2496?src=pr&el=footer&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=Azure). Last update [40d98de...fe565b8](https://codecov.io/gh/Azure/WALinuxAgent/pull/2496?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/protocol/extensions_goal_state_from_vm_settings.py b/azurelinuxagent/common/protocol/extensions_goal_state_from_vm_settings.py
index dcf6c2c2..12a23173 100644
--- a/azurelinuxagent/common/protocol/extensions_goal_state_from_vm_settings.py
+++ b/azurelinuxagent/common/protocol/extensions_goal_state_from_vm_settings.py
@@ -22,10 +22,10 @@ import sys
 
 from azurelinuxagent.common.AgentGlobals import AgentGlobals
 from azurelinuxagent.common.exception import VmSettingsError
+from azurelinuxagent.common.future import ustr
 from azurelinuxagent.common.protocol.extensions_goal_state import ExtensionsGoalState
 from azurelinuxagent.common.protocol.restapi import VMAgentManifest, Extension, ExtensionRequestedState, ExtensionSettings
 from azurelinuxagent.common.utils.flexible_version import FlexibleVersion
-from azurelinuxagent.common.utils.textutil import format_exception
 
 
 class ExtensionsGoalStateFromVmSettings(ExtensionsGoalState):
@@ -53,7 +53,7 @@ class ExtensionsGoalStateFromVmSettings(ExtensionsGoalState):
             self._parse_vm_settings(json_text)
             self._do_common_validations()
         except Exception as e:
-            raise VmSettingsError("Error parsing vmSettings (etag: {0} HGAP: {1}): {2}\n{3}".format(etag, self._host_ga_plugin_version, format_exception(e), self.get_redacted_text()))
+            raise VmSettingsError("Error parsing vmSettings [HGAP: {0}]: {1}".format(self._host_ga_plugin_version, ustr(e)))
 
     @property
     def id(self):
@@ -173,13 +173,15 @@ class ExtensionsGoalStateFromVmSettings(ExtensionsGoalState):
         # }
         status_upload_blob = vm_settings.get("statusUploadBlob")
         if status_upload_blob is None:
-            raise Exception("Missing statusUploadBlob")
-        self._status_upload_blob = status_upload_blob.get("value")
-        if self._status_upload_blob is None:
-            raise Exception("Missing statusUploadBlob.value")
-        self._status_upload_blob_type = status_upload_blob.get("statusBlobType")
-        if self._status_upload_blob is None:
-            raise Exception("Missing statusUploadBlob.statusBlobType")
+            self._status_upload_blob = None
+            self._status_upload_blob_type = "BlockBlob"
+        else:
+            self._status_upload_blob = status_upload_blob.get("value")
+            if self._status_upload_blob is None:
+                raise Exception("Missing statusUploadBlob.value")
+            self._status_upload_blob_type = status_upload_blob.get("statusBlobType")
+            if self._status_upload_blob_type is None:
+                self._status_upload_blob_type = "BlockBlob"
 
     def _parse_required_features(self, vm_settings):
         # Sample:
diff --git a/azurelinuxagent/common/protocol/wire.py b/azurelinuxagent/common/protocol/wire.py
index 2f80ac21..cda6381f 100644
--- a/azurelinuxagent/common/protocol/wire.py
+++ b/azurelinuxagent/common/protocol/wire.py
@@ -1537,7 +1537,8 @@ class _VmSettingsError(object):
 
 
 class _VmSettingsErrorReporter(object):
-    _MaxErrors = 5  # Max number of error reported by period
+    _MaxLogErrors = 1  # Max number of errors by period reported to the local log
+    _MaxTelemetryErrors = 3  # Max number of errors  by period reported to telemetry
     _Period = timedelta(hours=1)  # How often to report the summary
 
     def __init__(self):
@@ -1558,8 +1559,10 @@ class _VmSettingsErrorReporter(object):
     def report_error(self, error, category=None):
         self._error_count += 1
 
-        if self._error_count <= _VmSettingsErrorReporter._MaxErrors:
+        if self._error_count <= _VmSettingsErrorReporter._MaxLogErrors:
             logger.info("[VmSettings] [Informational only, the Agent will continue normal operation] {0}", error)
+
+        if self._error_count <= _VmSettingsErrorReporter._MaxTelemetryErrors:
             add_event(op=WALAEventOperation.VmSettings, message=error, is_success=False, log_event=False)
 
         if category == _VmSettingsError.ServerError:


Test patch:
diff --git a/tests/data/hostgaplugin/ext_conf-no_status_upload_blob.xml b/tests/data/hostgaplugin/ext_conf-no_status_upload_blob.xml
new file mode 100644
index 00000000..5141c0dc
--- /dev/null
+++ b/tests/data/hostgaplugin/ext_conf-no_status_upload_blob.xml
@@ -0,0 +1,39 @@
+<?xml version="1.0" encoding="utf-8"?>
+<Extensions version="1.0.0.0" goalStateIncarnation="10"><GuestAgentExtension xmlns:i="http://www.w3.org/2001/XMLSchema-instance">
+  <GAFamilies>
+    <GAFamily>
+      <Name>Prod</Name>
+      <Uris>
+        <Uri>https://zrdfepirv2cdm03prdstr01a.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_uscentraleuap_manifest.xml</Uri>
+        <Uri>https://ardfepirv2cdm03prdstr01a.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_uscentraleuap_manifest.xml</Uri>
+      </Uris>
+    </GAFamily>
+  </GAFamilies>
+  <Location>CentralUSEUAP</Location>
+  <ServiceName>CRP</ServiceName>
+</GuestAgentExtension>
+<Plugins>
+  <Plugin name="Microsoft.Azure.Extensions.CustomScript" version="2.1.6" location="https://umsavwggj2v40kvqhc0w.blob.core.windows.net/5237dd14-0aad-f051-0fad-1e33e1b63091/5237dd14-0aad-f051-0fad-1e33e1b63091_manifest.xml" state="enabled" autoUpgrade="true" failoverlocation="https://umsafwzhkbm1rfrhl0ws.blob.core.windows.net/5237dd14-0aad-f051-0fad-1e33e1b63091/5237dd14-0aad-f051-0fad-1e33e1b63091_manifest.xml" runAsStartupTask="false" isJson="true" useExactVersion="true">
+    <additionalLocations>
+      <additionalLocation>https://umsanh4b5rfz0q0p4pwm.blob.core.windows.net/5237dd14-0aad-f051-0fad-1e33e1b63091/5237dd14-0aad-f051-0fad-1e33e1b63091_manifest.xml</additionalLocation>
+    </additionalLocations>
+  </Plugin>
+</Plugins>
+<PluginSettings>
+  <Plugin name="Microsoft.Azure.Extensions.CustomScript" version="2.1.6">
+    <DependsOn dependencyLevel="1">
+      <DependsOnExtension handler="Microsoft.Azure.Security.Monitoring.AzureSecurityLinuxAgent" />
+    </DependsOn>
+    <RuntimeSettings seqNo="0">{
+  "runtimeSettings": [
+    {
+      "handlerSettings": {
+        "publicSettings": {"commandToExecute":"echo 'cee174d4-4daa-4b07-9958-53b9649445c2'"}
+      }
+    }
+  ]
+}</RuntimeSettings>
+  </Plugin>
+</PluginSettings>
+<InVMArtifactsProfileBlob>https://dcrcl3a0xs.blob.core.windows.net/$system/edp0plkw2b.86f4ae0a-61f8-48ae-9199-40f402d56864.vmSettings?sv=2018-03-28&amp;sr=b&amp;sk=system-1&amp;sig=PaiLic%3d&amp;se=9999-01-01T00%3a00%3a00Z&amp;sp=r</InVMArtifactsProfileBlob>
+<InVMGoalStateMetaData inSvdSeqNo="10" createdOnTicks="637726657706205217" activityId="a33f6f53-43d6-4625-b322-1a39651a00c9" correlationId="9a47a2a2-e740-4bfc-b11b-4f2f7cfe7d2e" /></Extensions>
diff --git a/tests/data/hostgaplugin/vm_settings-no_status_upload_blob.json b/tests/data/hostgaplugin/vm_settings-no_status_upload_blob.json
new file mode 100644
index 00000000..c184454a
--- /dev/null
+++ b/tests/data/hostgaplugin/vm_settings-no_status_upload_blob.json
@@ -0,0 +1,65 @@
+{
+    "hostGAPluginVersion": "1.0.8.115",
+    "vmSettingsSchemaVersion": "0.0",
+    "activityId": "a33f6f53-43d6-4625-b322-1a39651a00c9",
+    "correlationId": "9a47a2a2-e740-4bfc-b11b-4f2f7cfe7d2e",
+    "extensionsLastModifiedTickCount": 637726657706205217,
+    "extensionGoalStatesSource": "Fabric",
+    "onHold": true,
+    "inVMMetadata": {
+        "subscriptionId": "8e037ad4-618f-4466-8bc8-5099d41ac15b",
+        "resourceGroupName": "rg-dc-86fjzhp",
+        "vmName": "edp0plkw2b",
+        "location": "CentralUSEUAP",
+        "vmId": "86f4ae0a-61f8-48ae-9199-40f402d56864",
+        "vmSize": "Standard_B2s",
+        "osType": "Linux"
+    },
+    "requiredFeatures": [
+        {
+            "name": "MultipleExtensionsPerHandler"
+        }
+    ],
+    "gaFamilies": [
+        {
+            "name": "Prod",
+            "uris": [
+                "https://zrdfepirv2cdm03prdstr01a.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_uscentraleuap_manifest.xml",
+                "https://ardfepirv2cdm03prdstr01a.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_uscentraleuap_manifest.xml"
+            ]
+        }
+    ],
+    "extensionGoalStates": [
+        {
+            "name": "Microsoft.Azure.Extensions.CustomScript",
+            "version": "2.1.6",
+            "location": "https://umsavwggj2v40kvqhc0w.blob.core.windows.net/5237dd14-0aad-f051-0fad-1e33e1b63091/5237dd14-0aad-f051-0fad-1e33e1b63091_manifest.xml",
+            "failoverlocation": "https://umsafwzhkbm1rfrhl0ws.blob.core.windows.net/5237dd14-0aad-f051-0fad-1e33e1b63091/5237dd14-0aad-f051-0fad-1e33e1b63091_manifest.xml",
+            "additionalLocations": [
+                "https://umsanh4b5rfz0q0p4pwm.blob.core.windows.net/5237dd14-0aad-f051-0fad-1e33e1b63091/5237dd14-0aad-f051-0fad-1e33e1b63091_manifest.xml"
+            ],
+            "state": "enabled",
+            "autoUpgrade": true,
+            "runAsStartupTask": false,
+            "isJson": true,
+            "useExactVersion": true,
+            "settingsSeqNo": 0,
+            "isMultiConfig": false,
+            "settings": [
+                {
+                    "publicSettings": "{\"commandToExecute\":\"echo 'cee174d4-4daa-4b07-9958-53b9649445c2'\"}"
+                }
+            ],
+            "dependsOn": [
+                {
+                    "DependsOnExtension": [
+                        {
+                            "handler": "Microsoft.Azure.Security.Monitoring.AzureSecurityLinuxAgent"
+                        }
+                    ],
+                    "dependencyLevel": 1
+                }
+            ]
+        }
+    ]
+}
diff --git a/tests/protocol/test_extensions_goal_state_from_extensions_config.py b/tests/protocol/test_extensions_goal_state_from_extensions_config.py
index d270f7ad..0fb1ef13 100644
--- a/tests/protocol/test_extensions_goal_state_from_extensions_config.py
+++ b/tests/protocol/test_extensions_goal_state_from_extensions_config.py
@@ -26,3 +26,13 @@ class ExtensionsGoalStateFromExtensionsConfigTestCase(AgentTestCase):
             self.assertEqual(AgentGlobals.GUID_ZERO, extensions_goal_state.activity_id, "Incorrect activity Id")
             self.assertEqual(AgentGlobals.GUID_ZERO, extensions_goal_state.correlation_id, "Incorrect correlation Id")
             self.assertEqual('1900-01-01T00:00:00.000000Z', extensions_goal_state.created_on_timestamp, "Incorrect GS Creation time")
+
+    def test_it_should_parse_missing_status_upload_blob_as_none(self):
+        data_file = mockwiredata.DATA_FILE_VM_SETTINGS.copy()
+        data_file["ext_conf"] = "hostgaplugin/ext_conf-no_status_upload_blob.xml"
+        with mock_wire_protocol(data_file) as protocol:
+            extensions_goal_state = protocol.get_extensions_goal_state()
+
+            self.assertIsNone(extensions_goal_state.status_upload_blob, "Expected status upload blob to be None")
+            self.assertEqual("BlockBlob", extensions_goal_state.status_upload_blob_type, "Expected status upload blob to be Block")
+
diff --git a/tests/protocol/test_extensions_goal_state_from_vm_settings.py b/tests/protocol/test_extensions_goal_state_from_vm_settings.py
index b8f4deb6..fe30eff0 100644
--- a/tests/protocol/test_extensions_goal_state_from_vm_settings.py
+++ b/tests/protocol/test_extensions_goal_state_from_vm_settings.py
@@ -47,6 +47,14 @@ class ExtensionsGoalStateFromVmSettingsTestCase(AgentTestCase):
         # dependency level (multi-config)
         self.assertEqual(1, vm_settings.extensions[3].settings[1].dependencyLevel, "Incorrect dependency level (multi-config)")
 
+    def test_create_from_vm_settings_should_parse_missing_status_upload_blob_as_none(self):
+        vm_settings_text = fileutil.read_file(os.path.join(data_dir, "hostgaplugin/vm_settings-no_status_upload_blob.json"))
+        vm_settings = ExtensionsGoalStateFactory.create_from_vm_settings("123", vm_settings_text)
+
+        self.assertIsNone(vm_settings.status_upload_blob, "Expected status upload blob to be None")
+        self.assertEqual("BlockBlob", vm_settings.status_upload_blob_type, "Expected status upload blob to be Block")
+
+
 class CaseFoldedDictionaryTestCase(AgentTestCase):
     def test_it_should_retrieve_items_ignoring_case(self):
         dictionary = json.loads('''{
diff --git a/tests/protocol/test_wire.py b/tests/protocol/test_wire.py
index e84ea2a6..48e6c9b4 100644
--- a/tests/protocol/test_wire.py
+++ b/tests/protocol/test_wire.py
@@ -1291,25 +1291,35 @@ class UpdateGoalStateTestCase(HttpRequestPredicates, AgentTestCase):
                 return None
             protocol.set_http_handlers(http_get_handler=http_get_handler)
 
+            def get_telemetry_messages():
+                return [kwargs["message"] for _, kwargs in add_event.call_args_list if kwargs["op"] == "VmSettings"]
+
+            def get_log_messages():
+                return [arg[0][0] for arg in logger_info.call_args_list   if "[VmSettings]" in arg[0][0]]
+
             with patch("azurelinuxagent.common.protocol.wire.add_event") as add_event:
-                for _ in range(_VmSettingsErrorReporter._MaxErrors + 3):
-                    protocol.client.update_goal_state()
+                with patch('azurelinuxagent.common.logger.info') as logger_info:
+                    for _ in range(_VmSettingsErrorReporter._MaxTelemetryErrors + 3):
+                        protocol.client.update_goal_state()
 
-                messages = [kwargs["message"] for _, kwargs in add_event.call_args_list if kwargs["op"] == "VmSettings"]
+                    telemetry_messages = get_telemetry_messages()
+                    self.assertEqual(_VmSettingsErrorReporter._MaxTelemetryErrors, len(telemetry_messages), "The number of errors reported to telemetry is not the max allowed (got: {0})".format(telemetry_messages))
 
-                self.assertEqual(_VmSettingsErrorReporter._MaxErrors, len(messages), "The number of errors reported is not the max allowed (got: {0})".format(messages))
+                    log_messages = get_log_messages()
+                    self.assertEqual(_VmSettingsErrorReporter._MaxLogErrors, len(log_messages), "The number of errors reported to the local log is not the max allowed (got: {0})".format(telemetry_messages))
 
             # Reset the error reporter and verify that additional errors are reported
             protocol.client._vm_settings_error_reporter._next_period = datetime.now()
             protocol.client.update_goal_state()  # this triggers the reset
 
             with patch("azurelinuxagent.common.protocol.wire.add_event") as add_event:
-                for _ in range(3):
-                    protocol.client.update_goal_state()
+                protocol.client.update_goal_state()
 
-                messages = [kwargs["message"] for _, kwargs in add_event.call_args_list if kwargs["op"] == "VmSettings"]
+                telemetry_messages = get_telemetry_messages()
+                self.assertEqual(1, len(telemetry_messages), "Expected additional errors to be reported to telemetry in the next period (got: {0})".format(telemetry_messages))
 
-                self.assertEqual(3, len(messages), "Expected additional errors to be reported in the next period (got: {0})".format(messages))
+                log_messages = get_log_messages()
+                self.assertEqual(1, len(log_messages), "Expected additional errors to be reported to the local log in the next period (got: {0})".format(telemetry_messages))
 
     def test_it_should_use_vm_settings_by_default(self):
         with mock_wire_protocol(mockwiredata.DATA_FILE_VM_SETTINGS) as protocol: