selftest/reproducible: Print error context on failure

Printed logs during the reproducible test look like this in case of
failure:
2025-01-12 00:39:00,807 - oe-selftest - INFO - Building reproducibleA (sstate allowed)...
2025-01-12 00:40:08,323 - oe-selftest - ERROR - Bitbake failed! but keep going... Log:
2025-01-12 00:40:08,323 - oe-selftest - INFO - Found ERROR (line 126):
2025-01-12 00:40:08,323 - oe-selftest - INFO -       NOTE: recipe opkg-utils-native-0.7.0-r0: task do_populate_sysroot_setscene: Succeeded
2025-01-12 00:40:08,323 - oe-selftest - INFO -       NOTE: Running setscene task 74 of 333 (virtual:native:.../poky/meta/recipes-devtools/opkg-utils/opkg-utils_0.7.0.bb:do_recipe_qa_setscene)
2025-01-12 00:40:08,323 - oe-selftest - INFO -       NOTE: recipe bash-5.2.37-r0: task do_populate_sysroot_setscene: Succeeded
2025-01-12 00:40:08,323 - oe-selftest - INFO -       NOTE: recipe cve-update-nvd2-native-1.0-r0: task do_unpack: Succeeded
2025-01-12 00:40:08,323 - oe-selftest - INFO -       NOTE: Running task 4 of 974 (.../poky/meta/recipes-core/hello-single/hello-fail_1.0.bb:do_cve_check)
2025-01-12 00:40:08,323 - oe-selftest - INFO -       NOTE: recipe bash-5.2.37-r0: task do_packagedata_setscene: Succeeded
2025-01-12 00:40:08,323 - oe-selftest - INFO -       NOTE: recipe hello-fail-1.0-r0: task do_packagedata_setscene: Started
2025-01-12 00:40:08,323 - oe-selftest - INFO -       NOTE: Running setscene task 77 of 333 (.../poky/meta/recipes-extended/bash/bash_5.2.37.bb:do_recipe_qa_setscene)
2025-01-12 00:40:08,323 - oe-selftest - INFO -       NOTE: Running setscene task 78 of 333 (.../poky/meta/recipes-core/ncurses/ncurses_6.5.bb:do_populate_sysroot_setscene)
2025-01-12 00:40:08,324 - oe-selftest - INFO -       NOTE: recipe hello-fail-1.0-r0: task do_populate_sysroot_setscene: Started
2025-01-12 00:40:08,324 - oe-selftest - INFO -       ERROR: hello-fail-1.0-r0 do_populate_sysroot_setscene: this is an error
2025-01-12 00:40:08,324 - oe-selftest - INFO -       ERROR: hello-fail-1.0-r0 do_populate_sysroot_setscene: Error executing a python function in exec_func_python() autogenerated:
2025-01-12 00:40:08,324 - oe-selftest - INFO -
2025-01-12 00:40:08,324 - oe-selftest - INFO -       The stack trace of python calls that resulted in this exception/failure was:
2025-01-12 00:40:08,324 - oe-selftest - INFO -       File: 'exec_func_python() autogenerated', lineno: 2, function: <module>
2025-01-12 00:40:08,324 - oe-selftest - INFO -            0001:
2025-01-12 00:40:08,324 - oe-selftest - INFO -        *** 0002:do_populate_sysroot_setscene(d)
2025-01-12 00:40:08,324 - oe-selftest - INFO -            0003:
2025-01-12 00:40:08,324 - oe-selftest - INFO -       File: '.../poky/meta/recipes-core/hello-single/hello-fail_1.0.bb', lineno: 17, function: do_populate_sysroot_setscene
2025-01-12 00:40:08,324 - oe-selftest - INFO -            0013:}
2025-01-12 00:40:08,324 - oe-selftest - INFO - Found ERROR (line 127):
2025-01-12 00:40:08,324 - oe-selftest - INFO -       NOTE: Running setscene task 74 of 333 (virtual:native:.../poky/meta/recipes-devtools/opkg-utils/opkg-utils_0.7.0.bb:do_recipe_qa_setscene)
2025-01-12 00:40:08,324 - oe-selftest - INFO -       NOTE: recipe bash-5.2.37-r0: task do_populate_sysroot_setscene: Succeeded
2025-01-12 00:40:08,324 - oe-selftest - INFO -       NOTE: recipe cve-update-nvd2-native-1.0-r0: task do_unpack: Succeeded
2025-01-12 00:40:08,324 - oe-selftest - INFO -       NOTE: Running task 4 of 974 (.../poky/meta/recipes-core/hello-single/hello-fail_1.0.bb:do_cve_check)
2025-01-12 00:40:08,324 - oe-selftest - INFO -       NOTE: recipe bash-5.2.37-r0: task do_packagedata_setscene: Succeeded
2025-01-12 00:40:08,324 - oe-selftest - INFO -       NOTE: recipe hello-fail-1.0-r0: task do_packagedata_setscene: Started
2025-01-12 00:40:08,324 - oe-selftest - INFO -       NOTE: Running setscene task 77 of 333 (.../poky/meta/recipes-extended/bash/bash_5.2.37.bb:do_recipe_qa_setscene)
2025-01-12 00:40:08,324 - oe-selftest - INFO -       NOTE: Running setscene task 78 of 333 (.../poky/meta/recipes-core/ncurses/ncurses_6.5.bb:do_populate_sysroot_setscene)
2025-01-12 00:40:08,324 - oe-selftest - INFO -       NOTE: recipe hello-fail-1.0-r0: task do_populate_sysroot_setscene: Started
2025-01-12 00:40:08,324 - oe-selftest - INFO -       ERROR: hello-fail-1.0-r0 do_populate_sysroot_setscene: this is an error
2025-01-12 00:40:08,324 - oe-selftest - INFO -       ERROR: hello-fail-1.0-r0 do_populate_sysroot_setscene: Error executing a python function in exec_func_python() autogenerated:
2025-01-12 00:40:08,325 - oe-selftest - INFO -
2025-01-12 00:40:08,325 - oe-selftest - INFO -       The stack trace of python calls that resulted in this exception/failure was:
2025-01-12 00:40:08,325 - oe-selftest - INFO -       File: 'exec_func_python() autogenerated', lineno: 2, function: <module>
2025-01-12 00:40:08,325 - oe-selftest - INFO -            0001:
2025-01-12 00:40:08,325 - oe-selftest - INFO -        *** 0002:do_populate_sysroot_setscene(d)
2025-01-12 00:40:08,325 - oe-selftest - INFO -            0003:
2025-01-12 00:40:08,325 - oe-selftest - INFO -       File: '.../poky/meta/recipes-core/hello-single/hello-fail_1.0.bb', lineno: 17, function: do_populate_sysroot_setscene
2025-01-12 00:40:08,325 - oe-selftest - INFO -            0013:}
2025-01-12 00:40:08,325 - oe-selftest - INFO -            0014:
2025-01-12 00:40:08,325 - oe-selftest - INFO - End of log:
2025-01-12 00:40:08,325 - oe-selftest - INFO -       NOTE: Running task 955 of 974 (.../poky/meta/recipes-core/hello-single/hello-fail_1.0.bb:do_populate_sysroot)
2025-01-12 00:40:08,325 - oe-selftest - INFO -       NOTE: recipe hello-fail-1.0-r0: task do_populate_sysroot: Started
2025-01-12 00:40:08,325 - oe-selftest - INFO -       NOTE: recipe hello-fail-1.0-r0: task do_populate_sysroot: Succeeded
2025-01-12 00:40:08,325 - oe-selftest - INFO -       NOTE: Running noexec task 973 of 974 (.../poky/meta/recipes-core/hello-single/hello-fail_1.0.bb:do_build)
2025-01-12 00:40:08,325 - oe-selftest - INFO -       NOTE: Running noexec task 974 of 974 (.../poky/meta/recipes-core/hello-single/hello-norepro_1.0.bb:do_build)
2025-01-12 00:40:08,325 - oe-selftest - INFO -       NOTE: Tasks Summary: Attempted 974 tasks of which 958 didn't need to be rerun and all succeeded.
2025-01-12 00:40:08,325 - oe-selftest - INFO -       NOTE: Generating JSON CVE summary
2025-01-12 00:40:08,325 - oe-selftest - INFO -       Complete CVE JSON report summary created at: .../poky/build-master-st/reproducibleA/tmp/log/cve/cve-summary.json
2025-01-12 00:40:08,325 - oe-selftest - INFO -
2025-01-12 00:40:08,325 - oe-selftest - INFO -       Summary: There were 2 ERROR messages, returning a non-zero exit code.
2025-01-12 00:40:08,326 - oe-selftest - ERROR - reproducibleA build failed. Trying to compute built packages differences but the test will fail.

Fixes [YOCTO #15655] (second half).

Signed-off-by: Yoann Congal <yoann.congal@smile.fr>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>

diff --git a/meta/lib/oeqa/selftest/cases/reproducible.py b/meta/lib/oeqa/selftest/cases/reproducible.py
index 9597d7669781cb6d5e257aed8cd2d0ab2d29d635..3fb0e5ee5bad845972afc5c8ecc393117bf3a383 100644 (file)
--- a/meta/lib/oeqa/selftest/cases/reproducible.py
+++ b/meta/lib/oeqa/selftest/cases/reproducible.py
@@ -239,18 +239,31 @@ class ReproducibleTests(OESelftestTestCase):
         # may reuse the previous log file so restart the bitbake server.
         bitbake("--kill-server")
 
+        def print_condensed_error_log(logs, context_lines=10, tail_lines=20):
+            """Prints errors with context and the end of the log."""
+
+            logs = logs.split("\n")
+            for i, line in enumerate(logs):
+                if line.startswith("ERROR"):
+                    self.logger.info("Found ERROR (line %d):" % (i + 1))
+                    for l in logs[i-context_lines:i+context_lines]:
+                        self.logger.info("      " + l)
+
+            self.logger.info("End of log:")
+            for l in logs[-tail_lines:]:
+                self.logger.info("      " + l)
+
         bitbake_failure_count = 0
         if not use_sstate:
             if self.sstate_targets:
                self.logger.info("Building prebuild for %s (sstate allowed)..." % (name))
                self.write_config(config)
                try:
-                   bitbake("--continue "+' '.join(self.sstate_targets), limit_exc_output=20)
+                   bitbake("--continue "+' '.join(self.sstate_targets))
                except AssertionError as e:
                    bitbake_failure_count += 1
                    self.logger.error("Bitbake failed! but keep going... Log:")
-                   for line in str(e).split("\n"):
-                       self.logger.info("    "+line)
+                   print_condensed_error_log(str(e))
 
             # This config fragment will disable using shared and the sstate
             # mirror, forcing a complete build from scratch
@@ -264,13 +277,11 @@ class ReproducibleTests(OESelftestTestCase):
         d = get_bb_vars(capture_vars)
         # targets used to be called images
         try:
-            bitbake("--continue "+' '.join(getattr(self, 'images', self.targets)), limit_exc_output=20)
+            bitbake("--continue "+' '.join(getattr(self, 'images', self.targets)))
         except AssertionError as e:
             bitbake_failure_count += 1
-
             self.logger.error("Bitbake failed! but keep going... Log:")
-            for line in str(e).split("\n"):
-                self.logger.info("    "+line)
+            print_condensed_error_log(str(e))
 
             # The calling function expects the existence of the deploy
             # directories containing the packages.