Repository: Azure/WALinuxAgent
Pull request #2173 (2021-02-10 15:58:04)

Monitor agent's throttle time

codecov[bot]: # [Codecov](https://codecov.io/gh/Azure/WALinuxAgent/pull/2173?src=pr&el=h1) Report
> Merging [#2173](https://codecov.io/gh/Azure/WALinuxAgent/pull/2173?src=pr&el=desc) (6be3bae) into [develop](https://codecov.io/gh/Azure/WALinuxAgent/commit/d33acb4537880ae3d9d016f3f865f8783db48f49?el=desc) (d33acb4) will **decrease** coverage by `0.08%`.
> The diff coverage is `68.29%`.

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

```diff
@@             Coverage Diff             @@
##           develop    #2173      +/-   ##
===========================================
- Coverage    70.53%   70.44%   -0.09%     
===========================================
  Files           96       96              
  Lines        13373    13387      +14     
  Branches      1883     1888       +5     
===========================================
- Hits          9432     9431       -1     
- Misses        3533     3543      +10     
- Partials       408      413       +5     
```


| [Impacted Files](https://codecov.io/gh/Azure/WALinuxAgent/pull/2173?src=pr&el=tree) | Coverage Δ | |
|---|---|---|
| [azurelinuxagent/common/cgroup.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2173/diff?src=pr&el=tree#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi9jZ3JvdXAucHk=) | `88.07% <67.50%> (-6.09%)` | :arrow_down: |
| [azurelinuxagent/common/cgroupconfigurator.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2173/diff?src=pr&el=tree#diff-YXp1cmVsaW51eGFnZW50L2NvbW1vbi9jZ3JvdXBjb25maWd1cmF0b3IucHk=) | `66.88% <100.00%> (ø)` | |
| [azurelinuxagent/ga/collect\_telemetry\_events.py](https://codecov.io/gh/Azure/WALinuxAgent/pull/2173/diff?src=pr&el=tree#diff-YXp1cmVsaW51eGFnZW50L2dhL2NvbGxlY3RfdGVsZW1ldHJ5X2V2ZW50cy5weQ==) | `89.65% <0.00%> (-1.73%)` | :arrow_down: |

------

[Continue to review full report at Codecov](https://codecov.io/gh/Azure/WALinuxAgent/pull/2173?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/2173?src=pr&el=footer). Last update [d33acb4...9e2fd16](https://codecov.io/gh/Azure/WALinuxAgent/pull/2173?src=pr&el=lastupdated). Read the [comment docs](https://docs.codecov.io/docs/pull-request-comments).


Patch:
diff --git a/azurelinuxagent/common/cgroup.py b/azurelinuxagent/common/cgroup.py
index cefc6f93..bbf955b9 100644
--- a/azurelinuxagent/common/cgroup.py
+++ b/azurelinuxagent/common/cgroup.py
@@ -38,39 +38,25 @@ class MetricsCounter(object):
     PROCESSOR_PERCENT_TIME = "% Processor Time"
     TOTAL_MEM_USAGE = "Total Memory Usage"
     MAX_MEM_USAGE = "Max Memory Usage"
+    THROTTLED_TIME = "Throttled Time"
 
 
 re_user_system_times = re.compile(r'user (\d+)\nsystem (\d+)\n')
 
 
-class CGroupContollers(object):
-    CPU = "cpu"
-    MEMORY = "memory"
-
-
 class CGroup(object):
-    @staticmethod
-    def create(cgroup_path, controller, extension_name):
-        """
-        Factory method to create the correct CGroup.
-        """
-        if controller == CGroupContollers.CPU:
-            return CpuCgroup(extension_name, cgroup_path)
-        if controller == CGroupContollers.MEMORY:
-            return MemoryCgroup(extension_name, cgroup_path)
-        raise CGroupsException('CGroup controller {0} is not supported'.format(controller))
-
-    def __init__(self, name, cgroup_path, controller_type):
+    def __init__(self, name, cgroup_path):
         """
         Initialize _data collection for the Memory controller
         :param: name: Name of the CGroup
         :param: cgroup_path: Path of the controller
-        :param: controller_type:
         :return:
         """
         self.name = name
         self.path = cgroup_path
-        self.controller = controller_type
+
+    def __str__(self):
+        return "{0} [{1}]".format(self.name, self.path)
 
     def _get_cgroup_file(self, file_name):
         return os.path.join(self.path, file_name)
@@ -139,19 +125,17 @@ class CGroup(object):
 
 
 class CpuCgroup(CGroup):
-    def __init__(self, name, cgroup_path):
-        super(CpuCgroup, self).__init__(name, cgroup_path, CGroupContollers.CPU)
+    def __init__(self, name, cgroup_path, track_throttled_time=False):
+        super(CpuCgroup, self).__init__(name, cgroup_path)
 
         self._osutil = get_osutil()
         self._previous_cgroup_cpu = None
         self._previous_system_cpu = None
         self._current_cgroup_cpu = None
         self._current_system_cpu = None
-
-    def __str__(self):
-        return "cgroup: Name: {0}, cgroup_path: {1}; Controller: {2}".format(
-            self.name, self.path, self.controller
-        )
+        self._track_throttled_time = track_throttled_time
+        self._previous_throttled_time = None
+        self._current_throttled_time = None
 
     def _get_cpu_ticks(self, allow_no_such_file_or_directory_error=False):
         """
@@ -161,24 +145,53 @@ class CpuCgroup(CGroup):
         returns 0; this is useful when the function can be called before the cgroup has been created.
         """
         try:
-            cpu_stat = self._get_file_contents('cpuacct.stat')
+            cpuacct_stat = self._get_file_contents('cpuacct.stat')
         except Exception as e:
             if not isinstance(e, (IOError, OSError)) or e.errno != errno.ENOENT:  # pylint: disable=E1101
                 raise CGroupsException("Failed to read cpuacct.stat: {0}".format(ustr(e)))
             if not allow_no_such_file_or_directory_error:
                 raise e
-            cpu_stat = None
+            cpuacct_stat = None
 
         cpu_ticks = 0
 
-        if cpu_stat is not None:
-            match = re_user_system_times.match(cpu_stat)
+        if cpuacct_stat is not None:
+            #
+            # Sample file:
+            #     # cat /sys/fs/cgroup/cpuacct/azure.slice/walinuxagent.service/cpuacct.stat
+            #     user 10190
+            #     system 3160
+            #
+            match = re_user_system_times.match(cpuacct_stat)
             if not match:
-                raise CGroupsException("The contents of {0} are invalid: {1}".format(self._get_cgroup_file('cpuacct.stat'), cpu_stat))
+                raise CGroupsException("The contents of {0} are invalid: {1}".format(self._get_cgroup_file('cpuacct.stat'), cpuacct_stat))
             cpu_ticks = int(match.groups()[0]) + int(match.groups()[1])
 
         return cpu_ticks
 
+    def _get_throttled_time(self):
+        try:
+            with open(os.path.join(self.path, 'cpu.stat')) as cpu_stat:
+                #
+                # Sample file:
+                #
+                #   # cat /sys/fs/cgroup/cpuacct/azure.slice/walinuxagent.service/cpu.stat
+                #   nr_periods  51660
+                #   nr_throttled 19461
+                #   throttled_time 1529590856339
+                #
+                for line in cpu_stat:
+                    match = re.match(r'throttled_time\s+(\d+)', line)
+                    if match is not None:
+                        return int(match.groups()[0])
+                raise Exception("Cannot find throttled_time")
+        except (IOError, OSError) as e:
+            if e.errno == errno.ENOENT:
+                return 0
+            raise CGroupsException("Failed to read cpu.stat: {0}".format(ustr(e)))
+        except Exception as e:
+            raise CGroupsException("Failed to read cpu.stat: {0}".format(ustr(e)))
+
     def _cpu_usage_initialized(self):
         return self._current_cgroup_cpu is not None and self._current_system_cpu is not None
 
@@ -190,6 +203,8 @@ class CpuCgroup(CGroup):
             raise CGroupsException("initialize_cpu_usage() should be invoked only once")
         self._current_cgroup_cpu = self._get_cpu_ticks(allow_no_such_file_or_directory_error=True)
         self._current_system_cpu = self._osutil.get_total_cpu_ticks_since_boot()
+        if self._track_throttled_time:
+            self._current_throttled_time = self._get_throttled_time()
 
     def get_cpu_usage(self):
         """
@@ -213,26 +228,29 @@ class CpuCgroup(CGroup):
 
         return round(100.0 * self._osutil.get_processor_cores() * float(cgroup_delta) / float(system_delta), 3)
 
+    def get_throttled_time(self):
+        """
+        Computes the throttled time (in nanoseconds) since the last call to this function.
+        NOTE: initialize_cpu_usage() must be invoked before calling this function
+        """
+        if not self._cpu_usage_initialized():
+            raise CGroupsException("initialize_cpu_usage() must be invoked before the first call to get_throttled_time()")
+
+        self._previous_throttled_time = self._current_throttled_time
+        self._current_throttled_time = self._get_throttled_time()
+
+        return  self._current_throttled_time - self._previous_throttled_time
+
     def get_tracked_metrics(self):
-        return [
+        tracked = [
             MetricValue(MetricsCategory.CPU_CATEGORY, MetricsCounter.PROCESSOR_PERCENT_TIME, self.name, self.get_cpu_usage()),
         ]
+        if self._track_throttled_time:
+            tracked.append(MetricValue(MetricsCategory.CPU_CATEGORY, MetricsCounter.THROTTLED_TIME, self.name, self.get_throttled_time()))
+        return tracked
 
 
 class MemoryCgroup(CGroup):
-    def __init__(self, name, cgroup_path):
-        """
-        Initialize _data collection for the Memory controller
-
-        :return: MemoryCgroup
-        """
-        super(MemoryCgroup, self).__init__(name, cgroup_path, CGroupContollers.MEMORY)
-
-    def __str__(self):
-        return "cgroup: Name: {0}, cgroup_path: {1}; Controller: {2}".format(
-            self.name, self.path, self.controller
-        )
-
     def get_memory_usage(self):
         """
         Collect memory.usage_in_bytes from the cgroup.
diff --git a/azurelinuxagent/common/cgroupconfigurator.py b/azurelinuxagent/common/cgroupconfigurator.py
index 06c3e6ea..a0202cf0 100644
--- a/azurelinuxagent/common/cgroupconfigurator.py
+++ b/azurelinuxagent/common/cgroupconfigurator.py
@@ -126,7 +126,7 @@ class CGroupConfigurator(object):
 
                 if self._agent_cpu_cgroup_path is not None:
                     self.__log_cgroup_info("Agent CPU cgroup: {0}", self._agent_cpu_cgroup_path)
-                    CGroupsTelemetry.track_cgroup(CpuCgroup(agent_unit_name, self._agent_cpu_cgroup_path))
+                    CGroupsTelemetry.track_cgroup(CpuCgroup(agent_unit_name, self._agent_cpu_cgroup_path, track_throttled_time=True))
                     self._cgroups_enabled = True
 
                 self.__log_cgroup_info('Cgroups enabled: {0}', self._cgroups_enabled)


Test patch:
diff --git a/tests/common/test_cgroupconfigurator.py b/tests/common/test_cgroupconfigurator.py
index a590bad2..e6c68b0f 100644
--- a/tests/common/test_cgroupconfigurator.py
+++ b/tests/common/test_cgroupconfigurator.py
@@ -28,7 +28,7 @@ import threading
 
 from nose.plugins.attrib import attr
 
-from azurelinuxagent.common.cgroup import CGroup
+from azurelinuxagent.common.cgroup import CpuCgroup, MemoryCgroup
 from azurelinuxagent.common.cgroupconfigurator import CGroupConfigurator
 from azurelinuxagent.common.cgroupstelemetry import CGroupsTelemetry
 from azurelinuxagent.common.event import WALAEventOperation
@@ -204,8 +204,8 @@ cgroup on /sys/fs/cgroup/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blki
     def test_disable_should_reset_tracked_cgroups(self):
         with self._get_cgroup_configurator(initialize=False) as configurator:
             # Start tracking a couple of dummy cgroups
-            CGroupsTelemetry.track_cgroup(CGroup("dummy", "/sys/fs/cgroup/memory/system.slice/dummy.service", "cpu"))
-            CGroupsTelemetry.track_cgroup(CGroup("dummy", "/sys/fs/cgroup/memory/system.slice/dummy.service", "memory"))
+            CGroupsTelemetry.track_cgroup(CpuCgroup("dummy", "/sys/fs/cgroup/memory/system.slice/dummy.service"))
+            CGroupsTelemetry.track_cgroup(MemoryCgroup("dummy", "/sys/fs/cgroup/memory/system.slice/dummy.service"))
 
             configurator.disable()
 
diff --git a/tests/common/test_cgroups.py b/tests/common/test_cgroups.py
index 4e33a5e1..47e1917f 100644
--- a/tests/common/test_cgroups.py
+++ b/tests/common/test_cgroups.py
@@ -20,8 +20,9 @@ from __future__ import print_function
 import errno
 import os
 import random
+import shutil
 
-from azurelinuxagent.common.cgroup import CpuCgroup, MemoryCgroup, CGroup
+from azurelinuxagent.common.cgroup import CpuCgroup, MemoryCgroup
 from azurelinuxagent.common.exception import CGroupsException
 from azurelinuxagent.common.osutil import get_osutil
 from azurelinuxagent.common.utils import fileutil
@@ -36,21 +37,8 @@ def consume_cpu_time():
 
 
 class TestCGroup(AgentTestCase):
-    def test_correct_creation(self):
-        test_cgroup = CGroup.create("dummy_path", "cpu", "test_extension")
-        self.assertIsInstance(test_cgroup, CpuCgroup)
-        self.assertEqual(test_cgroup.controller, "cpu")
-        self.assertEqual(test_cgroup.path, "dummy_path")
-        self.assertEqual(test_cgroup.name, "test_extension")
-
-        test_cgroup = CGroup.create("dummy_path", "memory", "test_extension")
-        self.assertIsInstance(test_cgroup, MemoryCgroup)
-        self.assertEqual(test_cgroup.controller, "memory")
-        self.assertEqual(test_cgroup.path, "dummy_path")
-        self.assertEqual(test_cgroup.name, "test_extension")
-
     def test_is_active(self):
-        test_cgroup = CGroup.create(self.tmp_dir, "cpu", "test_extension")
+        test_cgroup = CpuCgroup("test_extension", self.tmp_dir)
         self.assertEqual(False, test_cgroup.is_active())
 
         with open(os.path.join(self.tmp_dir, "tasks"), mode="wb") as tasks:
@@ -60,10 +48,10 @@ class TestCGroup(AgentTestCase):
 
     @patch("azurelinuxagent.common.logger.periodic_warn")
     def test_is_active_file_not_present(self, patch_periodic_warn):
-        test_cgroup = CGroup.create(self.tmp_dir, "cpu", "test_extension")
+        test_cgroup = CpuCgroup("test_extension", self.tmp_dir)
         self.assertEqual(False, test_cgroup.is_active())
 
-        test_cgroup = CGroup.create(os.path.join(self.tmp_dir, "this_cgroup_does_not_exist"), "memory", "test_extension")
+        test_cgroup = MemoryCgroup("test_extension", os.path.join(self.tmp_dir, "this_cgroup_does_not_exist"))
         self.assertEqual(False, test_cgroup.is_active())
 
         self.assertEqual(0, patch_periodic_warn.call_count)
@@ -71,7 +59,7 @@ class TestCGroup(AgentTestCase):
     @patch("azurelinuxagent.common.logger.periodic_warn")
     def test_is_active_incorrect_file(self, patch_periodic_warn):
         open(os.path.join(self.tmp_dir, "tasks"), mode="wb").close()
-        test_cgroup = CGroup.create(os.path.join(self.tmp_dir, "tasks"), "cpu", "test_extension")
+        test_cgroup = CpuCgroup("test_extension", os.path.join(self.tmp_dir, "tasks"))
         self.assertEqual(False, test_cgroup.is_active())
         self.assertEqual(1, patch_periodic_warn.call_count)
 
@@ -153,7 +141,7 @@ class TestCpuCgroup(AgentTestCase):
 
         self.assertEqual(cpu_usage, round(100.0 * 0.000445181085968 * osutil.get_processor_cores(), 3))
 
-    def test_initialie_cpu_usage_should_set_the_cgroup_usage_to_0_when_the_cgroup_does_not_exist(self):
+    def test_initialize_cpu_usage_should_set_the_cgroup_usage_to_0_when_the_cgroup_does_not_exist(self):
         cgroup = CpuCgroup("test", "/sys/fs/cgroup/cpu/system.slice/test")
 
         io_error_2 = IOError()
@@ -189,12 +177,19 @@ class TestCpuCgroup(AgentTestCase):
         with self.assertRaises(CGroupsException):
             cpu_usage = cgroup.get_cpu_usage()  # pylint: disable=unused-variable
 
+    def test_get_throttled_time_should_return_the_value_since_its_last_invocation(self):
+        test_file = os.path.join(self.tmp_dir, "cpu.stat")
+        shutil.copyfile(os.path.join(data_dir, "cgroups", "cpu.stat_t0"), test_file)  # throttled_time = 50
+        cgroup = CpuCgroup("test", self.tmp_dir, track_throttled_time=True)
+        cgroup.initialize_cpu_usage()
+        shutil.copyfile(os.path.join(data_dir, "cgroups", "cpu.stat_t1"), test_file)  # throttled_time = 2075541442327
 
-class TestMemoryCgroup(AgentTestCase):
-    def test_memory_cgroup_create(self):
-        test_mem_cg = MemoryCgroup("test_extension", os.path.join(data_dir, "cgroups", "memory_mount"))
-        self.assertEqual("memory", test_mem_cg.controller)
+        throttled_time = cgroup.get_throttled_time()
 
+        self.assertEqual(throttled_time, 2075541442327 - 50, "The value of throttled_time is incorrect")
+
+
+class TestMemoryCgroup(AgentTestCase):
     def test_get_metrics(self):
         test_mem_cg = MemoryCgroup("test_extension", os.path.join(data_dir, "cgroups", "memory_mount"))
 
diff --git a/tests/common/test_cgroupstelemetry.py b/tests/common/test_cgroupstelemetry.py
index 0caeda35..1dbfb3d1 100644
--- a/tests/common/test_cgroupstelemetry.py
+++ b/tests/common/test_cgroupstelemetry.py
@@ -19,7 +19,7 @@ import os
 import random
 import time
 
-from azurelinuxagent.common.cgroup import CGroup
+from azurelinuxagent.common.cgroup import CpuCgroup, MemoryCgroup
 from azurelinuxagent.common.cgroupstelemetry import CGroupsTelemetry
 from azurelinuxagent.common.utils import fileutil
 from tests.tools import AgentTestCase, data_dir, patch
@@ -105,11 +105,10 @@ class TestCGroupsTelemetry(AgentTestCase):
     @staticmethod
     def _track_new_extension_cgroups(num_extensions):
         for i in range(num_extensions):
-            dummy_cpu_cgroup = CGroup.create("dummy_cpu_path_{0}".format(i), "cpu", "dummy_extension_{0}".format(i))
+            dummy_cpu_cgroup = CpuCgroup("dummy_extension_{0}".format(i), "dummy_cpu_path_{0}".format(i))
             CGroupsTelemetry.track_cgroup(dummy_cpu_cgroup)
 
-            dummy_memory_cgroup = CGroup.create("dummy_memory_path_{0}".format(i), "memory",
-                                                "dummy_extension_{0}".format(i))
+            dummy_memory_cgroup = MemoryCgroup("dummy_extension_{0}".format(i), "dummy_memory_path_{0}".format(i))
             CGroupsTelemetry.track_cgroup(dummy_memory_cgroup)
 
     def _assert_cgroups_are_tracked(self, num_extensions):
diff --git a/tests/data/cgroups/cpu.stat_t0 b/tests/data/cgroups/cpu.stat_t0
new file mode 100644
index 00000000..0b5278e2
--- /dev/null
+++ b/tests/data/cgroups/cpu.stat_t0
@@ -0,0 +1,3 @@
+nr_periods 1
+nr_throttled 1
+throttled_time 50
diff --git a/tests/data/cgroups/cpu.stat_t1 b/tests/data/cgroups/cpu.stat_t1
new file mode 100644
index 00000000..d5e43984
--- /dev/null
+++ b/tests/data/cgroups/cpu.stat_t1
@@ -0,0 +1,3 @@
+nr_periods 66927
+nr_throttled 25803
+throttled_time 2075541442327
diff --git a/tests/ga/test_monitor.py b/tests/ga/test_monitor.py
index b690bca6..05fcf4d8 100644
--- a/tests/ga/test_monitor.py
+++ b/tests/ga/test_monitor.py
@@ -21,7 +21,7 @@ import random
 import string
 
 from azurelinuxagent.common import event, logger
-from azurelinuxagent.common.cgroup import CGroup, CpuCgroup, MemoryCgroup, MetricValue
+from azurelinuxagent.common.cgroup import CpuCgroup, MemoryCgroup, MetricValue
 from azurelinuxagent.common.cgroupstelemetry import CGroupsTelemetry
 from azurelinuxagent.common.event import EVENTS_DIRECTORY
 from azurelinuxagent.common.protocol.healthservice import HealthService
@@ -250,15 +250,6 @@ class TestExtensionMetricsDataTelemetry(AgentTestCase):
         self.assertEqual(0, patch_periodic_warn.call_count)
         self.assertEqual(0, patch_add_metric.call_count)  # No metrics should be sent.
 
-    @patch('azurelinuxagent.common.event.EventLogger.add_metric')
-    @patch('azurelinuxagent.common.logger.Logger.periodic_warn')
-    def test_send_extension_metrics_telemetry_for_unsupported_cgroup(self, patch_periodic_warn, patch_add_metric, *args):  # pylint: disable=unused-argument
-        CGroupsTelemetry._tracked.append(CGroup("cgroup_name", "/test/path", "io"))  # pylint: disable=protected-access
-
-        PollResourceUsage().run()
-        self.assertEqual(1, patch_periodic_warn.call_count)
-        self.assertEqual(0, patch_add_metric.call_count)  # No metrics should be sent.
-
     def test_generate_extension_metrics_telemetry_dictionary(self, *args):  # pylint: disable=unused-argument
         num_polls = 10
         num_extensions = 1
@@ -272,11 +263,10 @@ class TestExtensionMetricsDataTelemetry(AgentTestCase):
         # no need to initialize the CPU usage, since we mock get_cpu_usage() below
         with patch("azurelinuxagent.common.cgroup.CpuCgroup.initialize_cpu_usage"):
             for i in range(num_extensions):
-                dummy_cpu_cgroup = CGroup.create("dummy_cpu_path_{0}".format(i), "cpu", "dummy_extension_{0}".format(i))
+                dummy_cpu_cgroup = CpuCgroup("dummy_extension_{0}".format(i), "dummy_cpu_path_{0}".format(i))
                 CGroupsTelemetry.track_cgroup(dummy_cpu_cgroup)
 
-                dummy_memory_cgroup = CGroup.create("dummy_memory_path_{0}".format(i), "memory",
-                                                    "dummy_extension_{0}".format(i))
+                dummy_memory_cgroup = MemoryCgroup("dummy_extension_{0}".format(i), "dummy_memory_path_{0}".format(i))
                 CGroupsTelemetry.track_cgroup(dummy_memory_cgroup)
 
         self.assertEqual(2 * num_extensions, len(CGroupsTelemetry._tracked))  # pylint: disable=protected-access