diff --git a/azurelinuxagent/agent.py b/azurelinuxagent/agent.py index 90b4253400..d1ac3544f4 100644 --- a/azurelinuxagent/agent.py +++ b/azurelinuxagent/agent.py @@ -129,7 +129,7 @@ def main(args=[]): elif command == "help": usage() elif command == "start": - start() + start(conf_file_path=conf_file_path) else: try: agent = Agent(verbose, conf_file_path=conf_file_path) @@ -217,13 +217,16 @@ def usage(): "").format(sys.argv[0]))) print("") -def start(): +def start(conf_file_path=None): """ Start agent daemon in a background process and set stdout/stderr to /dev/null """ devnull = open(os.devnull, 'w') - subprocess.Popen([sys.argv[0], '-daemon'], stdout=devnull, stderr=devnull) + args = [sys.argv[0], '-daemon'] + if conf_file_path is not None: + args.append('-configuration-path:{0}'.format(conf_file_path)) + subprocess.Popen(args, stdout=devnull, stderr=devnull) if __name__ == '__main__' : main() diff --git a/azurelinuxagent/common/event.py b/azurelinuxagent/common/event.py index 116478bf32..723b8bff58 100644 --- a/azurelinuxagent/common/event.py +++ b/azurelinuxagent/common/event.py @@ -25,7 +25,7 @@ import threading import platform -from datetime import datetime +from datetime import datetime, timedelta import azurelinuxagent.common.logger as logger @@ -39,6 +39,7 @@ DISTRO_CODE_NAME, AGENT_VERSION, \ CURRENT_AGENT, CURRENT_VERSION +_EVENT_MSG = "Event: name={0}, op={1}, message={2}" class WALAEventOperation: ActivateResourceDisk = "ActivateResourceDisk" @@ -47,6 +48,7 @@ class WALAEventOperation: Enable = "Enable" HealthCheck = "HealthCheck" HeartBeat = "HeartBeat" + HostPlugin = "HostPlugin" Install = "Install" InitializeHostPlugin = "InitializeHostPlugin" ProcessGoalState = "ProcessGoalState" @@ -58,10 +60,19 @@ class WALAEventOperation: Upgrade = "Upgrade" Update = "Update" +def _log_event(name, op, message, is_success=True): + global _EVENT_MSG + + if not is_success: + logger.error(_EVENT_MSG, name, op, message) + else: + logger.info(_EVENT_MSG, name, op, message) + class EventLogger(object): def __init__(self): self.event_dir = None + self.periodic_events = {} def save_event(self, data): if self.event_dir is None: @@ -92,9 +103,33 @@ def save_event(self, data): except IOError as e: raise EventError("Failed to write events to file:{0}", e) + def reset_periodic(self): + self.periodic_messages = {} + + def is_period_elapsed(self, delta, h): + return h not in self.periodic_messages or \ + (self.periodic_messages[h] + delta) <= datetime.now() + + def add_periodic(self, + delta, name, op="", is_success=True, duration=0, + version=CURRENT_VERSION, message="", evt_type="", + is_internal=False, log_event=True, force=False): + + h = hash(name+op+ustr(is_success)+message) + + if force or self.is_period_elapsed(delta, h): + self.add_event(name, + op=op, is_success=is_success, duration=duration, + version=version, message=message, evt_type=evt_type, + is_internal=is_internal, log_event=log_event) + self.periodic_messages[h] = datetime.now() + def add_event(self, name, op="", is_success=True, duration=0, version=CURRENT_VERSION, - message="", evt_type="", is_internal=False): + message="", evt_type="", is_internal=False, log_event=True): + if not is_success or log_event: + _log_event(name, op, message, is_success=is_success) + event = TelemetryEvent(1, "69B669B9-4AF8-4C50-BDC4-6006FA76E975") event.parameters.append(TelemetryEventParam('Name', name)) event.parameters.append(TelemetryEventParam('Version', str(version))) @@ -129,21 +164,40 @@ def report_event(op, is_success=True, message=''): message=message, op=op) +def report_periodic(delta, op, is_success=True, message=''): + from azurelinuxagent.common.version import AGENT_NAME, CURRENT_VERSION + add_periodic(delta, AGENT_NAME, + version=CURRENT_VERSION, + is_success=is_success, + message=message, + op=op) def add_event(name, op="", is_success=True, duration=0, version=CURRENT_VERSION, message="", evt_type="", is_internal=False, log_event=True, reporter=__event_logger__): - if log_event or not is_success: - log = logger.info if is_success else logger.error - log("Event: name={0}, op={1}, message={2}", name, op, message) + if reporter.event_dir is None: + logger.warn("Event reporter is not initialized.") + _log_event(name, op, message, is_success=is_success) + return + + reporter.add_event( + name, op=op, is_success=is_success, duration=duration, + version=str(version), message=message, evt_type=evt_type, + is_internal=is_internal, log_event=log_event) +def add_periodic( + delta, name, op="", is_success=True, duration=0, version=CURRENT_VERSION, + message="", evt_type="", is_internal=False, log_event=True, force=False, + reporter=__event_logger__): if reporter.event_dir is None: logger.warn("Event reporter is not initialized.") + _log_event(name, op, message, is_success=is_success) return - reporter.add_event(name, op=op, is_success=is_success, duration=duration, - version=str(version), message=message, evt_type=evt_type, - is_internal=is_internal) + reporter.add_periodic( + delta, name, op=op, is_success=is_success, duration=duration, + version=str(version), message=message, evt_type=evt_type, + is_internal=is_internal, log_event=log_event, force=force) def init_event_logger(event_dir, reporter=__event_logger__): reporter.event_dir = event_dir diff --git a/azurelinuxagent/common/future.py b/azurelinuxagent/common/future.py index 8509732a14..8d5b70b752 100644 --- a/azurelinuxagent/common/future.py +++ b/azurelinuxagent/common/future.py @@ -13,8 +13,6 @@ bytebuffer = memoryview - read_input = input - elif sys.version_info[0] == 2: import httplib as httpclient from urlparse import urlparse @@ -24,8 +22,6 @@ bytebuffer = buffer - read_input = raw_input - else: raise ImportError("Unknown python version:{0}".format(sys.version_info)) diff --git a/azurelinuxagent/common/logger.py b/azurelinuxagent/common/logger.py index c1eb18fe01..bfdc73aa4e 100644 --- a/azurelinuxagent/common/logger.py +++ b/azurelinuxagent/common/logger.py @@ -20,7 +20,13 @@ import os import sys from azurelinuxagent.common.future import ustr -from datetime import datetime +from datetime import datetime, timedelta + +EVERY_DAY = timedelta(days=1) +EVERY_HALF_DAY = timedelta(hours=12) +EVERY_HOUR = timedelta(hours=1) +EVERY_HALF_HOUR = timedelta(minutes=30) +EVERY_FIFTEEN_MINUTES = timedelta(minutes=15) class Logger(object): """ @@ -28,10 +34,23 @@ class Logger(object): """ def __init__(self, logger=None, prefix=None): self.appenders = [] - if logger is not None: - self.appenders.extend(logger.appenders) + self.logger = self if logger is None else logger + self.periodic_messages = {} self.prefix = prefix + def reset_periodic(self): + self.logger.periodic_messages = {} + + def is_period_elapsed(self, delta, h): + return h not in self.logger.periodic_messages or \ + (self.logger.periodic_messages[h] + delta) <= datetime.now() + + def periodic(self, delta, msg_format, *args): + h = hash(msg_format) + if self.is_period_elapsed(delta, h): + self.info(msg_format, *args) + self.logger.periodic_messages[h] = datetime.now() + def verbose(self, msg_format, *args): self.log(LogLevel.VERBOSE, msg_format, *args) @@ -62,8 +81,12 @@ def log(self, level, msg_format, *args): log_item = ustr(log_item.encode('ascii', "backslashreplace"), encoding="ascii") + for appender in self.appenders: appender.write(level, log_item) + if self.logger != self: + for appender in self.logger.appenders: + appender.write(level, log_item) def add_appender(self, appender_type, level, path): appender = _create_logger_appender(appender_type, level, path) @@ -129,6 +152,12 @@ class AppenderType(object): def add_logger_appender(appender_type, level=LogLevel.INFO, path=None): DEFAULT_LOGGER.add_appender(appender_type, level, path) +def reset_periodic(): + DEFAULT_LOGGER.reset_periodic() + +def periodic(delta, msg_format, *args): + DEFAULT_LOGGER.periodic(delta, msg_format, *args) + def verbose(msg_format, *args): DEFAULT_LOGGER.verbose(msg_format, *args) diff --git a/azurelinuxagent/common/protocol/hostplugin.py b/azurelinuxagent/common/protocol/hostplugin.py index 4968ce8943..9af8a97367 100644 --- a/azurelinuxagent/common/protocol/hostplugin.py +++ b/azurelinuxagent/common/protocol/hostplugin.py @@ -143,7 +143,9 @@ def put_vm_log(self, content): headers = {"x-ms-vmagentlog-deploymentid": self.deployment_id, "x-ms-vmagentlog-containerid": self.container_id} - logger.info("HostGAPlugin: Put VM log to [{0}]".format(url)) + logger.periodic( + logger.EVERY_FIFTEEN_MINUTES, + "HostGAPlugin: Put VM log to [{0}]".format(url)) try: response = restutil.http_put(url, content, headers) if response.status != httpclient.OK: @@ -175,7 +177,7 @@ def put_vm_status(self, status_blob, sas_url, config_blob_type=None): self._put_page_blob_status(sas_url, status_blob) if not HostPluginProtocol.is_default_channel(): - logger.info("HostGAPlugin: Setting host plugin as default channel") + logger.verbose("HostGAPlugin: Setting host plugin as default channel") HostPluginProtocol.set_default_channel(True) except Exception as e: message = "HostGAPlugin: Exception Put VM status: {0}, {1}".format(e, traceback.format_exc()) diff --git a/azurelinuxagent/common/protocol/metadata.py b/azurelinuxagent/common/protocol/metadata.py index 664fbf8f35..b0b6f6723d 100644 --- a/azurelinuxagent/common/protocol/metadata.py +++ b/azurelinuxagent/common/protocol/metadata.py @@ -236,14 +236,14 @@ def get_ext_handlers(self, last_etag=None): return ext_list, etag def get_ext_handler_pkgs(self, ext_handler): - logger.info("Get extension handler packages") + logger.verbose("Get extension handler packages") pkg_list = ExtHandlerPackageList() manifest = None for version_uri in ext_handler.versionUris: try: manifest, etag = self._get_data(version_uri.uri) - logger.info("Successfully downloaded manifest") + logger.verbose("Successfully downloaded manifest") break except ProtocolError as e: logger.warn("Failed to fetch manifest: {0}", e) diff --git a/azurelinuxagent/common/protocol/wire.py b/azurelinuxagent/common/protocol/wire.py index 936be8c602..d731e11321 100644 --- a/azurelinuxagent/common/protocol/wire.py +++ b/azurelinuxagent/common/protocol/wire.py @@ -597,9 +597,9 @@ def call_storage_service(http_req, *args, **kwargs): Call storage service, handle SERVICE_UNAVAILABLE(503) """ - # force the chk_proxy arg to True, since all calls to storage should - # use a configured proxy - kwargs['chk_proxy'] = True + # Default to use the configured HTTP proxy + if not 'chk_proxy' in kwargs or kwargs['chk_proxy'] is None: + kwargs['chk_proxy'] = True for retry in range(0, 3): resp = http_req(*args, **kwargs) @@ -626,7 +626,7 @@ def fetch_manifest(self, version_uris): logger.verbose("Manifest could not be downloaded, falling back to host plugin") host = self.get_host_plugin() uri, headers = host.get_artifact_request(version.uri) - response = self.fetch(uri, headers) + response = self.fetch(uri, headers, chk_proxy=False) if not response: host = self.get_host_plugin(force_update=True) logger.info("Retry fetch in {0} seconds", @@ -642,14 +642,15 @@ def fetch_manifest(self, version_uris): return response raise ProtocolError("Failed to fetch manifest from all sources") - def fetch(self, uri, headers=None): + def fetch(self, uri, headers=None, chk_proxy=None): logger.verbose("Fetch [{0}] with headers [{1}]", uri, headers) return_value = None try: resp = self.call_storage_service( restutil.http_get, uri, - headers) + headers, + chk_proxy=chk_proxy) if resp.status == httpclient.OK: return_value = self.decode_config(resp.read()) else: @@ -831,7 +832,7 @@ def upload_status_blob(self): if not blob_type in ["BlockBlob", "PageBlob"]: blob_type = "BlockBlob" - logger.info("Status Blob type is unspecified " + logger.verbose("Status Blob type is unspecified " "-- assuming it is a BlockBlob") try: @@ -998,17 +999,17 @@ def get_artifacts_profile(self): artifacts_profile = None if self.has_artifacts_profile_blob(): blob = self.ext_conf.artifacts_profile_blob - logger.info("Getting the artifacts profile") + logger.verbose("Getting the artifacts profile") profile = self.fetch(blob) if profile is None: logger.warn("Download failed, falling back to host plugin") host = self.get_host_plugin() uri, headers = host.get_artifact_request(blob) - profile = self.decode_config(self.fetch(uri, headers)) + profile = self.decode_config(self.fetch(uri, headers, chk_proxy=False)) if not textutil.is_str_none_or_whitespace(profile): - logger.info("Artifacts profile downloaded successfully") + logger.verbose("Artifacts profile downloaded successfully") artifacts_profile = InVMArtifactsProfile(profile) return artifacts_profile diff --git a/azurelinuxagent/common/version.py b/azurelinuxagent/common/version.py index 9b095bb8f9..e7ca452416 100644 --- a/azurelinuxagent/common/version.py +++ b/azurelinuxagent/common/version.py @@ -113,7 +113,7 @@ def get_distro(): AGENT_NAME = "WALinuxAgent" AGENT_LONG_NAME = "Azure Linux Agent" -AGENT_VERSION = '2.2.13' +AGENT_VERSION = '2.2.13.1' AGENT_LONG_VERSION = "{0}-{1}".format(AGENT_NAME, AGENT_VERSION) AGENT_DESCRIPTION = """ The Azure Linux Agent supports the provisioning and running of Linux diff --git a/azurelinuxagent/daemon/main.py b/azurelinuxagent/daemon/main.py index 5b8db2f5a1..e8dbb375cf 100644 --- a/azurelinuxagent/daemon/main.py +++ b/azurelinuxagent/daemon/main.py @@ -79,7 +79,7 @@ def run(self, child_args=None): err_msg = traceback.format_exc() add_event(name=AGENT_NAME, is_success=False, message=ustr(err_msg), op=WALAEventOperation.UnhandledError) - logger.info("Sleep 15 seconds and restart daemon") + logger.warn("Daemon ended with exception -- Sleep 15 seconds and restart daemon") time.sleep(15) def check_pid(self): diff --git a/azurelinuxagent/ga/exthandlers.py b/azurelinuxagent/ga/exthandlers.py index b44ed6d4b2..4324d9245d 100644 --- a/azurelinuxagent/ga/exthandlers.py +++ b/azurelinuxagent/ga/exthandlers.py @@ -781,7 +781,6 @@ def collect_heartbeat(self): heartbeat_file = os.path.join(conf.get_lib_dir(), self.get_heartbeat_file()) - self.logger.info("Collect heart beat") if not os.path.isfile(heartbeat_file): raise ExtensionError("Failed to get heart beat file") if not self.is_responsive(heartbeat_file): diff --git a/azurelinuxagent/ga/update.py b/azurelinuxagent/ga/update.py index 67eb785b28..10eac82bb2 100644 --- a/azurelinuxagent/ga/update.py +++ b/azurelinuxagent/ga/update.py @@ -38,7 +38,7 @@ import azurelinuxagent.common.utils.restutil as restutil import azurelinuxagent.common.utils.textutil as textutil -from azurelinuxagent.common.event import add_event, \ +from azurelinuxagent.common.event import add_event, add_periodic, \ elapsed_milliseconds, \ WALAEventOperation from azurelinuxagent.common.exception import UpdateError, ProtocolError @@ -46,6 +46,7 @@ from azurelinuxagent.common.osutil import get_osutil from azurelinuxagent.common.protocol import get_protocol_util from azurelinuxagent.common.protocol.hostplugin import HostPluginProtocol +from azurelinuxagent.common.protocol.wire import WireProtocol from azurelinuxagent.common.utils.flexible_version import FlexibleVersion from azurelinuxagent.common.version import AGENT_NAME, AGENT_VERSION, AGENT_LONG_VERSION, \ AGENT_DIR_GLOB, AGENT_PKG_GLOB, \ @@ -67,7 +68,6 @@ MAX_FAILURE = 3 # Max failure allowed for agent before blacklisted GOAL_STATE_INTERVAL = 3 -REPORT_STATUS_INTERVAL = 15 ORPHAN_WAIT_INTERVAL = 15 * 60 * 60 @@ -207,19 +207,21 @@ def run_latest(self, child_args=None): latest_agent.mark_failure(is_fatal=True) except Exception as e: - msg = u"Agent {0} launched with command '{1}' failed with exception: {2}".format( - agent_name, - agent_cmd, - ustr(e)) - logger.warn(msg) - add_event( - AGENT_NAME, - version=agent_version, - op=WALAEventOperation.Enable, - is_success=False, - message=msg) - if latest_agent is not None: - latest_agent.mark_failure(is_fatal=True) + # Ignore child errors during termination + if self.running: + msg = u"Agent {0} launched with command '{1}' failed with exception: {2}".format( + agent_name, + agent_cmd, + ustr(e)) + logger.warn(msg) + add_event( + AGENT_NAME, + version=agent_version, + op=WALAEventOperation.Enable, + is_success=False, + message=msg) + if latest_agent is not None: + latest_agent.mark_failure(is_fatal=True) self.child_process = None return @@ -266,17 +268,14 @@ def run(self): last_etag = exthandlers_handler.last_etag exthandlers_handler.run() - log_event = last_etag != exthandlers_handler.last_etag or \ - (datetime.utcnow() >= send_event_time) - add_event( - AGENT_NAME, - version=CURRENT_VERSION, - op=WALAEventOperation.ProcessGoalState, - is_success=True, - duration=elapsed_milliseconds(utc_start), - log_event=log_event) - if log_event: - send_event_time += timedelta(minutes=REPORT_STATUS_INTERVAL) + if last_etag != exthandlers_handler.last_etag: + add_event( + AGENT_NAME, + version=CURRENT_VERSION, + op=WALAEventOperation.ProcessGoalState, + is_success=True, + duration=elapsed_milliseconds(utc_start), + log_event=True) test_agent = self.get_test_agent() if test_agent is not None and test_agent.in_slice: @@ -423,10 +422,7 @@ def _upgrade_available(self, base_version=CURRENT_VERSION): # The code leaves on disk available, but blacklisted, agents so as to # preserve the state. Otherwise, those agents could be again # downloaded and inappropriately retried. - host = None - if protocol and protocol.client: - host = protocol.client.get_host_plugin() - + host = self._get_host_plugin(protocol=protocol) self._set_agents([GuestAgent(pkg=pkg, host=host) for pkg in pkg_list.versions]) self._purge_agents() self._filter_blacklisted_agents() @@ -505,6 +501,13 @@ def _find_agents(self): logger.warn(u"Exception occurred loading available agents: {0}", ustr(e)) return + def _get_host_plugin(self, protocol=None): + return protocol.client.get_host_plugin() \ + if protocol and \ + type(protocol) is WireProtocol and \ + protocol.client \ + else None + def _get_pid_files(self): pid_file = conf.get_agent_pid_file_path() @@ -602,6 +605,8 @@ def _sentinal_file_path(self): return os.path.join(conf.get_lib_dir(), AGENT_SENTINAL_FILE) def _shutdown(self): + self.running = False + if not os.path.isfile(self._sentinal_file_path()): return @@ -647,7 +652,7 @@ def __init__(self, path=None, pkg=None, host=None): self.version = FlexibleVersion(version) location = u"disk" if path is not None else u"package" - logger.verbose(u"Instantiating Agent {0} from {1}", self.name, location) + logger.verbose(u"Loading Agent {0} from package {1}", self.name, location) self.error = None self.supported = None @@ -716,7 +721,7 @@ def mark_failure(self, is_fatal=False): os.makedirs(self.get_agent_dir()) self.error.mark_failure(is_fatal=is_fatal) self.error.save() - if is_fatal: + if self.error.is_blacklisted: logger.warn(u"Agent {0} is permanently blacklisted", self.name) except Exception as e: logger.warn(u"Agent {0} failed recording error state: {1}", self.name, ustr(e)) @@ -727,7 +732,7 @@ def _ensure_downloaded(self): logger.verbose(u"Ensuring Agent {0} is downloaded", self.name) if self.is_blacklisted: - logger.info(u"Agent {0} is blacklisted - skipping download", self.name) + logger.verbose(u"Agent {0} is blacklisted - skipping download", self.name) return if self.is_downloaded: diff --git a/azurelinuxagent/pa/deprovision/default.py b/azurelinuxagent/pa/deprovision/default.py index b6be1e4ccd..bdd108f4fc 100644 --- a/azurelinuxagent/pa/deprovision/default.py +++ b/azurelinuxagent/pa/deprovision/default.py @@ -27,10 +27,15 @@ import azurelinuxagent.common.utils.shellutil as shellutil from azurelinuxagent.common.exception import ProtocolError -from azurelinuxagent.common.future import read_input from azurelinuxagent.common.osutil import get_osutil from azurelinuxagent.common.protocol import get_protocol_util +def read_input(message): + if sys.version_info[0] >= 3: + return input(message) + else: + return raw_input(message) + class DeprovisionAction(object): def __init__(self, func, args=[], kwargs={}): self.func = func @@ -209,7 +214,6 @@ def setup_changed_unique_id(self): self.del_cloud_init(warnings, actions, include_once=False) self.del_dhcp_lease(warnings, actions) self.del_lib_dir_files(warnings, actions) - self.del_resolv(warnings, actions) return warnings, actions @@ -217,8 +221,8 @@ def run(self, force=False, deluser=False): warnings, actions = self.setup(deluser) self.do_warnings(warnings) - self.do_confirmation(force=force) - self.do_actions(actions) + if self.do_confirmation(force=force): + self.do_actions(actions) def run_changed_unique_id(self): ''' @@ -259,5 +263,3 @@ def handle_interrupt_signal(self, signum, frame): print ('Deprovisioning may not be interrupted.') return - - diff --git a/tests/common/test_event.py b/tests/common/test_event.py index f53541100f..a485edf410 100644 --- a/tests/common/test_event.py +++ b/tests/common/test_event.py @@ -17,12 +17,78 @@ from __future__ import print_function +from datetime import datetime + +import azurelinuxagent.common.event as event +import azurelinuxagent.common.logger as logger + from azurelinuxagent.common.event import init_event_logger, add_event from azurelinuxagent.common.future import ustr +from azurelinuxagent.common.version import CURRENT_VERSION + from tests.tools import * class TestEvent(AgentTestCase): + + @patch('azurelinuxagent.common.event.EventLogger.add_event') + def test_periodic_emits_if_not_previously_sent(self, mock_event): + init_event_logger(tempfile.mkdtemp()) + event.__event_logger__.reset_periodic() + + event.add_periodic(logger.EVERY_DAY, "FauxEvent") + mock_event.assert_called_once() + + @patch('azurelinuxagent.common.event.EventLogger.add_event') + def test_periodic_does_not_emit_if_previously_sent(self, mock_event): + init_event_logger(tempfile.mkdtemp()) + event.__event_logger__.reset_periodic() + + event.add_periodic(logger.EVERY_DAY, "FauxEvent") + self.assertEqual(1, mock_event.call_count) + + event.add_periodic(logger.EVERY_DAY, "FauxEvent") + self.assertEqual(1, mock_event.call_count) + + @patch('azurelinuxagent.common.event.EventLogger.add_event') + def test_periodic_emits_if_forced(self, mock_event): + init_event_logger(tempfile.mkdtemp()) + event.__event_logger__.reset_periodic() + + event.add_periodic(logger.EVERY_DAY, "FauxEvent") + self.assertEqual(1, mock_event.call_count) + + event.add_periodic(logger.EVERY_DAY, "FauxEvent", force=True) + self.assertEqual(2, mock_event.call_count) + + @patch('azurelinuxagent.common.event.EventLogger.add_event') + def test_periodic_emits_after_elapsed_delta(self, mock_event): + init_event_logger(tempfile.mkdtemp()) + event.__event_logger__.reset_periodic() + + event.add_periodic(logger.EVERY_DAY, "FauxEvent") + self.assertEqual(1, mock_event.call_count) + + event.add_periodic(logger.EVERY_DAY, "FauxEvent") + self.assertEqual(1, mock_event.call_count) + + h = hash("FauxEvent"+""+ustr(True)+"") + event.__event_logger__.periodic_messages[h] = \ + datetime.now() - logger.EVERY_DAY - logger.EVERY_HOUR + event.add_periodic(logger.EVERY_DAY, "FauxEvent") + self.assertEqual(2, mock_event.call_count) + + @patch('azurelinuxagent.common.event.EventLogger.add_event') + def test_periodic_forwards_args(self, mock_event): + init_event_logger(tempfile.mkdtemp()) + event.__event_logger__.reset_periodic() + + event.add_periodic(logger.EVERY_DAY, "FauxEvent") + mock_event.assert_called_once_with( + "FauxEvent", + duration=0, evt_type='', is_internal=False, is_success=True, + log_event=True, message='', op='', version=str(CURRENT_VERSION)) + def test_save_event(self): tmp_evt = tempfile.mkdtemp() init_event_logger(tmp_evt) diff --git a/tests/common/test_logger.py b/tests/common/test_logger.py new file mode 100644 index 0000000000..9e298b311b --- /dev/null +++ b/tests/common/test_logger.py @@ -0,0 +1,66 @@ +# Copyright 2016 Microsoft Corporation +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# +# Requires Python 2.4+ and Openssl 1.0+ +# + +from datetime import datetime + +import azurelinuxagent.common.logger as logger + +from tests.tools import * + +_MSG = "This is our test logging message {0} {1}" +_DATA = ["arg1", "arg2"] + +class TestLogger(AgentTestCase): + + @patch('azurelinuxagent.common.logger.Logger.info') + def test_periodic_emits_if_not_previously_sent(self, mock_info): + logger.reset_periodic() + + logger.periodic(logger.EVERY_DAY, _MSG, *_DATA) + mock_info.assert_called_once() + + @patch('azurelinuxagent.common.logger.Logger.info') + def test_periodic_does_not_emit_if_previously_sent(self, mock_info): + logger.reset_periodic() + + logger.periodic(logger.EVERY_DAY, _MSG, *_DATA) + self.assertEqual(1, mock_info.call_count) + + logger.periodic(logger.EVERY_DAY, _MSG, *_DATA) + self.assertEqual(1, mock_info.call_count) + + @patch('azurelinuxagent.common.logger.Logger.info') + def test_periodic_emits_after_elapsed_delta(self, mock_info): + logger.reset_periodic() + + logger.periodic(logger.EVERY_DAY, _MSG, *_DATA) + self.assertEqual(1, mock_info.call_count) + + logger.periodic(logger.EVERY_DAY, _MSG, *_DATA) + self.assertEqual(1, mock_info.call_count) + + logger.DEFAULT_LOGGER.periodic_messages[hash(_MSG)] = \ + datetime.now() - logger.EVERY_DAY - logger.EVERY_HOUR + logger.periodic(logger.EVERY_DAY, _MSG, *_DATA) + self.assertEqual(2, mock_info.call_count) + + @patch('azurelinuxagent.common.logger.Logger.info') + def test_periodic_forwards_message_and_args(self, mock_info): + logger.reset_periodic() + + logger.periodic(logger.EVERY_DAY, _MSG, *_DATA) + mock_info.assert_called_once_with(_MSG, *_DATA) diff --git a/tests/ga/test_update.py b/tests/ga/test_update.py index a83db95221..0c8642cfa0 100644 --- a/tests/ga/test_update.py +++ b/tests/ga/test_update.py @@ -23,6 +23,7 @@ import shutil from azurelinuxagent.common.protocol.hostplugin import * +from azurelinuxagent.common.protocol.metadata import * from azurelinuxagent.common.protocol.wire import * from azurelinuxagent.common.utils.fileutil import * from azurelinuxagent.ga.update import * @@ -1019,6 +1020,21 @@ def test_filter_blacklisted_agents(self): self.assertEqual(kept_agents, self.update_handler.agents) return + @patch('azurelinuxagent.common.protocol.wire.WireClient.get_host_plugin') + def test_get_host_plugin_returns_host_for_wireserver(self, mock_get_host): + protocol = WireProtocol('12.34.56.78') + mock_get_host.return_value = "faux host" + host = self.update_handler._get_host_plugin(protocol=protocol) + mock_get_host.assert_called_once() + self.assertEqual("faux host", host) + + @patch('azurelinuxagent.common.protocol.wire.WireClient.get_host_plugin') + def test_get_host_plugin_returns_none_otherwise(self, mock_get_host): + protocol = MetadataProtocol() + host = self.update_handler._get_host_plugin(protocol=protocol) + mock_get_host.assert_not_called() + self.assertEqual(None, host) + def test_get_latest_agent(self): latest_version = self.prepare_agents() @@ -1324,6 +1340,24 @@ def test_run_latest_exception_blacklists(self): self.assertEqual(1, latest_agent.error.failure_count) return + def test_run_latest_exception_does_not_blacklist_if_terminating(self): + self.prepare_agents() + + latest_agent = self.update_handler.get_latest_agent() + self.assertTrue(latest_agent.is_available) + self.assertEqual(0.0, latest_agent.error.last_failure) + self.assertEqual(0, latest_agent.error.failure_count) + + with patch('azurelinuxagent.ga.update.UpdateHandler.get_latest_agent', return_value=latest_agent): + self.update_handler.running = False + self._test_run_latest(mock_child=ChildMock(side_effect=Exception("Attempt blacklisting"))) + + self.assertTrue(latest_agent.is_available) + self.assertFalse(latest_agent.error.is_blacklisted) + self.assertEqual(0.0, latest_agent.error.last_failure) + self.assertEqual(0, latest_agent.error.failure_count) + return + @patch('signal.signal') def test_run_latest_captures_signals(self, mock_signal): self._test_run_latest() @@ -1462,12 +1496,14 @@ def test_set_sentinal_writes_current_agent(self): def test_shutdown(self): self.update_handler._set_sentinal() self.update_handler._shutdown() + self.assertFalse(self.update_handler.running) self.assertFalse(os.path.isfile(self.update_handler._sentinal_file_path())) return def test_shutdown_ignores_missing_sentinal_file(self): self.assertFalse(os.path.isfile(self.update_handler._sentinal_file_path())) self.update_handler._shutdown() + self.assertFalse(self.update_handler.running) self.assertFalse(os.path.isfile(self.update_handler._sentinal_file_path())) return diff --git a/tests/pa/test_deprovision.py b/tests/pa/test_deprovision.py index c4cd9b41a4..24456786c4 100644 --- a/tests/pa/test_deprovision.py +++ b/tests/pa/test_deprovision.py @@ -15,6 +15,7 @@ # Requires Python 2.4+ and Openssl 1.0+ # +import signal import tempfile import azurelinuxagent.common.utils.fileutil as fileutil @@ -25,6 +26,33 @@ class TestDeprovision(AgentTestCase): + @patch('signal.signal') + @patch('azurelinuxagent.common.osutil.get_osutil') + @patch('azurelinuxagent.common.protocol.get_protocol_util') + @patch('azurelinuxagent.pa.deprovision.default.read_input') + def test_confirmation(self, + mock_read, mock_protocol, mock_util, mock_signal): + dh = DeprovisionHandler() + + dh.setup = Mock() + dh.setup.return_value = ([], []) + dh.do_actions = Mock() + + # Do actions if confirmed + mock_read.return_value = "y" + dh.run() + self.assertEqual(1, dh.do_actions.call_count) + + # Skip actions if not confirmed + mock_read.return_value = "n" + dh.run() + self.assertEqual(1, dh.do_actions.call_count) + + # Do actions if forced + mock_read.return_value = "n" + dh.run(force=True) + self.assertEqual(2, dh.do_actions.call_count) + @patch("azurelinuxagent.pa.deprovision.default.DeprovisionHandler.cloud_init_dirs") @patch("azurelinuxagent.pa.deprovision.default.DeprovisionHandler.cloud_init_files") def test_del_cloud_init_without_once(self, diff --git a/tests/protocol/test_wire.py b/tests/protocol/test_wire.py index ba9fc7db9e..02976cac4f 100644 --- a/tests/protocol/test_wire.py +++ b/tests/protocol/test_wire.py @@ -80,26 +80,36 @@ def test_call_storage_kwargs(self, url = testurl headers = {} - # no kwargs + # no kwargs -- Default to True WireClient.call_storage_service(http_req) - # kwargs, no chk_proxy + + # kwargs, no chk_proxy -- Default to True WireClient.call_storage_service(http_req, url, headers) - # kwargs, chk_proxy False + + # kwargs, chk_proxy None -- Default to True + WireClient.call_storage_service(http_req, + url, + headers, + chk_proxy=None) + + # kwargs, chk_proxy False -- Keep False WireClient.call_storage_service(http_req, url, headers, chk_proxy=False) - # kwargs, chk_proxy True + + # kwargs, chk_proxy True -- Keep True WireClient.call_storage_service(http_req, url, headers, chk_proxy=True) # assert - self.assertTrue(http_patch.call_count == 4) - for c in http_patch.call_args_list: - self.assertTrue(c[-1]['chk_proxy'] == True) + self.assertTrue(http_patch.call_count == 5) + for i in range(0,5): + c = http_patch.call_args_list[i][-1]['chk_proxy'] + self.assertTrue(c == (True if i != 3 else False)) def test_status_blob_parsing(self, *args): wire_protocol_client = WireProtocol(wireserver_url).client