Health store integration #1196

hglkrijger · 2018-05-31T22:02:20Z

The intent of this work is to add health signals for the host channel, which we can use to monitor PF rollouts. The following signals are in place:

GuestAgentPluginHeartbeat

monitors the host plugin process is alive by calling /health
check every 1m, send every 1m, failure > 5m unhealthy

{
  "Version": "1.0",
  "Observations": [
    {
      "IsHealthy": true,
      "Description": "",
      "Value": "",
      "ObservationName": "GuestAgentPluginHeartbeat"
    }
  ],
  "Api": "reporttargethealth",
  "Source": "WALinuxAgent"
}

GuestAgentPluginVersions

monitors the host plugin channel is available by calling /versions
determine health on usage (process start), send immediately, no failure rollup

{
  "Version": "1.0",
  "Observations": [
    {
      "Description": "",
      "Value": "",
      "IsHealthy": true,
      "ObservationName": "GuestAgentPluginVersions"
    }
  ],
  "Api": "reporttargethealth",
  "Source": "WALinuxAgent"
}

GuestAgentPluginArtifact

monitors the /extensionArtifact api
failure is determined by status codes 5xx, except 502, which is an upstream failure
determine health on usage (extension/manifest/agent download), send every 1m, failure > 5m unhealthy
we fetch for the purpose of extension handling (WireClient) and agent updates (GuestAgent), and may want to distinguish between these signals, so the source is listed in the Description field
WireClient:

{
  "Version": "1.0",
  "Observations": [
    {
      "IsHealthy": true,
      "Description": "WireClient",
      "Value": "",
      "ObservationName": "GuestAgentPluginArtifact"
    }
  ],
  "Api": "reporttargethealth",
  "Source": "WALinuxAgent"
}

GuestAgent:

{
  "Version": "1.0",
  "Observations": [
    {
      "IsHealthy": true,
      "Description": "GuestAgent",
      "Value": "",
      "ObservationName": "GuestAgentPluginArtifact"
    }
  ],
  "Api": "reporttargethealth",
  "Source": "WALinuxAgent"
}

GuestAgentPluginStatus

monitors the /status api
failure is determined by status codes 5xx, except 502, which is an upstream failure
check every goal_state_interval (3s), send every 1m, failure > 5m unhealthy

{
  "Api": "reporttargethealth",
  "Observations": [
    {
      "Value": "",
      "ObservationName": "GuestAgentPluginStatus",
      "Description": "",
      "IsHealthy": true
    }
  ],
  "Version": "1.0",
  "Source": "WALinuxAgent"
}

Observations are reported to http://{wireserver_ip}:80/HealthService

Additional changes

removed 400s from the ResourceGoneError; this is legacy host plugin behavior which has since been fixed
switched extension package downloads from the base handler to client fetch, to simplify number of changes
updated the logging prefix to ExtHandler, for brevity
removed enable events from the logs, for clarity
updated tests accordingly

boumenot · 2018-06-04T21:12:13Z

azurelinuxagent/common/utils/restutil.py

@@ -62,6 +61,10 @@
    httpclient.ACCEPTED
 ]

+UPSTREAM_FAILURE_CODES = [


HOSTPLUGIN_UPSTREAM_FAILURE_CODES ?

boumenot · 2018-06-04T21:20:16Z

azurelinuxagent/ga/exthandlers.py

@@ -1117,7 +1113,7 @@ def set_handler_status(self, status="NotReady", message="", code=0):
        except (IOError, ValueError, ProtocolError) as e:
            fileutil.clean_ioerror(e,
                paths=[status_file])
-            self.logger.error("Failed to save handler status: {0}", traceback.format_exc())
+            self.logger.error("Failed to save handler status: {0}", ustr(e))


ustr(e) [](start = 67, length = 8)

The traceback was valuable in locating the cause. I would not remove it.

I removed this because I found that it was not populated, due to the way the threads work. Are you sure this specific one was useful? If so I can add it back.

Well, crap. Now you're fighting my memory, and I only half trust it. I thought this was a code path where the traceback was used to diagnose a failure. Your mind is fresh. If you think it is useless, please remove it.

There is no harm in having both - I will add it back along with the error message, in case I missed something.

boumenot · 2018-06-04T21:51:12Z

azurelinuxagent/ga/monitor.py

+
+        if datetime.datetime.utcnow() < (last_host_plugin_heartbeat + MonitorHandler.HOST_PLUGIN_HEARTBEAT_PERIOD):
+            return last_host_plugin_heartbeat
+


This construct is used over and over again. This should be refactored into something for better re-use. Please open an issue if you cannot address it for this commit.

I have made some changes here, which I will push. Let me know if you think it still requires further refactoring.

boumenot · 2018-06-04T21:52:52Z

azurelinuxagent/ga/monitor.py

-                        or other_errors > 0:
-
-                    msg = "hostplugin:{0};protocol:{1};other:{2}"\
-                        .format(hostplugin_errors,


Did you just re-format the file? It's hard to see real changes when the formatting gets adjusted this much. Keep the format changes because I want them, but consider doing them in a distinct phase to make code review easier.

I usually keep reformats/whitespace to separate commits, but in a review this size I understand it becomes too difficult to look at them separately.

Well, hell, this stomps all over work I've been doing for cgroups. Again. I see another two hours of rebasing ahead of me.

boumenot · 2018-06-04T21:53:14Z

azurelinuxagent/ga/update.py

@@ -540,7 +542,7 @@ def _purge_agents(self):

        known_versions = [agent.version for agent in self.agents]
        if CURRENT_VERSION not in known_versions:
-            logger.info(
+            logger.verbose(


boumenot · 2018-06-04T21:54:06Z

tests/protocol/test_hostplugin.py

                self._validate_hostplugin_args(
                    patch_http.call_args_list[0],
                    test_goal_state,
                    exp_method, exp_url, exp_data)

+                # second call is to health service


second call is to health service [](start = 16, length = 34)

Thank you, this makes it so much easier to read.

boumenot · 2018-06-04T21:59:30Z

tests/protocol/test_hostplugin.py

+        jstr = patch_http_post.call_args_list[1][0][1]
+        obj = json.loads(jstr)
+        self.assertEqual(1, len(obj['Observations']))
+        self.assertFalse(obj['Observations'][0]['IsHealthy'])


self.assertFalse(obj['Observations'][0]['IsHealthy']) [](start = 7, length = 54)

I think this is really what you want the test to assert, but it takes a lot of code to actually get there. I have found this to be true for other parts of the agent. 😢

boumenot · 2018-06-04T22:00:36Z

tests/protocol/test_hostplugin.py

-
+
+    @patch("azurelinuxagent.common.utils.restutil.http_get")
+    def test_health(self, patch_http_get):


test_health [](start = 8, length = 11)

I think there should be a test case for HTTP 502. I think there should be a test case of /extensionArtifact and /vmAgentLog. What else am I missing?

There are quite a few tests still coming.

boumenot

🕐

boumenot

A few more comments, but otherwise LGTM.

boumenot · 2018-06-05T16:44:02Z

azurelinuxagent/common/protocol/hostplugin.py

+        if last_timestamp is None:
+            last_timestamp = datetime.datetime.utcnow() - period
+
+        return datetime.datetime.utcnow() >= (last_timestamp + period)


Now I see it. Would you please add a docstring to the method to make that clearer.

boumenot · 2018-06-05T16:46:01Z

azurelinuxagent/ga/exthandlers.py

@@ -1117,7 +1113,7 @@ def set_handler_status(self, status="NotReady", message="", code=0):
        except (IOError, ValueError, ProtocolError) as e:
            fileutil.clean_ioerror(e,
                paths=[status_file])
-            self.logger.error("Failed to save handler status: {0}", traceback.format_exc())
+            self.logger.error("Failed to save handler status: {0}", ustr(e))


Well, crap. Now you're fighting my memory, and I only half trust it. I thought this was a code path where the traceback was used to diagnose a failure. Your mind is fresh. If you think it is useless, please remove it.

boumenot · 2018-06-05T16:47:42Z

tests/ga/test_monitor.py

+        self.assertEqual(None, monitor_handler.last_telemetry_heartbeat)
+
+        monitor_handler.start()
+        time.sleep(1)


Can we change this to milliseconds instead, or patch time to avoid sleeping in a unit test.

I made these shorter. Since I want to test how the thread sleep functions, I felt patching time would negate the value of the test.

boumenot · 2018-06-05T16:50:18Z

tests/protocol/test_healthservice.py

+        self.assertEqual(200, len(o.value))
+        self.assertEqual(200, len(o.description))
+
+        self.assertEqual(64, len(o.as_obj['ObservationName']))


What are you asserting length? What do the values 64 and 128 represent? Why don't you just assert the contents? I think I am missing something.

This test is to assert the maximum string length for these fields; longer values cause 400s. The other tests do assert value. Specifically this ensures that even though we set a 200 character string, the json representation is 64/128.

boumenot · 2018-06-05T17:22:45Z

tests/protocol/test_hostplugin.py

+        self.assertEqual(1, patch_should_report.call_count)
+        self.assertEqual(1, patch_report_status.call_count)
+
+    def test_should_report(self):


This is test clarifies a lot of things for me - nice!

boumenot · 2018-06-05T17:25:27Z

tests/ga/test_monitor.py

        self.assertNotEqual(0, patch_hostplugin_heartbeat.call_count)
        self.assertNotEqual(0, patch_send_events.call_count)
        self.assertNotEqual(0, patch_telemetry_heartbeat.call_count)

-        monitor_handler.should_run = False
+        monitor_handler.stop()


I like this change!

hglkrijger · 2018-06-05T21:13:18Z

Merging, since this is approved, but if there is any more feedback I will be happy to address it in the next PR for integrating IMDS health signals.

hglkrijger added 30 commits May 29, 2018 12:58

refactor monitor daemon

6f0b291

initial commit for hostga health monitor

97aa665

send telemetry when hostplugin heartbeat fails

1920e3f

adjust monitor delta

33240bb

fix call

0a73ce6

use correct endpoint

3f90f20

update version

051e9f5

cleanup

427a04f

add content type header

3399ef9

cleanup logging

89e67f6

update observation name

c466c11

minor refactor

f386a74

add signal for /versions

88c34ae

debugging

9a25a69

fix

165f5c8

remove debugging

90b1727

verbose logs

55ac6fe

cleanup, add report for artifacts

28994c0

minor cleanup

21d76b1

minor refactor and cleanup

6eaa000

switch to using fetch over download_ext_handler_pkg directly

1388bb5

whitespace cleanup

2f2abfc

switch default

d5b7874

exception formatting

1806eb4

debugging

21493bc

remove debugging

17157be

remove 400 from resource gone codes

edb824a

rollup hostplugin fetch reporting

a0b53ec

update exthandler prefix

f3ee5cb

report fetch from GuestAgent

38f53b2

boumenot reviewed Jun 4, 2018

View reviewed changes

hglkrijger added 2 commits June 4, 2018 14:40

cleanup the monitor thread; heartbeat tests

3d952b4

update naming for PR feedback

f9e16d0

boumenot reviewed Jun 4, 2018

View reviewed changes

fix import test

493f347

boumenot requested changes Jun 4, 2018

View reviewed changes

hglkrijger added 12 commits June 4, 2018 15:44

mock events for monitor tests

e76f578

adjust handler model

98dcf0e

monitor thread clean shutdown for unit tests

a608772

switch to thread join

3dbaff7

correct init sequence

9d8640e

event thread None check

58586a0

add healthservice tests

8a16a86

update health service tests

91a6c37

test observationsare cleared after failures

ccccd19

test for status codes

a5673be

additional tests for reporting

3ee3f27

better json compare

14f022f

boumenot approved these changes Jun 5, 2018

View reviewed changes

hglkrijger added 2 commits June 5, 2018 12:08

PR feedback

1a465fa

additional bounds safety; new test

47f18c5

hglkrijger merged commit 1cf3b74 into Azure:master Jun 5, 2018

hglkrijger deleted the health-store branch June 5, 2018 21:13

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Health store integration #1196

Health store integration #1196

hglkrijger commented May 31, 2018 •

edited

Loading

boumenot Jun 4, 2018

hglkrijger Jun 4, 2018

boumenot Jun 4, 2018

hglkrijger Jun 4, 2018

boumenot Jun 5, 2018

hglkrijger Jun 5, 2018

boumenot Jun 4, 2018

hglkrijger Jun 4, 2018

boumenot Jun 4, 2018

hglkrijger Jun 4, 2018

jasonzio Jun 6, 2018

boumenot Jun 4, 2018

boumenot Jun 4, 2018

boumenot Jun 4, 2018

boumenot Jun 4, 2018

hglkrijger Jun 4, 2018

boumenot left a comment

boumenot left a comment

boumenot Jun 5, 2018

boumenot Jun 5, 2018

boumenot Jun 5, 2018

hglkrijger Jun 5, 2018

boumenot Jun 5, 2018

hglkrijger Jun 5, 2018

boumenot Jun 5, 2018

hglkrijger Jun 5, 2018

boumenot Jun 5, 2018

hglkrijger commented Jun 5, 2018


		if datetime.datetime.utcnow() < (last_host_plugin_heartbeat + MonitorHandler.HOST_PLUGIN_HEARTBEAT_PERIOD):
		return last_host_plugin_heartbeat



		@patch("azurelinuxagent.common.utils.restutil.http_get")
		def test_health(self, patch_http_get):

Health store integration #1196

Health store integration #1196

Conversation

hglkrijger commented May 31, 2018 • edited Loading

GuestAgentPluginHeartbeat

GuestAgentPluginVersions

GuestAgentPluginArtifact

GuestAgentPluginStatus

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

second call is to health service [](start = 16, length = 34)

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

boumenot left a comment

Choose a reason for hiding this comment

boumenot left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

hglkrijger commented Jun 5, 2018

hglkrijger commented May 31, 2018 •

edited

Loading