Repository: Azure/WALinuxAgent
Pull request #809 (2017-07-21 21:52:42)

[#807] -- The agent should not emit duplicate events
Signed-off-by: Brendan Dixon <brendandixon@me.com>


Patch:
diff --git a/azurelinuxagent/common/event.py b/azurelinuxagent/common/event.py
index 723b8bff..5e63f5e4 100644
--- a/azurelinuxagent/common/event.py
+++ b/azurelinuxagent/common/event.py
@@ -27,6 +27,7 @@ import platform
 
 from datetime import datetime, timedelta
 
+import azurelinuxagent.common.conf as conf
 import azurelinuxagent.common.logger as logger
 
 from azurelinuxagent.common.exception import EventError, ProtocolError
@@ -43,6 +44,7 @@ _EVENT_MSG = "Event: name={0}, op={1}, message={2}"
 
 class WALAEventOperation:
     ActivateResourceDisk = "ActivateResourceDisk"
+    AutoUpdate = "AutoUpdate"
     Disable = "Disable"
     Download = "Download"
     Enable = "Enable"
@@ -60,6 +62,58 @@ class WALAEventOperation:
     Upgrade = "Upgrade"
     Update = "Update"
 
+
+class EventStatus(object):
+    EVENT_STATUS_FILE = "event_status.json"
+
+    def __init__(self, status_dir=conf.get_lib_dir()):
+        self._path = os.path.join(status_dir, EventStatus.EVENT_STATUS_FILE)
+        self._load()
+
+    def clear(self):
+        self.status = {}
+        self._save()
+
+    def event_marked(self, name, version, op):
+        return self._event_name(name, version, op) in self.status
+
+    def event_succeeded(self, name, version, op):
+        event = self._event_name(name, version, op)
+        if event not in self.status:
+            return True
+        return self.status[event] == True
+
+    def mark_event_status(self, name, version, op, status):
+        event = self._event_name(name, version, op)
+        self.status[event] = (status == True)
+        self._save()
+
+    def _event_name(self, name, version, op):
+        return "{0}-{1}-{2}".format(name, version, op)
+
+    def _load(self):
+        try:
+            self.status = {}
+            if os.path.isfile(self._path):
+                with open(self._path, 'r') as f:
+                    self.status = json.load(f)
+        except Exception as e:
+            logger.warn("Exception occurred loading event status: {0}".format(e))
+            self.status = {}
+
+    def _save(self):
+        try:
+            with open(self._path, 'w') as f:
+                json.dump(self.status, f)
+        except Exception as e:
+            logger.warn("Exception occurred saving event status: {0}".format(e))
+
+__event_status__ = EventStatus()
+__event_status_operations__ = [
+        WALAEventOperation.AutoUpdate,
+        WALAEventOperation.ReportStatus
+    ]
+
 def _log_event(name, op, message, is_success=True):
     global _EVENT_MSG
 
@@ -180,10 +234,12 @@ def add_event(name, op="", is_success=True, duration=0, version=CURRENT_VERSION,
         _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)
+    if should_emit_event(name, version, op, is_success):
+        mark_event_status(name, version, op, is_success)
+        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,
@@ -199,6 +255,17 @@ def add_periodic(
         version=str(version), message=message, evt_type=evt_type,
         is_internal=is_internal, log_event=log_event, force=force)
 
+def mark_event_status(name, version, op, status):
+    if op in __event_status_operations__:
+        __event_status__.mark_event_status(name, version, op, status)
+
+def should_emit_event(name, version, op, status):
+    return \
+        op not in __event_status_operations__ or \
+        __event_status__ is None or \
+        not __event_status__.event_marked(name, version, op) or \
+        __event_status__.event_succeeded(name, version, op) != status
+
 def init_event_logger(event_dir, reporter=__event_logger__):
     reporter.event_dir = event_dir
 
diff --git a/azurelinuxagent/ga/monitor.py b/azurelinuxagent/ga/monitor.py
index dcfd6a4c..f0bd4e43 100644
--- a/azurelinuxagent/ga/monitor.py
+++ b/azurelinuxagent/ga/monitor.py
@@ -37,7 +37,7 @@ from azurelinuxagent.common.protocol.restapi import TelemetryEventParam, \
 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, \
-                                            CURRENT_AGENT, CURRENT_VERSION
+                                            AGENT_NAME, CURRENT_VERSION
 
 
 def parse_event(data_str):
@@ -184,9 +184,9 @@ class MonitorHandler(object):
             if datetime.datetime.utcnow() >= (last_heartbeat + period):
                 last_heartbeat = datetime.datetime.utcnow()
                 add_event(
-                    op=WALAEventOperation.HeartBeat,
-                    name=CURRENT_AGENT,
+                    name=AGENT_NAME,
                     version=CURRENT_VERSION,
+                    op=WALAEventOperation.HeartBeat,
                     is_success=True)
             try:
                 self.collect_and_send_events()
diff --git a/azurelinuxagent/ga/update.py b/azurelinuxagent/ga/update.py
index 549ac6bf..39109eda 100644
--- a/azurelinuxagent/ga/update.py
+++ b/azurelinuxagent/ga/update.py
@@ -348,6 +348,15 @@ class UpdateHandler(object):
         return
 
     def _upgrade_available(self, base_version=CURRENT_VERSION):
+        # Emit an event expressing the state of AutoUpdate
+        # Note:
+        # - Duplicate events get suppressed; state transitions always emit
+        add_event(
+            AGENT_NAME,
+            version=CURRENT_VERSION,
+            op=WALAEventOperation.AutoUpdate,
+            is_success=conf.get_autoupdate_enabled())
+
         # Ignore new agents if updating is disabled
         if not conf.get_autoupdate_enabled():
             return False
@@ -705,7 +714,7 @@ class GuestAgent(object):
 
     @property
     def _is_optional(self):
-        return self.error.is_sentinel and self.supported.is_supported
+        return self.error is not None and self.error.is_sentinel and self.supported.is_supported
 
     @property
     def _in_slice(self):


Test patch:
diff --git a/tests/common/test_event.py b/tests/common/test_event.py
index a485edf4..d6710578 100644
--- a/tests/common/test_event.py
+++ b/tests/common/test_event.py
@@ -22,7 +22,8 @@ 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.event import init_event_logger, add_event, \
+                                    mark_event_status, should_emit_event
 from azurelinuxagent.common.future import ustr
 from azurelinuxagent.common.version import CURRENT_VERSION
 
@@ -30,6 +31,79 @@ from tests.tools import *
 
 
 class TestEvent(AgentTestCase):
+    def test_event_status_event_marked(self):
+        d = tempfile.mkdtemp()
+        es = event.EventStatus(d)
+
+        self.assertFalse(es.event_marked("Foo", "1.2", "FauxOperation"))
+        es.mark_event_status("Foo", "1.2", "FauxOperation", True)
+        self.assertTrue(es.event_marked("Foo", "1.2", "FauxOperation"))
+
+        es = event.EventStatus(d)
+        self.assertTrue(es.event_marked("Foo", "1.2", "FauxOperation"))
+
+    def test_event_status_defaults_to_success(self):
+        es = event.EventStatus(tempfile.mkdtemp())
+        self.assertTrue(es.event_succeeded("Foo", "1.2", "FauxOperation"))
+
+    def test_event_status_records_status(self):
+        d = tempfile.mkdtemp()
+        es = event.EventStatus(tempfile.mkdtemp())
+
+        es.mark_event_status("Foo", "1.2", "FauxOperation", True)
+        self.assertTrue(es.event_succeeded("Foo", "1.2", "FauxOperation"))
+
+        es.mark_event_status("Foo", "1.2", "FauxOperation", False)
+        self.assertFalse(es.event_succeeded("Foo", "1.2", "FauxOperation"))
+
+    def test_event_status_preserves_state(self):
+        d = tempfile.mkdtemp()
+        es = event.EventStatus(d)
+
+        es.mark_event_status("Foo", "1.2", "FauxOperation", False)
+        self.assertFalse(es.event_succeeded("Foo", "1.2", "FauxOperation"))
+
+        es = event.EventStatus(d)
+        self.assertFalse(es.event_succeeded("Foo", "1.2", "FauxOperation"))
+
+    def test_should_emit_event_ignores_unknown_operations(self):
+        event.__event_status__ = event.EventStatus(tempfile.mkdtemp())
+
+        self.assertTrue(event.should_emit_event("Foo", "1.2", "FauxOperation", True))
+        self.assertTrue(event.should_emit_event("Foo", "1.2", "FauxOperation", False))
+
+        # Marking the event has no effect
+        event.mark_event_status("Foo", "1.2", "FauxOperation", True)
+
+        self.assertTrue(event.should_emit_event("Foo", "1.2", "FauxOperation", True))
+        self.assertTrue(event.should_emit_event("Foo", "1.2", "FauxOperation", False))
+
+
+    def test_should_emit_event_handles_known_operations(self):
+        event.__event_status__ = event.EventStatus(tempfile.mkdtemp())
+
+        # Known operations always initially "fire"
+        for op in event.__event_status_operations__:
+            self.assertTrue(event.should_emit_event("Foo", "1.2", op, True))
+            self.assertTrue(event.should_emit_event("Foo", "1.2", op, False))
+
+        # Note a success event...
+        for op in event.__event_status_operations__:
+            event.mark_event_status("Foo", "1.2", op, True)
+
+        # Subsequent success events should not fire, but failures will
+        for op in event.__event_status_operations__:
+            self.assertFalse(event.should_emit_event("Foo", "1.2", op, True))
+            self.assertTrue(event.should_emit_event("Foo", "1.2", op, False))
+
+        # Note a failure event...
+        for op in event.__event_status_operations__:
+            event.mark_event_status("Foo", "1.2", op, False)
+
+        # Subsequent success events fire and failure do not
+        for op in event.__event_status_operations__:
+            self.assertTrue(event.should_emit_event("Foo", "1.2", op, True))
+            self.assertFalse(event.should_emit_event("Foo", "1.2", op, False))
 
     @patch('azurelinuxagent.common.event.EventLogger.add_event')
     def test_periodic_emits_if_not_previously_sent(self, mock_event):