From 3c5bdc8fa801ec080b38df05b96e0da2481d9e5a Mon Sep 17 00:00:00 2001 From: dganesan Date: Wed, 14 Jul 2021 13:13:48 -0700 Subject: [PATCH 1/9] Created a helper function to format exceptions --- azurelinuxagent/agent.py | 5 ++-- azurelinuxagent/common/event.py | 2 +- .../common/persist_firewall_rules.py | 5 ++-- azurelinuxagent/common/protocol/wire.py | 5 ++-- azurelinuxagent/common/utils/restutil.py | 3 +-- azurelinuxagent/common/utils/textutil.py | 6 +++++ azurelinuxagent/daemon/main.py | 4 +-- .../ga/collect_telemetry_events.py | 6 ++--- azurelinuxagent/ga/exthandlers.py | 26 +++++++------------ azurelinuxagent/ga/remoteaccess.py | 4 +-- azurelinuxagent/ga/send_telemetry_events.py | 6 ++--- azurelinuxagent/ga/update.py | 11 ++++---- tests/common/osutil/test_default.py | 3 +-- tests/common/osutil/test_freebsd.py | 4 +-- 14 files changed, 41 insertions(+), 49 deletions(-) diff --git a/azurelinuxagent/agent.py b/azurelinuxagent/agent.py index eb880a95a3..f4d2d2f5fa 100644 --- a/azurelinuxagent/agent.py +++ b/azurelinuxagent/agent.py @@ -28,7 +28,6 @@ import subprocess import sys import threading -import traceback from azurelinuxagent.common import cgroupconfigurator, logcollector from azurelinuxagent.common.cgroupapi import SystemdCgroupsApi @@ -38,7 +37,7 @@ from azurelinuxagent.common.future import ustr from azurelinuxagent.common.logcollector import LogCollector, OUTPUT_RESULTS_FILE_PATH from azurelinuxagent.common.osutil import get_osutil -from azurelinuxagent.common.utils import fileutil +from azurelinuxagent.common.utils import fileutil, textutil from azurelinuxagent.common.utils.flexible_version import FlexibleVersion from azurelinuxagent.common.utils.networkutil import AddFirewallRules from azurelinuxagent.common.version import AGENT_NAME, AGENT_LONG_VERSION, AGENT_VERSION, \ @@ -301,7 +300,7 @@ def main(args=None): except Exception: logger.error(u"Failed to run '{0}': {1}", command, - traceback.format_exc()) + textutil.format_exception()) def parse_args(sys_args): diff --git a/azurelinuxagent/common/event.py b/azurelinuxagent/common/event.py index 1fe90214fc..4deec05a31 100644 --- a/azurelinuxagent/common/event.py +++ b/azurelinuxagent/common/event.py @@ -320,7 +320,7 @@ def report_dropped_events_error(count, errors, operation_name): def _update_errors_and_get_count(error_count, errors, error): error_count += 1 if len(errors) < CollectOrReportEventDebugInfo.__MAX_ERRORS_TO_REPORT: - errors.add("{0}: {1}".format(ustr(error), traceback.format_exc())) + errors.add("{0}: {1}".format(ustr(error), textutil.format_exception())) return error_count def update_unicode_error(self, unicode_err): diff --git a/azurelinuxagent/common/persist_firewall_rules.py b/azurelinuxagent/common/persist_firewall_rules.py index ac336cdaea..bbd7fd617c 100644 --- a/azurelinuxagent/common/persist_firewall_rules.py +++ b/azurelinuxagent/common/persist_firewall_rules.py @@ -17,14 +17,13 @@ # import os import sys -import traceback import azurelinuxagent.common.conf as conf from azurelinuxagent.common import logger from azurelinuxagent.common.event import add_event, WALAEventOperation from azurelinuxagent.common.future import ustr from azurelinuxagent.common.osutil import get_osutil, systemd -from azurelinuxagent.common.utils import shellutil, fileutil +from azurelinuxagent.common.utils import shellutil, fileutil, textutil from azurelinuxagent.common.utils.networkutil import AddFirewallRules from azurelinuxagent.common.utils.shellutil import CommandError @@ -277,7 +276,7 @@ def __log_network_setup_service_logs(self): logger.warn(msg) except Exception: msg = "Ran into unexpected error when getting logs for {0} service. Error: {1}".format( - self._network_setup_service_name, traceback.format_exc()) + self._network_setup_service_name, textutil.format_exception()) logger.warn(msg) # Log service status and logs if we can fetch them from journalctl and send it to Kusto, diff --git a/azurelinuxagent/common/protocol/wire.py b/azurelinuxagent/common/protocol/wire.py index 33645bf823..f97809b9e6 100644 --- a/azurelinuxagent/common/protocol/wire.py +++ b/azurelinuxagent/common/protocol/wire.py @@ -20,7 +20,6 @@ import os import random import time -import traceback import xml.sax.saxutils as saxutils from collections import defaultdict from datetime import datetime, timedelta @@ -808,7 +807,7 @@ def try_update_goal_state(self): self._last_try_update_goal_state_failed = True message = u"An error occurred while retrieving the goal state: {0}".format(ustr(e)) add_event(AGENT_NAME, op=WALAEventOperation.FetchGoalState, version=CURRENT_VERSION, is_success=False, message=message, log_event=False) - message = u"An error occurred while retrieving the goal state: {0}".format(ustr(traceback.format_exc())) + message = u"An error occurred while retrieving the goal state: {0}".format(textutil.format_exception()) logger.warn(message) 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)) @@ -1207,7 +1206,7 @@ def _send_event(provider_id, debug_info): events_per_provider[event.providerId] += 1 except Exception as error: - logger.warn("Unexpected error when generating Events: {0}, {1}", ustr(error), traceback.format_exc()) + logger.warn("Unexpected error when generating Events: {0}, {1}", ustr(error), textutil.format_exception()) # Send out all events left in buffer. for provider_id in list(buf.keys()): diff --git a/azurelinuxagent/common/utils/restutil.py b/azurelinuxagent/common/utils/restutil.py index 06dbde9197..d4562ff0f7 100644 --- a/azurelinuxagent/common/utils/restutil.py +++ b/azurelinuxagent/common/utils/restutil.py @@ -21,7 +21,6 @@ import re import threading import time -import traceback import socket import struct @@ -627,5 +626,5 @@ def read_response_error(resp): result = textutil.replace_non_ascii(result) except Exception: - logger.warn(traceback.format_exc()) + logger.warn(textutil.format_exception()) return result diff --git a/azurelinuxagent/common/utils/textutil.py b/azurelinuxagent/common/utils/textutil.py index 21d0adf66b..82a5c7a6ad 100644 --- a/azurelinuxagent/common/utils/textutil.py +++ b/azurelinuxagent/common/utils/textutil.py @@ -24,6 +24,7 @@ import string import struct import sys +import traceback import xml.dom.minidom as minidom import zlib @@ -430,3 +431,8 @@ def str_to_encoded_ustr(s, encoding='utf-8'): return ustr(s) # For Py2, explicitly convert the string to unicode with the specified encoding return ustr(s, encoding=encoding) + + +def format_exception(): + # Placeholder function to format exception message + return ustr(traceback.format_exc()) diff --git a/azurelinuxagent/daemon/main.py b/azurelinuxagent/daemon/main.py index 93ba9eb902..a8e98b2945 100644 --- a/azurelinuxagent/daemon/main.py +++ b/azurelinuxagent/daemon/main.py @@ -20,7 +20,6 @@ import os import sys import time -import traceback import azurelinuxagent.common.conf as conf import azurelinuxagent.common.logger as logger @@ -32,6 +31,7 @@ from azurelinuxagent.common.protocol.util import get_protocol_util from azurelinuxagent.common.protocol.wire import WireProtocol from azurelinuxagent.common.rdma import setup_rdma_device +from azurelinuxagent.common.utils import textutil from azurelinuxagent.common.version import AGENT_NAME, AGENT_LONG_NAME, \ AGENT_VERSION, \ DISTRO_NAME, DISTRO_VERSION, PY_VERSION_MAJOR, PY_VERSION_MINOR, \ @@ -82,7 +82,7 @@ def run(self, child_args=None): try: self.daemon(child_args) except Exception as e: # pylint: disable=W0612 - err_msg = traceback.format_exc() + err_msg = textutil.format_exception() add_event(name=AGENT_NAME, is_success=False, message=ustr(err_msg), op=WALAEventOperation.UnhandledError) logger.warn("Daemon ended with exception -- Sleep 15 seconds and restart daemon") diff --git a/azurelinuxagent/ga/collect_telemetry_events.py b/azurelinuxagent/ga/collect_telemetry_events.py index c3a17ca1f7..4e86f0a4b2 100644 --- a/azurelinuxagent/ga/collect_telemetry_events.py +++ b/azurelinuxagent/ga/collect_telemetry_events.py @@ -21,7 +21,6 @@ import os import re import threading -import traceback from collections import defaultdict import azurelinuxagent.common.logger as logger @@ -35,6 +34,7 @@ from azurelinuxagent.common.interfaces import ThreadHandlerInterface from azurelinuxagent.common.telemetryevent import TelemetryEvent, TelemetryEventParam, \ GuestAgentGenericLogsSchema, GuestAgentExtensionEventsSchema +from azurelinuxagent.common.utils import textutil from azurelinuxagent.ga.exthandlers import HANDLER_NAME_PATTERN from azurelinuxagent.ga.periodic_operation import PeriodicOperation @@ -117,7 +117,7 @@ def _operation(self): delete_all_event_files = False except Exception as error: msg = "Unknown error occurred when trying to collect extension events. Error: {0}, Stack: {1}".format( - ustr(error), traceback.format_exc()) + ustr(error), textutil.format_exception()) add_event(op=WALAEventOperation.ExtensionTelemetryEventProcessing, message=msg, is_success=False) finally: # Always ensure that the events directory are being deleted each run except when Telemetry Service is stopped, @@ -205,7 +205,7 @@ def _capture_extension_events(self, handler_name, handler_event_dir_path): raise except Exception as error: msg = "Failed to process event file {0}: {1}, {2}".format(event_file, ustr(error), - traceback.format_exc()) + textutil.format_exception()) logger.warn(msg) add_log_event(level=logger.LogLevel.WARNING, message=msg, forced=True) finally: diff --git a/azurelinuxagent/ga/exthandlers.py b/azurelinuxagent/ga/exthandlers.py index ebd5676757..4ec7665cdd 100644 --- a/azurelinuxagent/ga/exthandlers.py +++ b/azurelinuxagent/ga/exthandlers.py @@ -27,7 +27,6 @@ import sys import tempfile import time -import traceback import zipfile from collections import defaultdict from functools import partial @@ -49,6 +48,7 @@ from azurelinuxagent.common.future import ustr, is_file_not_found_error from azurelinuxagent.common.protocol.restapi import ExtensionStatus, ExtensionSubStatus, ExtHandler, ExtHandlerStatus, \ VMStatus, GoalStateAggregateStatus, ExtensionState, ExtHandlerRequestedState, Extension +from azurelinuxagent.common.utils import textutil from azurelinuxagent.common.utils.archive import ARCHIVE_DIRECTORY_NAME from azurelinuxagent.common.utils.flexible_version import FlexibleVersion from azurelinuxagent.common.version import AGENT_NAME, CURRENT_VERSION, \ @@ -114,14 +114,6 @@ class ExtCommandEnvVariable(object): ExtensionSupportedFeatures = "{0}_EXTENSION_SUPPORTED_FEATURES".format(Prefix) -def get_traceback(e): # pylint: disable=R1710 - if sys.version_info[0] == 3: # pylint: disable=R1705 - return e.__traceback__ - elif sys.version_info[0] == 2: - ex_type, ex, tb = sys.exc_info() # pylint: disable=W0612 - return tb - - def validate_has_key(obj, key, full_key_path): if key not in obj: raise ExtensionStatusError(msg="Invalid status format by extension: Missing {0} key".format(full_key_path), @@ -332,7 +324,7 @@ def run(self): activity_id, correlation_id, gs_creation_time = self.get_goal_state_debug_metadata() except Exception as error: - msg = u"ProcessExtensionsInGoalState - Exception processing extension handlers: {0}\n{1}".format(ustr(error), traceback.extract_tb(get_traceback(error))) + msg = u"ProcessExtensionsInGoalState - Exception processing extension handlers: {0}\n{1}".format(ustr(error), textutil.format_exception()) logger.warn(msg) add_event(op=WALAEventOperation.ExtensionProcessing, is_success=False, message=msg, log_event=False) return @@ -352,7 +344,7 @@ def goal_state_debug_info(duration=None): self.__process_and_handle_extensions(etag) self._cleanup_outdated_handlers() except Exception as error: - error = u"ProcessExtensionsInGoalState - Exception processing extension handlers: {0}\n{1}".format(ustr(error), traceback.extract_tb(get_traceback(error))) + error = u"ProcessExtensionsInGoalState - Exception processing extension handlers: {0}\n{1}".format(ustr(error), textutil.format_exception()) finally: duration = elapsed_milliseconds(utc_start) if error is None: @@ -389,7 +381,7 @@ def __process_and_handle_extensions(self, etag): code=GoalStateAggregateStatusCodes.Success, message="GoalState executed successfully") except Exception as error: - msg = "Unexpected error when processing goal state: {0}; {1}".format(ustr(error), traceback.format_exc()) + msg = "Unexpected error when processing goal state: {0}; {1}".format(ustr(error), textutil.format_exception()) self.__gs_aggregate_status = GoalStateAggregateStatus(status=GoalStateStatus.Failed, seq_no=etag, code=GoalStateAggregateStatusCodes.GoalStateUnknownFailure, message=msg) @@ -588,7 +580,7 @@ def wait_for_handler_completion(handler_i, wait_until, extension=None): except Exception: msg = "Failed to wait for Handler completion due to unknown error. Marking the dependent extension as failed: {0}, {1}".format( - extension_name, traceback.format_exc()) + extension_name, textutil.format_exception()) raise Exception(msg) # In case of timeout or terminal error state, we log it and raise @@ -970,7 +962,7 @@ def report_ext_handlers_status(self, incarnation_changed=False): self.write_ext_handlers_status_to_info_file(vm_status) except Exception as error: - msg = u"Failed to report status: {0}\n{1}".format(ustr(error), traceback.extract_tb(get_traceback(error))) + msg = u"Failed to report status: {0}\n{1}".format(ustr(error), textutil.format_exception()) logger.warn(msg) add_event(AGENT_NAME, version=CURRENT_VERSION, @@ -1793,7 +1785,7 @@ def get_extension_handler_statuses(self, handler_status, incarnation_changed): self.get_extension_full_name(), ustr(error)) self.report_error_on_incarnation_change(incarnation_changed, event_msg=msg, log_msg="{0}.\nStack Trace: {1}".format( - msg, traceback.format_exc())) + msg, textutil.format_exception())) # Since this is a Handler level error and we need to do it per extension, breaking here and logging # error since we wont be able to report error anyways and saving it as a handler status (legacy behavior) self.set_handler_status(message=msg, code=-1) @@ -1811,7 +1803,7 @@ def get_extension_handler_statuses(self, handler_status, incarnation_changed): self.get_extension_full_name(ext), ustr(error)) self.report_error_on_incarnation_change(incarnation_changed, event_msg=msg, log_msg="{0}.\nStack Trace: {1}".format( - msg, traceback.format_exc()), + msg, textutil.format_exception()), extension=ext) # Unexpected error, for single config, keep the behavior as is @@ -2086,7 +2078,7 @@ def set_handler_status(self, status="NotReady", message="", code=0): self.ext_handler.name, self.ext_handler.properties.version)) except (IOError, ValueError, ProtocolError) as error: fileutil.clean_ioerror(error, paths=[status_file]) - self.logger.error("Failed to save handler status: {0}, {1}", ustr(error), traceback.format_exc()) + self.logger.error("Failed to save handler status: {0}, {1}", ustr(error), textutil.format_exception()) def get_handler_status(self): state_dir = self.get_conf_dir() diff --git a/azurelinuxagent/ga/remoteaccess.py b/azurelinuxagent/ga/remoteaccess.py index f12fd0d49c..3b74b220cb 100644 --- a/azurelinuxagent/ga/remoteaccess.py +++ b/azurelinuxagent/ga/remoteaccess.py @@ -19,7 +19,6 @@ import os import os.path -import traceback from datetime import datetime, timedelta import azurelinuxagent.common.conf as conf @@ -27,6 +26,7 @@ from azurelinuxagent.common.event import add_event, WALAEventOperation from azurelinuxagent.common.future import ustr from azurelinuxagent.common.osutil import get_osutil +from azurelinuxagent.common.utils import textutil from azurelinuxagent.common.utils.cryptutil import CryptUtil from azurelinuxagent.common.version import AGENT_NAME, CURRENT_VERSION @@ -57,7 +57,7 @@ def run(self): self._remote_access = self._protocol.client.get_remote_access() self._handle_remote_access() except Exception as e: - msg = u"Exception processing goal state for remote access users: {0} {1}".format(ustr(e), traceback.format_exc()) + msg = u"Exception processing goal state for remote access users: {0} {1}".format(ustr(e), textutil.format_exception()) add_event(AGENT_NAME, version=CURRENT_VERSION, op=WALAEventOperation.RemoteAccessHandling, diff --git a/azurelinuxagent/ga/send_telemetry_events.py b/azurelinuxagent/ga/send_telemetry_events.py index 0f52686c5f..71f326ada3 100644 --- a/azurelinuxagent/ga/send_telemetry_events.py +++ b/azurelinuxagent/ga/send_telemetry_events.py @@ -19,13 +19,13 @@ import datetime import threading import time -import traceback from azurelinuxagent.common import logger from azurelinuxagent.common.event import add_event, WALAEventOperation from azurelinuxagent.common.exception import ServiceStoppedError from azurelinuxagent.common.future import ustr, Queue, Empty from azurelinuxagent.common.interfaces import ThreadHandlerInterface +from azurelinuxagent.common.utils import textutil def get_send_telemetry_events_handler(protocol_util): @@ -136,7 +136,7 @@ def _process_telemetry_thread(self): except Exception as error: err_msg = "An unknown error occurred in the {0} thread main loop, stopping thread. Error: {1}, Stack: {2}".format( - self.get_thread_name(), ustr(error), traceback.format_exc()) + self.get_thread_name(), ustr(error), textutil.format_exception()) add_event(op=WALAEventOperation.UnhandledError, message=err_msg, is_success=False) def _send_events_in_queue(self, first_event): @@ -162,4 +162,4 @@ def _get_events_in_queue(self, first_event): yield event except Exception as error: logger.error("Some exception when fetching event from queue: {0}, {1}".format(ustr(error), - traceback.format_exc())) \ No newline at end of file + textutil.format_exception())) \ No newline at end of file diff --git a/azurelinuxagent/ga/update.py b/azurelinuxagent/ga/update.py index c656388d24..8c737f708d 100644 --- a/azurelinuxagent/ga/update.py +++ b/azurelinuxagent/ga/update.py @@ -27,7 +27,6 @@ import subprocess import sys import time -import traceback import uuid import zipfile @@ -57,7 +56,7 @@ from azurelinuxagent.ga.env import get_env_handler from azurelinuxagent.ga.collect_telemetry_events import get_collect_telemetry_events_handler -from azurelinuxagent.ga.exthandlers import HandlerManifest, get_traceback, ExtHandlersHandler, list_agent_lib_directory +from azurelinuxagent.ga.exthandlers import HandlerManifest, ExtHandlersHandler, list_agent_lib_directory from azurelinuxagent.ga.monitor import get_monitor_handler from azurelinuxagent.ga.send_telemetry_events import get_send_telemetry_events_handler @@ -233,7 +232,7 @@ def run_latest(self, child_args=None): agent_cmd, ustr(e)) logger.warn(msg) - detailed_message = '{0} {1}'.format(msg, traceback.format_exc()) + detailed_message = '{0} {1}'.format(msg, textutil.format_exception()) add_event( AGENT_NAME, version=agent_version, @@ -332,7 +331,7 @@ def run(self, debug=False): msg = u"Agent {0} failed with exception: {1}".format(CURRENT_AGENT, ustr(error)) self._set_sentinel(msg=msg) logger.warn(msg) - logger.warn(traceback.format_exc()) + logger.warn(textutil.format_exception()) sys.exit(1) # additional return here because sys.exit is mocked in unit tests return @@ -743,7 +742,7 @@ def _upgrade_available(self, protocol, base_version=CURRENT_VERSION): or (len(self.agents) > 0 and self.agents[0].version > base_version) except Exception as e: # pylint: disable=W0612 - msg = u"Exception retrieving agent manifests: {0}".format(ustr(traceback.format_exc())) + msg = u"Exception retrieving agent manifests: {0}".format(textutil.format_exception()) add_event(AGENT_NAME, op=WALAEventOperation.Download, version=CURRENT_VERSION, is_success=False, message=msg) return False @@ -901,7 +900,7 @@ def __init__(self, path=None, pkg=None, host=None): msg = u"Agent {0} install failed with exception: {1}".format( self.name, ustr(e)) - detailed_msg = '{0} {1}'.format(msg, traceback.extract_tb(get_traceback(e))) + detailed_msg = '{0} {1}'.format(msg, textutil.format_exception()) add_event( AGENT_NAME, version=self.version, diff --git a/tests/common/osutil/test_default.py b/tests/common/osutil/test_default.py index 65d7ae0f75..414fc9327e 100644 --- a/tests/common/osutil/test_default.py +++ b/tests/common/osutil/test_default.py @@ -20,7 +20,6 @@ import socket import subprocess import tempfile -import traceback import unittest import mock @@ -296,7 +295,7 @@ def test_no_primary_does_not_throw(self): try: osutil.DefaultOSUtil().get_first_if()[0] except Exception as e: # pylint: disable=unused-variable - print(traceback.format_exc()) + print(textutil.format_exception()) exception = True self.assertFalse(exception) diff --git a/tests/common/osutil/test_freebsd.py b/tests/common/osutil/test_freebsd.py index 0be36a482d..912ebef81f 100644 --- a/tests/common/osutil/test_freebsd.py +++ b/tests/common/osutil/test_freebsd.py @@ -15,11 +15,11 @@ # Requires Python 2.6+ and Openssl 1.0+ # -import traceback import unittest import azurelinuxagent.common.utils.shellutil as shellutil from azurelinuxagent.common.osutil.freebsd import FreeBSDOSUtil +from azurelinuxagent.common.utils import textutil from tests.tools import AgentTestCase, patch from .test_default import osutil_get_dhcp_pid_should_return_a_list_of_pids @@ -120,7 +120,7 @@ def test_no_primary_does_not_throw(self): try: freebsdosutil.get_first_if()[0] except Exception as e: # pylint: disable=unused-variable - print(traceback.format_exc()) + print(textutil.format_exception()) exception = True # pylint: disable=unused-variable if __name__ == '__main__': From d8890fcb183f7f146383017ff2582e0fd2d1fe29 Mon Sep 17 00:00:00 2001 From: dganesan Date: Wed, 14 Jul 2021 13:38:46 -0700 Subject: [PATCH 2/9] Fixed Pylint error --- azurelinuxagent/ga/exthandlers.py | 1 - 1 file changed, 1 deletion(-) diff --git a/azurelinuxagent/ga/exthandlers.py b/azurelinuxagent/ga/exthandlers.py index 4ec7665cdd..f68f480a93 100644 --- a/azurelinuxagent/ga/exthandlers.py +++ b/azurelinuxagent/ga/exthandlers.py @@ -24,7 +24,6 @@ import re import shutil import stat -import sys import tempfile import time import zipfile From 06ef0a76c1e0bc185eeb8bfabf78d856077332dd Mon Sep 17 00:00:00 2001 From: dganesan Date: Fri, 16 Jul 2021 11:08:36 -0700 Subject: [PATCH 3/9] Updated the format_exception function to accept exception as a parameter --- azurelinuxagent/agent.py | 4 ++-- azurelinuxagent/common/event.py | 3 ++- .../common/persist_firewall_rules.py | 4 ++-- azurelinuxagent/common/protocol/wire.py | 4 ++-- azurelinuxagent/common/utils/restutil.py | 4 ++-- azurelinuxagent/common/utils/textutil.py | 16 +++++++++++++-- azurelinuxagent/daemon/main.py | 2 +- .../ga/collect_telemetry_events.py | 4 ++-- azurelinuxagent/ga/exthandlers.py | 20 ++++++++++--------- azurelinuxagent/ga/remoteaccess.py | 2 +- azurelinuxagent/ga/send_telemetry_events.py | 4 ++-- azurelinuxagent/ga/update.py | 8 ++++---- tests/common/osutil/test_default.py | 2 +- tests/common/osutil/test_freebsd.py | 2 +- 14 files changed, 47 insertions(+), 32 deletions(-) diff --git a/azurelinuxagent/agent.py b/azurelinuxagent/agent.py index f4d2d2f5fa..e9b806ff9c 100644 --- a/azurelinuxagent/agent.py +++ b/azurelinuxagent/agent.py @@ -297,10 +297,10 @@ def main(args=None): agent.collect_logs(log_collector_full_mode) elif command == AgentCommands.SetupFirewall: agent.setup_firewall(firewall_metadata) - except Exception: + except Exception as e: logger.error(u"Failed to run '{0}': {1}", command, - textutil.format_exception()) + textutil.format_exception(e)) def parse_args(sys_args): diff --git a/azurelinuxagent/common/event.py b/azurelinuxagent/common/event.py index 4deec05a31..764adba50b 100644 --- a/azurelinuxagent/common/event.py +++ b/azurelinuxagent/common/event.py @@ -320,7 +320,7 @@ def report_dropped_events_error(count, errors, operation_name): def _update_errors_and_get_count(error_count, errors, error): error_count += 1 if len(errors) < CollectOrReportEventDebugInfo.__MAX_ERRORS_TO_REPORT: - errors.add("{0}: {1}".format(ustr(error), textutil.format_exception())) + errors.add("{0}: {1}".format(ustr(error), traceback.format_exc())) return error_count def update_unicode_error(self, unicode_err): @@ -491,6 +491,7 @@ def add_event(self, name, op=WALAEventOperation.Unknown, is_success=True, durati self.add_common_event_parameters(event, datetime.utcnow()) data = get_properties(event) + logger.warn(json.dumps(data)) try: self.save_event(json.dumps(data)) except EventError as e: diff --git a/azurelinuxagent/common/persist_firewall_rules.py b/azurelinuxagent/common/persist_firewall_rules.py index bbd7fd617c..bd143454ab 100644 --- a/azurelinuxagent/common/persist_firewall_rules.py +++ b/azurelinuxagent/common/persist_firewall_rules.py @@ -274,9 +274,9 @@ def __log_network_setup_service_logs(self): msg = "Unable to fetch service logs, Command: {0} failed with ExitCode: {1}\nStdout: {2}\nStderr: {3}".format( ' '.join(cmd), error.returncode, error.stdout, error.stderr) logger.warn(msg) - except Exception: + except Exception as e: msg = "Ran into unexpected error when getting logs for {0} service. Error: {1}".format( - self._network_setup_service_name, textutil.format_exception()) + self._network_setup_service_name, textutil.format_exception(e)) logger.warn(msg) # Log service status and logs if we can fetch them from journalctl and send it to Kusto, diff --git a/azurelinuxagent/common/protocol/wire.py b/azurelinuxagent/common/protocol/wire.py index f97809b9e6..d05796369c 100644 --- a/azurelinuxagent/common/protocol/wire.py +++ b/azurelinuxagent/common/protocol/wire.py @@ -807,7 +807,7 @@ def try_update_goal_state(self): self._last_try_update_goal_state_failed = True message = u"An error occurred while retrieving the goal state: {0}".format(ustr(e)) add_event(AGENT_NAME, op=WALAEventOperation.FetchGoalState, version=CURRENT_VERSION, is_success=False, message=message, log_event=False) - message = u"An error occurred while retrieving the goal state: {0}".format(textutil.format_exception()) + message = u"An error occurred while retrieving the goal state: {0}".format(textutil.format_exception(e)) logger.warn(message) 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)) @@ -1206,7 +1206,7 @@ def _send_event(provider_id, debug_info): events_per_provider[event.providerId] += 1 except Exception as error: - logger.warn("Unexpected error when generating Events: {0}, {1}", ustr(error), textutil.format_exception()) + logger.warn("Unexpected error when generating Events: {0}, {1}", ustr(error), textutil.format_exception(error)) # Send out all events left in buffer. for provider_id in list(buf.keys()): diff --git a/azurelinuxagent/common/utils/restutil.py b/azurelinuxagent/common/utils/restutil.py index d4562ff0f7..71ffab5b9c 100644 --- a/azurelinuxagent/common/utils/restutil.py +++ b/azurelinuxagent/common/utils/restutil.py @@ -625,6 +625,6 @@ def read_response_error(resp): result = textutil.replace_non_ascii(result) - except Exception: - logger.warn(textutil.format_exception()) + except Exception as e: + logger.warn(textutil.format_exception(e)) return result diff --git a/azurelinuxagent/common/utils/textutil.py b/azurelinuxagent/common/utils/textutil.py index 82a5c7a6ad..a4a80ea697 100644 --- a/azurelinuxagent/common/utils/textutil.py +++ b/azurelinuxagent/common/utils/textutil.py @@ -433,6 +433,18 @@ def str_to_encoded_ustr(s, encoding='utf-8'): return ustr(s, encoding=encoding) -def format_exception(): +def format_exception(exception): # Placeholder function to format exception message - return ustr(traceback.format_exc()) + msg = ''.join(traceback.format_exception(etype=type(exception), value=exception, tb=get_traceback(exception))) + if sys.version_info[0] == 2: + msg = "{0}{1}".format("Traceback might not work as expected because the agent is running on Python 2\n", msg) + return ustr(msg) + + +def get_traceback(e): # pylint: disable=R1710 + if sys.version_info[0] == 3: # pylint: disable=R1705 + return e.__traceback__ + elif sys.version_info[0] == 2: + ex_type, ex, tb = sys.exc_info() # pylint: disable=W0612 + return tb + diff --git a/azurelinuxagent/daemon/main.py b/azurelinuxagent/daemon/main.py index a8e98b2945..bc97b440f8 100644 --- a/azurelinuxagent/daemon/main.py +++ b/azurelinuxagent/daemon/main.py @@ -82,7 +82,7 @@ def run(self, child_args=None): try: self.daemon(child_args) except Exception as e: # pylint: disable=W0612 - err_msg = textutil.format_exception() + err_msg = textutil.format_exception(e) add_event(name=AGENT_NAME, is_success=False, message=ustr(err_msg), op=WALAEventOperation.UnhandledError) logger.warn("Daemon ended with exception -- Sleep 15 seconds and restart daemon") diff --git a/azurelinuxagent/ga/collect_telemetry_events.py b/azurelinuxagent/ga/collect_telemetry_events.py index 4e86f0a4b2..527cfc480b 100644 --- a/azurelinuxagent/ga/collect_telemetry_events.py +++ b/azurelinuxagent/ga/collect_telemetry_events.py @@ -117,7 +117,7 @@ def _operation(self): delete_all_event_files = False except Exception as error: msg = "Unknown error occurred when trying to collect extension events. Error: {0}, Stack: {1}".format( - ustr(error), textutil.format_exception()) + ustr(error), textutil.format_exception(error)) add_event(op=WALAEventOperation.ExtensionTelemetryEventProcessing, message=msg, is_success=False) finally: # Always ensure that the events directory are being deleted each run except when Telemetry Service is stopped, @@ -205,7 +205,7 @@ def _capture_extension_events(self, handler_name, handler_event_dir_path): raise except Exception as error: msg = "Failed to process event file {0}: {1}, {2}".format(event_file, ustr(error), - textutil.format_exception()) + textutil.format_exception(error)) logger.warn(msg) add_log_event(level=logger.LogLevel.WARNING, message=msg, forced=True) finally: diff --git a/azurelinuxagent/ga/exthandlers.py b/azurelinuxagent/ga/exthandlers.py index e1f19a0213..d2bb1bf298 100644 --- a/azurelinuxagent/ga/exthandlers.py +++ b/azurelinuxagent/ga/exthandlers.py @@ -24,8 +24,10 @@ import re import shutil import stat +import sys import tempfile import time +import traceback import zipfile from collections import defaultdict from functools import partial @@ -322,7 +324,7 @@ def run(self): activity_id, correlation_id, gs_creation_time = self.get_goal_state_debug_metadata() except Exception as error: - msg = u"ProcessExtensionsInGoalState - Exception processing extension handlers: {0}\n{1}".format(ustr(error), textutil.format_exception()) + msg = u"ProcessExtensionsInGoalState - Exception processing extension handlers: {0}\n{1}".format(ustr(error), textutil.format_exception(error)) logger.warn(msg) add_event(op=WALAEventOperation.ExtensionProcessing, is_success=False, message=msg, log_event=False) return @@ -342,7 +344,7 @@ def goal_state_debug_info(duration=None): self.__process_and_handle_extensions(etag) self._cleanup_outdated_handlers() except Exception as error: - error = u"ProcessExtensionsInGoalState - Exception processing extension handlers: {0}\n{1}".format(ustr(error), textutil.format_exception()) + error = u"ProcessExtensionsInGoalState - Exception processing extension handlers: {0}\n{1}".format(ustr(error), textutil.format_exception(error)) finally: duration = elapsed_milliseconds(utc_start) if error is None: @@ -379,7 +381,7 @@ def __process_and_handle_extensions(self, etag): code=GoalStateAggregateStatusCodes.Success, message="GoalState executed successfully") except Exception as error: - msg = "Unexpected error when processing goal state: {0}; {1}".format(ustr(error), textutil.format_exception()) + msg = "Unexpected error when processing goal state: {0}; {1}".format(ustr(error), textutil.format_exception(error)) self.__gs_aggregate_status = GoalStateAggregateStatus(status=GoalStateStatus.Failed, seq_no=etag, code=GoalStateAggregateStatusCodes.GoalStateUnknownFailure, message=msg) @@ -576,9 +578,9 @@ def wait_for_handler_completion(handler_i, wait_until, extension=None): break time.sleep(5) - except Exception: + except Exception as e: msg = "Failed to wait for Handler completion due to unknown error. Marking the dependent extension as failed: {0}, {1}".format( - extension_name, textutil.format_exception()) + extension_name, textutil.format_exception(e)) raise Exception(msg) # In case of timeout or terminal error state, we log it and raise @@ -960,7 +962,7 @@ def report_ext_handlers_status(self, incarnation_changed=False): self.write_ext_handlers_status_to_info_file(vm_status) except Exception as error: - msg = u"Failed to report status: {0}\n{1}".format(ustr(error), textutil.format_exception()) + msg = u"Failed to report status: {0}\n{1}".format(ustr(error), textutil.format_exception(error)) logger.warn(msg) add_event(AGENT_NAME, version=CURRENT_VERSION, @@ -1783,7 +1785,7 @@ def get_extension_handler_statuses(self, handler_status, incarnation_changed): self.get_extension_full_name(), ustr(error)) self.report_error_on_incarnation_change(incarnation_changed, event_msg=msg, log_msg="{0}.\nStack Trace: {1}".format( - msg, textutil.format_exception())) + msg, textutil.format_exception(error))) # Since this is a Handler level error and we need to do it per extension, breaking here and logging # error since we wont be able to report error anyways and saving it as a handler status (legacy behavior) self.set_handler_status(message=msg, code=-1) @@ -1801,7 +1803,7 @@ def get_extension_handler_statuses(self, handler_status, incarnation_changed): self.get_extension_full_name(ext), ustr(error)) self.report_error_on_incarnation_change(incarnation_changed, event_msg=msg, log_msg="{0}.\nStack Trace: {1}".format( - msg, textutil.format_exception()), + msg, textutil.format_exception(error)), extension=ext) # Unexpected error, for single config, keep the behavior as is @@ -2076,7 +2078,7 @@ def set_handler_status(self, status="NotReady", message="", code=0): self.ext_handler.name, self.ext_handler.properties.version)) except (IOError, ValueError, ProtocolError) as error: fileutil.clean_ioerror(error, paths=[status_file]) - self.logger.error("Failed to save handler status: {0}, {1}", ustr(error), textutil.format_exception()) + self.logger.error("Failed to save handler status: {0}, {1}", ustr(error), textutil.format_exception(error)) def get_handler_status(self): state_dir = self.get_conf_dir() diff --git a/azurelinuxagent/ga/remoteaccess.py b/azurelinuxagent/ga/remoteaccess.py index 3b74b220cb..2488b6c7b3 100644 --- a/azurelinuxagent/ga/remoteaccess.py +++ b/azurelinuxagent/ga/remoteaccess.py @@ -57,7 +57,7 @@ def run(self): self._remote_access = self._protocol.client.get_remote_access() self._handle_remote_access() except Exception as e: - msg = u"Exception processing goal state for remote access users: {0} {1}".format(ustr(e), textutil.format_exception()) + msg = u"Exception processing goal state for remote access users: {0} {1}".format(ustr(e), textutil.format_exception(e)) add_event(AGENT_NAME, version=CURRENT_VERSION, op=WALAEventOperation.RemoteAccessHandling, diff --git a/azurelinuxagent/ga/send_telemetry_events.py b/azurelinuxagent/ga/send_telemetry_events.py index 71f326ada3..59809997c5 100644 --- a/azurelinuxagent/ga/send_telemetry_events.py +++ b/azurelinuxagent/ga/send_telemetry_events.py @@ -136,7 +136,7 @@ def _process_telemetry_thread(self): except Exception as error: err_msg = "An unknown error occurred in the {0} thread main loop, stopping thread. Error: {1}, Stack: {2}".format( - self.get_thread_name(), ustr(error), textutil.format_exception()) + self.get_thread_name(), ustr(error), textutil.format_exception(error)) add_event(op=WALAEventOperation.UnhandledError, message=err_msg, is_success=False) def _send_events_in_queue(self, first_event): @@ -162,4 +162,4 @@ def _get_events_in_queue(self, first_event): yield event except Exception as error: logger.error("Some exception when fetching event from queue: {0}, {1}".format(ustr(error), - textutil.format_exception())) \ No newline at end of file + textutil.format_exception(error))) \ No newline at end of file diff --git a/azurelinuxagent/ga/update.py b/azurelinuxagent/ga/update.py index 8c737f708d..d59c62e5fd 100644 --- a/azurelinuxagent/ga/update.py +++ b/azurelinuxagent/ga/update.py @@ -232,7 +232,7 @@ def run_latest(self, child_args=None): agent_cmd, ustr(e)) logger.warn(msg) - detailed_message = '{0} {1}'.format(msg, textutil.format_exception()) + detailed_message = '{0} {1}'.format(msg, textutil.format_exception(e)) add_event( AGENT_NAME, version=agent_version, @@ -331,7 +331,7 @@ def run(self, debug=False): msg = u"Agent {0} failed with exception: {1}".format(CURRENT_AGENT, ustr(error)) self._set_sentinel(msg=msg) logger.warn(msg) - logger.warn(textutil.format_exception()) + logger.warn(textutil.format_exception(error)) sys.exit(1) # additional return here because sys.exit is mocked in unit tests return @@ -742,7 +742,7 @@ def _upgrade_available(self, protocol, base_version=CURRENT_VERSION): or (len(self.agents) > 0 and self.agents[0].version > base_version) except Exception as e: # pylint: disable=W0612 - msg = u"Exception retrieving agent manifests: {0}".format(textutil.format_exception()) + msg = u"Exception retrieving agent manifests: {0}".format(textutil.format_exception(e)) add_event(AGENT_NAME, op=WALAEventOperation.Download, version=CURRENT_VERSION, is_success=False, message=msg) return False @@ -900,7 +900,7 @@ def __init__(self, path=None, pkg=None, host=None): msg = u"Agent {0} install failed with exception: {1}".format( self.name, ustr(e)) - detailed_msg = '{0} {1}'.format(msg, textutil.format_exception()) + detailed_msg = '{0} {1}'.format(msg, textutil.format_exception(e)) add_event( AGENT_NAME, version=self.version, diff --git a/tests/common/osutil/test_default.py b/tests/common/osutil/test_default.py index 05770b2625..a736974e22 100644 --- a/tests/common/osutil/test_default.py +++ b/tests/common/osutil/test_default.py @@ -290,7 +290,7 @@ def test_no_primary_does_not_throw(self): try: osutil.DefaultOSUtil().get_first_if()[0] except Exception as e: # pylint: disable=unused-variable - print(textutil.format_exception()) + print(textutil.format_exception(e)) exception = True self.assertFalse(exception) diff --git a/tests/common/osutil/test_freebsd.py b/tests/common/osutil/test_freebsd.py index 912ebef81f..3851836013 100644 --- a/tests/common/osutil/test_freebsd.py +++ b/tests/common/osutil/test_freebsd.py @@ -120,7 +120,7 @@ def test_no_primary_does_not_throw(self): try: freebsdosutil.get_first_if()[0] except Exception as e: # pylint: disable=unused-variable - print(textutil.format_exception()) + print(textutil.format_exception(e)) exception = True # pylint: disable=unused-variable if __name__ == '__main__': From a786281f0def680b8b58f1d895aafdfcac3e6459 Mon Sep 17 00:00:00 2001 From: dganesan Date: Fri, 16 Jul 2021 11:10:53 -0700 Subject: [PATCH 4/9] Removed logger --- azurelinuxagent/common/event.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/azurelinuxagent/common/event.py b/azurelinuxagent/common/event.py index 764adba50b..ed11c5089a 100644 --- a/azurelinuxagent/common/event.py +++ b/azurelinuxagent/common/event.py @@ -491,7 +491,7 @@ def add_event(self, name, op=WALAEventOperation.Unknown, is_success=True, durati self.add_common_event_parameters(event, datetime.utcnow()) data = get_properties(event) - logger.warn(json.dumps(data)) + try: self.save_event(json.dumps(data)) except EventError as e: From 011cc2f96267f63f8d8a1cfaa2a64f07db150316 Mon Sep 17 00:00:00 2001 From: dganesan Date: Fri, 16 Jul 2021 11:14:10 -0700 Subject: [PATCH 5/9] Fixed Pylint error --- azurelinuxagent/ga/exthandlers.py | 2 -- 1 file changed, 2 deletions(-) diff --git a/azurelinuxagent/ga/exthandlers.py b/azurelinuxagent/ga/exthandlers.py index d2bb1bf298..724d198a19 100644 --- a/azurelinuxagent/ga/exthandlers.py +++ b/azurelinuxagent/ga/exthandlers.py @@ -24,10 +24,8 @@ import re import shutil import stat -import sys import tempfile import time -import traceback import zipfile from collections import defaultdict from functools import partial From a24056d2249b534a8bc7583ee0d0a1862aca23d7 Mon Sep 17 00:00:00 2001 From: dganesan Date: Sun, 18 Jul 2021 19:52:14 -0700 Subject: [PATCH 6/9] Fixed logging and updated logic to process exceptions --- azurelinuxagent/common/protocol/wire.py | 4 ++-- azurelinuxagent/common/utils/textutil.py | 19 ++++++++++--------- .../ga/collect_telemetry_events.py | 4 ++-- azurelinuxagent/ga/exthandlers.py | 18 +++++++++--------- azurelinuxagent/ga/remoteaccess.py | 2 +- azurelinuxagent/ga/send_telemetry_events.py | 7 +++---- azurelinuxagent/ga/update.py | 9 ++++----- 7 files changed, 31 insertions(+), 32 deletions(-) diff --git a/azurelinuxagent/common/protocol/wire.py b/azurelinuxagent/common/protocol/wire.py index d05796369c..c678f49dae 100644 --- a/azurelinuxagent/common/protocol/wire.py +++ b/azurelinuxagent/common/protocol/wire.py @@ -807,7 +807,7 @@ def try_update_goal_state(self): self._last_try_update_goal_state_failed = True message = u"An error occurred while retrieving the goal state: {0}".format(ustr(e)) add_event(AGENT_NAME, op=WALAEventOperation.FetchGoalState, version=CURRENT_VERSION, is_success=False, message=message, log_event=False) - message = u"An error occurred while retrieving the goal state: {0}".format(textutil.format_exception(e)) + message = u"An error occurred while retrieving the goal state:\n {0}".format(textutil.format_exception(e)) logger.warn(message) 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)) @@ -1206,7 +1206,7 @@ def _send_event(provider_id, debug_info): events_per_provider[event.providerId] += 1 except Exception as error: - logger.warn("Unexpected error when generating Events: {0}, {1}", ustr(error), textutil.format_exception(error)) + logger.warn("Unexpected error when generating Events:\n {0}", textutil.format_exception(error)) # Send out all events left in buffer. for provider_id in list(buf.keys()): diff --git a/azurelinuxagent/common/utils/textutil.py b/azurelinuxagent/common/utils/textutil.py index a4a80ea697..0aef2e5ac6 100644 --- a/azurelinuxagent/common/utils/textutil.py +++ b/azurelinuxagent/common/utils/textutil.py @@ -435,16 +435,17 @@ def str_to_encoded_ustr(s, encoding='utf-8'): def format_exception(exception): # Placeholder function to format exception message - msg = ''.join(traceback.format_exception(etype=type(exception), value=exception, tb=get_traceback(exception))) + e = None if sys.version_info[0] == 2: - msg = "{0}{1}".format("Traceback might not work as expected because the agent is running on Python 2\n", msg) - return ustr(msg) + _, e, tb = sys.exc_info() + else: + tb = exception.__traceback__ + msg = ustr(exception) + "\n" + if tb is None or (sys.version_info[0] == 2 and e != exception): + msg += "[Traceback not available]" + else: + msg += ''.join(traceback.format_exception(etype=type(exception), value=exception, tb=tb)) -def get_traceback(e): # pylint: disable=R1710 - if sys.version_info[0] == 3: # pylint: disable=R1705 - return e.__traceback__ - elif sys.version_info[0] == 2: - ex_type, ex, tb = sys.exc_info() # pylint: disable=W0612 - return tb + return msg diff --git a/azurelinuxagent/ga/collect_telemetry_events.py b/azurelinuxagent/ga/collect_telemetry_events.py index 527cfc480b..2a4a937e10 100644 --- a/azurelinuxagent/ga/collect_telemetry_events.py +++ b/azurelinuxagent/ga/collect_telemetry_events.py @@ -116,8 +116,8 @@ def _operation(self): # the telemetry service comes back up delete_all_event_files = False except Exception as error: - msg = "Unknown error occurred when trying to collect extension events. Error: {0}, Stack: {1}".format( - ustr(error), textutil.format_exception(error)) + msg = "Unknown error occurred when trying to collect extension events.:\n{0}".format( + textutil.format_exception(error)) add_event(op=WALAEventOperation.ExtensionTelemetryEventProcessing, message=msg, is_success=False) finally: # Always ensure that the events directory are being deleted each run except when Telemetry Service is stopped, diff --git a/azurelinuxagent/ga/exthandlers.py b/azurelinuxagent/ga/exthandlers.py index 724d198a19..8ec7c522f1 100644 --- a/azurelinuxagent/ga/exthandlers.py +++ b/azurelinuxagent/ga/exthandlers.py @@ -322,7 +322,7 @@ def run(self): activity_id, correlation_id, gs_creation_time = self.get_goal_state_debug_metadata() except Exception as error: - msg = u"ProcessExtensionsInGoalState - Exception processing extension handlers: {0}\n{1}".format(ustr(error), textutil.format_exception(error)) + msg = u"ProcessExtensionsInGoalState - Exception processing extension handlers:\n{0}".format(textutil.format_exception(error)) logger.warn(msg) add_event(op=WALAEventOperation.ExtensionProcessing, is_success=False, message=msg, log_event=False) return @@ -342,7 +342,7 @@ def goal_state_debug_info(duration=None): self.__process_and_handle_extensions(etag) self._cleanup_outdated_handlers() except Exception as error: - error = u"ProcessExtensionsInGoalState - Exception processing extension handlers: {0}\n{1}".format(ustr(error), textutil.format_exception(error)) + error = u"ProcessExtensionsInGoalState - Exception processing extension handlers:\n {0}".format(textutil.format_exception(error)) finally: duration = elapsed_milliseconds(utc_start) if error is None: @@ -379,7 +379,7 @@ def __process_and_handle_extensions(self, etag): code=GoalStateAggregateStatusCodes.Success, message="GoalState executed successfully") except Exception as error: - msg = "Unexpected error when processing goal state: {0}; {1}".format(ustr(error), textutil.format_exception(error)) + msg = "Unexpected error when processing goal state: \n {0}".format(textutil.format_exception(error)) self.__gs_aggregate_status = GoalStateAggregateStatus(status=GoalStateStatus.Failed, seq_no=etag, code=GoalStateAggregateStatusCodes.GoalStateUnknownFailure, message=msg) @@ -960,7 +960,7 @@ def report_ext_handlers_status(self, incarnation_changed=False): self.write_ext_handlers_status_to_info_file(vm_status) except Exception as error: - msg = u"Failed to report status: {0}\n{1}".format(ustr(error), textutil.format_exception(error)) + msg = u"Failed to report status: \n {0}".format(textutil.format_exception(error)) logger.warn(msg) add_event(AGENT_NAME, version=CURRENT_VERSION, @@ -1779,8 +1779,8 @@ def get_extension_handler_statuses(self, handler_status, incarnation_changed): ext_handler_status = ExtHandlerStatus() set_properties("ExtHandlerStatus", ext_handler_status, get_properties(handler_status)) except Exception as error: - msg = "Something went wrong when trying to get a copy of the Handler status for {0}: {1}".format( - self.get_extension_full_name(), ustr(error)) + msg = "Something went wrong when trying to get a copy of the Handler status for {0}".format( + self.get_extension_full_name()) self.report_error_on_incarnation_change(incarnation_changed, event_msg=msg, log_msg="{0}.\nStack Trace: {1}".format( msg, textutil.format_exception(error))) @@ -1797,8 +1797,8 @@ def get_extension_handler_statuses(self, handler_status, incarnation_changed): ext_handler_statuses.append(ext_handler_status) except ExtensionError as error: - msg = "Unknown error when trying to fetch status from extension {0}: {1}".format( - self.get_extension_full_name(ext), ustr(error)) + msg = "Unknown error when trying to fetch status from extension {0}".format( + self.get_extension_full_name(ext)) self.report_error_on_incarnation_change(incarnation_changed, event_msg=msg, log_msg="{0}.\nStack Trace: {1}".format( msg, textutil.format_exception(error)), @@ -2076,7 +2076,7 @@ def set_handler_status(self, status="NotReady", message="", code=0): self.ext_handler.name, self.ext_handler.properties.version)) except (IOError, ValueError, ProtocolError) as error: fileutil.clean_ioerror(error, paths=[status_file]) - self.logger.error("Failed to save handler status: {0}, {1}", ustr(error), textutil.format_exception(error)) + self.logger.error("Failed to save handler status: {0}", textutil.format_exception(error)) def get_handler_status(self): state_dir = self.get_conf_dir() diff --git a/azurelinuxagent/ga/remoteaccess.py b/azurelinuxagent/ga/remoteaccess.py index 2488b6c7b3..592df1b74c 100644 --- a/azurelinuxagent/ga/remoteaccess.py +++ b/azurelinuxagent/ga/remoteaccess.py @@ -57,7 +57,7 @@ def run(self): self._remote_access = self._protocol.client.get_remote_access() self._handle_remote_access() except Exception as e: - msg = u"Exception processing goal state for remote access users: {0} {1}".format(ustr(e), textutil.format_exception(e)) + msg = u"Exception processing goal state for remote access users: {0}".format(textutil.format_exception(e)) add_event(AGENT_NAME, version=CURRENT_VERSION, op=WALAEventOperation.RemoteAccessHandling, diff --git a/azurelinuxagent/ga/send_telemetry_events.py b/azurelinuxagent/ga/send_telemetry_events.py index 59809997c5..c048e73c99 100644 --- a/azurelinuxagent/ga/send_telemetry_events.py +++ b/azurelinuxagent/ga/send_telemetry_events.py @@ -135,8 +135,8 @@ def _process_telemetry_thread(self): self._send_events_in_queue(first_event) except Exception as error: - err_msg = "An unknown error occurred in the {0} thread main loop, stopping thread. Error: {1}, Stack: {2}".format( - self.get_thread_name(), ustr(error), textutil.format_exception(error)) + err_msg = "An unknown error occurred in the {0} thread main loop, stopping thread.\n {1}".format( + self.get_thread_name(), textutil.format_exception(error)) add_event(op=WALAEventOperation.UnhandledError, message=err_msg, is_success=False) def _send_events_in_queue(self, first_event): @@ -161,5 +161,4 @@ def _get_events_in_queue(self, first_event): self._queue.task_done() yield event except Exception as error: - logger.error("Some exception when fetching event from queue: {0}, {1}".format(ustr(error), - textutil.format_exception(error))) \ No newline at end of file + logger.error("Some exception when fetching event from queue: {0}".format(textutil.format_exception(error))) \ No newline at end of file diff --git a/azurelinuxagent/ga/update.py b/azurelinuxagent/ga/update.py index d59c62e5fd..8654db5269 100644 --- a/azurelinuxagent/ga/update.py +++ b/azurelinuxagent/ga/update.py @@ -227,10 +227,9 @@ def run_latest(self, child_args=None): except Exception as e: # Ignore child errors during termination if self.is_running: - msg = u"Agent {0} launched with command '{1}' failed with exception: {2}".format( + msg = u"Agent {0} launched with command '{1}' failed with exception: \n".format( agent_name, - agent_cmd, - ustr(e)) + agent_cmd) logger.warn(msg) detailed_message = '{0} {1}'.format(msg, textutil.format_exception(e)) add_event( @@ -898,8 +897,8 @@ def __init__(self, path=None, pkg=None, host=None): # is corrupt (e.g., missing the HandlerManifest.json file) self.mark_failure(is_fatal=os.path.isfile(self.get_agent_pkg_path())) - msg = u"Agent {0} install failed with exception: {1}".format( - self.name, ustr(e)) + msg = u"Agent {0} install failed with exception: \n".format( + self.name) detailed_msg = '{0} {1}'.format(msg, textutil.format_exception(e)) add_event( AGENT_NAME, From 5478638fb3bb5be5d9f15b0e5e0dd7ddbc9410cc Mon Sep 17 00:00:00 2001 From: dganesan Date: Sun, 18 Jul 2021 19:59:23 -0700 Subject: [PATCH 7/9] Fixed logging and updated logic to process exceptions --- azurelinuxagent/ga/collect_telemetry_events.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/azurelinuxagent/ga/collect_telemetry_events.py b/azurelinuxagent/ga/collect_telemetry_events.py index 2a4a937e10..63f845289e 100644 --- a/azurelinuxagent/ga/collect_telemetry_events.py +++ b/azurelinuxagent/ga/collect_telemetry_events.py @@ -204,7 +204,7 @@ def _capture_extension_events(self, handler_name, handler_event_dir_path): # This is a trade-off between data replication vs data loss. raise except Exception as error: - msg = "Failed to process event file {0}: {1}, {2}".format(event_file, ustr(error), + msg = "Failed to process event file {0}: \n, {1}".format(event_file, textutil.format_exception(error)) logger.warn(msg) add_log_event(level=logger.LogLevel.WARNING, message=msg, forced=True) From e83d3356314c8bb8a21d17b800d5e5b39da92f23 Mon Sep 17 00:00:00 2001 From: dganesan Date: Mon, 19 Jul 2021 13:22:00 -0700 Subject: [PATCH 8/9] Fixed minor PR comments --- azurelinuxagent/common/protocol/wire.py | 4 ++-- azurelinuxagent/common/utils/textutil.py | 2 +- azurelinuxagent/ga/collect_telemetry_events.py | 4 ++-- azurelinuxagent/ga/exthandlers.py | 4 ++-- azurelinuxagent/ga/send_telemetry_events.py | 2 +- 5 files changed, 8 insertions(+), 8 deletions(-) diff --git a/azurelinuxagent/common/protocol/wire.py b/azurelinuxagent/common/protocol/wire.py index c678f49dae..eb8476a5ae 100644 --- a/azurelinuxagent/common/protocol/wire.py +++ b/azurelinuxagent/common/protocol/wire.py @@ -807,7 +807,7 @@ def try_update_goal_state(self): self._last_try_update_goal_state_failed = True message = u"An error occurred while retrieving the goal state: {0}".format(ustr(e)) add_event(AGENT_NAME, op=WALAEventOperation.FetchGoalState, version=CURRENT_VERSION, is_success=False, message=message, log_event=False) - message = u"An error occurred while retrieving the goal state:\n {0}".format(textutil.format_exception(e)) + message = u"An error occurred while retrieving the goal state: {0}".format(textutil.format_exception(e)) logger.warn(message) 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)) @@ -1206,7 +1206,7 @@ def _send_event(provider_id, debug_info): events_per_provider[event.providerId] += 1 except Exception as error: - logger.warn("Unexpected error when generating Events:\n {0}", textutil.format_exception(error)) + logger.warn("Unexpected error when generating Events:{0}", textutil.format_exception(error)) # Send out all events left in buffer. for provider_id in list(buf.keys()): diff --git a/azurelinuxagent/common/utils/textutil.py b/azurelinuxagent/common/utils/textutil.py index 0aef2e5ac6..153eb80643 100644 --- a/azurelinuxagent/common/utils/textutil.py +++ b/azurelinuxagent/common/utils/textutil.py @@ -434,7 +434,7 @@ def str_to_encoded_ustr(s, encoding='utf-8'): def format_exception(exception): - # Placeholder function to format exception message + # Function to format exception message e = None if sys.version_info[0] == 2: _, e, tb = sys.exc_info() diff --git a/azurelinuxagent/ga/collect_telemetry_events.py b/azurelinuxagent/ga/collect_telemetry_events.py index 63f845289e..0503fd6b3f 100644 --- a/azurelinuxagent/ga/collect_telemetry_events.py +++ b/azurelinuxagent/ga/collect_telemetry_events.py @@ -116,7 +116,7 @@ def _operation(self): # the telemetry service comes back up delete_all_event_files = False except Exception as error: - msg = "Unknown error occurred when trying to collect extension events.:\n{0}".format( + msg = "Unknown error occurred when trying to collect extension events:{0}".format( textutil.format_exception(error)) add_event(op=WALAEventOperation.ExtensionTelemetryEventProcessing, message=msg, is_success=False) finally: @@ -204,7 +204,7 @@ def _capture_extension_events(self, handler_name, handler_event_dir_path): # This is a trade-off between data replication vs data loss. raise except Exception as error: - msg = "Failed to process event file {0}: \n, {1}".format(event_file, + msg = "Failed to process event file {0}:{1}".format(event_file, textutil.format_exception(error)) logger.warn(msg) add_log_event(level=logger.LogLevel.WARNING, message=msg, forced=True) diff --git a/azurelinuxagent/ga/exthandlers.py b/azurelinuxagent/ga/exthandlers.py index 8ec7c522f1..6da02bf111 100644 --- a/azurelinuxagent/ga/exthandlers.py +++ b/azurelinuxagent/ga/exthandlers.py @@ -322,7 +322,7 @@ def run(self): activity_id, correlation_id, gs_creation_time = self.get_goal_state_debug_metadata() except Exception as error: - msg = u"ProcessExtensionsInGoalState - Exception processing extension handlers:\n{0}".format(textutil.format_exception(error)) + msg = u"ProcessExtensionsInGoalState - Exception processing extension handlers:{0}".format(textutil.format_exception(error)) logger.warn(msg) add_event(op=WALAEventOperation.ExtensionProcessing, is_success=False, message=msg, log_event=False) return @@ -342,7 +342,7 @@ def goal_state_debug_info(duration=None): self.__process_and_handle_extensions(etag) self._cleanup_outdated_handlers() except Exception as error: - error = u"ProcessExtensionsInGoalState - Exception processing extension handlers:\n {0}".format(textutil.format_exception(error)) + error = u"ProcessExtensionsInGoalState - Exception processing extension handlers:{0}".format(textutil.format_exception(error)) finally: duration = elapsed_milliseconds(utc_start) if error is None: diff --git a/azurelinuxagent/ga/send_telemetry_events.py b/azurelinuxagent/ga/send_telemetry_events.py index c048e73c99..c2e277769a 100644 --- a/azurelinuxagent/ga/send_telemetry_events.py +++ b/azurelinuxagent/ga/send_telemetry_events.py @@ -135,7 +135,7 @@ def _process_telemetry_thread(self): self._send_events_in_queue(first_event) except Exception as error: - err_msg = "An unknown error occurred in the {0} thread main loop, stopping thread.\n {1}".format( + err_msg = "An unknown error occurred in the {0} thread main loop, stopping thread.{1}".format( self.get_thread_name(), textutil.format_exception(error)) add_event(op=WALAEventOperation.UnhandledError, message=err_msg, is_success=False) From e2eb2bc1ec88cdff87e317415428239306bd6140 Mon Sep 17 00:00:00 2001 From: dganesan Date: Mon, 19 Jul 2021 13:29:34 -0700 Subject: [PATCH 9/9] Fixed minor PR comments --- azurelinuxagent/ga/exthandlers.py | 4 ++-- azurelinuxagent/ga/update.py | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/azurelinuxagent/ga/exthandlers.py b/azurelinuxagent/ga/exthandlers.py index 6da02bf111..d50b227cb9 100644 --- a/azurelinuxagent/ga/exthandlers.py +++ b/azurelinuxagent/ga/exthandlers.py @@ -379,7 +379,7 @@ def __process_and_handle_extensions(self, etag): code=GoalStateAggregateStatusCodes.Success, message="GoalState executed successfully") except Exception as error: - msg = "Unexpected error when processing goal state: \n {0}".format(textutil.format_exception(error)) + msg = "Unexpected error when processing goal state:{0}".format(textutil.format_exception(error)) self.__gs_aggregate_status = GoalStateAggregateStatus(status=GoalStateStatus.Failed, seq_no=etag, code=GoalStateAggregateStatusCodes.GoalStateUnknownFailure, message=msg) @@ -960,7 +960,7 @@ def report_ext_handlers_status(self, incarnation_changed=False): self.write_ext_handlers_status_to_info_file(vm_status) except Exception as error: - msg = u"Failed to report status: \n {0}".format(textutil.format_exception(error)) + msg = u"Failed to report status: {0}".format(textutil.format_exception(error)) logger.warn(msg) add_event(AGENT_NAME, version=CURRENT_VERSION, diff --git a/azurelinuxagent/ga/update.py b/azurelinuxagent/ga/update.py index 8654db5269..474335363c 100644 --- a/azurelinuxagent/ga/update.py +++ b/azurelinuxagent/ga/update.py @@ -897,7 +897,7 @@ def __init__(self, path=None, pkg=None, host=None): # is corrupt (e.g., missing the HandlerManifest.json file) self.mark_failure(is_fatal=os.path.isfile(self.get_agent_pkg_path())) - msg = u"Agent {0} install failed with exception: \n".format( + msg = u"Agent {0} install failed with exception:".format( self.name) detailed_msg = '{0} {1}'.format(msg, textutil.format_exception(e)) add_event(