DataSourceAzure: push dmesg log to KVP (#670)

Pushing dmesg log to KVP to help troubleshoot VM boot issues

2 files changed, 41 insertions, 2 deletions

diff --git a/cloudinit/sources/helpers/azure.py b/cloudinit/sources/helpers/azure.py
index 2b3303c7..d3055d08 100755
--- a/cloudinit/sources/helpers/azure.py
+++ b/cloudinit/sources/helpers/azure.py
@@ -224,7 +224,8 @@ def push_log_to_kvp(file_name=CFG_BUILTIN['def_log_file']):
     based on the file size.
     The first time this function is called after VM boot, It will push the last
     n bytes of the log file such that n < MAX_LOG_TO_KVP_LENGTH
-    If called again on the same boot, it continues from where it left off."""
+    If called again on the same boot, it continues from where it left off.
+    In addition to cloud-init.log, dmesg log will also be collected."""
 
     start_index = get_last_log_byte_pushed_to_kvp_index()
 
@@ -245,6 +246,15 @@ def push_log_to_kvp(file_name=CFG_BUILTIN['def_log_file']):
             "Exception when dumping log file: %s" % repr(ex),
             logger_func=LOG.warning)
 
+    LOG.debug("Dumping dmesg log to KVP")
+    try:
+        out, _ = subp.subp(['dmesg'], decode=False, capture=True)
+        report_compressed_event("dmesg", out)
+    except Exception as ex:
+        report_diagnostic_event(
+            "Exception when dumping dmesg log: %s" % repr(ex),
+            logger_func=LOG.warning)
+
 
 @azure_ds_telemetry_reporter
 def get_last_log_byte_pushed_to_kvp_index():
diff --git a/tests/unittests/test_reporting_hyperv.py b/tests/unittests/test_reporting_hyperv.py
index 8f7b3694..9324b78d 100644
--- a/tests/unittests/test_reporting_hyperv.py
+++ b/tests/unittests/test_reporting_hyperv.py
@@ -230,8 +230,33 @@ class TextKvpReporter(CiTestCase):
             instantiated_handler_registry.unregister_item("telemetry",
                                                           force=False)
 
+    @mock.patch('cloudinit.sources.helpers.azure.report_compressed_event')
+    @mock.patch('cloudinit.sources.helpers.azure.report_diagnostic_event')
+    @mock.patch('cloudinit.subp.subp')
+    def test_push_log_to_kvp_exception_handling(self, m_subp, m_diag, m_com):
+        reporter = HyperVKvpReportingHandler(kvp_file_path=self.tmp_file_path)
+        try:
+            instantiated_handler_registry.register_item("telemetry", reporter)
+            log_file = self.tmp_path("cloud-init.log")
+            azure.MAX_LOG_TO_KVP_LENGTH = 100
+            azure.LOG_PUSHED_TO_KVP_INDEX_FILE = self.tmp_path(
+                'log_pushed_to_kvp')
+            with open(log_file, "w") as f:
+                log_content = "A" * 50 + "B" * 100
+                f.write(log_content)
+
+            m_com.side_effect = Exception("Mock Exception")
+            azure.push_log_to_kvp(log_file)
+
+            # exceptions will trigger diagnostic reporting calls
+            self.assertEqual(m_diag.call_count, 3)
+        finally:
+            instantiated_handler_registry.unregister_item("telemetry",
+                                                          force=False)
+
+    @mock.patch('cloudinit.subp.subp')
     @mock.patch.object(LogHandler, 'publish_event')
-    def test_push_log_to_kvp(self, publish_event):
+    def test_push_log_to_kvp(self, publish_event, m_subp):
         reporter = HyperVKvpReportingHandler(kvp_file_path=self.tmp_file_path)
         try:
             instantiated_handler_registry.register_item("telemetry", reporter)
@@ -249,6 +274,10 @@ class TextKvpReporter(CiTestCase):
                 f.write(extra_content)
             azure.push_log_to_kvp(log_file)
 
+            # make sure dmesg is called every time
+            m_subp.assert_called_with(
+                ['dmesg'], capture=True, decode=False)
+
             for call_arg in publish_event.call_args_list:
                 event = call_arg[0][0]
                 self.assertNotEqual(