Add more timestamps in coreboot.

This adds a number of timestamps in ramstage and romstage
so we can figure out where execution time goes.

Change-Id: Iea17c08774e623fc1ca3fa4505b70523ba4cbf01
Signed-off-by: Stefan Reinauer <reinauer@google.com>
Reviewed-on: http://review.coreboot.org/749
Tested-by: build bot (Jenkins)
Reviewed-by: Ronald G. Minnich <rminnich@gmail.com>

src/arch/x86/lib/cbfs_and_run.c

@@ -20,16 +20,19 @@
 #include <console/console.h>
 #include <cbfs.h>
 #include <arch/stages.h>
+#include <timestamp.h>
 
 static void cbfs_and_run_core(const char *filename, unsigned ebp)
 {
 	u8 *dst;
 
+	timestamp_add_now(TS_START_COPYRAM);
 	print_debug("Loading image.\n");
 	dst = cbfs_load_stage(filename);
 	if ((void *)dst == (void *) -1)
 		die("FATAL: Essential component is missing.\n");
 
+	timestamp_add_now(TS_END_COPYRAM);
 	print_debug("Jumping to image.\n");
 	__asm__ volatile (
 		"movl %%eax, %%ebp\n"

src/boot/hardwaremain.c

@@ -41,6 +41,7 @@ it with the version available from LANL.
 #if CONFIG_WRITE_HIGH_TABLES
 #include <cbmem.h>
 #endif
+#include <timestamp.h>
 
 /**
  * @brief Main function of the RAM part of coreboot.
@@ -56,7 +57,9 @@ void hardwaremain(int boot_complete);
 void hardwaremain(int boot_complete)
 {
 	struct lb_memory *lb_mem;
+	tsc_t timestamps[6];
 
+	timestamps[0] = rdtsc();
 	post_code(POST_ENTRY_RAMSTAGE);
 
 	/* console_init() MUST PRECEDE ALL printk()! */
@@ -78,18 +81,26 @@ void hardwaremain(int boot_complete)
 	/* FIXME: Is there a better way to handle this? */
 	init_timer();
 
+	timestamps[1] = rdtsc();
 	/* Find the devices we don't have hard coded knowledge about. */
 	dev_enumerate();
 	post_code(POST_DEVICE_ENUMERATION_COMPLETE);
+
+	timestamps[2] = rdtsc();
 	/* Now compute and assign the bus resources. */
 	dev_configure();
 	post_code(POST_DEVICE_CONFIGURATION_COMPLETE);
+
+	timestamps[3] = rdtsc();
 	/* Now actually enable devices on the bus */
 	dev_enable();
+
+	timestamps[4] = rdtsc();
 	/* And of course initialize devices on the bus */
 	dev_initialize();
 	post_code(POST_DEVICES_ENABLED);
 
+	timestamps[5] = rdtsc();
 #if CONFIG_WRITE_HIGH_TABLES == 1
 	cbmem_initialize();
 #if CONFIG_CONSOLE_CBMEM
@@ -101,10 +112,20 @@ void hardwaremain(int boot_complete)
 	post_code(0x8a);
 #endif
 
+	timestamp_add(TS_START_RAMSTAGE, timestamps[0]);
+	timestamp_add(TS_DEVICE_ENUMERATE, timestamps[1]);
+	timestamp_add(TS_DEVICE_CONFIGURE, timestamps[2]);
+	timestamp_add(TS_DEVICE_ENABLE, timestamps[3]);
+	timestamp_add(TS_DEVICE_INITIALIZE, timestamps[4]);
+	timestamp_add(TS_DEVICE_DONE, timestamps[5]);
+	timestamp_add_now(TS_WRITE_TABLES);
+
 	/* Now that we have collected all of our information
 	 * write our configuration tables.
 	 */
 	lb_mem = write_tables();
+
+	timestamp_add_now(TS_LOAD_PAYLOAD);
 	cbfs_load_payload(lb_mem, CONFIG_CBFS_PREFIX "/payload");
 	printk(BIOS_ERR, "Boot failed.\n");
 }

src/include/timestamp.h

@@ -35,14 +35,32 @@ struct timestamp_table {
 } __attribute__((packed));
 
 enum timestamp_id {
-	TS_BEFORE_INITRAM = 1,
+	TS_START_ROMSTAGE = 1,
-	TS_AFTER_INITRAM = 2,
+	TS_BEFORE_INITRAM = 2,
+	TS_AFTER_INITRAM = 3,
+	TS_END_ROMSTAGE = 4,
+	TS_START_COPYRAM = 8,
+	TS_END_COPYRAM = 9,
+	TS_START_RAMSTAGE = 10,
+	TS_DEVICE_ENUMERATE = 30,
+	TS_DEVICE_CONFIGURE = 40,
+	TS_DEVICE_ENABLE = 50,
+	TS_DEVICE_INITIALIZE = 60,
+	TS_DEVICE_DONE = 70,
+	TS_WRITE_TABLES = 80,
+	TS_LOAD_PAYLOAD = 90,
 	TS_ACPI_WAKE_JUMP = 98,
 	TS_SELFBOOT_JUMP = 99,
 };
 
+#if CONFIG_COLLECT_TIMESTAMPS
 void timestamp_init(tsc_t base);
 void timestamp_add(enum timestamp_id id, tsc_t ts_time);
 void timestamp_add_now(enum timestamp_id id);
+#else
+#define timestamp_init(base)
+#define timestamp_add(id, time)
+#define timestamp_add_now(id)
+#endif
 
 #endif