Repository: Azure/WALinuxAgent

Issue:
`systemctl stop waagent` hangs
Reproes on Ubuntu 16.04 as well as CentOS 7.

`systemctl stop walinuxagent` command hangs for a long time, although it eventually succeeds like after maybe 30-40 seconds. It used to be instant. I think it's related to the signal handling behavior that has been recently changed.

Discussion:
msftclas: Hi __@brendandixon__, I'm your friendly neighborhood Microsoft Pull Request Bot (You can call me MSBOT). Thanks for your contribution!
    <span>You've already signed the contribution license agreement. Thanks!</span>
        <p>The agreement was validated by Microsoft and real humans are currently evaluating your PR.</p>

TTYL, MSBOT;

hglkrijger: looks good. I will start a manual test
ahmetalpbalkan: LGTM
hglkrijger: manual test looks good to me:

```
2016/07/12 22:44:36.108346 INFO Checking for agent family Test updates
2016/07/12 22:44:36.117106 INFO Wire server endpoint:168.63.129.16
2016/07/12 22:44:36.150410 INFO Instantiating Agent WALinuxAgent-2.1.5.4 from package
2016/07/12 22:44:36.160788 INFO Agent WALinuxAgent-2.1.5.4 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2016/07/12 22:44:36.178844 INFO Ensuring Agent WALinuxAgent-2.1.5.4 is downloaded
2016/07/12 22:44:36.231748 INFO Agent WALinuxAgent-2.1.5.4 downloaded from https://rdfepirv2sg1prdstr03.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent__Test__2.1.5.4
2016/07/12 22:44:36.257189 INFO Agent WALinuxAgent-2.1.5.4 unpacked successfully to /var/lib/waagent/WALinuxAgent-2.1.5.4
2016/07/12 22:44:36.282298 INFO Agent WALinuxAgent-2.1.5.4 loaded manifest from /var/lib/waagent/WALinuxAgent-2.1.5.4/HandlerManifest.json
2016/07/12 22:44:36.299637 INFO Agent WALinuxAgent-2.1.5.4 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2016/07/12 22:44:36.312612 INFO Agent WALinuxAgent-2.1.5.4 downloaded successfully
2016/07/12 22:44:36.321573 INFO Event: name=WALinuxAgent, op=Install, message=Agent WALinuxAgent-2.1.5.4 downloaded successfully
2016/07/12 22:44:36.337051 INFO Instantiating Agent WALinuxAgent-2.1.5.5 from package
2016/07/12 22:44:36.346417 INFO Agent WALinuxAgent-2.1.5.5 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2016/07/12 22:44:36.359618 INFO Ensuring Agent WALinuxAgent-2.1.5.5 is downloaded
2016/07/12 22:44:36.413727 INFO Agent WALinuxAgent-2.1.5.5 downloaded from https://rdfepirv2sg1prdstr03.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent__Test__2.1.5.5
2016/07/12 22:44:36.438037 INFO Agent WALinuxAgent-2.1.5.5 unpacked successfully to /var/lib/waagent/WALinuxAgent-2.1.5.5
2016/07/12 22:44:36.451359 INFO Agent WALinuxAgent-2.1.5.5 loaded manifest from /var/lib/waagent/WALinuxAgent-2.1.5.5/HandlerManifest.json
2016/07/12 22:44:36.473522 INFO Agent WALinuxAgent-2.1.5.5 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2016/07/12 22:44:36.493318 INFO Agent WALinuxAgent-2.1.5.5 downloaded successfully
2016/07/12 22:44:36.502272 INFO Event: name=WALinuxAgent, op=Install, message=Agent WALinuxAgent-2.1.5.5 downloaded successfully
2016/07/12 22:44:36.516464 INFO Agent WALinuxAgent-2.1.5.rc5 discovered WALinuxAgent-2.1.5.5 as an update and will exit
2016/07/12 22:44:36.535733 INFO Event: name=WALinuxAgent, op=Enable, message=Agent WALinuxAgent-2.1.5.rc5 launched with command 'python -u /usr/sbin/waagent -run-exthandlers' returned code: 0
2016/07/12 22:44:36.536585 INFO Agent WALinuxAgent-2.1.5.rc5 launched with command 'python -u /usr/sbin/waagent -run-exthandlers' returned code: 0
2016/07/12 22:44:36.537991 INFO Instantiating Agent WALinuxAgent-2.1.5.4 from disk
2016/07/12 22:44:36.539193 INFO Agent WALinuxAgent-2.1.5.4 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2016/07/12 22:44:36.540657 INFO Ensuring Agent WALinuxAgent-2.1.5.4 is downloaded
2016/07/12 22:44:36.542193 INFO Agent WALinuxAgent-2.1.5.4 was previously downloaded - skipping download
2016/07/12 22:44:36.543853 INFO Agent WALinuxAgent-2.1.5.4 loaded manifest from /var/lib/waagent/WALinuxAgent-2.1.5.4/HandlerManifest.json
2016/07/12 22:44:36.545412 INFO Instantiating Agent WALinuxAgent-2.1.5.5 from disk
2016/07/12 22:44:36.546685 INFO Agent WALinuxAgent-2.1.5.5 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2016/07/12 22:44:36.548155 INFO Ensuring Agent WALinuxAgent-2.1.5.5 is downloaded
2016/07/12 22:44:36.549747 INFO Agent WALinuxAgent-2.1.5.5 was previously downloaded - skipping download
2016/07/12 22:44:36.551340 INFO Agent WALinuxAgent-2.1.5.5 loaded manifest from /var/lib/waagent/WALinuxAgent-2.1.5.5/HandlerManifest.json
2016/07/12 22:44:36.553260 INFO Determined Agent WALinuxAgent-2.1.5.5 to be the latest agent
2016/07/12 22:44:36.706866 INFO Agent WALinuxAgent-2.1.5.5 launched with command 'python -u bin/WALinuxAgent-2.1.5.rc5-py2.7.egg -run-exthandlers'
2016/07/12 22:44:36.801841 INFO Agent WALinuxAgent-2.1.5.5 is running as the current agent
2016/07/12 22:44:36.810830 INFO Event: name=WALinuxAgent, op=, message=Agent WALinuxAgent-2.1.5.5 is running as the current agent
```

Patch:
diff --git a/azurelinuxagent/common/version.py b/azurelinuxagent/common/version.py
index 4f3e5972..d529bb86 100644
--- a/azurelinuxagent/common/version.py
+++ b/azurelinuxagent/common/version.py
@@ -66,6 +66,9 @@ AGENT_NAME_PATTERN = re.compile(AGENT_PATTERN)
 AGENT_DIR_PATTERN = re.compile(".*/{0}".format(AGENT_PATTERN))
 
 
+# Set the CURRENT_AGENT and CURRENT_VERSION to match the agent directory name
+# - This ensures the agent will "see itself" using the same name and version
+#   as the code that downloads agents.
 def set_current_agent():
     path = os.getcwd()
     lib_dir = conf.get_lib_dir()
@@ -80,6 +83,9 @@ def set_current_agent():
     return agent, FlexibleVersion(version)
 CURRENT_AGENT, CURRENT_VERSION = set_current_agent()
 
+def is_current_agent_installed():
+    return CURRENT_AGENT == AGENT_LONG_VERSION
+
 
 __distro__ = get_distro()
 DISTRO_NAME = __distro__[0]
diff --git a/azurelinuxagent/ga/exthandlers.py b/azurelinuxagent/ga/exthandlers.py
index 8ed2f65f..d3c8f329 100644
--- a/azurelinuxagent/ga/exthandlers.py
+++ b/azurelinuxagent/ga/exthandlers.py
@@ -230,7 +230,7 @@ class ExtHandlersHandler(object):
     def report_ext_handlers_status(self):
         """Go thru handler_state dir, collect and report status"""
         vm_status = VMStatus()
-        vm_status.vmAgent.version = AGENT_VERSION
+        vm_status.vmAgent.version = str(CURRENT_VERSION)
         vm_status.vmAgent.status = "Ready"
         vm_status.vmAgent.message = "Guest Agent is running"
 
diff --git a/azurelinuxagent/ga/monitor.py b/azurelinuxagent/ga/monitor.py
index 0ac86d4a..f49cef89 100644
--- a/azurelinuxagent/ga/monitor.py
+++ b/azurelinuxagent/ga/monitor.py
@@ -36,7 +36,8 @@ from azurelinuxagent.common.protocol.restapi import TelemetryEventParam, \
                                                     set_properties
 from azurelinuxagent.common.utils.textutil import parse_doc, findall, find, getattrib
 from azurelinuxagent.common.version import DISTRO_NAME, DISTRO_VERSION, \
-                                            DISTRO_CODE_NAME, AGENT_LONG_VERSION
+                                            DISTRO_CODE_NAME, AGENT_LONG_VERSION, \
+                                            CURRENT_AGENT, CURRENT_VERSION
 
 
 def parse_event(data_str):
@@ -106,7 +107,7 @@ class MonitorHandler(object):
                                                  platform.release())
         self.sysinfo.append(TelemetryEventParam("OSVersion", osversion))
         self.sysinfo.append(
-            TelemetryEventParam("GAVersion", AGENT_LONG_VERSION))
+            TelemetryEventParam("GAVersion", CURRENT_AGENT))
 
         try:
             ram = self.osutil.get_total_mem()
diff --git a/azurelinuxagent/ga/update.py b/azurelinuxagent/ga/update.py
index 749071d6..6dae7aff 100644
--- a/azurelinuxagent/ga/update.py
+++ b/azurelinuxagent/ga/update.py
@@ -44,7 +44,8 @@ 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, \
                                             AGENT_PATTERN, AGENT_NAME_PATTERN, AGENT_DIR_PATTERN, \
-                                            CURRENT_AGENT, CURRENT_VERSION
+                                            CURRENT_AGENT, CURRENT_VERSION, \
+                                            is_current_agent_installed
 
 from azurelinuxagent.ga.exthandlers import HandlerManifest
 
@@ -87,6 +88,7 @@ class UpdateHandler(object):
         self.child_launch_time = None
         self.child_launch_attempts = 0
         self.child_process = None
+
         self.signal_handler = None
         return
 
@@ -98,25 +100,29 @@ class UpdateHandler(object):
         Note:
         - Most events should be tagged to the launched agent (agent_version)
         """
+
+        if self.child_process is not None:
+            raise Exception("Illegal attempt to launch multiple goal state Agent processes")
+
+        if self.signal_handler is None:
+            self.signal_handler = signal.signal(signal.SIGTERM, self.forward_signal)
+
         latest_agent = self.get_latest_agent()
-        if latest_agent == None:
+        if latest_agent is None:
+            logger.info(u"Installed Agent {0} is the most current agent", CURRENT_AGENT)
             agent_cmd = "python -u {0} -run-exthandlers".format(sys.argv[0])
             agent_dir = os.getcwd()
             agent_name = CURRENT_AGENT
             agent_version = CURRENT_VERSION
         else:
+            logger.info(u"Determined Agent {0} to be the latest agent", latest_agent.name)
             agent_cmd = latest_agent.get_agent_cmd()
             agent_dir = latest_agent.get_agent_dir()
             agent_name = latest_agent.name
             agent_version = latest_agent.version
 
-        if self.child_process is not None:
-            raise Exception("Illegal attempt to launch multiple child processes")
-
         try:
 
-            self.signal_handler = signal.signal(signal.SIGTERM, self.forward_signal)
-
             # Launch the correct Python version for python-based agents
             cmds = shlex.split(agent_cmd)
             if cmds[0].lower() == "python":
@@ -131,41 +137,32 @@ class UpdateHandler(object):
                 stdout=sys.stdout,
                 stderr=sys.stderr)
 
-            msg = u"Agent {0} launched with command '{1}'".format(agent_name, agent_cmd)
-            logger.info(msg)
-            add_event(AGENT_NAME, version=agent_version, message=msg)
+            logger.info(u"Agent {0} launched with command '{1}'", agent_name, agent_cmd)
 
             ret = self.child_process.wait()
-            if ret == None:
+            if ret is None:
                 ret = 1
+
+            msg = u"Agent {0} launched with command '{1}' returned code: {2}".format(
+                agent_name,
+                agent_cmd,
+                ret)
+            add_event(
+                AGENT_NAME,
+                version=agent_version,
+                op=WALAEventOperation.Enable,
+                is_success=(ret <= 0),
+                message=msg)
+
             if ret > 0:
-                msg = u"Agent {0} launched with command '{1}' failed with code: {2}".format(
-                    agent_name,
-                    agent_cmd,
-                    ret)
                 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()
             else:
-                msg = u"Agent {0} launched with command '{1}' returned {2}".format(
-                    agent_name,
-                    agent_cmd,
-                    ret)
                 logger.info(msg)
-                add_event(
-                    AGENT_NAME,
-                    version=agent_version,
-                    op=WALAEventOperation.Enable,
-                    is_success=True,
-                    message=msg)
+
         except Exception as e:
-            msg = u"Agent {0} launch failed with command '{1}' failed with exception: {2}".format(
+            msg = u"Agent {0} launched with command '{1}' failed with exception: {2}".format(
                 agent_name,
                 agent_cmd,
                 ustr(e))
@@ -178,14 +175,6 @@ class UpdateHandler(object):
                 message=msg)
             if latest_agent is not None:
                 latest_agent.mark_failure(is_fatal=True)
-                msg = u"Agent {0} is blacklisted".format(agent_name)
-                logger.info(msg)
-                add_event(
-                    AGENT_NAME,
-                    version=agent_version,
-                    op=WALAEventOperation.Enable,
-                    is_success=False,
-                    message=msg)
 
         self.child_process = None
         return
@@ -195,10 +184,7 @@ class UpdateHandler(object):
         This is the main loop which watches for agent and extension updates.
         """
 
-        msg = u"Agent {0} is running as the current agent".format(
-            CURRENT_AGENT)
-        logger.info(msg)
-        add_event(AGENT_NAME, version=CURRENT_VERSION, is_success=True, message=msg)
+        logger.info(u"Agent {0} is running as the goal state agent", CURRENT_AGENT)
 
         # Launch monitoring threads
         from azurelinuxagent.ga.monitor import get_monitor_handler
@@ -213,34 +199,20 @@ class UpdateHandler(object):
         # TODO: Add means to stop running
         try:
             while self.running:
-                # Check for a new agent.
-                # If a new agent exists (that is, ensure_latest_agent returns
-                # true), exit to allow the daemon to respawn using that agent.
                 if self._ensure_latest_agent():
-                    msg = u"Agent {0} discovered agent update and will exit".format(
-                        CURRENT_AGENT)
-                    logger.info(msg)
-                    add_event(
-                        AGENT_NAME,
-                        version=CURRENT_VERSION,
-                        is_success=True,
-                        message=msg)
+                    if len(self.agents) > 0:
+                        logger.info(
+                            u"Agent {0} discovered {1} as an update and will exit",
+                            CURRENT_AGENT,
+                            self.agents[0].name)
                     break
 
-                # Process extensions
                 exthandlers_handler.run()
                 
                 time.sleep(25)
 
         except Exception as e:
-            msg = u"Agent {0} failed with exception: {1}".format(CURRENT_AGENT, ustr(e))
-            logger.warn(msg)
-            add_event(
-                AGENT_NAME,
-                version=CURRENT_VERSION,
-                op=WALAEventOperation.Enable,
-                is_success=False,
-                message=msg)
+            logger.warn(u"Agent {0} failed with exception: {1}", CURRENT_AGENT, ustr(e))
             sys.exit(1)
 
         sys.exit(0)
@@ -250,9 +222,14 @@ class UpdateHandler(object):
         if self.child_process is None:
             return
         
+        logger.info(
+            u"Agent {0} forwarding signal {1} to {2}",
+            CURRENT_AGENT,
+            signum,
+            self.child_agent.name if self.child_agent is not None else CURRENT_AGENT)
         self.child_process.send_signal(signum)
 
-        if not self.signal_handler in (None, signal.SIG_IGN, signal.SIG_DFL):
+        if self.signal_handler not in (None, signal.SIG_IGN, signal.SIG_DFL):
             self.signal_handler(signum, frame)
         elif self.signal_handler is signal.SIG_DFL:
             if signum == signal.SIGTERM:
@@ -286,6 +263,9 @@ class UpdateHandler(object):
         if next_attempt_time > now:
             return False
 
+        family = conf.get_autoupdate_gafamily()
+        logger.info("Checking for agent family {0} updates", family)
+
         self.last_attempt_time = now
         try:
             protocol = self.protocol_util.get_protocol()
@@ -295,43 +275,39 @@ class UpdateHandler(object):
             logger.warn(msg)
             add_event(
                 AGENT_NAME,
+                op=WALAEventOperation.Download,
                 version=CURRENT_VERSION,
                 is_success=False,
                 message=msg)
             return False
 
         if self.last_etag is not None and self.last_etag == etag:
-            msg = u"Incarnation {0} has no agent updates".format(etag)
-            logger.info(msg)
-            add_event(AGENT_NAME, version=CURRENT_VERSION, message=msg)
+            logger.info(u"Incarnation {0} has no agent updates", etag)
             return False
 
-        logger.info("Check for agent updates")
-
-        family = conf.get_autoupdate_gafamily()
         manifests = [m for m in manifest_list.vmAgentManifests if m.family == family]
         if len(manifests) == 0:
-            msg = u"Incarnation {0} has no agent family {1} updates".format(etag, family)
-            logger.info(msg)
-            add_event(AGENT_NAME, version=CURRENT_VERSION, message=msg)
+            logger.info(u"Incarnation {0} has no agent family {1} updates", etag, family)
             return False
 
         try:
             pkg_list = protocol.get_vmagent_pkgs(manifests[0])
         except ProtocolError as e:
-            msg= u"Incarnation {0} failed to get {1} package list: {1}".format(etag,
-                                                                               family,
-                                                                               ustr(e))
+            msg= u"Incarnation {0} failed to get {1} package list: {2}".format(
+                etag,
+                family,
+                ustr(e))
             logger.warn(msg)
             add_event(
                 AGENT_NAME,
+                op=WALAEventOperation.Download,
                 version=CURRENT_VERSION,
                 is_success=False,
                 message=msg)
             return False
 
         # Set the agents to those available for download at least as current as the existing agent
-        # and remove from disk any agent no longer report to the VM.
+        # and remove from disk any agent no longer reported to the VM.
         # Note:
         #  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.
@@ -350,6 +326,7 @@ class UpdateHandler(object):
         too frequently, raise an Exception to force blacklisting.
         """
         if latest_agent is None:
+            self.child_agent = None
             return
 
         if self.child_agent is None or latest_agent.version != self.child_agent.version:
@@ -386,12 +363,7 @@ class UpdateHandler(object):
                                     for agent_dir in glob.iglob(path) if os.path.isdir(agent_dir)])
                 self._filter_blacklisted_agents()
             except Exception as e:
-                msg = u"Exception occurred loading available agents: {0}".format(ustr(e))
-                add_event(
-                    AGENT_NAME,
-                    version=CURRENT_VERSION,
-                    is_success=False,
-                    message=msg)
+                logger.warn(u"Exception occurred loading available agents: {0}", ustr(e))
         return
 
     def _purge_agents(self):
@@ -400,25 +372,27 @@ class UpdateHandler(object):
         (without removing the current, running agent).
         """
         path = os.path.join(conf.get_lib_dir(), "{0}-*".format(AGENT_NAME))
+
         known_versions = [agent.version for agent in self.agents]
-        known_versions.append(CURRENT_VERSION)
+        if not is_current_agent_installed() and CURRENT_VERSION not in known_versions:
+            logger.warn(
+                u"Running Agent {0} was not found in the agent manifest - adding to list",
+                CURRENT_VERSION)
+            known_versions.append(CURRENT_VERSION)
+
         for agent_path in glob.iglob(path):
             try:
                 name = fileutil.trim_ext(agent_path, "zip")
                 m = AGENT_DIR_PATTERN.match(name)
-                if m is not None and not FlexibleVersion(m.group(1)) in known_versions:
+                if m is not None and FlexibleVersion(m.group(1)) not in known_versions:
                     if os.path.isfile(agent_path):
+                        logger.info(u"Purging outdated Agent file {0}", agent_path)
                         os.remove(agent_path)
                     else:
+                        logger.info(u"Purging outdated Agent directory {0}", agent_path)
                         shutil.rmtree(agent_path)
             except Exception as e:
-                msg = u"Exception purging {0}: {1}".format(agent_path, ustr(e))
-                logger.warn(msg)
-                add_event(
-                    AGENT_NAME,
-                    version=CURRENT_VERSION,
-                    is_success=False,
-                    message=msg)
+                logger.warn(u"Purging {0} raised exception: {1}", agent_path, ustr(e))
         return
 
     def _set_agents(self, agents=[]):
@@ -430,6 +404,7 @@ class UpdateHandler(object):
 class GuestAgent(object):
     def __init__(self, path=None, pkg=None):
         self.pkg = pkg
+        version = None
         if path is not None:
             m = AGENT_DIR_PATTERN.match(path)
             if m == None:
@@ -442,9 +417,13 @@ class GuestAgent(object):
             raise UpdateError(u"Illegal agent version: {0}".format(version))
         self.version = FlexibleVersion(version)
 
+        location = u"disk" if path is not None else u"package"
+        logger.info(u"Instantiating Agent {0} from {1}", self.name, location)
+
         self.error = None
         self._load_error()
         self._ensure_downloaded()
+        return
 
     @property
     def name(self):
@@ -479,33 +458,30 @@ class GuestAgent(object):
 
     @property
     def is_downloaded(self):
-        return os.path.isfile(self.get_agent_manifest_path())
+        return self.is_blacklisted or os.path.isfile(self.get_agent_manifest_path())
 
     def mark_failure(self, is_fatal=False):
         try:
             if not os.path.isdir(self.get_agent_dir()):
                 os.makedirs(self.get_agent_dir())
-            self.error.mark_failure(is_fatal)
+            self.error.mark_failure(is_fatal=is_fatal)
             self.error.save()
             if is_fatal:
-                msg = u"Agent {0} is permanently blacklisted".format(self.name)
-                logger.warn(msg)
-                add_event(AGENT_NAME, version=self.version, is_success=False, message=msg)
+                logger.warn(u"Agent {0} is permanently blacklisted", self.name)
         except Exception as e:
-            msg = u"Agent {0} failed recording error state: {1}".format(ustr(e))
-            logger.warn(msg)
-            add_event(AGENT_NAME, version=self.version, is_success=False, message=msg)
+            logger.warn(u"Agent {0} failed recording error state: {1}", ustr(e))
         return
 
     def _ensure_downloaded(self):
         try:
+            logger.info(u"Ensuring Agent {0} is downloaded", self.name)
+
             if self.is_blacklisted:
-                msg = u"Agent {0} is blacklisted - skipping download".format(self.name)
-                logger.info(msg)
-                add_event(AGENT_NAME, version=self.version, is_success=True, message=msg)
+                logger.info(u"Agent {0} is blacklisted - skipping download", self.name)
                 return
 
             if self.is_downloaded:
+                logger.info(u"Agent {0} was previously downloaded - skipping download", self.name)
                 self._load_manifest()
                 return
 
@@ -544,9 +520,6 @@ class GuestAgent(object):
         return
 
     def _download(self):
-        msg = u"Initiating download of Agent {0}".format(self.name)
-        logger.info(msg)
-        add_event(AGENT_NAME, version=self.version, message=msg)
         package = None
 
         for uri in self.pkg.uris:
@@ -555,14 +528,19 @@ class GuestAgent(object):
                 if resp.status == restutil.httpclient.OK:
                     package = resp.read()
                     fileutil.write_file(self.get_agent_pkg_path(), bytearray(package), asbin=True)
+                    logger.info(u"Agent {0} downloaded from {1}", self.name, uri.uri)
                     break
             except restutil.HttpError as e:
-                msg = u"Agent {0} download from {1} failed".format(self.name, uri.uri)
-                logger.warn(msg)
-                add_event(AGENT_NAME, version=self.version, is_success=False, message=msg)
+                logger.warn(u"Agent {0} download from {1} failed", self.name, uri.uri)
 
         if not os.path.isfile(self.get_agent_pkg_path()):
             msg = u"Unable to download Agent {0} from any URI".format(self.name)
+            add_event(
+                AGENT_NAME,
+                op=WALAEventOperation.Download,
+                version=CURRENT_VERSION,
+                is_success=False,
+                message=msg)
             raise UpdateError(msg)
         return
 
@@ -571,15 +549,12 @@ class GuestAgent(object):
             if self.error is None:
                 self.error = GuestAgentError(self.get_agent_error_file())
             self.error.load()
+            logger.info(u"Agent {0} error state: {1}", self.name, ustr(self.error))
         except Exception as e:
-            msg = u"Agent {0} failed loading error state: {1}".format(ustr(e))
-            logger.warn(msg)
-            add_event(AGENT_NAME, version=self.version, is_success=False, message=msg)
+            logger.warn(u"Agent {0} failed loading error state: {1}", self.name, ustr(e))
         return
 
     def _load_manifest(self):
-        logger.info(u"Loading Agent manifest from {0}", self.get_agent_manifest_path())
-
         path = self.get_agent_manifest_path()
         if not os.path.isfile(path):
             msg = u"Agent {0} is missing the {1} file".format(self.name, AGENT_MANIFEST_FILE)
@@ -610,6 +585,10 @@ class GuestAgent(object):
                 ustr(e))
             raise UpdateError(msg)
 
+        logger.info(
+            u"Agent {0} loaded manifest from {1}",
+            self.name,
+            self.get_agent_manifest_path())
         logger.verbose(u"Successfully loaded Agent {0} {1}: {2}",
             self.name,
             AGENT_MANIFEST_FILE,
@@ -617,13 +596,12 @@ class GuestAgent(object):
         return
 
     def _unpack(self):
-        logger.info(u"Unpacking agent package {0}", self.name)
-
         try:
             if os.path.isdir(self.get_agent_dir()):
                 shutil.rmtree(self.get_agent_dir())
 
             zipfile.ZipFile(self.get_agent_pkg_path()).extractall(self.get_agent_dir())
+
         except Exception as e:
             msg = u"Exception unpacking Agent {0} from {1}: {2}".format(
                 self.name,
@@ -633,13 +611,14 @@ class GuestAgent(object):
 
         if not os.path.isdir(self.get_agent_dir()):
             msg = u"Unpacking Agent {0} failed to create directory {1}".format(
-                        self.name,
-                        self.get_agent_dir())
+                self.name,
+                self.get_agent_dir())
             raise UpdateError(msg)
 
-        msg = u"Agent {0} successfully unpacked".format(self.name)
-        logger.info(msg)
-        add_event(AGENT_NAME, version=self.version, message=msg)
+        logger.info(
+            u"Agent {0} unpacked successfully to {1}",
+            self.name,
+            self.get_agent_dir())
         return
 
 
@@ -705,3 +684,9 @@ class GuestAgentError(object):
             u"was_fatal" : self.was_fatal
         }  
         return data
+
+    def __str__(self):
+        return "Last Failure: {0}, Total Failures: {1}, Fatal: {2}".format(
+            self.last_failure,
+            self.failure_count,
+            self.was_fatal)


Test patch:
diff --git a/tests/ga/test_update.py b/tests/ga/test_update.py
index 36241b16..49006606 100644
--- a/tests/ga/test_update.py
+++ b/tests/ga/test_update.py
@@ -134,6 +134,16 @@ class UpdateTestCase(AgentTestCase):
         v.sort(reverse=True)
         return v
 
+    def get_error_file(self, error_data=NO_ERROR):
+        fp = tempfile.NamedTemporaryFile(mode="w")
+        json.dump(error_data if error_data is not None else NO_ERROR, fp)
+        fp.seek(0)
+        return fp
+
+    def create_error(self, error_data=NO_ERROR):
+        with self.get_error_file(error_data) as path:
+            return GuestAgentError(path.name)
+
     def copy_agents(self, *agents):
         if len(agents) <= 0:
             agents = get_agent_pkgs()
@@ -206,16 +216,6 @@ class UpdateTestCase(AgentTestCase):
 
 
 class TestGuestAgentError(UpdateTestCase):
-    def get_error_file(self, error_data=NO_ERROR):
-        fp = tempfile.NamedTemporaryFile(mode="w")
-        json.dump(error_data if error_data is not None else NO_ERROR, fp)
-        fp.seek(0)
-        return fp
-
-    def create_error(self, error_data=NO_ERROR):
-        with self.get_error_file(error_data) as path:
-            return GuestAgentError(path.name)
-
     def test_creation(self):
         self.assertRaises(TypeError, GuestAgentError)
         self.assertRaises(UpdateError, GuestAgentError, None)
@@ -297,6 +297,22 @@ class TestGuestAgentError(UpdateTestCase):
         self.assertTrue(err.failure_count < MAX_FAILURE)
         return
 
+    def test_str(self):
+        err = self.create_error(error_data=NO_ERROR)
+        s = "Last Failure: {0}, Total Failures: {1}, Fatal: {2}".format(
+            NO_ERROR["last_failure"],
+            NO_ERROR["failure_count"],
+            NO_ERROR["was_fatal"])
+        self.assertEqual(s, str(err))
+
+        err = self.create_error(error_data=WITH_ERROR)
+        s = "Last Failure: {0}, Total Failures: {1}, Fatal: {2}".format(
+            WITH_ERROR["last_failure"],
+            WITH_ERROR["failure_count"],
+            WITH_ERROR["was_fatal"])
+        self.assertEqual(s, str(err))
+        return
+
 
 class TestGuestAgent(UpdateTestCase):
     def setUp(self):
@@ -331,7 +347,9 @@ class TestGuestAgent(UpdateTestCase):
         path = ".".join((os.path.join(conf.get_lib_dir(), get_agent_name()), "zip"))
         self.assertEqual(path, agent.get_agent_pkg_path())
 
-        self.assertFalse(agent.is_downloaded)
+        self.assertTrue(agent.is_downloaded)
+        # Note: Agent will get blacklisted since the package for this test is invalid
+        self.assertTrue(agent.is_blacklisted)
         self.assertFalse(agent.is_available)
         return
 
@@ -455,6 +473,14 @@ class TestGuestAgent(UpdateTestCase):
         self.assertRaises(UpdateError, agent._load_manifest)
         return
 
+    def test_load_error(self):
+        agent = GuestAgent(path=self.agent_path)
+        agent.error = None
+
+        agent._load_error()
+        self.assertTrue(agent.error is not None)
+        return
+
     @patch("azurelinuxagent.ga.update.GuestAgent._ensure_downloaded")
     @patch("azurelinuxagent.ga.update.restutil.http_get")
     def test_download(self, mock_http_get, mock_ensure):
@@ -575,6 +601,22 @@ class TestUpdate(UpdateTestCase):
         self.update_handler = get_update_handler()
         return
 
+    def test_creation(self):
+        self.assertTrue(self.update_handler.running)
+
+        self.assertEqual(None, self.update_handler.last_etag)
+        self.assertEqual(None, self.update_handler.last_attempt_time)
+
+        self.assertEqual(0, len(self.update_handler.agents))
+
+        self.assertEqual(None, self.update_handler.child_agent)
+        self.assertEqual(None, self.update_handler.child_launch_time)
+        self.assertEqual(0, self.update_handler.child_launch_attempts)
+        self.assertEqual(None, self.update_handler.child_process)
+
+        self.assertEqual(None, self.update_handler.signal_handler)
+        return
+
     def _test_ensure_latest_agent(
             self,
             base_version=FlexibleVersion(AGENT_VERSION),
@@ -914,6 +956,19 @@ class TestUpdate(UpdateTestCase):
         self.assertEqual(1, latest_agent.error.failure_count)
         return
 
+    @patch('signal.signal')
+    def test_run_latest_captures_signals(self, mock_signal):
+        self._test_run_latest()
+        self.assertEqual(1, mock_signal.call_count)
+        return
+
+    @patch('signal.signal')
+    def test_run_latest_creates_only_one_signal_handler(self, mock_signal):
+        self.update_handler.signal_handler = "Not None"
+        self._test_run_latest()
+        self.assertEqual(0, mock_signal.call_count)
+        return
+
     def _test_run(self, invocations=1, calls=[call.run()], enable_updates=False):
         conf.get_autoupdate_enabled = Mock(return_value=enable_updates)