Merge pull request #776 from brendandixon/master

Address #769, #764, #761,#757, #754, #746, #740

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()

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

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))
 

azurelinuxagent/common/logger.py

@@ -20,18 +20,37 @@
 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):
     """
     Logger class
     """
     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)
 

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())

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)

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

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

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):

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):