Repository: Azure/WALinuxAgent

Issue:
CGroups error in Ubuntu 14.04
```
2018/07/31 11:41:06.400633 ERROR ExtHandler monitor: Exception tracking wrapper and agent: 'Hierarchy memory is not mounted' [Traceback (most recent call last):
  File "bin/WALinuxAgent-2.2.30-py2.7.egg/azurelinuxagent/ga/monitor.py", line 397, in init_cgroups
    CGroupsTelemetry.track_cgroup(CGroups.for_extension(""))
  File "bin/WALinuxAgent-2.2.30-py2.7.egg/azurelinuxagent/common/cgroups.py", line 360, in for_extension
    return CGroups(name, CGroups._construct_custom_path_for_hierarchy)
  File "bin/WALinuxAgent-2.2.30-py2.7.egg/azurelinuxagent/common/cgroups.py", line 401, in __init__
    raise CGroupsException("Hierarchy {0} is not mounted".format(hierarchy))
azurelinuxagent.common.cgroups.CGroupsException: 'Hierarchy memory is not mounted'
]
```

Discussion:

Patch:
diff --git a/azurelinuxagent/ga/monitor.py b/azurelinuxagent/ga/monitor.py
index c1215806..d6b66921 100644
--- a/azurelinuxagent/ga/monitor.py
+++ b/azurelinuxagent/ga/monitor.py
@@ -406,7 +406,11 @@ class MonitorHandler(object):
             CGroupsTelemetry.track_cgroup(CGroups.for_extension(""))
             CGroupsTelemetry.track_agent()
         except Exception as e:
-            logger.error("monitor: Exception tracking wrapper and agent: {0} [{1}]", e, traceback.format_exc())
+            # when a hierarchy is not mounted, we raise an exception
+            # and we should therefore only issue a warning, since this
+            # is not unexpected
+            logger.warn("Monitor: cgroups not initialized: {0}", ustr(e))
+            logger.verbose(traceback.format_exc())
 
     def send_cgroup_telemetry(self):
         if self.last_cgroup_telemetry is None:
@@ -419,13 +423,15 @@ class MonitorHandler(object):
                         if value > 0:
                             report_metric(metric_group, metric_name, cgroup_name, value)
             except Exception as e:
-                logger.warn("Failed to collect performance metrics: {0} [{1}]", e, traceback.format_exc())
+                logger.warn("Monitor: failed to collect cgroups performance metrics: {0}", ustr(e))
+                logger.verbose(traceback.format_exc())
 
             # Look for extension cgroups we're not already tracking and track them
             try:
                 CGroupsTelemetry.update_tracked(self.protocol.client.get_current_handlers())
             except Exception as e:
-                logger.warn("Monitor: updating tracked extensions raised {0}: {1}", e, traceback.format_exc())
+                logger.warn("Monitor: failed to update cgroups tracked extensions: {0}", ustr(e))
+                logger.verbose(traceback.format_exc())
 
             self.last_cgroup_telemetry = datetime.datetime.utcnow()
 
diff --git a/azurelinuxagent/pa/provision/cloudinit.py b/azurelinuxagent/pa/provision/cloudinit.py
index 9609d7da..3f3cdb04 100644
--- a/azurelinuxagent/pa/provision/cloudinit.py
+++ b/azurelinuxagent/pa/provision/cloudinit.py
@@ -69,9 +69,10 @@ class CloudInitProvisionHandler(ProvisionHandler):
                 duration=elapsed_milliseconds(utc_start))
 
         except ProvisionError as e:
-            logger.error("Provisioning failed: {0}", ustr(e))
+            msg = "Provisioning with cloud-init failed: {0} ({1}s)".format(ustr(e), self._get_uptime_seconds())
+            logger.error(msg)
             self.report_not_ready("ProvisioningFailed", ustr(e))
-            self.report_event(ustr(e))
+            self.report_event(msg)
             return
 
     def wait_for_ovfenv(self, max_retry=1800, sleep_time=1):
diff --git a/azurelinuxagent/pa/provision/default.py b/azurelinuxagent/pa/provision/default.py
index a6e50824..0eb0823c 100644
--- a/azurelinuxagent/pa/provision/default.py
+++ b/azurelinuxagent/pa/provision/default.py
@@ -98,9 +98,10 @@ class ProvisionHandler(object):
             logger.info("Provisioning complete")
 
         except (ProtocolError, ProvisionError) as e:
+            msg = "Provisioning failed: {0} ({1}s)".format(ustr(e), self._get_uptime_seconds())
+            logger.error(msg)
             self.report_not_ready("ProvisioningFailed", ustr(e))
-            self.report_event(ustr(e), is_success=False)
-            logger.error("Provisioning failed: {0}", ustr(e))
+            self.report_event(msg, is_success=False)
             return
 
     @staticmethod


Test patch:
diff --git a/tests/pa/test_provision.py b/tests/pa/test_provision.py
index 0335bc9c..27f75266 100644
--- a/tests/pa/test_provision.py
+++ b/tests/pa/test_provision.py
@@ -268,8 +268,8 @@ class TestProvision(AgentTestCase):
         fileutil.write_file(ovfenv_file, ovfenv_data)
 
         ph.run()
-        ph.report_event.assert_called_once_with(
-            '[ProvisionError] --unit-test--', is_success=False)
+        positional_args, kw_args = ph.report_event.call_args_list[0]
+        self.assertTrue(re.match(r'Provisioning failed: \[ProvisionError\] --unit-test-- \(\d+\.\d+s\)', positional_args[0]) is not None)
 
     @patch('azurelinuxagent.pa.provision.default.ProvisionHandler.write_agent_disabled')
     @distros()