Really complete SPL & u-boot log on all consoles

PATCH New Siarhei Siamashka 4 participants 10 messages Jan 13, 2015 – Jan 17, 2015 Arm/Allwinner sunXi SoC support

Share & tools

Siarhei Siamashka

author

2015-01-13 12:30 UTC #0 lore raw

cover Really complete SPL & u-boot log on all consoles

By enabling pre-console buffer in both SPL and u-boot and some minor tweaks, it is possible to see all log messages (including SPL messages too) on VGA/HDMI/LCD console and other stdio based consoles.

The first patch adds the necessary code to implement this feature. The second patch enables it for Allwinner (sunxi) devices.

Siarhei Siamashka (2):
console: Allow pre-console buffer to also extract SPL log messages
sunxi: Enable SPL pre-console buffer

 common/console.c               | 65 ++++++++++++++++++++++++++++++++++++++----
 include/configs/sunxi-common.h | 27 ++++++++++++++++--
 2 files changed, 84 insertions(+), 8 deletions(-)

Signature · 1 line

2.0.5

Siarhei Siamashka

author

2015-01-13 12:30 UTC #1 lore raw

PATCH 1/2 console: Allow pre-console buffer to also extract SPL log messages

It is possible to enable pre-console buffer in SPL and later extract log messages from it when updating stdio consoles in u-boot.

Signed-off-by Siarhei Siamashka <[email protected]>

---
 common/console.c | 65 +++++++++++++++++++++++++++++++++++++++++++++++++++-----
 1 file changed, 60 insertions(+), 5 deletions(-)

common/console.c +60 -5

index fc1963b..fbbe897 100644
@@ -404,17 +404,49 @@ int tstc(void)
 	return serial_tstc();
 }
 
+/*
+ * The pre-console buffer helps to ensure that log messages can reach stdio
+ * consoles even from the very bottom of SPL.
+ *
+ * To get the full use of it, the SPL build should have the following defines:
+ *   CONFIG_PRE_CONSOLE_BUFFER - define to enable the SPL pre-console buffer
+ *   CONFIG_PRE_CON_BUF_ADDR   - address in SRAM of the SPL pre-console buffer
+ *   CONFIG_PRE_CON_BUF_SZ     - size of the SPL pre-console buffer
+ *   CONFIG_PRE_CON_IDX_ADDR   - address of the index variable duplicate
+ *
+ * The main u-boot build should have the following defines:
+ *   CONFIG_PRE_CONSOLE_BUFFER - define to enable the main pre-console buffer
+ *   CONFIG_PRE_CON_BUF_ADDR   - address in DRAM of the main pre-console buffer
+ *   CONFIG_PRE_CON_BUF_SZ     - size of the main pre-console buffer
+ * and
+ *   CONFIG_SPL_PRE_CONSOLE_BUFFER - same as CONFIG_PRE_CONSOLE_BUFFER in SPL
+ *   CONFIG_SPL_PRE_CON_BUF_ADDR   - same as CONFIG_SPL_CON_BUF_ADDR in SPL
+ *   CONFIG_SPL_PRE_CON_BUF_SZ     - same as CONFIG_PRE_CON_BUF_SZ in SPL
+ *   CONFIG_SPL_PRE_CON_IDX_ADDR   - same as CONFIG_PRE_CON_IDX_ADDR in SPL
+ */
 #define PRE_CONSOLE_FLUSHPOINT1_SERIAL			0
 #define PRE_CONSOLE_FLUSHPOINT2_EVERYTHING_BUT_SERIAL	1
 
 #ifdef CONFIG_PRE_CONSOLE_BUFFER
+
+#ifdef CONFIG_PRE_CON_IDX_ADDR
+#define PRECON_BUF_IDX (*(unsigned long *)(CONFIG_PRE_CON_IDX_ADDR))
+#else
+#define PRECON_BUF_IDX (gd->precon_buf_idx)
+#endif
+
+#define PRECON_SPL_BUF_IDX (*(unsigned long *)(CONFIG_SPL_PRE_CON_IDX_ADDR))
+
 #define CIRC_BUF_IDX(idx) ((idx) % (unsigned long)CONFIG_PRE_CON_BUF_SZ)
+#define CIRC_SPL_BUF_IDX(idx) ((idx) % (unsigned long)CONFIG_SPL_PRE_CON_BUF_SZ)
 
 static void pre_console_putc(const char c)
 {
 	char *buffer = (char *)CONFIG_PRE_CON_BUF_ADDR;
 
 	buffer[CIRC_BUF_IDX(gd->precon_buf_idx++)] = c;
+	/* Update the index variable duplicate */
+	PRECON_BUF_IDX = gd->precon_buf_idx;
 }
 
 static void pre_console_puts(const char *s)

@@ -425,13 +457,36 @@ static void pre_console_puts(const char *s)
 
 static void print_pre_console_buffer(int flushpoint)
 {
-	unsigned long i = 0;
-	char *buffer = (char *)CONFIG_PRE_CON_BUF_ADDR;
+	unsigned long i;
+	char *buffer;
+
+	/* Update the index variable duplicate (to do it at least once) */
+	PRECON_BUF_IDX = gd->precon_buf_idx;
+
+#if defined(CONFIG_SPL_PRE_CONSOLE_BUFFER) && !defined(CONFIG_SPL_BUILD)
+	i = 0;
+	buffer = (char *)CONFIG_SPL_PRE_CON_BUF_ADDR;
+
+	if (PRECON_SPL_BUF_IDX > CONFIG_SPL_PRE_CON_BUF_SZ)
+		i = PRECON_SPL_BUF_IDX - CONFIG_SPL_PRE_CON_BUF_SZ;
+
+	while (i < PRECON_SPL_BUF_IDX) {
+		switch (flushpoint) {
+		case PRE_CONSOLE_FLUSHPOINT2_EVERYTHING_BUT_SERIAL:
+			console_putc_noserial(stdout,
+					      buffer[CIRC_SPL_BUF_IDX(i)]);
+			break;
+		}
+		i++;
+	}
+#endif
+	i = 0;
+	buffer = (char *)CONFIG_PRE_CON_BUF_ADDR;
 
-	if (gd->precon_buf_idx > CONFIG_PRE_CON_BUF_SZ)
-		i = gd->precon_buf_idx - CONFIG_PRE_CON_BUF_SZ;
+	if (PRECON_BUF_IDX > CONFIG_PRE_CON_BUF_SZ)
+		i = PRECON_BUF_IDX - CONFIG_PRE_CON_BUF_SZ;
 
-	while (i < gd->precon_buf_idx)
+	while (i < PRECON_BUF_IDX)
 		switch (flushpoint) {
 		case PRE_CONSOLE_FLUSHPOINT1_SERIAL:
 			putc(buffer[CIRC_BUF_IDX(i++)]);

Signature · 1 line

2.0.5

Simon Glass

2015-01-13 21:15 UTC #2 lore raw

PATCH 1/2 console: Allow pre-console buffer to also extract SPL log messages

Hi Siarhei,

Quoted 25 lines · Siarhei Siamashka

It is possible to enable pre-console buffer in SPL and later extract log messages from it when updating stdio consoles in u-boot.

Signed-off-by Siarhei Siamashka <[email protected]>

---
 common/console.c | 65 +++++++++++++++++++++++++++++++++++++++++++++++++++-----
 1 file changed, 60 insertions(+), 5 deletions(-)

common/console.c +9 -0

index fc1963b..fbbe897 100644
@@ -404,17 +404,49 @@ int tstc(void)
        return serial_tstc();
 }
 
+/*
+ * The pre-console buffer helps to ensure that log messages can reach stdio
+ * consoles even from the very bottom of SPL.
+ *
+ * To get the full use of it, the SPL build should have the following defines:
+ *   CONFIG_PRE_CONSOLE_BUFFER - define to enable the SPL pre-console buffer
+ *   CONFIG_PRE_CON_BUF_ADDR   - address in SRAM of the SPL pre-console buffer
+ *   CONFIG_PRE_CON_BUF_SZ     - size of the SPL pre-console buffer
+ *   CONFIG_PRE_CON_IDX_ADDR   - address of the index variable duplicate

common/console.c int tstc(void) · line 425

Quoted 10 lines

common/console.c +10 -0

+ *
+ * The main u-boot build should have the following defines:
+ *   CONFIG_PRE_CONSOLE_BUFFER - define to enable the main pre-console buffer
+ *   CONFIG_PRE_CON_BUF_ADDR   - address in DRAM of the main pre-console buffer
+ *   CONFIG_PRE_CON_BUF_SZ     - size of the main pre-console buffer
+ * and
+ *   CONFIG_SPL_PRE_CONSOLE_BUFFER - same as CONFIG_PRE_CONSOLE_BUFFER in SPL
+ *   CONFIG_SPL_PRE_CON_BUF_ADDR   - same as CONFIG_SPL_CON_BUF_ADDR in SPL
+ *   CONFIG_SPL_PRE_CON_BUF_SZ     - same as CONFIG_PRE_CON_BUF_SZ in SPL
+ *   CONFIG_SPL_PRE_CON_IDX_ADDR   - same as CONFIG_PRE_CON_IDX_ADDR in SPL

Could this not be the first word of the buffer?

common/console.c int tstc(void) · line 426

Quoted 1 line

common/console.c +1 -0
+ */

These should all move to Kconfig I think, including the help text.

We might want to change SZ to SIZE.

Quoted 69 lines

common/console.c +40 -6

 #define PRE_CONSOLE_FLUSHPOINT1_SERIAL                 0
 #define PRE_CONSOLE_FLUSHPOINT2_EVERYTHING_BUT_SERIAL  1
 
 #ifdef CONFIG_PRE_CONSOLE_BUFFER
+
+#ifdef CONFIG_PRE_CON_IDX_ADDR
+#define PRECON_BUF_IDX (*(unsigned long *)(CONFIG_PRE_CON_IDX_ADDR))
+#else
+#define PRECON_BUF_IDX (gd->precon_buf_idx)
+#endif
+
+#define PRECON_SPL_BUF_IDX (*(unsigned long *)(CONFIG_SPL_PRE_CON_IDX_ADDR))
+
 #define CIRC_BUF_IDX(idx) ((idx) % (unsigned long)CONFIG_PRE_CON_BUF_SZ)
+#define CIRC_SPL_BUF_IDX(idx) ((idx) % (unsigned long)CONFIG_SPL_PRE_CON_BUF_SZ)
 
 static void pre_console_putc(const char c)
 {
        char *buffer = (char *)CONFIG_PRE_CON_BUF_ADDR;
 
        buffer[CIRC_BUF_IDX(gd->precon_buf_idx++)] = c;
+       /* Update the index variable duplicate */
+       PRECON_BUF_IDX = gd->precon_buf_idx;
 }
 
 static void pre_console_puts(const char *s)

@@ -425,13 +457,36 @@ static void pre_console_puts(const char *s)
 
 static void print_pre_console_buffer(int flushpoint)
 {
-       unsigned long i = 0;
-       char *buffer = (char *)CONFIG_PRE_CON_BUF_ADDR;
+       unsigned long i;
+       char *buffer;
+
+       /* Update the index variable duplicate (to do it at least once) */
+       PRECON_BUF_IDX = gd->precon_buf_idx;
+
+#if defined(CONFIG_SPL_PRE_CONSOLE_BUFFER) && !defined(CONFIG_SPL_BUILD)
+       i = 0;
+       buffer = (char *)CONFIG_SPL_PRE_CON_BUF_ADDR;
+
+       if (PRECON_SPL_BUF_IDX > CONFIG_SPL_PRE_CON_BUF_SZ)
+               i = PRECON_SPL_BUF_IDX - CONFIG_SPL_PRE_CON_BUF_SZ;
+
+       while (i < PRECON_SPL_BUF_IDX) {
+               switch (flushpoint) {
+               case PRE_CONSOLE_FLUSHPOINT2_EVERYTHING_BUT_SERIAL:
+                       console_putc_noserial(stdout,
+                                             buffer[CIRC_SPL_BUF_IDX(i)]);
+                       break;
+               }
+               i++;
+       }
+#endif
+       i = 0;
+       buffer = (char *)CONFIG_PRE_CON_BUF_ADDR;
 
-       if (gd->precon_buf_idx > CONFIG_PRE_CON_BUF_SZ)
-               i = gd->precon_buf_idx - CONFIG_PRE_CON_BUF_SZ;
+       if (PRECON_BUF_IDX > CONFIG_PRE_CON_BUF_SZ)
+               i = PRECON_BUF_IDX - CONFIG_PRE_CON_BUF_SZ;
 
-       while (i < gd->precon_buf_idx)
+       while (i < PRECON_BUF_IDX)
                switch (flushpoint) {
                case PRE_CONSOLE_FLUSHPOINT1_SERIAL:
                        putc(buffer[CIRC_BUF_IDX(i++)]);
--

Quoted 2 lines

2.0.5

Regards,
Simon

Siarhei Siamashka

author

2015-01-13 12:30 UTC #3 lore raw

PATCH 2/2 sunxi: Enable SPL pre-console buffer

In reply to Siarhei Siamashka

This allows to get log messages from SPL on stdio consoles. The pre-console buffer is placed in 2 KiB of SRAM, chopped off from the upper addresses of stack. This size is completely arbitrary and can be increased or decreased if necessary. Only normal SPL is supported, but not FEL mode.

Signed-off-by Siarhei Siamashka <[email protected]>

---
 include/configs/sunxi-common.h | 27 ++++++++++++++++++++++++---
 1 file changed, 24 insertions(+), 3 deletions(-)

include/configs/sunxi-common.h +24 -3

index e839053..9d00951 100644
@@ -170,11 +170,19 @@
 #define CONFIG_SYS_MMCSD_RAW_MODE_U_BOOT_SECTOR	80	/* 40KiB */
 #define CONFIG_SPL_PAD_TO		32768		/* decimal for 'dd' */
 
+/*
+ * Allocate 2 KiB pre-console buffer for SPL at the end of 32 KiB SRAM and
+ * the pre-console buffer index copy right below it (aligned at 8 bytes).
+ * The stack is placed below the pre-console buffer.
+ */
+#define CONFIG_SPL_PRE_CON_BUF_SZ	2048
+#define CONFIG_SPL_PRE_CON_BUF_ADDR	(0x00008000 - CONFIG_SPL_PRE_CON_BUF_SZ)
+#define CONFIG_SPL_PRE_CON_IDX_ADDR	(CONFIG_SPL_PRE_CON_BUF_ADDR - 8)
+#define LOW_LEVEL_SRAM_STACK		CONFIG_SPL_PRE_CON_IDX_ADDR
+#define CONFIG_SPL_STACK		LOW_LEVEL_SRAM_STACK
+
 #endif /* CONFIG_SPL */
 
-/* end of 32 KiB in sram */
-#define LOW_LEVEL_SRAM_STACK		0x00008000 /* End of sram */
-#define CONFIG_SPL_STACK		LOW_LEVEL_SRAM_STACK
 #define CONFIG_SYS_SPL_MALLOC_START	0x4ff00000
 #define CONFIG_SYS_SPL_MALLOC_SIZE	0x00080000	/* 512 KiB */

@@ -269,6 +277,14 @@
 #define CONFIG_MISC_INIT_R
 #define CONFIG_SYS_CONSOLE_IS_IN_ENV
 
+/* Enable pre-console buffer in SPL */
+#if defined(CONFIG_SPL_BUILD) && !defined(CONFIG_SPL_FEL)
+#define CONFIG_PRE_CONSOLE_BUFFER
+#define CONFIG_PRE_CON_BUF_SZ		CONFIG_SPL_PRE_CON_BUF_SZ
+#define CONFIG_PRE_CON_BUF_ADDR		CONFIG_SPL_PRE_CON_BUF_ADDR
+#define CONFIG_PRE_CON_IDX_ADDR		CONFIG_SPL_PRE_CON_IDX_ADDR
+#endif
+
 #ifndef CONFIG_SPL_BUILD
 #include <config_distro_defaults.h>

@@ -278,6 +294,11 @@
 /* Use the room between the end of bootm_size and the framebuffer */
 #define CONFIG_PRE_CON_BUF_ADDR		0x4f000000
 
+/* Extract SPL log messages from SRAM when updating the VGA console */
+#if !defined(CONFIG_SPL_FEL)
+#define CONFIG_SPL_PRE_CONSOLE_BUFFER
+#endif
+
 /*
  * 240M RAM (256M minimum minus space for the framebuffer),
  * 32M uncompressed kernel, 16M compressed kernel, 1M fdt,

Signature · 1 line

2.0.5

Hans de Goede

2015-01-14 08:17 UTC #4 lore raw

cover Really complete SPL & u-boot log on all consoles

In reply to Siarhei Siamashka

Hi Siarhei,

Quoted 10 lines · Siarhei Siamashka

By enabling pre-console buffer in both SPL and u-boot and some minor tweaks, it is possible to see all log messages (including SPL messages too) on VGA/HDMI/LCD console and other stdio based consoles.
The first patch adds the necessary code to implement this feature. The second patch enables it for Allwinner (sunxi) devices.
Siarhei Siamashka (2):
console: Allow pre-console buffer to also extract SPL log messages
sunxi: Enable SPL pre-console buffer

Interesting patchset, for 1/2 I agree with Simon's recommended changes, for 2/2, can we make the buffer 512 bytes please? SPL does not print out much, and RAM is very constraint in the SPL.

Also can you please send a v2 of the display series for the ssd2828 one of the coming days ? I'm going to send a pull-req to get everything pending in u-boot-sunxi/next today, and after that I would like to get the ssd2828 + my hitachi lcd panel patches ready for a follow-up pull-req.

Thanks & Regards,

Hans

Siarhei Siamashka

author

2015-01-14 12:57 UTC #5 lore raw

cover Really complete SPL & u-boot log on all consoles

Quoted 7 lines · On Wed, 14 Jan 2015 09:17:47 +0100 Hans de Goede <[email protected]> wrote:

Hi Siarhei,
Quoted 4 lines · Siarhei Siamashka
By enabling pre-console buffer in both SPL and u-boot and some minor tweaks, it is possible to see all log messages (including SPL messages too) on VGA/HDMI/LCD console and other stdio based consoles.

Quoted 8 lines

Quoted 6 lines
The first patch adds the necessary code to implement this feature. The second patch enables it for Allwinner (sunxi) devices.
Siarhei Siamashka (2):
console: Allow pre-console buffer to also extract SPL log messages
sunxi: Enable SPL pre-console buffer
Interesting patchset, for 1/2 I agree with Simon's recommended changes,

I'll reply to Simon's e-mail a bit later today.

Quoted 1 line

for 2/2, can we make the buffer 512 bytes please?

Sure. In fact I'm currently trying to do more in-depth SPL stack usage analysis. Just to see how much of it is really needed by the SPL and not to make guesses whether reducing the stack from 8K to 6K (or to some other arbitrary size) would be fine or not.

Currently u-boot already compiles code with '-fstack-usage' GCC option, which reports stack usage for each individual function in *.su files. The remaining part is how to find the total maximum stack usage, based on this information. There are some guides and papers, which mention the use of '-fstack-usage' option together with '-fcallgraph-info'. But '-fcallgraph-info' does not seem to be supported at least by my version of GCC. And there are various scripts and tools with different level of maturity and support. I'm sure that some u-boot developers are also using something (otherwise, what is the point enabling '-fstack-usage' GCC option in the first place?).

Anyway, none of the tools seemed convenient/usable enough to me. And I decided that it may be faster to quickly hack some script myself, tailored specifically for u-boot SPL:
http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph.rb

The results of running the script for u-boot v2015.01, analysing normal and FEL variants of SPL, built for Cubieboard2 with GCC 4.8:
http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph-v2015.01-cubieboard2.png
http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph-v2015.01-cubieboard2-fel.png

And all the same for the current sunxi-next branch:
http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph-sunxi-next-cubieboard2.png
http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph-sunxi-next-cubieboard2-fel.png

This may be not entirely accurate, because doing this properly needs correct tracking of indirect calls. Also there are 'dynamic' stack frames if variable length arrays are involved. But at least it gives an idea about the approximate stack size requirements.

Quoted 1 line

SPL does not print out much,

This can be changed. Having more detailed information about DRAM clock and timings in the log would be quite useful. If, with the Simon's help, we manage to implement handing over the u-boot log to the linux kernel (so that it shows in the dmesg log), then suddenly the diagnostic information from the SPL becomes a lot more accessible to the end users.

Quoted 1 line

and RAM is very constraint in the SPL.

Yes, exactly. Especially considering that we have already almost used it up the space for code+data (~22K out of available 24K). Everything is even much worse in the FEL mode. IMHO some improvements are needed and I'm preparing patches to address the most obvious problems.

This is also the reason why I was not very happy about
http://lists.denx.de/pipermail/u-boot/2014-December/199254.html

Quoted 5 lines

Also can you please send a v2 of the display series for the ssd2828 one of the coming days ? I'm going to send a pull-req to get everything pending in u-boot-sunxi/next today, and after that I would like to get the ssd2828 + my hitachi lcd panel patches ready for a follow-up pull-req.

Sure. Unfortunately it looks like I'm not going to get any feedback about the http://linux-sunxi.org/ICOU_Fatty_I tablet. So it does not make sense waiting any longer.

Signature · 2 lines

Best regards,
Siarhei Siamashka

Hans de Goede

2015-01-14 14:28 UTC #6 lore raw

cover Really complete SPL & u-boot log on all consoles

Hi,

Quoted 44 lines · Siarhei Siamashka

Quoted 7 lines · On Wed, 14 Jan 2015 09:17:47 +0100 Hans de Goede <[email protected]> wrote:
Hi Siarhei,
Quoted 4 lines · Siarhei Siamashka
By enabling pre-console buffer in both SPL and u-boot and some minor tweaks, it is possible to see all log messages (including SPL messages too) on VGA/HDMI/LCD console and other stdio based consoles.
Quoted 8 lines
Quoted 6 lines
The first patch adds the necessary code to implement this feature. The second patch enables it for Allwinner (sunxi) devices.
Siarhei Siamashka (2):
console: Allow pre-console buffer to also extract SPL log messages
sunxi: Enable SPL pre-console buffer
Interesting patchset, for 1/2 I agree with Simon's recommended changes,
I'll reply to Simon's e-mail a bit later today.
Quoted 1 line
for 2/2, can we make the buffer 512 bytes please?
Sure. In fact I'm currently trying to do more in-depth SPL stack usage analysis. Just to see how much of it is really needed by the SPL and not to make guesses whether reducing the stack from 8K to 6K (or to some other arbitrary size) would be fine or not.
Currently u-boot already compiles code with '-fstack-usage' GCC option, which reports stack usage for each individual function in *.su files. The remaining part is how to find the total maximum stack usage, based on this information. There are some guides and papers, which mention the use of '-fstack-usage' option together with '-fcallgraph-info'. But '-fcallgraph-info' does not seem to be supported at least by my version of GCC. And there are various scripts and tools with different level of maturity and support. I'm sure that some u-boot developers are also using something (otherwise, what is the point enabling '-fstack-usage' GCC option in the first place?).
Anyway, none of the tools seemed convenient/usable enough to me. And I decided that it may be faster to quickly hack some script myself, tailored specifically for u-boot SPL:
http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph.rb

Quoted 8 lines

The results of running the script for u-boot v2015.01, analysing normal and FEL variants of SPL, built for Cubieboard2 with GCC 4.8:
   http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph-v2015.01-cubieboard2.png
   http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph-v2015.01-cubieboard2-fel.png
And all the same for the current sunxi-next branch:
http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph-sunxi-next-cubieboard2.png
http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph-sunxi-next-cubieboard2-fel.png

Oh pretty pictures, nice. Good work.

Quoted 4 lines

This may be not entirely accurate, because doing this properly needs correct tracking of indirect calls. Also there are 'dynamic' stack frames if variable length arrays are involved. But at least it gives an idea about the approximate stack size requirements.

Thanks for working on this, this sounds like a very useful effort.

Regards,

Hans

Quoted 29 lines

Quoted 2 lines
SPL does not print out much,
This can be changed. Having more detailed information about DRAM clock and timings in the log would be quite useful. If, with the Simon's help, we manage to implement handing over the u-boot log to the linux kernel (so that it shows in the dmesg log), then suddenly the diagnostic information from the SPL becomes a lot more accessible to the end users.
Quoted 1 line
and RAM is very constraint in the SPL.
Yes, exactly. Especially considering that we have already almost used it up the space for code+data (~22K out of available 24K). Everything is even much worse in the FEL mode. IMHO some improvements are needed and I'm preparing patches to address the most obvious problems.
This is also the reason why I was not very happy about
http://lists.denx.de/pipermail/u-boot/2014-December/199254.html
Quoted 5 lines
Also can you please send a v2 of the display series for the ssd2828 one of the coming days ? I'm going to send a pull-req to get everything pending in u-boot-sunxi/next today, and after that I would like to get the ssd2828 + my hitachi lcd panel patches ready for a follow-up pull-req.
Sure. Unfortunately it looks like I'm not going to get any feedback about the http://linux-sunxi.org/ICOU_Fatty_I tablet. So it does not make sense waiting any longer.

Simon Glass

2015-01-14 14:59 UTC #7 lore raw

cover Really complete SPL & u-boot log on all consoles

In reply to Siarhei Siamashka

Hi,

Quoted 49 lines · Siarhei Siamashka

Quoted 7 lines · On Wed, 14 Jan 2015 09:17:47 +0100 Hans de Goede <[email protected]> wrote:
Hi Siarhei,
Quoted 4 lines · Siarhei Siamashka
By enabling pre-console buffer in both SPL and u-boot and some minor tweaks, it is possible to see all log messages (including SPL messages too) on VGA/HDMI/LCD console and other stdio based consoles.
Quoted 8 lines
Quoted 6 lines
The first patch adds the necessary code to implement this feature. The second patch enables it for Allwinner (sunxi) devices.
Siarhei Siamashka (2):
console: Allow pre-console buffer to also extract SPL log messages
sunxi: Enable SPL pre-console buffer
Interesting patchset, for 1/2 I agree with Simon's recommended changes,
I'll reply to Simon's e-mail a bit later today.
Quoted 1 line
for 2/2, can we make the buffer 512 bytes please?
Sure. In fact I'm currently trying to do more in-depth SPL stack usage analysis. Just to see how much of it is really needed by the SPL and not to make guesses whether reducing the stack from 8K to 6K (or to some other arbitrary size) would be fine or not.
Currently u-boot already compiles code with '-fstack-usage' GCC option, which reports stack usage for each individual function in *.su files. The remaining part is how to find the total maximum stack usage, based on this information. There are some guides and papers, which mention the use of '-fstack-usage' option together with '-fcallgraph-info'. But '-fcallgraph-info' does not seem to be supported at least by my version of GCC. And there are various scripts and tools with different level of maturity and support. I'm sure that some u-boot developers are also using something (otherwise, what is the point enabling '-fstack-usage' GCC option in the first place?).
Anyway, none of the tools seemed convenient/usable enough to me. And I decided that it may be faster to quickly hack some script myself, tailored specifically for u-boot SPL:
http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph.rb
The results of running the script for u-boot v2015.01, analysing normal and FEL variants of SPL, built for Cubieboard2 with GCC 4.8:
http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph-v2015.01-cubieboard2.png
http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph-v2015.01-cubieboard2-fel.png

Quoted 8 lines

And all the same for the current sunxi-next branch:
http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph-sunxi-next-cubieboard2.png
http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph-sunxi-next-cubieboard2-fel.png
This may be not entirely accurate, because doing this properly needs correct tracking of indirect calls. Also there are 'dynamic' stack frames if variable length arrays are involved. But at least it gives an idea about the approximate stack size requirements.

Nice work! The mmc path uses more stack than I would expect.

Quoted 8 lines

Quoted 2 lines
SPL does not print out much,
This can be changed. Having more detailed information about DRAM clock and timings in the log would be quite useful. If, with the Simon's help, we manage to implement handing over the u-boot log to the linux kernel (so that it shows in the dmesg log), then suddenly the diagnostic information from the SPL becomes a lot more accessible to the end users.

Let's not. We can print out DRAM clock info in U-Boot instead. It has a line devoted to DRAM and another to CPU. If even more info is required then we could add a command to print it.

But just because SPL sets up some clocks it doesn't mean that U-Boot proper cannot display the info.

Quoted 17 lines

Quoted 2 lines
and RAM is very constraint in the SPL.
Yes, exactly. Especially considering that we have already almost used it up the space for code+data (~22K out of available 24K). Everything is even much worse in the FEL mode. IMHO some improvements are needed and I'm preparing patches to address the most obvious problems.
This is also the reason why I was not very happy about
http://lists.denx.de/pipermail/u-boot/2014-December/199254.html
Quoted 5 lines
Also can you please send a v2 of the display series for the ssd2828 one of the coming days ? I'm going to send a pull-req to get everything pending in u-boot-sunxi/next today, and after that I would like to get the ssd2828 + my hitachi lcd panel patches ready for a follow-up pull-req.

Quoted 3 lines

Sure. Unfortunately it looks like I'm not going to get any feedback about the http://linux-sunxi.org/ICOU_Fatty_I tablet. So it does not make sense waiting any longer.

Regards,
Simon

Tom Rini

2015-01-14 15:27 UTC #8 lore raw

cover Really complete SPL & u-boot log on all consoles

In reply to Siarhei Siamashka

On Wed, Jan 14, 2015 at 02:57:29PM +0200, Siarhei Siamashka wrote:

[snip]

Quoted 3 lines

level of maturity and support. I'm sure that some u-boot developers are also using something (otherwise, what is the point enabling '-fstack-usage' GCC option in the first place?).

Not perfect, but in doc/README.SPL:
1) Build normally
2) Perform the following shell command to generate a list of C files used in used in

$ find spl -name '*.su' | sed -e 's:^spl/::' -e 's:[.]su$:.c:' > used-spl.list
3) Execute cflow:
$ cflow --main=board_init_r `cat used-spl.list` 2>&1 | $PAGER

And then, yeah, manual poking / just knowing that func() is or is not a big stack user.

Signature · 8 lines

Tom
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 836 bytes
Desc: Digital signature
URL: <http://lists.denx.de/pipermail/u-boot/attachments/20150114/bea9ece3/attachment.pgp>

Siarhei Siamashka

author

2015-01-17 03:50 UTC #9 lore raw

cover Really complete SPL & u-boot log on all consoles

Quoted 11 lines · On Wed, 14 Jan 2015 10:27:47 -0500 Tom Rini <[email protected]> wrote:

On Wed, Jan 14, 2015 at 02:57:29PM +0200, Siarhei Siamashka wrote:
[snip]
Quoted 3 lines
level of maturity and support. I'm sure that some u-boot developers are also using something (otherwise, what is the point enabling '-fstack-usage' GCC option in the first place?).
Not perfect, but in doc/README.SPL:
1) Build normally
2) Perform the following shell command to generate a list of C files used in used in

Quoted 6 lines

$ find spl -name '*.su' | sed -e 's:^spl/::' -e 's:[.]su$:.c:' > used-spl.list
3) Execute cflow:
$ cflow --main=board_init_r `cat used-spl.list` 2>&1 | $PAGER
And then, yeah, manual poking / just knowing that func() is or is not a big stack user.

Thanks for pointing to the relevant instructions. It does not look like cflow can produce the final stack usage number automatically though.

Meanwhile, I have improved my script to take care of the indirect calls too. For example, here is a comparison of the results from the initial prototype
http://people.freedesktop.org/~siamashka/files/20150114-spl-stackgraph/spl-stackgraph-v2015.01-cubieboard2-fel.png
and the newer indirect calls aware version:
http://people.freedesktop.org/~siamashka/files/20150116-spl-stackgraph/spl-stackgraph-v2015.01-cubieboard2-fel.png

On the first picture, the serial and i2c functions are in their own disconnected isles. On the second picture, indirect call sources and indirect call targets are identified. We are not really interested in the exact execution flow, but want to have a reasonably accurate estimation of the upper bound for stack usage. Underestimating stack usage is bad, but overestimating it a bit is perfectly fine. So we can just evaluate all the possible permutations of the indirect call execution paths (regardless of whether they are making any sense) and pick the one, which results in the maximal stack usage.

The indirect call sources (octagonal shaped nodes) are identified by basically looking for "b/bl/blx reg" instructions in the objdump log. The indirect call targets (octagonal shaped boxes with double boundary) are identified by parsing the relocation tables (if a function is ever called via a pointer, then this pointer must be stored somewhere and have an entry in the relocation table). This is rather simple, but seems to be reasonably reliable and efficient.

As for the dynamically sized arrays in functions. It makes no sense guessing. Somebody just has to provide an upper bound for these allocations to the script. Maybe even via a special comment tag in the source code, which can be parsed automatically?

Assembly functions, which do not have *.su information from GCC, may cause some difficulties in theory. I have added code to estimate the stack usage in such functions, based on parsing "push" and "sub sp, sp, #imm" instructions. But maybe these should be highlighted with a special color on the callgraph, so that the developer running the script could pay special attention to them?

The script is also able to detect suspected recursion cases. Currently u-boot SPL code has "get_current -> puts -> serial_puts -> get_current" self-destructive recursion. Which is activated by a serial console failure, which results in a debug message being printed to the serial console, which in turn causes it to fail again and attempt to print even more error messages...

In the case of indirect calls, evaluating weird permutations of caller->callee can result in a lot of complaints from the recursion detection logic in the script. This can be solved by re-running the script repeatedly and blacklisting impossible caller->callee pairs manually until the script is happy.

Anyway, right now I have a fully feature complete prototype of the (hopefully) accurate SPL stack usage detection tool. Which may take a few more days before it is cleaned up and ready to be contributed to u-boot. Just wonder if the use of Python is required for implementing u-boot tools or a Ruby script can be accepted too?

Signature · 2 lines

Best regards,
Siarhei Siamashka