lib/trace: Remove TRACE support

Looks like the option is generally not compatible with
garbage collections.

Nothing gets inlined, for example is_smp_boot() no longer
evaluates to constant false and thus the symbols from
secondary.S would need to be present for the build to pass
even if we set SMP=n.

Also the addresses of relocatable ramstage are currently
not normalised on the logs, so util/genprof would be unable
dress those.

Change-Id: I0b6f310e15e6f4992cd054d288903fea8390e5cf
Signed-off-by: Kyösti Mälkki <kyosti.malkki@gmail.com>
Reviewed-on: https://review.coreboot.org/c/coreboot/+/45757
Tested-by: build bot (Jenkins) <no-reply@coreboot.org>
Reviewed-by: Angel Pons <th3fanbus@gmail.com>
Reviewed-by: Nico Huber <nico.h@gmx.de>
This commit is contained in:
Kyösti Mälkki 2020-07-24 15:54:31 +03:00 committed by Nico Huber
parent 5e053af7a6
commit 8c99c27df1
14 changed files with 1 additions and 256 deletions

View File

@ -183,9 +183,6 @@ decompressor-generic-ccopts += -D__DECOMPRESSOR__
bootblock-generic-ccopts += -D__BOOTBLOCK__ bootblock-generic-ccopts += -D__BOOTBLOCK__
romstage-generic-ccopts += -D__ROMSTAGE__ romstage-generic-ccopts += -D__ROMSTAGE__
ramstage-generic-ccopts += -D__RAMSTAGE__ ramstage-generic-ccopts += -D__RAMSTAGE__
ifeq ($(CONFIG_TRACE),y)
ramstage-c-ccopts += -finstrument-functions
endif
ifeq ($(CONFIG_COVERAGE),y) ifeq ($(CONFIG_COVERAGE),y)
ramstage-c-ccopts += -fprofile-arcs -ftest-coverage ramstage-c-ccopts += -fprofile-arcs -ftest-coverage
endif endif

View File

@ -1113,23 +1113,12 @@ config DEBUG_INTEL_ME
is present on Intel 6-series chipsets. is present on Intel 6-series chipsets.
endif endif
config TRACE
bool "Trace function calls"
default n
help
If enabled, every function will print information to console once
the function is entered. The syntax is ~0xaaaabbbb(0xccccdddd)
the 0xaaaabbbb is the actual function and 0xccccdddd is EIP
of calling function. Please note some printk related functions
are omitted from trace to have good looking console dumps.
config DEBUG_FUNC config DEBUG_FUNC
bool "Enable function entry and exit reporting macros" if DEFAULT_CONSOLE_LOGLEVEL_8 bool "Enable function entry and exit reporting macros" if DEFAULT_CONSOLE_LOGLEVEL_8
default n default n
help help
This option enables additional function entry and exit debug messages This option enables additional function entry and exit debug messages
for select functions. If supported, this is less output than for select functions.
the TRACE option.
Note: This option will increase the size of the coreboot image. Note: This option will increase the size of the coreboot image.
If unsure, say N. If unsure, say N.

View File

@ -10,7 +10,6 @@
#include <console/vtxprintf.h> #include <console/vtxprintf.h>
#include <smp/spinlock.h> #include <smp/spinlock.h>
#include <smp/node.h> #include <smp/node.h>
#include <trace.h>
#include <timer.h> #include <timer.h>
DECLARE_SPIN_LOCK(console_lock) DECLARE_SPIN_LOCK(console_lock)
@ -81,7 +80,6 @@ int do_vprintk(int msg_level, const char *fmt, va_list args)
if (log_this < CONSOLE_LOG_FAST) if (log_this < CONSOLE_LOG_FAST)
return 0; return 0;
DISABLE_TRACE;
spin_lock(&console_lock); spin_lock(&console_lock);
console_time_run(); console_time_run();
@ -96,7 +94,6 @@ int do_vprintk(int msg_level, const char *fmt, va_list args)
console_time_stop(); console_time_stop();
spin_unlock(&console_lock); spin_unlock(&console_lock);
ENABLE_TRACE;
return i; return i;
} }

View File

@ -2,7 +2,6 @@
#include <console/vtxprintf.h> #include <console/vtxprintf.h>
#include <string.h> #include <string.h>
#include <trace.h>
struct vsnprintf_context { struct vsnprintf_context {
char *str_buf; char *str_buf;
@ -24,16 +23,12 @@ int vsnprintf(char *buf, size_t size, const char *fmt, va_list args)
int i; int i;
struct vsnprintf_context ctx; struct vsnprintf_context ctx;
DISABLE_TRACE;
ctx.str_buf = buf; ctx.str_buf = buf;
ctx.buf_limit = size ? size - 1 : 0; ctx.buf_limit = size ? size - 1 : 0;
i = vtxprintf(str_tx_byte, fmt, args, &ctx); i = vtxprintf(str_tx_byte, fmt, args, &ctx);
if (size) if (size)
*ctx.str_buf = '\0'; *ctx.str_buf = '\0';
ENABLE_TRACE;
return i; return i;
} }

View File

@ -3,7 +3,6 @@
#include <arch/io.h> #include <arch/io.h>
#include <boot/coreboot_tables.h> #include <boot/coreboot_tables.h>
#include <console/uart.h> #include <console/uart.h>
#include <trace.h>
#include "uart8250reg.h" #include "uart8250reg.h"
/* Should support 8250, 16450, 16550, 16550A type UARTs */ /* Should support 8250, 16450, 16550, 16550A type UARTs */
@ -54,7 +53,6 @@ static unsigned char uart8250_rx_byte(unsigned int base_port)
static void uart8250_init(unsigned int base_port, unsigned int divisor) static void uart8250_init(unsigned int base_port, unsigned int divisor)
{ {
DISABLE_TRACE;
/* Disable interrupts */ /* Disable interrupts */
outb(0x0, base_port + UART8250_IER); outb(0x0, base_port + UART8250_IER);
/* Enable FIFOs */ /* Enable FIFOs */
@ -72,7 +70,6 @@ static void uart8250_init(unsigned int base_port, unsigned int divisor)
/* Set to 3 for 8N1 */ /* Set to 3 for 8N1 */
outb(CONFIG_TTYS0_LCS, base_port + UART8250_LCR); outb(CONFIG_TTYS0_LCS, base_port + UART8250_LCR);
ENABLE_TRACE;
} }
static const unsigned int bases[] = { 0x3f8, 0x2f8, 0x3e8, 0x2e8 }; static const unsigned int bases[] = { 0x3f8, 0x2f8, 0x3e8, 0x2e8 };

View File

@ -1,28 +0,0 @@
/* SPDX-License-Identifier: GPL-2.0-only */
#ifndef __TRACE_H
#define __TRACE_H
#if !ENV_ROMSTAGE_OR_BEFORE && CONFIG(TRACE)
void __cyg_profile_func_enter(void *, void *)
__attribute__((no_instrument_function));
void __cyg_profile_func_exit(void *, void *)
__attribute__((no_instrument_function));
extern volatile int trace_dis;
#define DISABLE_TRACE do { trace_dis = 1; } while (0);
#define ENABLE_TRACE do { trace_dis = 0; } while (0);
#define DISABLE_TRACE_ON_FUNCTION __attribute__((no_instrument_function));
#else /* !CONFIG_TRACE */
#define DISABLE_TRACE
#define ENABLE_TRACE
#define DISABLE_TRACE_ON_FUNCTION
#endif
#endif

View File

@ -140,8 +140,6 @@ ramstage-y += wrdd.c
ramstage-$(CONFIG_CONSOLE_CBMEM) += cbmem_console.c ramstage-$(CONFIG_CONSOLE_CBMEM) += cbmem_console.c
ramstage-$(CONFIG_BOOTSPLASH) += bootsplash.c ramstage-$(CONFIG_BOOTSPLASH) += bootsplash.c
ramstage-$(CONFIG_BOOTSPLASH) += jpeg.c ramstage-$(CONFIG_BOOTSPLASH) += jpeg.c
ramstage-$(CONFIG_TRACE) += trace.c
postcar-$(CONFIG_TRACE) += trace.c
ramstage-$(CONFIG_COLLECT_TIMESTAMPS) += timestamp.c ramstage-$(CONFIG_COLLECT_TIMESTAMPS) += timestamp.c
ramstage-$(CONFIG_COVERAGE) += libgcov.c ramstage-$(CONFIG_COVERAGE) += libgcov.c
ramstage-y += edid.c ramstage-y += edid.c

View File

@ -1,21 +0,0 @@
/* SPDX-License-Identifier: GPL-2.0-only */
#include <console/console.h>
#include <trace.h>
int volatile trace_dis = 0;
void __cyg_profile_func_enter(void *func, void *callsite)
{
if (trace_dis)
return;
DISABLE_TRACE
printk(BIOS_INFO, "~%p(%p)\n", func, callsite);
ENABLE_TRACE
}
void __cyg_profile_func_exit(void *func, void *callsite)
{
}

View File

@ -1 +0,0 @@
genprof

View File

@ -1,12 +0,0 @@
CC=gcc
CFLAGS=-O2 -Wall
all: genprof
genprof: genprof.o
$(CC) $(CFLAGS) -o genprof $^
clean:
rm -f genprof *.o *~
distclean: clean

View File

@ -1,31 +0,0 @@
Function tracing
----------------
Enable CONFIG_TRACE in debug menu. Run the compiled image on target. You will get
a log with a lot of lines like:
...
~0x001072e8(0x00100099)
~0x00108bc0(0x0010730a)
...
First address is address of function which was just entered, the second address
is address of functions which call that.
You can use the log2dress to dress the log again:
...
src/arch/x86/lib/c_start.S:85 calls /home/ruik/coreboot/src/boot/selfboot.c:367
/home/ruik/coreboot/src/boot/selfboot.c:370 calls /home/ruik/coreboot/src/device/device.c:325
...
Alternatively, you can use genprof to generate a gmon.out file, which can be used
by gprof to show the call traces. You will need to install uthash library to compile
that.
Great use is:
make
./genprof /tmp/yourlog ; gprof ../../build/ramstage | ./gprof2dot.py -e0 -n0 | dot -Tpng -o output.png
Which generates a PNG with a call graph.

View File

@ -1 +0,0 @@
Format function tracing logs `Bash` `C`

View File

@ -1,114 +0,0 @@
#include <stdio.h>
#include <uthash.h>
#include <sys/gmon_out.h>
#include <stdlib.h>
#define GMON_SEC "seconds s"
uint32_t mineip = 0xffffffff;
uint32_t maxeip = 0;
/* a hash structure to hold the arc */
struct arec {
uint32_t eip;
uint32_t from;
uint32_t count;
UT_hash_handle hh;
};
struct arec *arc = NULL;
void note_arc(uint32_t eip, uint32_t from)
{
struct arec *s;
HASH_FIND_INT(arc, &eip, s);
if (s == NULL) {
s = malloc(sizeof(struct arec));
s->eip = eip;
s->from = from;
s->count = 1;
if (eip > maxeip)
maxeip = eip;
if (eip < mineip)
maxeip = eip;
HASH_ADD_INT(arc, eip, s);
} else {
s->count++;
}
}
int main(int argc, char* argv[])
{
FILE *f, *fo;
struct arec *s;
uint32_t eip, from, tmp;
uint8_t tag;
uint16_t hit;
if (argc != 2) {
fprintf(stderr, "Please specify the coreboot trace log as parameter\n");
return 1;
}
f = fopen(argv[1], "r");
if (f == NULL) {
perror("Unable to open the input file");
return 1;
}
fo = fopen("gmon.out", "w+");
if (fo == NULL) {
perror("Unable to open the output file");
fclose(f);
return 1;
}
while (!feof(f)) {
if (fscanf(f, "~%x(%x)%*[^\n]\n", &eip, &from) == 2) {
note_arc(eip, from);
} else if (fscanf(f, "%*c~%x(%x)%*[^\n]\n", &eip, &from) == 2) {
note_arc(eip, from);
} else {
/* just drop a line */
tmp = fscanf(f, "%*[^\n]\n");
}
}
/* write gprof header */
fwrite(GMON_MAGIC, 1, sizeof(GMON_MAGIC) - 1, fo);
tmp = GMON_VERSION;
fwrite(&tmp, 1, sizeof(tmp), fo);
tmp = 0;
fwrite(&tmp, 1, sizeof(tmp), fo);
fwrite(&tmp, 1, sizeof(tmp), fo);
fwrite(&tmp, 1, sizeof(tmp), fo);
/* write fake histogram */
tag = GMON_TAG_TIME_HIST;
fwrite(&tag, 1, sizeof(tag), fo);
fwrite(&mineip, 1, sizeof(mineip), fo);
fwrite(&maxeip, 1, sizeof(maxeip), fo);
/* size of histogram */
tmp = 1;
fwrite(&tmp, 1, sizeof(tmp), fo);
/* prof rate */
tmp = 1000;
fwrite(&tmp, 1, sizeof(tmp), fo);
fwrite(GMON_SEC, 1, sizeof(GMON_SEC) - 1, fo);
hit = 1;
fwrite(&hit, 1, sizeof(hit), fo);
/* write call graph data */
tag = GMON_TAG_CG_ARC;
for (s = arc; s != NULL; s = s->hh.next) {
fwrite(&tag, 1, sizeof(tag), fo);
fwrite(&s->from, 1, sizeof(s->from), fo);
fwrite(&s->eip, 1, sizeof(s->eip), fo);
fwrite(&s->count, 1, sizeof(s->count), fo);
}
fclose(fo);
fclose(f);
return 0;
}

View File

@ -1,20 +0,0 @@
#!/usr/bin/env bash
#Parse a log and get back the function names and line numbers
#Provide a log file as first argument
#Please rewrite to something more saner !
cat $1 | while read line ; do
A=`echo $line | cut -c 1`
if [ "$A" = '~' ] ; then
FROM=`echo $line | tr \~ \( | tr \) \( | awk -F\( '{print $3}'`
TO=`echo $line | tr \~ \( | tr \) \(|awk -F\( '{print $2}'`
addr2line -e ../../build/cbfs/fallback/ramstage.debug "$FROM" | tr -d "\n"
echo -n " calls "
addr2line -e ../../build/cbfs/fallback/ramstage.debug "$TO"
else
echo "$line"
fi
done