Repository: Azure/WALinuxAgent

Issue:
InitializeHostPlugin
This event is useful, but we should also have an extended version, like we do for ReportStatus. There is a good location for this in the [monitor thread](https://github.com/Azure/WALinuxAgent/blob/master/azurelinuxagent/ga/monitor.py#L335)

Discussion:

Patch:
diff --git a/azurelinuxagent/common/errorstate.py b/azurelinuxagent/common/errorstate.py
index 38aaa1f9..052db075 100644
--- a/azurelinuxagent/common/errorstate.py
+++ b/azurelinuxagent/common/errorstate.py
@@ -31,3 +31,15 @@ class ErrorState(object):
             return True
 
         return False
+
+    @property
+    def fail_time(self):
+        if self.timestamp is None:
+            return 'unknown'
+
+        delta = round((datetime.utcnow() - self.timestamp).seconds / 60.0, 2)
+        if delta < 60:
+            return '{0} min'.format(delta)
+
+        delta_hr = round(delta / 60.0, 2)
+        return '{0} hr'.format(delta_hr)
diff --git a/azurelinuxagent/common/event.py b/azurelinuxagent/common/event.py
index 71723d45..4852bb37 100644
--- a/azurelinuxagent/common/event.py
+++ b/azurelinuxagent/common/event.py
@@ -58,6 +58,7 @@ class WALAEventOperation:
     HeartBeat = "HeartBeat"
     HostPlugin = "HostPlugin"
     HostPluginHeartbeat = "HostPluginHeartbeat"
+    HostPluginHeartbeatExtended = "HostPluginHeartbeatExtended"
     HttpErrors = "HttpErrors"
     ImdsHeartbeat = "ImdsHeartbeat"
     Install = "Install"
diff --git a/azurelinuxagent/ga/monitor.py b/azurelinuxagent/ga/monitor.py
index e28d7321..c1215806 100644
--- a/azurelinuxagent/ga/monitor.py
+++ b/azurelinuxagent/ga/monitor.py
@@ -336,6 +336,15 @@ class MonitorHandler(object):
 
                 self.health_service.report_host_plugin_heartbeat(is_healthy)
 
+                if not is_healthy:
+                    add_event(
+                        name=AGENT_NAME,
+                        version=CURRENT_VERSION,
+                        op=WALAEventOperation.HostPluginHeartbeatExtended,
+                        is_success=False,
+                        message='{0} since successful heartbeat'.format(self.host_plugin_errorstate.fail_time),
+                        log_event=False)
+
             except Exception as e:
                 msg = "Exception sending host plugin heartbeat: {0}".format(ustr(e))
                 add_event(


Test patch:
diff --git a/tests/common/test_errorstate.py b/tests/common/test_errorstate.py
index 7513fe59..a0a7761d 100644
--- a/tests/common/test_errorstate.py
+++ b/tests/common/test_errorstate.py
@@ -12,6 +12,7 @@ class TestErrorState(unittest.TestCase):
         test_subject = ErrorState(timedelta(seconds=10000))
         self.assertFalse(test_subject.is_triggered())
         self.assertEqual(0, test_subject.count)
+        self.assertEqual('unknown', test_subject.fail_time)
 
     def test_errorstate01(self):
         """
@@ -21,6 +22,7 @@ class TestErrorState(unittest.TestCase):
         test_subject = ErrorState(timedelta(seconds=0))
         self.assertFalse(test_subject.is_triggered())
         self.assertEqual(0, test_subject.count)
+        self.assertEqual('unknown', test_subject.fail_time)
 
     def test_errorstate02(self):
         """
@@ -30,9 +32,9 @@ class TestErrorState(unittest.TestCase):
         test_subject = ErrorState(timedelta(seconds=0))
         test_subject.incr()
 
-
         self.assertTrue(test_subject.is_triggered())
         self.assertEqual(1, test_subject.count)
+        self.assertEqual('0.0 min', test_subject.fail_time)
 
     @patch('azurelinuxagent.common.errorstate.datetime')
     def test_errorstate03(self, mock_time):
@@ -52,6 +54,7 @@ class TestErrorState(unittest.TestCase):
         mock_time.utcnow = Mock(return_value=datetime.utcnow() + timedelta(minutes=30))
         test_subject.incr()
         self.assertTrue(test_subject.is_triggered())
+        self.assertEqual('29.0 min', test_subject.fail_time)
 
     def test_errorstate04(self):
         """
@@ -67,3 +70,35 @@ class TestErrorState(unittest.TestCase):
 
         test_subject.reset()
         self.assertTrue(test_subject.timestamp is None)
+
+    def test_errorstate05(self):
+        """
+        Test the fail_time for various scenarios
+        """
+
+        test_subject = ErrorState(timedelta(minutes=15))
+        self.assertEqual('unknown', test_subject.fail_time)
+
+        test_subject.incr()
+        self.assertEqual('0.0 min', test_subject.fail_time)
+
+        test_subject.timestamp = datetime.utcnow() - timedelta(seconds=60)
+        self.assertEqual('1.0 min', test_subject.fail_time)
+
+        test_subject.timestamp = datetime.utcnow() - timedelta(seconds=73)
+        self.assertEqual('1.22 min', test_subject.fail_time)
+
+        test_subject.timestamp = datetime.utcnow() - timedelta(seconds=120)
+        self.assertEqual('2.0 min', test_subject.fail_time)
+
+        test_subject.timestamp = datetime.utcnow() - timedelta(seconds=60 * 59)
+        self.assertEqual('59.0 min', test_subject.fail_time)
+
+        test_subject.timestamp = datetime.utcnow() - timedelta(seconds=60 * 60)
+        self.assertEqual('1.0 hr', test_subject.fail_time)
+
+        test_subject.timestamp = datetime.utcnow() - timedelta(seconds=60 * 95)
+        self.assertEqual('1.58 hr', test_subject.fail_time)
+
+        test_subject.timestamp = datetime.utcnow() - timedelta(seconds=60 * 60 * 3)
+        self.assertEqual('3.0 hr', test_subject.fail_time)
diff --git a/tests/ga/test_monitor.py b/tests/ga/test_monitor.py
index 5d53b1e7..4bcc1da4 100644
--- a/tests/ga/test_monitor.py
+++ b/tests/ga/test_monitor.py
@@ -201,4 +201,18 @@ class TestMonitor(AgentTestCase):
         monitor_handler.last_host_plugin_heartbeat = datetime.datetime.utcnow() - timedelta(hours=1)
         monitor_handler.send_host_plugin_heartbeat()
         self.assertEqual(1, patch_report_heartbeat.call_count)
+        self.assertEqual(0, args[5].call_count)
+        monitor_handler.stop()
+
+    @patch('azurelinuxagent.common.errorstate.ErrorState.is_triggered', return_value=True)
+    @patch("azurelinuxagent.common.protocol.healthservice.HealthService.report_host_plugin_heartbeat")
+    def test_failed_heartbeat_creates_telemetry(self, patch_report_heartbeat, _, *args):
+        monitor_handler = get_monitor_handler()
+        monitor_handler.init_protocols()
+        monitor_handler.last_host_plugin_heartbeat = datetime.datetime.utcnow() - timedelta(hours=1)
+        monitor_handler.send_host_plugin_heartbeat()
+        self.assertEqual(1, patch_report_heartbeat.call_count)
+        self.assertEqual(1, args[5].call_count)
+        self.assertEqual('HostPluginHeartbeatExtended', args[5].call_args[1]['op'])
+        self.assertEqual(False, args[5].call_args[1]['is_success'])
         monitor_handler.stop()