[RFC PATCH v1 0/7] Bootstage reports for CI

[RFC PATCH v1 0/7] Bootstage reports for CI

[Jerome Forissier]

The BOOTSTAGE Kconfig symbol allows to record boot time information
which can be consumed in several ways:

1) Printed to the console just before the OS is booted (when
   BOOTSTAGE_REPORT=y)
2) Printed to the console by the "bootstage report" command (when
   CMD_BOOTSTAGE=y)
3) Passed to the OS in the Device Tree (when BOOTSTAGE_FDT=y)
4) Written to some memory location in binary format before the OS is
   booted (when BOOTSTAGE_STASH=y)

None of these options are convenient for use in CI. Suppose we want to
monitor a set of boards for boot time regressions -- in other words,
make sure the boot time does not degrade unexpectedly as the code
evolves. For that, we'd like to be able to record the bootstage data in
some kind of database or persistent storage and possibly draw graphs
showing trends over time.

This RFC is a step in that direction. It introduces two new output
formats for the bootstage data. The two are independant, they are simply
two options I considered:

1) JSON
2) InfluxDB v2 line protocol [1]

Both depend on BOOTSTAGE_REPORT and are enabled by BOOTSTAGE_REPORT_JSON
and BOOTSTAGE_REPORT_INFLUXDB respectively. Each format comes with its
own test in test/py/tests. The InfluxDB test is special in that it is
able to upload the data to a cloud database, provided the environment
variables BOOTSTAGE_INFLUXDB_URI and BOOTSTAGE_INFLUXDB_TOKEN are set
properly.

I have been able to run a boot test on rpi4 in the sjg-lab with
BOOTSTGE_REPORT_INFLUXDB enabled. The CI log [2] shows that the data
were indeed uploaded to my InfluxDB Cloud test account.

This is published as an RFC since it is just an investigation. If
someone finds this useful I may folloow-up with a non-RFC series.

Comments are welcome.

[1] https://docs.influxdata.com/influxdb/v2/reference/syntax/line-protocol/
[2] https://source.denx.de/u-boot/custodians/u-boot-net/-/jobs/1097039#L116


Jerome Forissier (7):
  efi_loader: make efi_exit_boot_services() call bootstage_report()
  bootstage: add support for reporting in JSON format
  test/py/tests/test_bootstage.py: add test for JSON report
  bootstage: add support for reporting in InfluxDB v2 line format
  test/py/tests/test_bootstage.py: add test for InfluxDB report
  sandbox64_defconfig: enable bootstage report in JSON and InfluxDB
    formats
  test/py/tests/test_bootstage.py: upload bootstage data to InfluxDB
    cloud

 boot/Kconfig                    |  17 ++
 common/bootstage.c              | 289 +++++++++++++++++++++++++++++++-
 configs/sandbox64_defconfig     |   2 +
 lib/efi_loader/efi_boottime.c   |   7 +
 test/py/requirements.txt        |   1 +
 test/py/tests/test_bootstage.py |  57 +++++++
 6 files changed, 372 insertions(+), 1 deletion(-)

-- 
2.43.0

[RFC PATCH v1 1/7] efi_loader: make efi_exit_boot_services() call bootstage_report()

[Jerome Forissier]

CONFIG_BOOTSTAGE_REPORT is currently supported in the bootm command
only. Add support to the EFI boot.

Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
---

 lib/efi_loader/efi_boottime.c | 7 +++++++
 1 file changed, 7 insertions(+)

diff --git a/lib/efi_loader/efi_boottime.c b/lib/efi_loader/efi_boottime.c
index c8d9a6037f7..96da279afd4 100644
--- a/lib/efi_loader/efi_boottime.c
+++ b/lib/efi_loader/efi_boottime.c
@@ -8,6 +8,7 @@
 #define LOG_CATEGORY LOGC_EFI
 
 #include <bootm.h>
+#include <bootstage.h>
 #include <div64.h>
 #include <dm/device.h>
 #include <dm/root.h>
@@ -2179,6 +2180,12 @@ static efi_status_t EFIAPI efi_exit_boot_services(efi_handle_t image_handle,
 
 	EFI_ENTRY("%p, %zx", image_handle, map_key);
 
+#if !defined(USE_HOSTCC)
+#if CONFIG_IS_ENABLED(BOOTSTAGE)
+	bootstage_report();
+#endif
+#endif
+
 	/* Check that the caller has read the current memory map */
 	if (map_key != efi_memory_map_key) {
 		ret = EFI_INVALID_PARAMETER;
-- 
2.43.0

[RFC PATCH v1 2/7] bootstage: add support for reporting in JSON format

[Jerome Forissier]

Add a new Kconfig symbol: BOOTSTAGE_REPORT_JSON to report the bootstage
timing information in JSON format in addition to the human-readable
text format. JSON is easier to parse by machines and represent
graphically. The main goal is to be able to record boot statistics during
CI in order to detect performance regressions.

Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
---

 boot/Kconfig       |   7 ++
 common/bootstage.c | 156 ++++++++++++++++++++++++++++++++++++++++++++-
 2 files changed, 162 insertions(+), 1 deletion(-)

diff --git a/boot/Kconfig b/boot/Kconfig
index f101200ba7a..5e90e20141a 100644
--- a/boot/Kconfig
+++ b/boot/Kconfig
@@ -1167,6 +1167,13 @@ config BOOTSTAGE_REPORT
 		 29,916,167 26,005,792  bootm_start
 		 30,361,327    445,160  start_kernel
 
+config BOOTSTAGE_REPORT_JSON
+	bool "Display boot timing report in JSON format"
+	depends on BOOTSTAGE_REPORT
+	help
+	  Enable output of the boot time report in JSON format in addition to
+	  the human-readable text format.
+
 config BOOTSTAGE_RECORD_COUNT
 	int "Number of boot stage records to store"
 	depends on BOOTSTAGE
diff --git a/common/bootstage.c b/common/bootstage.c
index 4532100acea..1ab55ecbe8f 100644
--- a/common/bootstage.c
+++ b/common/bootstage.c
@@ -11,6 +11,7 @@
 #define LOG_CATEGORY	LOGC_BOOT
 
 #include <bootstage.h>
+#include <env.h>
 #include <hang.h>
 #include <log.h>
 #include <malloc.h>
@@ -19,6 +20,8 @@
 #include <asm/global_data.h>
 #include <linux/compiler.h>
 #include <linux/libfdt.h>
+#include <timestamp.h>
+#include <version.h>
 
 DECLARE_GLOBAL_DATA_PTR;
 
@@ -324,7 +327,7 @@ int bootstage_fdt_add_report(void)
 }
 #endif
 
-void bootstage_report(void)
+static void bootstage_report_text(void)
 {
 	struct bootstage_data *data = gd->bootstage;
 	struct bootstage_record *rec = data->record;
@@ -353,6 +356,157 @@ void bootstage_report(void)
 	}
 }
 
+/**
+ * Same as get_record_name() but with a %<n> suffix if needed to make the name a
+ * a unique key. More specifically, where get_record_name() would return "foo"
+ * twice for two distinct records, this function would return "foo" and "foo%1".
+ *
+ * @param buf	Buffer to put name if needed
+ * @param len	Length of buffer
+ * @param rec	Boot stage record to get the name from
+ * Return: pointer to name, either from the record or pointing to buf.
+ */
+static const char *get_unique_record_name(char *buf, int len,
+					  const struct bootstage_record *rec)
+{
+	struct bootstage_data *data = gd->bootstage;
+	const char *name;
+	char tmpbuf1[20];
+	char tmpbuf2[20];
+	int idx = 0;
+	int i;
+
+	name = get_record_name(tmpbuf1, sizeof(tmpbuf1), rec);
+
+	/* Count records with an identical name before @rec in the array */
+	for (i = 0; i < data->rec_count; i++) {
+		struct bootstage_record *irec = data->record + i;
+		const char *iname = get_record_name(tmpbuf2, sizeof(tmpbuf2),
+						    irec);
+
+		if (irec == rec)
+			break;
+		if (!strcmp(name, iname))
+			idx++;
+	}
+
+	if (idx)
+		snprintf(buf, len, "%s%%%d", name, idx);
+	else
+		strlcpy(buf, name, len);
+
+	return buf;
+}
+
+/**
+ * print_time_record_json() - print a time entry in JSON format for a bootstage
+ * record or a couple of bootstage records.
+ *
+ * The function prints "key_name": value
+ *
+ * - If @rec->start_us is non-zero, it means @rec holds accumulated time. In
+ *   this case, key_name is the unique record name and value is @rec->time_us.
+ * - Otherwise, @rec represents a boot stage with an associated timestamp. The
+ *   key name is obtained by concatenating the previous record name and the
+ *   current record name, separated by a tilda. The value is the elapsed time
+ *   between the two stages, that is: @rec->time_us - @prev->time_us.
+ *
+ * @rec: the record to print
+ * @prev: the previous timestamp record (used as a reference when @rec is a
+ * timestamp)
+ * Returns @rec if it is a timestamp, @prev otherwise
+ */
+static struct bootstage_record *
+print_time_record_json(struct bootstage_record *rec,
+		       struct bootstage_record *prev)
+{
+	char buf1[24];
+	char buf2[24];
+
+	if (rec->start_us) {
+		/* An "Accumulated time" entry in the text report */
+		printf("\"%s\": %lu",
+		       get_unique_record_name(buf1, sizeof(buf1), rec),
+		       rec->time_us);
+		return prev;
+	}
+
+	/* Elapsed time between two consecutive stages */
+	printf("\"%s~%s\": %lu",
+	       get_unique_record_name(buf1, sizeof(buf1), prev),
+	       get_unique_record_name(buf2, sizeof(buf2), rec),
+	       rec->time_us - prev->time_us);
+
+	return rec;
+}
+
+/**
+ * print_env_json() - print an environment variable in JSON format
+ *
+ * @env: the variable to print
+ * @cont: true if a continuation comma ', ' should be printed afterwards
+ */
+static void print_env_json(const char *env, bool cont)
+{
+	char *val = env_get(env);
+
+	printf("\"%s\": \"%s\"", env, val ? val : "");
+	if (cont)
+		puts(", ");
+}
+
+/**
+ * bootstage_report_json() - print the JSON bootstage report
+ */
+static void bootstage_report_json(void)
+{
+	struct bootstage_data *data = gd->bootstage;
+	struct bootstage_record *prev = data->record;
+	struct bootstage_record *rec = data->record;
+	struct bootstage_record *boot_end = NULL;
+	bool first = true;
+	int i;
+
+	puts("=== Begin JSON bootstage report ===\n");
+	puts("{ \"u_boot_version\": \"" PLAIN_VERSION "\", ");
+	puts("\"u_boot_date\": \"" U_BOOT_DATE "\", ");
+	puts("\"u_boot_time\": \"" U_BOOT_TIME "\", ");
+	puts("\"u_boot_tz\": \"" U_BOOT_TZ "\", ");
+	puts("\"env\": { ");
+	print_env_json("arch", 1);
+	print_env_json("board", 1);
+	print_env_json("board_name", 1);
+	print_env_json("cpu", 1);
+	print_env_json("vendor", 0);
+	puts(" }, \"bootstage_data\": { ");
+
+	for (i = 1, rec++; i < data->rec_count; i++, rec++) {
+		if (rec->id) {
+			if (!rec->start_us)
+				boot_end = rec;
+			if (!first)
+				puts(", ");
+			prev = print_time_record_json(rec, prev);
+			first = false;
+		}
+	}
+	if (boot_end)
+		printf(", \"total\": %ld", boot_end->time_us);
+
+	puts(" } }\n");
+	puts("=== End JSON bootstage report ===\n");
+}
+
+/**
+ * bootstage_report() - print the bootstage report(s)
+ */
+void bootstage_report(void)
+{
+	bootstage_report_text();
+	if (CONFIG_IS_ENABLED(BOOTSTAGE_REPORT_JSON))
+		bootstage_report_json();
+}
+
 /**
  * Append data to a memory buffer
  *
-- 
2.43.0

[RFC PATCH v1 3/7] test/py/tests/test_bootstage.py: add test for JSON report

[Jerome Forissier]

Add test for CONFIG_BOOTSTAGE_REPORT_JSON.

Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
---

 test/py/tests/test_bootstage.py | 9 +++++++++
 1 file changed, 9 insertions(+)

diff --git a/test/py/tests/test_bootstage.py b/test/py/tests/test_bootstage.py
index 379c1cae6dd..8d0afe2611b 100644
--- a/test/py/tests/test_bootstage.py
+++ b/test/py/tests/test_bootstage.py
@@ -30,6 +30,15 @@ def test_bootstage_report(ubman):
     assert 'Accumulated time:' in output
     assert 'dm_r' in output
 
+@pytest.mark.buildconfigspec('bootstage')
+@pytest.mark.buildconfigspec('cmd_bootstage')
+@pytest.mark.buildconfigspec('bootstage_report_json')
+def test_bootstage_report_json(ubman):
+    output = ubman.run_command('bootstage report')
+    assert '=== Begin JSON bootstage report ===' in output
+    assert '"dm_r"' in output
+    assert '"reset~board_init_f"' in output
+
 @pytest.mark.buildconfigspec('bootstage')
 @pytest.mark.buildconfigspec('cmd_bootstage')
 @pytest.mark.buildconfigspec('bootstage_stash')
-- 
2.43.0

[RFC PATCH v1 4/7] bootstage: add support for reporting in InfluxDB v2 line format

[Jerome Forissier]

Add a new Kconfig symbol: BOOTSTAGE_REPORT_INFLUXDB to report the
bootstage timing information in InfluxDB v2 line protocol format in
addition to the human-readable text format. InfluxDB provides an easy
way to record boot statistics during CI in order to detect performance
regressions.

[1] https://docs.influxdata.com/influxdb/v2/reference/syntax/line-protocol/

Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
---

 boot/Kconfig       |  10 ++++
 common/bootstage.c | 133 +++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 143 insertions(+)

diff --git a/boot/Kconfig b/boot/Kconfig
index 5e90e20141a..6249f3bb0c9 100644
--- a/boot/Kconfig
+++ b/boot/Kconfig
@@ -1174,6 +1174,16 @@ config BOOTSTAGE_REPORT_JSON
 	  Enable output of the boot time report in JSON format in addition to
 	  the human-readable text format.
 
+config BOOTSTAGE_REPORT_INFLUXDB
+	bool "Display boot timing report in InfluxDB v2 line protocol"
+	depends on BOOTSTAGE_REPORT
+	help
+	  Enable output of the boot time report in InfluxDB v2 line protocol
+	  format in addition to the human-readable text format.
+	  The report may be uploaded to the InfluxDB Cloud via an HTTPS POST.
+	  See https://docs.influxdata.com/influxdb/v2/reference/syntax/line-protocol/
+	  and https://docs.influxdata.com/influxdb/v2/write-data/developer-tools/api/.
+
 config BOOTSTAGE_RECORD_COUNT
 	int "Number of boot stage records to store"
 	depends on BOOTSTAGE
diff --git a/common/bootstage.c b/common/bootstage.c
index 1ab55ecbe8f..9009882ef73 100644
--- a/common/bootstage.c
+++ b/common/bootstage.c
@@ -497,6 +497,137 @@ static void bootstage_report_json(void)
 	puts("=== End JSON bootstage report ===\n");
 }
 
+/**
+ * puts_influxdb_escape() - Print a string, escaping the characters that have a
+ * special meaning in the InfluxDB v2 line protocol
+ *
+ * @str: the string to print
+ */
+static void puts_influxdb_escape(const char *str)
+{
+	const char *p = str;
+
+	while (p && *p) {
+		if (*p == ' ' || *p == ',' || *p == '=')
+			putc('\\');
+		putc(*p);
+		p++;
+	}
+}
+
+/**
+ * print_time_record_influxdb() - print a time entry in InfluxDB v2 line
+ * protocolformat for a bootstage record or a couple of bootstage records.
+ *
+ * The function prints [,]key_name=value
+ *
+ * - If @rec->start_us is non-zero, it means @rec holds accumulated time. In
+ *   this case, key_name is the unique record name and value is @rec->time_us.
+ * - Otherwise, @rec represents a boot stage with an associated timestamp. The
+ *   key name is obtained by concatenating the previous record name and the
+ *   current record name, separated by a tilda. The value is the elapsed time
+ *   between the two stages, that is: @rec->time_us - @prev->time_us.
+ *
+ * @rec: the record to print
+ * @prev: the previous timestamp record (used as a reference when @rec is a
+ * timestamp)
+ * @is_first: true if this is the first reported data (won't print a
+ * continuation comma first ',')
+ * Returns @rec if it is a timestamp, @prev otherwise
+ */
+static struct bootstage_record *
+print_time_record_influxdb(struct bootstage_record *rec,
+			   struct bootstage_record *prev, bool is_first)
+{
+	char buf1[24];
+	char buf2[24];
+
+	if (!is_first)
+		puts(",");
+	if (rec->start_us) {
+		/* An "Accumulated time" entry in the text report */
+		printf("%s=%lu",
+		       get_unique_record_name(buf1, sizeof(buf1), rec),
+		       rec->time_us);
+		return prev;
+	}
+
+	/* Elapsed time between two consecutive stages */
+	printf("%s~%s=%lu",
+	       get_unique_record_name(buf1, sizeof(buf1), prev),
+	       get_unique_record_name(buf2, sizeof(buf2), rec),
+	       rec->time_us - prev->time_us);
+
+	return rec;
+}
+
+/**
+ * print_env_influxdb() - print an environment variable in InfluxDB v2 line
+ * protocol format
+ *
+ * @env: the variable to print
+ * @cont: true if a continuation comma ', ' should be printed afterwards
+ */
+static void print_env_influxdb(const char *env, bool cont)
+{
+	char *val = env_get(env);
+
+	puts("env_");
+	puts(env);
+	puts("=\"");
+	if (val)
+		puts_influxdb_escape(val);
+	puts("\"");
+	if (cont)
+		puts(",");
+}
+
+/**
+ * bootstage_report_influxdb() - print the InfluxDB bootstage report
+ */
+static void bootstage_report_influxdb(void)
+{
+	struct bootstage_data *data = gd->bootstage;
+	struct bootstage_record *prev = data->record;
+	struct bootstage_record *rec = data->record;
+	struct bootstage_record *boot_end = NULL;
+	bool is_first = true;
+	int i;
+
+	puts("=== Begin InfluxDB v2 bootstage report ===\n");
+	puts("u-boot_bootstage_report,");
+	puts("u_boot_version=\"");
+	puts_influxdb_escape(PLAIN_VERSION);
+	puts("\",");
+	puts("u_boot_date=\"");
+	puts_influxdb_escape(U_BOOT_DATE);
+	puts("\",");
+	puts("u_boot_time=\"");
+	puts_influxdb_escape(U_BOOT_TIME);
+	puts("\",");
+	puts("u_boot_tz=\"");
+	puts_influxdb_escape(U_BOOT_TZ);
+	puts("\",");
+	print_env_influxdb("arch", 1);
+	print_env_influxdb("board", 1);
+	print_env_influxdb("board_name", 1);
+	print_env_influxdb("cpu", 1);
+	print_env_influxdb("vendor", 0);
+	puts(" ");
+	for (i = 1, rec++; i < data->rec_count; i++, rec++) {
+		if (rec->id) {
+			if (!rec->start_us)
+				boot_end = rec;
+			prev = print_time_record_influxdb(rec, prev, is_first);
+			is_first = false;
+		}
+	}
+	if (boot_end)
+		printf(",total=%ld", boot_end->time_us);
+	puts("\n");
+	puts("=== End InfluxDB v2 bootstage report ===\n");
+}
+
 /**
  * bootstage_report() - print the bootstage report(s)
  */
@@ -505,6 +636,8 @@ void bootstage_report(void)
 	bootstage_report_text();
 	if (CONFIG_IS_ENABLED(BOOTSTAGE_REPORT_JSON))
 		bootstage_report_json();
+	if (CONFIG_IS_ENABLED(BOOTSTAGE_REPORT_INFLUXDB))
+		bootstage_report_influxdb();
 }
 
 /**
-- 
2.43.0

[RFC PATCH v1 5/7] test/py/tests/test_bootstage.py: add test for InfluxDB report

[Jerome Forissier]

Add test for CONFIG_BOOTSTAGE_REPORT_INFLUXDB.

Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
---

 test/py/tests/test_bootstage.py | 11 +++++++++++
 1 file changed, 11 insertions(+)

diff --git a/test/py/tests/test_bootstage.py b/test/py/tests/test_bootstage.py
index 8d0afe2611b..5619eaf4676 100644
--- a/test/py/tests/test_bootstage.py
+++ b/test/py/tests/test_bootstage.py
@@ -39,6 +39,17 @@ def test_bootstage_report_json(ubman):
     assert '"dm_r"' in output
     assert '"reset~board_init_f"' in output
 
+@pytest.mark.buildconfigspec('bootstage')
+@pytest.mark.buildconfigspec('cmd_bootstage')
+@pytest.mark.buildconfigspec('bootstage_report_influxdb')
+def test_bootstage_report_influxdb(ubman):
+    output = ubman.run_command('bootstage report')
+    assert '=== Begin InfluxDB v2 bootstage report ===' in output
+    assert 'u-boot_bootstage_report,' in output
+    assert 'u_boot_version=' in output
+    assert 'dm_r=' in output
+    assert 'reset~board_init_f=' in output
+
 @pytest.mark.buildconfigspec('bootstage')
 @pytest.mark.buildconfigspec('cmd_bootstage')
 @pytest.mark.buildconfigspec('bootstage_stash')
-- 
2.43.0

[RFC PATCH v1 6/7] sandbox64_defconfig: enable bootstage report in JSON and InfluxDB formats

[Jerome Forissier]

Enable the bootstage report in JSON and InfluxDB formats. This also
enables the unit tests (test_bootstage_report_json() and
test_bootstage_report_influxdb() in test/py/tests/test_bootstage.py).

Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
---

 configs/sandbox64_defconfig | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/configs/sandbox64_defconfig b/configs/sandbox64_defconfig
index 1236ce474a6..c006a3300cd 100644
--- a/configs/sandbox64_defconfig
+++ b/configs/sandbox64_defconfig
@@ -20,6 +20,8 @@ CONFIG_FIT_VERBOSE=y
 CONFIG_LEGACY_IMAGE_FORMAT=y
 CONFIG_BOOTSTAGE=y
 CONFIG_BOOTSTAGE_REPORT=y
+CONFIG_BOOTSTAGE_REPORT_JSON=y
+CONFIG_BOOTSTAGE_REPORT_INFLUXDB=y
 CONFIG_BOOTSTAGE_FDT=y
 CONFIG_BOOTSTAGE_STASH=y
 CONFIG_BOOTSTAGE_STASH_SIZE=0x4096
-- 
2.43.0

[RFC PATCH v1 7/7] test/py/tests/test_bootstage.py: upload bootstage data to InfluxDB cloud

[Jerome Forissier]

If the BOOTSTAGE_INFLUXDB_URI and BOOTSTAGE_INFLUXDB_TOKEN environment
variables are set, the bootstage test will upload the timing information
to the specified InfluxDB instance. This is meant to be used in CI to
publish results for a particular board/build for later analysis. Note:
use "precision=us" in the URI, not "precision=ns" as shown in most
examples in the InfluxDB documentation. For details see [1].

[1] https://docs.influxdata.com/influxdb/v2/write-data/developer-tools/api

Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
---

 test/py/requirements.txt        |  1 +
 test/py/tests/test_bootstage.py | 39 ++++++++++++++++++++++++++++++++-
 2 files changed, 39 insertions(+), 1 deletion(-)

diff --git a/test/py/requirements.txt b/test/py/requirements.txt
index 804a427b351..dba380809a9 100644
--- a/test/py/requirements.txt
+++ b/test/py/requirements.txt
@@ -3,3 +3,4 @@ pycryptodomex==3.21.0
 pytest==6.2.5
 pytest-xdist==2.5.0
 FATtools==1.0.42
+requests=2.32.3
diff --git a/test/py/tests/test_bootstage.py b/test/py/tests/test_bootstage.py
index 5619eaf4676..efb27d51663 100644
--- a/test/py/tests/test_bootstage.py
+++ b/test/py/tests/test_bootstage.py
@@ -1,7 +1,9 @@
 # SPDX-License-Identifier: GPL-2.0
 # (C) Copyright 2023, Advanced Micro Devices, Inc.
 
+import os
 import pytest
+import requests
 
 """
 Test the bootstage command.
@@ -40,15 +42,50 @@ def test_bootstage_report_json(ubman):
     assert '"reset~board_init_f"' in output
 
 @pytest.mark.buildconfigspec('bootstage')
+
+# Extract the text string between two delimiters
+def extract_between(text, start_delimiter, end_delimiter):
+    startp = text.find(start_delimiter)
+    if startp == -1:
+        return None
+    startp += len(start_delimiter)
+    endp = text.find(end_delimiter, startp)
+    if endp == -1:
+        return None
+    return text[startp:endp].strip()
+
+def send_data_to_influxdb(data):
+    uri = os.environ.get("BOOTSTAGE_INFLUXDB_URI")
+    token = os.environ.get("BOOTSTAGE_INFLUXDB_TOKEN")
+    if not uri or not token:
+        print("Warning: BOOTSTAGE_INFLUXDB_URI or BOOTSTAGE_INFLUXDB_TOKEN "
+              "not set, cannot send bootstage data")
+        return
+    headers = {
+        "Authorization": f"Token {token}",
+        "Content-Type": "text/plain;charset=utf-8"
+    }
+    try:
+        rsp = requests.post(uri, headers= headers, data=data.encode('utf-8'))
+        rsp.raise_for_status()
+        print(f"Data succcessfully sent to {uri}")
+    except requests.exceptions.RequestException as e:
+        print(f"Error sending data to {uri}: {e}")
+
 @pytest.mark.buildconfigspec('cmd_bootstage')
 @pytest.mark.buildconfigspec('bootstage_report_influxdb')
 def test_bootstage_report_influxdb(ubman):
     output = ubman.run_command('bootstage report')
-    assert '=== Begin InfluxDB v2 bootstage report ===' in output
+    start_delimiter = '=== Begin InfluxDB v2 bootstage report ==='
+    end_delimiter = '=== End InfluxDB v2 bootstage report ==='
+    assert start_delimiter in output
     assert 'u-boot_bootstage_report,' in output
     assert 'u_boot_version=' in output
     assert 'dm_r=' in output
     assert 'reset~board_init_f=' in output
+    data = extract_between(output, start_delimiter, end_delimiter)
+    if data:
+        send_data_to_influxdb(data)
 
 @pytest.mark.buildconfigspec('bootstage')
 @pytest.mark.buildconfigspec('cmd_bootstage')
-- 
2.43.0

Re: [RFC PATCH v1 0/7] Bootstage reports for CI

[Tom Rini]

[-- Attachment #1: Type: text/plain, Size: 3186 bytes --]

On Fri, Apr 11, 2025 at 05:29:26PM +0200, Jerome Forissier wrote:

> The BOOTSTAGE Kconfig symbol allows to record boot time information
> which can be consumed in several ways:
> 
> 1) Printed to the console just before the OS is booted (when
>    BOOTSTAGE_REPORT=y)
> 2) Printed to the console by the "bootstage report" command (when
>    CMD_BOOTSTAGE=y)
> 3) Passed to the OS in the Device Tree (when BOOTSTAGE_FDT=y)
> 4) Written to some memory location in binary format before the OS is
>    booted (when BOOTSTAGE_STASH=y)
> 
> None of these options are convenient for use in CI. Suppose we want to
> monitor a set of boards for boot time regressions -- in other words,
> make sure the boot time does not degrade unexpectedly as the code
> evolves. For that, we'd like to be able to record the bootstage data in
> some kind of database or persistent storage and possibly draw graphs
> showing trends over time.
> 
> This RFC is a step in that direction. It introduces two new output
> formats for the bootstage data. The two are independant, they are simply
> two options I considered:
> 
> 1) JSON
> 2) InfluxDB v2 line protocol [1]
> 
> Both depend on BOOTSTAGE_REPORT and are enabled by BOOTSTAGE_REPORT_JSON
> and BOOTSTAGE_REPORT_INFLUXDB respectively. Each format comes with its
> own test in test/py/tests. The InfluxDB test is special in that it is
> able to upload the data to a cloud database, provided the environment
> variables BOOTSTAGE_INFLUXDB_URI and BOOTSTAGE_INFLUXDB_TOKEN are set
> properly.
> 
> I have been able to run a boot test on rpi4 in the sjg-lab with
> BOOTSTGE_REPORT_INFLUXDB enabled. The CI log [2] shows that the data
> were indeed uploaded to my InfluxDB Cloud test account.
> 
> This is published as an RFC since it is just an investigation. If
> someone finds this useful I may folloow-up with a non-RFC series.
> 
> Comments are welcome.
> 
> [1] https://docs.influxdata.com/influxdb/v2/reference/syntax/line-protocol/
> [2] https://source.denx.de/u-boot/custodians/u-boot-net/-/jobs/1097039#L116

This is very interesting. One thing I wonder about wrt reporting is if
what would be in the JUnit XML report already is enough, or if we need
more granularity? Something like the following might work to get them
saved for Simon's lab like they are for the emulated targets:
diff --git a/.gitlab-ci.yml b/.gitlab-ci.yml
index e54bdd6c4bec..8ec5dfbb2528 100644
--- a/.gitlab-ci.yml
+++ b/.gitlab-ci.yml
@@ -558,6 +558,7 @@ coreboot test.py:
     - export USE_LABGRID_SJG=1
     # export verbose="-v"
     - ${SRC}/test/py/test.py --role ${ROLE} --build-dir "${OUT}"
+        --junitxml="${OUT}"/results.xml
         --capture=tee-sys -k "not bootstd ${TEST_PY_TEST_SPEC}" || ret=$?
     - U_BOOT_BOARD_IDENTITY="${ROLE}" u-boot-test-release || true
     - if [[ $ret -ne 0 ]]; then
@@ -568,7 +569,10 @@ coreboot test.py:
     paths:
       - "build/${BOARD}/test-log.html"
       - "build/${BOARD}/multiplexed_log.css"
+      - "build/${BOARD}/results.xml"
     expire_in: 1 week
+    reports:
+      junit: build/${BOARD}/results.xml
 
 rpi3:
   variables:

-- 
Tom

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 659 bytes --]

Re: [RFC PATCH v1 1/7] efi_loader: make efi_exit_boot_services() call bootstage_report()

[Simon Glass]

Hi Jerome,

On Fri, 11 Apr 2025 at 09:31, Jerome Forissier
<jerome.forissier@linaro.org> wrote:
>
> CONFIG_BOOTSTAGE_REPORT is currently supported in the bootm command
> only. Add support to the EFI boot.
>
> Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
> ---
>
>  lib/efi_loader/efi_boottime.c | 7 +++++++
>  1 file changed, 7 insertions(+)
>

If you have time, could you take a look at unifying
announce_and_cleanup() with the duplicate code in EFI?

Regards,
Simon

Re: [RFC PATCH v1 1/7] efi_loader: make efi_exit_boot_services() call bootstage_report()

[Tom Rini]

[-- Attachment #1: Type: text/plain, Size: 807 bytes --]

On Fri, Apr 11, 2025 at 12:32:12PM -0600, Simon Glass wrote:
> Hi Jerome,
> 
> On Fri, 11 Apr 2025 at 09:31, Jerome Forissier
> <jerome.forissier@linaro.org> wrote:
> >
> > CONFIG_BOOTSTAGE_REPORT is currently supported in the bootm command
> > only. Add support to the EFI boot.
> >
> > Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
> > ---
> >
> >  lib/efi_loader/efi_boottime.c | 7 +++++++
> >  1 file changed, 7 insertions(+)
> >
> 
> If you have time, could you take a look at unifying
> announce_and_cleanup() with the duplicate code in EFI?

And the duplicating code in arch/{arm,x86,riscv}. Maybe there's some
good place we can stick the bootstage calls, board_quiesce_devices() and
dm_remove_devices_active(). But maybe not, I'm not sure honestly.

-- 
Tom

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 659 bytes --]

Re: [RFC PATCH v1 1/7] efi_loader: make efi_exit_boot_services() call bootstage_report()

[Simon Glass]

Hi Tom,

On Fri, 11 Apr 2025 at 12:46, Tom Rini <trini@konsulko.com> wrote:
>
> On Fri, Apr 11, 2025 at 12:32:12PM -0600, Simon Glass wrote:
> > Hi Jerome,
> >
> > On Fri, 11 Apr 2025 at 09:31, Jerome Forissier
> > <jerome.forissier@linaro.org> wrote:
> > >
> > > CONFIG_BOOTSTAGE_REPORT is currently supported in the bootm command
> > > only. Add support to the EFI boot.
> > >
> > > Signed-off-by: Jerome Forissier <jerome.forissier@linaro.org>
> > > ---
> > >
> > >  lib/efi_loader/efi_boottime.c | 7 +++++++
> > >  1 file changed, 7 insertions(+)
> > >
> >
> > If you have time, could you take a look at unifying
> > announce_and_cleanup() with the duplicate code in EFI?
>
> And the duplicating code in arch/{arm,x86,riscv}. Maybe there's some
> good place we can stick the bootstage calls, board_quiesce_devices() and
> dm_remove_devices_active(). But maybe not, I'm not sure honestly.

Yes. I started a series at the weekend to drop board_quiesce_devices()
but in a few cases it is needed, so then I thought about creating an
event for those 3-4 cases, but then I didn't go any further. I will
see if I can at least send a WIP series this weekend to help.

Regards,
Simon