Improvements in telemetry for vmSettings (Azure#2482) (Azure#2485)

Co-authored-by: narrieta <narrieta>

azurelinuxagent/common/protocol/extensions_goal_state.py

@@ -127,10 +127,11 @@ def compare_extensions(first, second):
  compare_array(first.settings, second.settings, compare_settings, "settings")
 
  def compare_settings(first, second):
+ # Note that we do not compare protectedSettings since the same settings can be re-encrypted, resulting
+ # on different encrypted text for the same plain text.
  compare_attributes(first, second, "name")
  compare_attributes(first, second, "sequenceNumber")
  compare_attributes(first, second, "publicSettings")
- compare_attributes(first, second, "protectedSettings")
  compare_attributes(first, second, "certificateThumbprint")
  compare_attributes(first, second, "dependencyLevel")
  compare_attributes(first, second, "state")
@@ -157,7 +158,7 @@ def compare_attributes(first, second, attribute, ignore_order=False):
  second_value.sort()
 
  if first_value != second_value:
- if attribute.lower() in ('protectedsettings', 'publicsettings'):
+ if attribute.lower() == 'publicsettings':
  mistmatch = "[REDACTED] != [REDACTED] (Attribute: {0})".format(".".join(context))
  else:
  mistmatch = "[{0}] != [{1}] (Attribute: {2})".format(first_value, second_value, ".".join(context))

azurelinuxagent/common/protocol/extensions_goal_state_from_vm_settings.py

@@ -53,7 +53,7 @@ def __init__(self, etag, json_text):
  self._parse_vm_settings(json_text)
  self._do_common_validations()
  except Exception as e:
- raise VmSettingsError("Error parsing vmSettings (etag: {0}): {1}\n{2}".format(etag, format_exception(e), self.get_redacted_text()))
+ 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()))
 
  @property
  def id(self):
@@ -139,14 +139,16 @@ def _parse_simple_attributes(self, vm_settings):
  # "extensionGoalStatesSource": "Fabric",
  # ...
  # }
- self._activity_id = self._string_to_id(vm_settings.get("activityId"))
- self._correlation_id = self._string_to_id(vm_settings.get("correlationId"))
- self._created_on_timestamp = self._ticks_to_utc_timestamp(vm_settings.get("extensionsLastModifiedTickCount"))
 
+ # The HGAP version is included in some messages, so parse it first
  host_ga_plugin_version = vm_settings.get("hostGAPluginVersion")
  if host_ga_plugin_version is not None:
  self._host_ga_plugin_version = FlexibleVersion(host_ga_plugin_version)
 
+ self._activity_id = self._string_to_id(vm_settings.get("activityId"))
+ self._correlation_id = self._string_to_id(vm_settings.get("correlationId"))
+ self._created_on_timestamp = self._ticks_to_utc_timestamp(vm_settings.get("extensionsLastModifiedTickCount"))
+
  schema_version = vm_settings.get("vmSettingsSchemaVersion")
  if schema_version is not None:
  self._schema_version = FlexibleVersion(schema_version)

azurelinuxagent/common/protocol/wire.py

@@ -894,7 +894,7 @@ def raise_not_supported(reset_state=False):
  correlation_id = str(uuid.uuid4())
 
  def format_message(msg):
- return "GET vmSettings [correlation ID: {0} eTag: {1}]: {2}".format(correlation_id, etag, msg)
+ return "GET vmSettings [correlation ID: {0} eTag: {1} HGAP: {2}]: {3}".format(correlation_id, etag, self._host_plugin_version, msg)
 
  try:
  def get_vm_settings():

azurelinuxagent/ga/exthandlers.py

@@ -300,8 +300,9 @@ def run(self):
  try:
  extensions_goal_state = self.protocol.get_extensions_goal_state()
 
- # self.ext_handlers and etag need to be initialized first, since status reporting depends on them
- self.ext_handlers = extensions_goal_state.extensions
+ # self.ext_handlers and etag need to be initialized first, since status reporting depends on them; also
+ # we make a deep copy of the extensions, since changes are made to self.ext_handlers while processing the extensions
+ self.ext_handlers = copy.deepcopy(extensions_goal_state.extensions)
  etag = self.protocol.client.get_goal_state().incarnation
 
  if not self._extension_processing_allowed():

tests/protocol/test_extensions_goal_state.py

@@ -31,10 +31,7 @@ def test_compare_should_report_mismatches_between_extensions_config_and_vm_setti
  from_extensions_config = protocol.client.get_extensions_goal_state()
  from_vm_settings = protocol.client._cached_vm_settings
 
- mismatch_messages = {
- 'publicSettings': None,
- 'protectedSettings': None
- }
+ public_settings_mismatch = [""]
 
  def assert_compare_raises(setup_copy, failing_attribute):
  from_vm_settings_copy = copy.deepcopy(from_vm_settings)
@@ -43,9 +40,7 @@ def assert_compare_raises(setup_copy, failing_attribute):
  with self.assertRaisesRegexCM(GoalStateMismatchError, re.escape("(Attribute: {0})".format(failing_attribute)), re.DOTALL) as context_manager:
  ExtensionsGoalState.compare(from_extensions_config, from_vm_settings_copy)
  if context_manager.exception.attribute == 'publicSettings':
- mismatch_messages['publicSettings'] = str(context_manager.exception)
- elif context_manager.exception.attribute == 'protectedSettings':
- mismatch_messages['protectedSettings'] = str(context_manager.exception)
+ public_settings_mismatch[0] = str(context_manager.exception)
 
  assert_compare_raises(lambda c: setattr(c, "_activity_id", 'MOCK_ACTIVITY_ID'), "activity_id")
  assert_compare_raises(lambda c: setattr(c, "_correlation_id", 'MOCK_CORRELATION_ID'), "correlation_id")
@@ -64,19 +59,16 @@ def assert_compare_raises(setup_copy, failing_attribute):
  assert_compare_raises(lambda c: setattr(c.extensions[0], "manifest_uris", ['MOCK_URI']), r"extensions[0].manifest_uris")
  assert_compare_raises(lambda c: setattr(c.extensions[0], "supports_multi_config", True), r"extensions[0].supports_multi_config")
 
+ # NOTE: protectedSettings are not compared, so we skip them below
  assert_compare_raises(lambda c: setattr(c.extensions[0].settings[0], "name", 'MOCK_NAME'), r"extensions[0].settings[0].name")
  assert_compare_raises(lambda c: setattr(c.extensions[0].settings[0], "sequenceNumber", 98765), r"extensions[0].settings[0].sequenceNumber")
  assert_compare_raises(lambda c: setattr(c.extensions[0].settings[0], "publicSettings", {'MOCK_NAME': 'MOCK_VALUE'}), r"extensions[0].settings[0].publicSettings")
- assert_compare_raises(lambda c: setattr(c.extensions[0].settings[0], "protectedSettings", 'MOCK_SETTINGS'), r"extensions[0].settings[0].protectedSettings")
  assert_compare_raises(lambda c: setattr(c.extensions[0].settings[0], "certificateThumbprint", 'MOCK_CERT'), r"extensions[0].settings[0].certificateThumbprint")
  assert_compare_raises(lambda c: setattr(c.extensions[0].settings[0], "dependencyLevel", 56789), r"extensions[0].settings[0].dependencyLevel")
  assert_compare_raises(lambda c: setattr(c.extensions[0].settings[0], "state", 'MOCK_STATE'), r"extensions[0].settings[0].state")
 
  expected = r'^\[GoalStateMismatchError\] Mismatch in Goal States \[Incarnation 1\] != \[Etag: 1\]: \[REDACTED\] != \[REDACTED\] \(Attribute: .*\.publicSettings\)$'
- self.assertRegex(mismatch_messages['publicSettings'], expected, 'Expected the protected settings to be redacted. Got: "{0}"'.format(mismatch_messages['publicSettings']))
-
- expected = r'^\[GoalStateMismatchError\] Mismatch in Goal States \[Incarnation 1\] != \[Etag: 1\]: \[REDACTED\] != \[REDACTED\] \(Attribute: .*\.protectedSettings\)$'
- self.assertRegex(mismatch_messages['protectedSettings'], expected, 'Expected the protected settings to be redacted. Got: "{0}"'.format(mismatch_messages['protectedSettings']))
+ self.assertRegex(public_settings_mismatch[0], expected, 'Expected the protected settings to be redacted. Got: "{0}"'.format(public_settings_mismatch[0]))
 
  def test_create_from_extensions_config_should_assume_block_when_blob_type_is_not_valid(self):
  data_file = mockwiredata.DATA_FILE.copy()