From 477dcf37d9c23da91514df66cd51670d112fd69c Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Lubom=C3=ADr=20Sedl=C3=A1=C5=99?= <lsedlar@redhat.com>
Date: Wed, 17 Feb 2021 10:52:08 +0100
Subject: [PATCH] Store extended traceback for gather errors
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

When a gathering thread raises an exception, it gets forwarded to the
main thread and re-raised there. However, during this transition it
loses details about exact location of the problem.

This patch creates an extended traceback in the worker, which should
make it easier to track the problem down later.

JIRA: RHELCMP-4259
Signed-off-by: Lubomír Sedlář <lsedlar@redhat.com>
---
 pungi/compose.py                | 15 +++++++++++++++
 pungi/phases/gather/__init__.py |  4 ++++
 pungi/scripts/pungi_koji.py     |  7 +------
 tests/test_compose.py           | 30 ++++++++++++++++++++++++++++++
 4 files changed, 50 insertions(+), 6 deletions(-)

diff --git a/pungi/compose.py b/pungi/compose.py
index ec9c5640..f1229439 100644
--- a/pungi/compose.py
+++ b/pungi/compose.py
@@ -26,6 +26,7 @@ import shutil
 import json
 
 import kobo.log
+import kobo.tback
 from productmd.composeinfo import ComposeInfo
 from productmd.images import Images
 from dogpile.cache import make_region
@@ -590,6 +591,20 @@ class Compose(kobo.log.LoggingBase):
                 separators=(",", ": "),
             )
 
+    def traceback(self, detail=None):
+        """Store an extended traceback. This method should only be called when
+        handling an exception.
+
+        :param str detail: Extra information appended to the filename
+        """
+        basename = "traceback"
+        if detail:
+            basename += "-" + detail
+        tb_path = self.paths.log.log_file("global", basename)
+        self.log_error("Extended traceback in: %s", tb_path)
+        with open(tb_path, "wb") as f:
+            f.write(kobo.tback.Traceback().get_traceback())
+
 
 def get_ordered_variant_uids(compose):
     if not hasattr(compose, "_ordered_variant_uids"):
diff --git a/pungi/phases/gather/__init__.py b/pungi/phases/gather/__init__.py
index b559cfbc..9338d5da 100644
--- a/pungi/phases/gather/__init__.py
+++ b/pungi/phases/gather/__init__.py
@@ -730,6 +730,10 @@ def _gather_variants(
                 try:
                     que.put((arch, gather_packages(*args, **kwargs)))
                 except Exception as exc:
+                    compose.log_error(
+                        "Error in gathering for %s.%s: %s", variant, arch, exc
+                    )
+                    compose.traceback("gather-%s-%s" % (variant, arch))
                     errors.put(exc)
 
             # Run gather_packages() in parallel with multi threads and store
diff --git a/pungi/scripts/pungi_koji.py b/pungi/scripts/pungi_koji.py
index 54763e3b..dd568128 100644
--- a/pungi/scripts/pungi_koji.py
+++ b/pungi/scripts/pungi_koji.py
@@ -637,15 +637,10 @@ def cli_main():
         main()
     except (Exception, KeyboardInterrupt) as ex:
         if COMPOSE:
-            tb_path = COMPOSE.paths.log.log_file("global", "traceback")
             COMPOSE.log_error("Compose run failed: %s" % ex)
-            COMPOSE.log_error("Extended traceback in: %s" % tb_path)
+            COMPOSE.traceback()
             COMPOSE.log_critical("Compose failed: %s" % COMPOSE.topdir)
             COMPOSE.write_status("DOOMED")
-            import kobo.tback
-
-            with open(tb_path, "wb") as f:
-                f.write(kobo.tback.Traceback().get_traceback())
         else:
             print("Exception: %s" % ex)
             raise
diff --git a/tests/test_compose.py b/tests/test_compose.py
index 628973bd..94940909 100644
--- a/tests/test_compose.py
+++ b/tests/test_compose.py
@@ -777,3 +777,33 @@ class DumpContainerMetadataTest(unittest.TestCase):
     def test_dump_empty_metadata(self, ThreadPool):
         self.compose.dump_containers_metadata()
         self.assertFalse(os.path.isfile(self.tmp_dir + "/compose/metadata/osbs.json"))
+
+
+class TracebackTest(unittest.TestCase):
+    def setUp(self):
+        self.tmp_dir = tempfile.mkdtemp()
+        with mock.patch("pungi.compose.ComposeInfo"):
+            self.compose = Compose({}, self.tmp_dir)
+        self.patcher = mock.patch("kobo.tback.Traceback")
+        self.Traceback = self.patcher.start()
+        self.Traceback.return_value.get_traceback.return_value = b"traceback"
+
+    def tearDown(self):
+        shutil.rmtree(self.tmp_dir)
+        self.patcher.stop()
+
+    def assertTraceback(self, filename):
+        self.assertTrue(
+            os.path.isfile("%s/logs/global/%s.global.log" % (self.tmp_dir, filename))
+        )
+        self.assertEqual(
+            self.Traceback.mock_calls, [mock.call(), mock.call().get_traceback()]
+        )
+
+    def test_traceback_default(self):
+        self.compose.traceback()
+        self.assertTraceback("traceback")
+
+    def test_with_detail(self):
+        self.compose.traceback("extra-info")
+        self.assertTraceback("traceback-extra-info")