| Message ID | 20250112002310.4045706-2-yoann.congal@smile.fr |
|---|---|
| State | Accepted, archived |
| Commit | b3bc820e58b65a976e0abce85fcdffd067697ecf |
| Headers | show |
| Series | [1/2] selftest/reproducible: Print full log path on failure | expand |
On Sun, 2025-01-12 at 01:23 +0100, Yoann Congal via lists.openembedded.org wrote: > From: Yoann Congal <yoann.congal@smile.fr> > > 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> > --- > RFC: As you can see, some lines are displayed multiple times if they are > in multiple errors contexts. I started implementing merging contexts > blocks but the code I wrote is really not good. If someone has a clever > idea on how to do this, I'll take it. > In the meantime, I think this simpler patch can be merged and the > print_condensed_error_log function improved later if that is worth it. Thanks for working on this. I think the multiple lines is fine. As someone who spends a lot of time looking at failures, I'm fine with too much information rather than the current situation where it isn't clear. Obviously it is nice to make it really concise but that is a nice to have. Cheers, Richard
diff --git a/meta/lib/oeqa/selftest/cases/reproducible.py b/meta/lib/oeqa/selftest/cases/reproducible.py index 9597d76697..3fb0e5ee5b 100644 --- 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.