Repository: Azure/WALinuxAgent
Pull request #1924 (2020-06-26 19:14:14)

Move AutoUpdate reporting to HeartBeat event (#1919)
<!-- DO NOT DELETE THIS TEMPLATE -->

## Description

Cherry-pick hotfix from release branch into develop.

<!--
Please add an informative description that covers that changes made by the pull request. 
This checklist is used to make sure that common issues in a pull request are addressed.
This will expedite the process of getting your pull request merged and avoid extra work on your part to fix issues discovered during the review process.
-->

---

### PR information
- [ ] The title of the PR is clear and informative.
- [ ] There are a small number of commits, each of which has an informative message. This means that previously merged commits do not appear in the history of the PR. For information on cleaning up the commits in your pull request, [see this page](https://github.com/Azure/azure-powershell/blob/master/documentation/development-docs/cleaning-up-commits.md).
- [ ] Except for special cases involving multiple contributors, the PR is started from a fork of the main repository, not a branch.
- [ ] If applicable, the PR references the bug/issue that it fixes in the description.
- [ ] New Unit tests were added for the changes made and Travis.CI is passing.

### Quality of Code and Contribution Guidelines
- [ ] I have read the [contribution guidelines](https://github.com/Azure/WALinuxAgent/blob/master/.github/CONTRIBUTING.md).

codecov[bot]: # [Codecov](https://codecov.io/gh/Azure/WALinuxAgent/pull/1924?src=pr&el=h1) Report
> Merging [#1924](https://codecov.io/gh/Azure/WALinuxAgent/pull/1924?src=pr&el=desc) into [develop](https://codecov.io/gh/Azure/WALinuxAgent/commit/71654c4dec506d721042eaf3950471600ce4e392&el=desc) will **decrease** coverage by `0.01%`.
> The diff coverage is `100.00%`.

[![Impacted file tree graph](https://codecov.io/gh/Azure/WALinuxAgent/pull/1924/graphs/tree.svg?width=650&height=150&src=pr&token=ae90E2KYCw)](https://codecov.io/gh/Azure/WALinuxAgent/pull/1924?src=pr&el=tree)

```diff
@@             Coverage Diff             @@
##           develop    #1924      +/-   ##
===========================================
- Coverage    69.60%   69.59%   -0.02%     
===========================================
  Files           85       85              
  Lines        11921    11918       -3     
  Branches      1670     1670              
===========================================
- Hits          8298     8294       -4     
- Misses        3252     3253       +1     
  Partials       371      371              
```


| [Impacted Files](https://codecov.io/gh/Azure/WALinuxAgent/pull/1924?src=pr&el=tree) | Coverage Δ | |
|---|---|---|
| [azurelinuxagent/common/event.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/1924/diff?src=pr&el=tree#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi9ldmVudC5weQ==) | `85.93% <ø> (-0.04%)` | :arrow_down: |
| [azurelinuxagent/ga/update.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/1924/diff?src=pr&el=tree#diff-YXp1cmVsaW51eGFnZW50L2dhL3VwZGF0ZS5weQ==) | `87.59% <100.00%> (-0.20%)` | :arrow_down: |

------

[Continue to review full report at Codecov](https://codecov.io/gh/Azure/WALinuxAgent/pull/1924?src=pr&el=continue).
> **Legend** - [Click here to learn more](https://docs.codecov.io/docs/codecov-delta)
> `Δ = absolute <relative> (impact)`, `ø = not affected`, `? = missing data`
> Powered by [Codecov](https://codecov.io/gh/Azure/WALinuxAgent/pull/1924?src=pr&el=footer). Last update [71654c4...924c989](https://codecov.io/gh/Azure/WALinuxAgent/pull/1924?src=pr&el=lastupdated). Read the [comment docs](https://docs.codecov.io/docs/pull-request-comments).


Patch:
diff --git a/azurelinuxagent/common/event.py b/azurelinuxagent/common/event.py
index 5fd52b3c..eca62556 100644
--- a/azurelinuxagent/common/event.py
+++ b/azurelinuxagent/common/event.py
@@ -71,7 +71,6 @@ class WALAEventOperation:
     AgentBlacklisted = "AgentBlacklisted"
     AgentEnabled = "AgentEnabled"
     ArtifactsProfileBlob = "ArtifactsProfileBlob"
-    AutoUpdate = "AutoUpdate"
     CGroupsCleanUp = "CGroupsCleanUp"
     CGroupsDebug = "CGroupsDebug"
     CGroupsInfo = "CGroupsInfo"
@@ -181,7 +180,6 @@ class EventStatus(object):
 
 __event_status__ = EventStatus()
 __event_status_operations__ = [
-        WALAEventOperation.AutoUpdate,
         WALAEventOperation.ReportStatus
     ]
 
diff --git a/azurelinuxagent/ga/update.py b/azurelinuxagent/ga/update.py
index 77656525..6fec60ee 100644
--- a/azurelinuxagent/ga/update.py
+++ b/azurelinuxagent/ga/update.py
@@ -266,7 +266,7 @@ class UpdateHandler(object):
                 PY_VERSION_MINOR, PY_VERSION_MICRO)
             logger.info(os_info_msg)
             add_event(AGENT_NAME, op=WALAEventOperation.OSInfo, message=os_info_msg)
-
+            
             # Launch monitoring threads
             from azurelinuxagent.ga.monitor import get_monitor_handler
             monitor_thread = get_monitor_handler()
@@ -350,7 +350,6 @@ class UpdateHandler(object):
                             message="Incarnation {0}".format(exthandlers_handler.last_etag))
 
                 self._send_heartbeat_telemetry(protocol)
-
                 time.sleep(goal_state_interval)
 
         except Exception as e:
@@ -446,11 +445,6 @@ class UpdateHandler(object):
                 logger.info(message)
                 add_event(AGENT_NAME, op=WALAEventOperation.ConfigurationChange, message=message)
 
-            # Always report the value of AutoUpdate
-            auto_update_enabled = conf.get_autoupdate_enabled()
-            logger.info("AutoUpdate.Enabled: {0}}", auto_update_enabled)
-            add_event(op=WALAEventOperation.AutoUpdate, is_success=auto_update_enabled, log_event=False)
-
         except Exception as e:
             logger.warn("Failed to log changes in configuration: {0}", ustr(e))
 
@@ -672,7 +666,6 @@ class UpdateHandler(object):
     def _upgrade_available(self, protocol, base_version=CURRENT_VERSION):
         # Ignore new agents if updating is disabled
         if not conf.get_autoupdate_enabled():
-            logger.warn(u"Agent auto-update is disabled.")
             return False
 
         now = time.time()
@@ -756,13 +749,21 @@ class UpdateHandler(object):
 
         if datetime.utcnow() >= (self._last_telemetry_heartbeat + UpdateHandler.TELEMETRY_HEARTBEAT_PERIOD):
             dropped_packets = self.osutil.get_firewall_dropped_packets(protocol.get_endpoint())
-            msg = "{0};{1};{2};{3}".format(self._heartbeat_counter, self._heartbeat_id, dropped_packets, self._heartbeat_update_goal_state_error_count)
+            auto_update_enabled = 1 if conf.get_autoupdate_enabled() else 0
+            telemetry_msg = "{0};{1};{2};{3};{4}".format(self._heartbeat_counter, self._heartbeat_id, dropped_packets,
+                                                         self._heartbeat_update_goal_state_error_count, auto_update_enabled)
 
-            add_event(name=AGENT_NAME, version=CURRENT_VERSION, op=WALAEventOperation.HeartBeat, is_success=True, message=msg, log_event=False)
+            add_event(name=AGENT_NAME, version=CURRENT_VERSION, op=WALAEventOperation.HeartBeat, is_success=True,
+                      message=telemetry_msg, log_event=False)
             self._heartbeat_counter += 1
             self._heartbeat_update_goal_state_error_count = 0
 
-            logger.info(u"[HEARTBEAT] Agent {0} is running as the goal state agent", CURRENT_AGENT)
+            debug_log_msg = "[DEBUG HeartbeatCounter: {0};HeartbeatId: {1};DroppedPackets: {2};" \
+                            "UpdateGSErrors: {3};AutoUpdate: {4}]".format(self._heartbeat_counter,
+                                                                          self._heartbeat_id, dropped_packets,
+                                                                          self._heartbeat_update_goal_state_error_count,
+                                                                          auto_update_enabled)
+            logger.info(u"[HEARTBEAT] Agent {0} is running as the goal state agent {1}", CURRENT_AGENT, debug_log_msg)
             self._last_telemetry_heartbeat = datetime.utcnow()
 
 


Test patch:
diff --git a/tests/ga/test_update.py b/tests/ga/test_update.py
index 209b0524..c745ca6c 100644
--- a/tests/ga/test_update.py
+++ b/tests/ga/test_update.py
@@ -1476,10 +1476,8 @@ class TestUpdate(UpdateTestCase):
         update_handler.last_telemetry_heartbeat = datetime.utcnow() - timedelta(hours=1)
         update_handler._send_heartbeat_telemetry(mock_protocol)
         self.assertEqual(1, patch_add_event.call_count)
-        self.assertTrue(
-            any(call_args[0] == "[HEARTBEAT] Agent {0} is running as the goal state agent" for call_args in patch_info.call_args),
-            "The heartbeat was not written to the agent's log"
-        )
+        self.assertTrue(any(call_args[0] == "[HEARTBEAT] Agent {0} is running as the goal state agent {1}"
+                            for call_args in patch_info.call_args), "The heartbeat was not written to the agent's log")
 
 
 class MonitorThreadTest(AgentTestCase):