timestamps: Add timestamps around the vbios load & init

Add timestamps before and after the vBIOS load and after the vBIOS
run.  This lets us see exactly how long it took to load it from the
ROM chip, and how long it takes to run.

BUG=b:64549506
TEST=Build & boot Grunt, see vBIOS load & initialization times.

Change-Id: I878ba653eb086ad6c6614aa08a6d3fe216a9323e
Signed-off-by: Martin Roth <martinroth@chromium.org>
Reviewed-on: https://review.coreboot.org/25018
Reviewed-by: Aaron Durbin <adurbin@chromium.org>
Reviewed-by: Paul Menzel <paulepanter@users.sourceforge.net>
Reviewed-by: Marshall Dawson <marshalldawson3rd@gmail.com>
Tested-by: build bot (Jenkins) <no-reply@coreboot.org>
diff --git a/src/commonlib/include/commonlib/timestamp_serialized.h b/src/commonlib/include/commonlib/timestamp_serialized.h
index de92c72..11baf16 100644
--- a/src/commonlib/include/commonlib/timestamp_serialized.h
+++ b/src/commonlib/include/commonlib/timestamp_serialized.h
@@ -54,6 +54,9 @@
 	TS_DEVICE_CONFIGURE = 40,
 	TS_DEVICE_ENABLE = 50,
 	TS_DEVICE_INITIALIZE = 60,
+	TS_OPROM_INITIALIZE = 65,
+	TS_OPROM_COPY_END = 66,
+	TS_OPROM_END = 67,
 	TS_DEVICE_DONE = 70,
 	TS_CBMEM_POST = 75,
 	TS_WRITE_TABLES = 80,
@@ -166,6 +169,9 @@
 	{ TS_DEVICE_CONFIGURE,	"device configuration" },
 	{ TS_DEVICE_ENABLE,	"device enable" },
 	{ TS_DEVICE_INITIALIZE,	"device initialization" },
+	{ TS_OPROM_INITIALIZE,	"Option ROM initialization" },
+	{ TS_OPROM_COPY_END,	"Option ROM copy done" },
+	{ TS_OPROM_END,		"Option ROM run done"   },
 	{ TS_DEVICE_DONE,	"device setup done" },
 	{ TS_CBMEM_POST,	"cbmem post" },
 	{ TS_WRITE_TABLES,	"write tables" },
diff --git a/src/device/pci_device.c b/src/device/pci_device.c
index 02eca66..c18f529 100644
--- a/src/device/pci_device.c
+++ b/src/device/pci_device.c
@@ -48,6 +48,7 @@
 #include <device/hypertransport.h>
 #include <pc80/i8259.h>
 #include <security/vboot/vbnv.h>
+#include <timestamp.h>
 
 u8 pci_moving_config8(struct device *dev, unsigned int reg)
 {
@@ -719,6 +720,7 @@
 
 	if (!should_load_oprom(dev))
 		return;
+	timestamp_add_now(TS_OPROM_INITIALIZE);
 
 	rom = pci_rom_probe(dev);
 	if (rom == NULL)
@@ -727,6 +729,7 @@
 	ram = pci_rom_load(dev, rom);
 	if (ram == NULL)
 		return;
+	timestamp_add_now(TS_OPROM_COPY_END);
 
 	if (!should_run_oprom(dev))
 		return;
@@ -734,6 +737,7 @@
 	run_bios(dev, (unsigned long)ram);
 	gfx_set_init_done(1);
 	printk(BIOS_DEBUG, "VGA Option ROM was run\n");
+	timestamp_add_now(TS_OPROM_END);
 }
 
 /** Default device operation for PCI devices */