Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Additional telemetry for goal state #2675

Merged
merged 3 commits into from
Sep 30, 2022
Merged
Changes from 2 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
35 changes: 25 additions & 10 deletions azurelinuxagent/common/protocol/goal_state.py
Original file line number Diff line number Diff line change
Expand Up @@ -192,7 +192,9 @@ def _update(self, force_update):
incarnation, xml_text, xml_doc = GoalState._fetch_goal_state(self._wire_client)
goal_state_updated = force_update or incarnation != self._incarnation
if goal_state_updated:
self.logger.info('Fetched a new incarnation for the WireServer goal state [incarnation {0}]', incarnation)
message = 'Fetched a new incarnation for the WireServer goal state [incarnation {0}]'.format(incarnation)
self.logger.info(message)
add_event(op=WALAEventOperation.GoalState, message=message)

vm_settings, vm_settings_updated = None, False
try:
Expand All @@ -203,11 +205,15 @@ def _update(self, force_update):

if vm_settings_updated:
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)
message = "Fetched new vmSettings [HostGAPlugin correlation ID: {0} eTag: {1} source: {2}]".format(vm_settings.hostga_plugin_correlation_id, vm_settings.etag, vm_settings.source)
self.logger.info(message)
add_event(op=WALAEventOperation.GoalState, message=message)
# 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:
self.logger.info("The vmSettings originated via Fabric; will ignore them.")
message = "The vmSettings originated via Fabric; will ignore them."
self.logger.info(message)
add_event(op=WALAEventOperation.GoalState, message=message)
vm_settings, vm_settings_updated = None, False

# If neither goal state has changed we are done with the update
Expand Down Expand Up @@ -265,7 +271,9 @@ def _check_certificates(self):
raise GoalStateInconsistentError(message)

def _restore_wire_server_goal_state(self, incarnation, xml_text, xml_doc, vm_settings_support_stopped_error):
self.logger.info('The HGAP stopped supporting vmSettings; will fetched the goal state from the WireServer.')
msg = 'The HGAP stopped supporting vmSettings; will fetched the goal state from the WireServer.'
self.logger.info(msg)
add_event(op=WALAEventOperation.VmSettings, message=msg)
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)
Expand All @@ -274,7 +282,7 @@ def _restore_wire_server_goal_state(self, incarnation, xml_text, xml_doc, vm_set
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)
self.logger.info(msg)
add_event(op=WALAEventOperation.VmSettings, message=msg, is_success=True)
add_event(op=WALAEventOperation.VmSettings, message=msg)

def save_to_history(self, data, file_name):
self._history.save(data, file_name)
Expand Down Expand Up @@ -351,7 +359,9 @@ def _fetch_full_wire_server_goal_state(self, incarnation, xml_doc):
"""
try:
self.logger.info('')
self.logger.info('Fetching full goal state from the WireServer [incarnation {0}]', incarnation)
message = 'Fetching full goal state from the WireServer [incarnation {0}]'.format(incarnation)
self.logger.info(message)
add_event(op=WALAEventOperation.GoalState, message=message)

role_instance = find(xml_doc, "RoleInstance")
role_instance_id = findtext(role_instance, "InstanceId")
Expand Down Expand Up @@ -391,9 +401,12 @@ def _fetch_full_wire_server_goal_state(self, incarnation, xml_doc):
certs = Certificates(xml_text, self.logger)
# 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:
self.logger.info("Downloaded certificate {0}".format(c))
message = "Downloaded certificate {0}".format(c)
self.logger.info(message)
add_event(op=WALAEventOperation.GoalState, message=message)
if len(certs.warnings) > 0:
self.logger.warn(certs.warnings)
add_event(op=WALAEventOperation.GoalState, message=certs.warnings)
self._history.save_certificates(json.dumps(certs.summary))

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do you think it's useful to add?

self.logger.info('Fetch goal state completed')

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I left that one out, but I can add it if you think it'd be useful. If the operation fails we would get telemetry for the ProtocolError, otherwise we can assume it completed successfully.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd add to avoid assumption. Especially it's useful for on callers or somebody who queries our data without knowing our code.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In general, the telemetry skips successful operations (when possible) and reports only errors, but I'll go ahead and add this one

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

added

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree. Since we are adding related information, I thought this would be useful to avoid confusion. Thanks for the change.

remote_access = None
Expand Down Expand Up @@ -455,9 +468,11 @@ def __init__(self, xml_text, my_logger):
return

# if the certificates format is not Pkcs7BlobWithPfxContents do not parse it
certificateFormat = findtext(xml_doc, "Format")
if certificateFormat and certificateFormat != "Pkcs7BlobWithPfxContents":
my_logger.warn("The Format is not Pkcs7BlobWithPfxContents. Format is " + certificateFormat)
certificate_format = findtext(xml_doc, "Format")
if certificate_format and certificate_format != "Pkcs7BlobWithPfxContents":
message = "The Format is not Pkcs7BlobWithPfxContents. Format is {0}".format(certificate_format)
my_logger.warn(message)
add_event(op=WALAEventOperation.GoalState, message=message)
return

cryptutil = CryptUtil(conf.get_openssl_cmd())
Expand Down