diff mbox series

[RFC] test/cyclic: try to avoid spurious test failures due to cyclic callbacks

Message ID 20240524210817.1953298-1-rasmus.villemoes@prevas.dk
State New
Delegated to: Stefan Roese
Headers show
Series [RFC] test/cyclic: try to avoid spurious test failures due to cyclic callbacks | expand

Commit Message

Rasmus Villemoes May 24, 2024, 9:08 p.m. UTC
Looking at failed pipelines on
https://dev.azure.com/u-boot/u-boot/_build, it is easy to find lots of
examples that have failed spuriously for the same reason: The "cyclic
function ... took too long" message being printed in the middle of
some console output, causing the 'expect' machinery to fail to find
the expected output.

This mostly happens on QEMU and/or sandbox, i.e. cases where U-Boot
isn't really the only thing running on the CPU, so random host
scheduling can cause several millisecond delays, and if that just
happens to interrupt the U-boot code while one of those cyclic
callbacks are running, that message will be printed.

This is one attempt at trying to avoid those spurious and annoying
failures: Add a "backdoor" that allows bumping the threshold, and in
the test framework, make sure that every time we boot we set that
threshold to a high enough value that should eliminate 99% of those
warnings.

I chose an env-var-with-callback instead of, say, teaching the
'cyclic' command something new. The latter is not always enabled, so
it would be more complicated to hook up; setting an env var that is
not used for anything is, to quote Douglas Adams, mostly harmless. I
made it "hidden" so as not to mess up any existing "print the whole
evnironment test", and also to sort-of emphasize that this isn't
really meant to be an official interface.

Signed-off-by: Rasmus Villemoes <rasmus.villemoes@prevas.dk>
---

Not really tested except booted into sandbox, adding a printf in the
callback to see that it gets called, using 'cyclic demo' to register a
demo callback, and using this mechanism to _lower_ the threshold to
see that the new value actually takes effect. In particular, I have no
idea if the test/py/ part of this works as intended.

 common/cyclic.c                | 17 ++++++++++++++---
 include/env_callback.h         |  7 +++++++
 test/py/u_boot_console_base.py |  1 +
 3 files changed, 22 insertions(+), 3 deletions(-)
diff mbox series

Patch

diff --git a/common/cyclic.c b/common/cyclic.c
index a49bfc88f5c..50cc7a02ba5 100644
--- a/common/cyclic.c
+++ b/common/cyclic.c
@@ -9,6 +9,7 @@ 
  */
 
 #include <cyclic.h>
+#include <env.h>
 #include <log.h>
 #include <malloc.h>
 #include <time.h>
@@ -20,6 +21,17 @@  DECLARE_GLOBAL_DATA_PTR;
 
 void hw_watchdog_reset(void);
 
+static unsigned int max_cpu_time = CONFIG_CYCLIC_MAX_CPU_TIME_US;
+
+static int on_cyclic_max_cpu_time(const char *name, const char *value,
+				  enum env_op op, int flags)
+{
+	if (op != env_op_delete)
+		max_cpu_time = dectoul(value, NULL);
+	return 0;
+}
+U_BOOT_ENV_CALLBACK(cyclic_max_cpu_time, on_cyclic_max_cpu_time);
+
 struct hlist_head *cyclic_get_list(void)
 {
 	/* Silence "discards 'volatile' qualifier" warning. */
@@ -82,11 +94,10 @@  void cyclic_run(void)
 			cyclic->cpu_time_us += cpu_time;
 
 			/* Check if cpu-time exceeds max allowed time */
-			if ((cpu_time > CONFIG_CYCLIC_MAX_CPU_TIME_US) &&
+			if ((cpu_time > max_cpu_time) &&
 			    (!cyclic->already_warned)) {
 				pr_err("cyclic function %s took too long: %lldus vs %dus max\n",
-				       cyclic->name, cpu_time,
-				       CONFIG_CYCLIC_MAX_CPU_TIME_US);
+				       cyclic->name, cpu_time, max_cpu_time);
 
 				/*
 				 * Don't disable this function, just warn once
diff --git a/include/env_callback.h b/include/env_callback.h
index 23bc650c162..c0979b14302 100644
--- a/include/env_callback.h
+++ b/include/env_callback.h
@@ -68,6 +68,12 @@ 
 #define BOOTSTD_CALLBACK
 #endif
 
+#ifdef CONFIG_CYCLIC
+#define CYCLIC_CALLBACK ENV_DOT_ESCAPE ".cyclic_max_cpu_time:cyclic_max_cpu_time,"
+#else
+#define CYCLIC_CALLBACK
+#endif
+
 /*
  * This list of callback bindings is static, but may be overridden by defining
  * a new association in the ".callbacks" environment variable.
@@ -82,6 +88,7 @@ 
 	SILENT_CALLBACK \
 	"stdin:console,stdout:console,stderr:console," \
 	"serial#:serialno," \
+	CYCLIC_CALLBACK \
 	CFG_ENV_CALLBACK_LIST_STATIC
 
 #ifndef CONFIG_SPL_BUILD
diff --git a/test/py/u_boot_console_base.py b/test/py/u_boot_console_base.py
index 26b6de07f88..908b06359ec 100644
--- a/test/py/u_boot_console_base.py
+++ b/test/py/u_boot_console_base.py
@@ -186,6 +186,7 @@  class ConsoleBase(object):
                     continue
                 raise Exception('Bad pattern found on console: ' +
                                 self.bad_pattern_ids[m - 2])
+            self.run_command("env set .cyclic_max_cpu_time 100000")
 
         except Exception as ex:
             self.log.error(str(ex))