[coreboot-gerrit] New patch to review for coreboot: DO NOT MERGE: Quark: Bad imdr->root reference

Lee Leahy (leroy.p.leahy@intel.com) gerrit at coreboot.org
Thu Jan 5 00:47:18 CET 2017


Lee Leahy (leroy.p.leahy at intel.com) just uploaded a new patch set to gerrit, which you can find at https://review.coreboot.org/18042

-gerrit

commit 6df4f9cfb3a559c7668a1003d6cd4efb32adaa24
Author: Lee Leahy <leroy.p.leahy at intel.com>
Date:   Mon Dec 26 11:04:27 2016 -0800

    DO NOT MERGE: Quark: Bad imdr->root reference
    
    Test run on the Galileo Gen2 (Quark) using VBOOT_MOCK_SECDATA.
    
    Add debugging support to determine location of bad reference.  The
    address at 0x80007d60 is valid and points to the "CAR data" in ESRAM.
    
    The following log is produced:
    
    coreboot-4.5-762-gcf3e69f Wed Jan  4 23:24:50 UTC 2017 bootblock starting...
    cbfs_prepare_program_locate @ ffff935a
    boot_device_init
    locators[0]->prepare: ffffaa51
    vboot_prepare
    verification_should_run
    verification_should_run
    verification_should_run returning 0
    verstage_should_load
    VBOOT: Loading verstage.
    cbfs_boot_locate
    vboot_locate
    vb2_logic_executed
    verification_should_run
    verification_should_run returning 0
    verstage_should_load
    vb2_logic_executed returning 0
    CBFS: 'Master Header Locator' located CBFS at [611000:7fffc0)
    CBFS: Locating 'fallback/verstage'
    CBFS: Found @ offset 54280 size 779c
    cbfs_file_data
    cbfs_prog_stage_load
    prog_run
    Calling fallback/verstage, 0xffe65300(0x00000000)
    
    coreboot-4.5-762-gcf3e69f Wed Jan  4 23:24:50 UTC 2017 verstage starting...
    run_romstage()
    cbfs_prepare_program_locate @ ffe6654f
    boot_device_init
    locators[0]->prepare: ffe677ea
    vboot_prepare
    verification_should_run
    verification_should_run
    verstage_main
    vb2_init_work_context
    vb2_init_work_context
    vb2_working_data_size
    vboot_get_working_data
    vb2_get_shared_data
    vboot_get_working_data
    read_vbnv
    vbnv.c: read_vbnv
    vbnv.c: verify_vbnv
    vbnv.c: reset_vbnv
    vboot_platform_is_resuming
    antirollback_read_space_firmware
    mock: antirollback_read_space_firmware
    get_developer_mode_switch
    get_wipeout_mode_switch
    boot_device_ro
    Phase 1
    vb2api_fw_phase1
    FMAP: Found "FLASH" version 1.1 at 610000.
    FMAP: base = ff800000 size = 800000 #areas = 28
    VB2:vb2_fail() Need recovery, reason: 0x2c / 0x3
    VB2:vb2_check_recovery() Recovery reason from previous boot: 0x2c / 0x3
    VB2:vb2_check_recovery() We have a recovery request: 0x2c / 0x0
    Recovery requested (1009000e)
    save_if_needed
    Saving nvdata
    vbnv.c: save_vbnv
    Saving secdata
    mock: antirollback_write_space_firmware
    extend_pcrs
    mock: tpm_extend_pcr
    mock: tpm_extend_pcr
    car_set_var
    vb2_save_recovery_reason_vbnv
    vboot_locate
    vb2_logic_executed
    verification_should_run
    vb2_get_selected_region
    vb2_get_selected_region
    vb2_selected_region
    vboot_get_working_data
    80000000: sel_reg
    reg->offset or reg->size is zero, returning -1
    CBFS: 'Master Header Locator' located CBFS at [611000:7fffc0)
    CBFS: Locating 'fallback/romstage'
    CBFS: Found @ offset 80 size 8a0c
    
    coreboot-4.5-762-gcf3e69f Wed Jan  4 23:24:50 UTC 2017 romstage starting...
    prev_sleep_state 0
    vboot_locate
    vb2_logic_executed
    verification_should_run
    verification_should_run returning 0
    verstage_should_load
    verstage_should_load returning 0
    vb2_get_selected_region
    vb2_get_selected_region
    vb2_selected_region
    cbmem_find
    imd_init_backing_with_recover
    imd_init_backing
    cbmem_get_imd
    0x00000000: CAN_USE_GLOBALS
    NULL
    imd = backing
    80007d60: imd
    imd_handle_init
    imd_handle_init_partial_recovery
    imd_handle_init_partial_recovery
    imd_handle_init
    imdr_get_root_pointer
    relative_pointer
    imdr_entry_find
    imdr_root
    80007d60: imdr
    imdr_root returning fffefff7
    
    Change-Id: Ia6c5a99ed73291f50c149c046786e67036507fc1
---
 src/lib/cbfs.c           |  6 ++++++
 src/lib/imd.c            | 17 +++++++++++++++++
 src/lib/imd_cbmem.c      | 16 ++++++++++++++++
 src/vboot/common.c       | 21 +++++++++++++++++++++
 src/vboot/secdata_mock.c |  7 +++++++
 src/vboot/vbnv.c         | 14 ++++++++++++++
 src/vboot/vboot_loader.c | 21 +++++++++++++++++++++
 src/vboot/vboot_logic.c  | 15 +++++++++++++++
 src/vboot/verstage.c     |  3 +++
 9 files changed, 120 insertions(+)

diff --git a/src/lib/cbfs.c b/src/lib/cbfs.c
index ff166d8..5b61e9e 100644
--- a/src/lib/cbfs.c
+++ b/src/lib/cbfs.c
@@ -272,6 +272,7 @@ static int cbfs_master_header_props(struct cbfs_props *props)
 	int32_t rel_offset;
 	size_t offset;
 
+printk(BIOS_DEBUG, "boot_device_ro\n" );
 	bdev = boot_device_ro();
 
 	if (bdev == NULL)
@@ -282,10 +283,12 @@ static int cbfs_master_header_props(struct cbfs_props *props)
 	/* Find location of header using signed 32-bit offset from
 	 * end of CBFS region. */
 	offset = fmap_top - sizeof(int32_t);
+printk(BIOS_DEBUG, "rdev_readat, fmap_top: 0x%08lx, offset: 0x%08lx\n", fmap_top, offset );
 	if (rdev_readat(bdev, &rel_offset, offset, sizeof(int32_t)) < 0)
 		return -1;
 
 	offset = fmap_top + rel_offset;
+printk(BIOS_DEBUG, "rdev_readat, rel_offset: 0x%08x, offset: 0x%08lx\n", rel_offset, offset );
 	if (rdev_readat(bdev, &header, offset, sizeof(header)) < 0)
 		return -1;
 
@@ -352,11 +355,14 @@ void cbfs_prepare_program_locate(void)
 {
 	int i;
 
+printk(BIOS_DEBUG, "cbfs_prepare_program_locate @ %p\n", &cbfs_prepare_program_locate );
+printk(BIOS_DEBUG, "boot_device_init\n" );
 	boot_device_init();
 
 	for (i = 0; i < ARRAY_SIZE(locators); i++) {
 		if (locators[i]->prepare == NULL)
 			continue;
+printk(BIOS_DEBUG, "locators[%d]->prepare: %p\n", i, locators[i]->prepare);
 		locators[i]->prepare();
 	}
 }
diff --git a/src/lib/imd.c b/src/lib/imd.c
index 2fc6fac..3e13a1b 100644
--- a/src/lib/imd.c
+++ b/src/lib/imd.c
@@ -68,6 +68,9 @@ static bool imd_root_pointer_valid(const struct imd_root_pointer *rp)
 
 static struct imd_root *imdr_root(const struct imdr *imdr)
 {
+printk(BIOS_DEBUG, "%p: imdr\n", imdr);
+printk(BIOS_DEBUG, "imdr_root returning %p\n", imdr->r);
+
 	return imdr->r;
 }
 
@@ -261,10 +264,14 @@ static const struct imd_entry *imdr_entry_find(const struct imdr *imdr,
 	struct imd_entry *e;
 	size_t i;
 
+printk(BIOS_DEBUG, "imdr_root\n");
 	r = imdr_root(imdr);
 
 	if (r == NULL)
+{
+printk(BIOS_DEBUG, "imdr_entry_find returning NULL\n");
 		return NULL;
+}
 
 	e = NULL;
 	/* Skip first entry covering the root. */
@@ -275,6 +282,7 @@ static const struct imd_entry *imdr_entry_find(const struct imdr *imdr,
 		break;
 	}
 
+printk(BIOS_DEBUG, "imdr_entry_find returning %p\n", e);
 	return e;
 }
 
@@ -407,25 +415,34 @@ void imd_handle_init_partial_recovery(struct imd *imd)
 	struct imd_root_pointer *rp;
 	struct imdr *imdr;
 
+printk(BIOS_DEBUG, "imd_handle_init_partial_recovery\n");
 	if (imd->lg.limit == 0)
 		return;
 
+printk(BIOS_DEBUG, "imd_handle_init\n");
 	imd_handle_init(imd, (void *)imd->lg.limit);
 
 	/* Initialize root pointer for the large regions. */
 	imdr = &imd->lg;
+printk(BIOS_DEBUG, "imdr_get_root_pointer\n");
 	rp = imdr_get_root_pointer(imdr);
+printk(BIOS_DEBUG, "relative_pointer\n");
 	imdr->r = relative_pointer(rp, rp->root_offset);
 
+printk(BIOS_DEBUG, "imdr_entry_find\n");
 	e = imdr_entry_find(imdr, SMALL_REGION_ID);
 
 	if (e == NULL)
 		return;
 
+printk(BIOS_DEBUG, "imdr_entry_at\n");
 	imd->sm.limit = (uintptr_t)imdr_entry_at(imdr, e);
+printk(BIOS_DEBUG, "imdr_entry_size\n");
 	imd->sm.limit += imdr_entry_size(imdr, e);
 	imdr = &imd->sm;
+printk(BIOS_DEBUG, "imdr_get_root_pointer\n");
 	rp = imdr_get_root_pointer(imdr);
+printk(BIOS_DEBUG, "relative_pointer\n");
 	imdr->r = relative_pointer(rp, rp->root_offset);
 }
 
diff --git a/src/lib/imd_cbmem.c b/src/lib/imd_cbmem.c
index b0273f4..0a4fc39 100644
--- a/src/lib/imd_cbmem.c
+++ b/src/lib/imd_cbmem.c
@@ -43,10 +43,13 @@
 
 static inline struct imd *cbmem_get_imd(void)
 {
+printk(BIOS_DEBUG, "0x%08x: CAN_USE_GLOBALS\n", CAN_USE_GLOBALS);
 	if (CAN_USE_GLOBALS) {
 		static struct imd imd_cbmem;
+printk(BIOS_DEBUG, "%p: &imd_cbmem\n", &imd_cbmem);
 		return &imd_cbmem;
 	}
+printk(BIOS_DEBUG, "NULL\n");
 	return NULL;
 }
 
@@ -76,13 +79,19 @@ static struct imd *imd_init_backing(struct imd *backing)
 {
 	struct imd *imd;
 
+printk(BIOS_DEBUG, "cbmem_get_imd\n");
 	imd = cbmem_get_imd();
 
 	if (imd != NULL)
+{
+printk(BIOS_DEBUG, "%p: imd\n", imd);
 		return imd;
+}
 
+printk(BIOS_DEBUG, "imd = backing\n");
 	imd = backing;
 
+printk(BIOS_DEBUG, "%p: imd\n", imd);
 	return imd;
 }
 
@@ -90,14 +99,18 @@ static struct imd *imd_init_backing_with_recover(struct imd *backing)
 {
 	struct imd *imd;
 
+printk(BIOS_DEBUG, "imd_init_backing\n");
 	imd = imd_init_backing(backing);
 	if (!CAN_USE_GLOBALS) {
 		/* Always partially recover if we can't keep track of whether
 		 * we have already initialized CBMEM in this stage. */
+printk(BIOS_DEBUG, "imd_handle_init\n");
 		imd_handle_init(imd, cbmem_top());
+printk(BIOS_DEBUG, "imd_handle_init_partial_recovery\n");
 		imd_handle_init_partial_recovery(imd);
 	}
 
+printk(BIOS_DEBUG, "%p: imd\n", imd);
 	return imd;
 }
 
@@ -234,13 +247,16 @@ void *cbmem_find(u32 id)
 	struct imd imd_backing;
 	const struct imd_entry *e;
 
+printk(BIOS_DEBUG, "imd_init_backing_with_recover\n");
 	imd = imd_init_backing_with_recover(&imd_backing);
 
+printk(BIOS_DEBUG, "imd_entry_find\n");
 	e = imd_entry_find(imd, id);
 
 	if (e == NULL)
 		return NULL;
 
+printk(BIOS_DEBUG, "imd_entry_at\n");
 	return imd_entry_at(imd, e);
 }
 
diff --git a/src/vboot/common.c b/src/vboot/common.c
index cfdb82a..e6c0727 100644
--- a/src/vboot/common.c
+++ b/src/vboot/common.c
@@ -46,6 +46,7 @@ static const size_t vb_work_buf_size = 16 * KiB;
 
 static struct vb2_working_data * const vboot_get_working_data(void)
 {
+printk(BIOS_DEBUG, "vboot_get_working_data\n" );
 	if (IS_ENABLED(CONFIG_VBOOT_DYNAMIC_WORK_BUFFER))
 		/* cbmem_add() does a cbmem_find() first. */
 		return cbmem_add(CBMEM_ID_VBOOT_WORKBUF, vb_work_buf_size);
@@ -55,6 +56,7 @@ static struct vb2_working_data * const vboot_get_working_data(void)
 
 static size_t vb2_working_data_size(void)
 {
+printk(BIOS_DEBUG, "vb2_working_data_size\n" );
 	if (IS_ENABLED(CONFIG_VBOOT_DYNAMIC_WORK_BUFFER))
 		return vb_work_buf_size;
 	else
@@ -64,15 +66,18 @@ static size_t vb2_working_data_size(void)
 static struct selected_region *vb2_selected_region(void)
 {
 	struct selected_region *sel_reg = NULL;
+printk(BIOS_DEBUG, "vb2_selected_region\n" );
 
 	/* Ramstage and postcar always uses cbmem as a source of truth. */
 	if (ENV_RAMSTAGE || ENV_POSTCAR)
 		sel_reg = cbmem_find(CBMEM_ID_VBOOT_SEL_REG);
 	else if (ENV_ROMSTAGE) {
 		/* Try cbmem first. Fall back on working data if not found. */
+printk(BIOS_DEBUG, "cbmem_find\n" );
 		sel_reg = cbmem_find(CBMEM_ID_VBOOT_SEL_REG);
 
 		if (sel_reg == NULL) {
+printk(BIOS_DEBUG, "CBMEM not initialized\n" );
 			struct vb2_working_data *wd = vboot_get_working_data();
 			sel_reg = &wd->selected_region;
 		}
@@ -82,6 +87,7 @@ static struct selected_region *vb2_selected_region(void)
 		sel_reg = &wd->selected_region;
 	}
 
+printk(BIOS_DEBUG, "%p: sel_reg\n", sel_reg);
 	return sel_reg;
 }
 
@@ -90,6 +96,7 @@ void vb2_init_work_context(struct vb2_context *ctx)
 	struct vb2_working_data *wd;
 	size_t work_size;
 
+printk(BIOS_DEBUG, "vb2_init_work_context\n" );
 	/* First initialize the working data region. */
 	work_size = vb2_working_data_size();
 	wd = vboot_get_working_data();
@@ -111,28 +118,39 @@ void vb2_init_work_context(struct vb2_context *ctx)
 
 struct vb2_shared_data *vb2_get_shared_data(void)
 {
+printk(BIOS_DEBUG, "vb2_get_shared_data\n" );
 	struct vb2_working_data *wd = vboot_get_working_data();
 	return (void *)((uintptr_t)wd + wd->buffer_offset);
 }
 
 int vb2_get_selected_region(struct region *region)
 {
+printk(BIOS_DEBUG, "vb2_get_selected_region\n" );
 	const struct selected_region *reg = vb2_selected_region();
 
 	if (reg == NULL)
+{
+printk(BIOS_DEBUG, "reg is NULL, returning -1\n");
 		return -1;
+}
 
 	if (reg->offset == 0 && reg->size == 0)
+{
+printk(BIOS_DEBUG, "reg->offset or reg->size is zero, returning -1\n");
 		return -1;
+}
 
 	region->offset = reg->offset;
 	region->size = reg->size;
+printk(BIOS_DEBUG, "0x%08x: reg->offset\n", reg->offset);
+printk(BIOS_DEBUG, "0x%08x: reg->size\n", reg->size);
 
 	return 0;
 }
 
 void vb2_set_selected_region(const struct region *region)
 {
+printk(BIOS_DEBUG, "vb2_set_selected_region\n" );
 	struct selected_region *reg = vb2_selected_region();
 
 	assert(reg != NULL);
@@ -143,6 +161,7 @@ void vb2_set_selected_region(const struct region *region)
 
 int vb2_is_slot_selected(void)
 {
+printk(BIOS_DEBUG, "vb2_is_slot_selected\n" );
 	const struct selected_region *reg = vb2_selected_region();
 
 	assert(reg != NULL);
@@ -152,6 +171,7 @@ int vb2_is_slot_selected(void)
 
 void vb2_store_selected_region(void)
 {
+printk(BIOS_DEBUG, "vb2_store_selected_region\n" );
 	const struct vb2_working_data *wd;
 	struct selected_region *sel_reg;
 
@@ -176,6 +196,7 @@ void vb2_store_selected_region(void)
 #if !IS_ENABLED(CONFIG_VBOOT_DYNAMIC_WORK_BUFFER)
 static void vb2_store_selected_region_cbmem(int unused)
 {
+printk(BIOS_DEBUG, "vb2_store_selected_region_cbmem\n" );
 	vb2_store_selected_region();
 }
 ROMSTAGE_CBMEM_INIT_HOOK(vb2_store_selected_region_cbmem)
diff --git a/src/vboot/secdata_mock.c b/src/vboot/secdata_mock.c
index 9c966d9..847f836 100644
--- a/src/vboot/secdata_mock.c
+++ b/src/vboot/secdata_mock.c
@@ -7,37 +7,44 @@
  */
 
 #include <antirollback.h>
+#include <console/console.h>
 #include <stdlib.h>
 #include <vb2_api.h>
 
 uint32_t tpm_extend_pcr(struct vb2_context *ctx, int pcr,
 			enum vb2_pcr_digest which_digest)
 {
+printk(BIOS_DEBUG, "mock: tpm_extend_pcr\n");
 	return TPM_SUCCESS;
 }
 
 uint32_t tpm_clear_and_reenable(void)
 {
+printk(BIOS_DEBUG, "mock: tpm_clear_and_reenable\n");
 	return TPM_SUCCESS;
 }
 
 uint32_t antirollback_read_space_firmware(struct vb2_context *ctx)
 {
+printk(BIOS_DEBUG, "mock: antirollback_read_space_firmware\n");
 	vb2api_secdata_create(ctx);
 	return TPM_SUCCESS;
 }
 
 uint32_t antirollback_write_space_firmware(struct vb2_context *ctx)
 {
+printk(BIOS_DEBUG, "mock: antirollback_write_space_firmware\n");
 	return TPM_SUCCESS;
 }
 
 uint32_t antirollback_lock_space_firmware()
 {
+printk(BIOS_DEBUG, "mock: antirollback_lock_space_firmware\n");
 	return TPM_SUCCESS;
 }
 
 uint32_t antirollback_lock_space_rec_hash(void)
 {
+printk(BIOS_DEBUG, "mock: antirollback_lock_space_rec_hash\n");
 	return TPM_SUCCESS;
 }
diff --git a/src/vboot/vbnv.c b/src/vboot/vbnv.c
index 6537bf0..ad9587f 100644
--- a/src/vboot/vbnv.c
+++ b/src/vboot/vbnv.c
@@ -14,6 +14,7 @@
  */
 
 #include <arch/early_variables.h>
+#include <console/console.h>
 #include <string.h>
 #include <types.h>
 #include <vboot/vbnv.h>
@@ -25,11 +26,13 @@ static uint8_t vbnv[VBOOT_VBNV_BLOCK_SIZE] CAR_GLOBAL;
 /* Wrappers for accessing the variables marked as CAR_GLOBAL. */
 static inline int is_vbnv_initialized(void)
 {
+printk(BIOS_DEBUG, "vbnv.c: is_vbnv_initialized\n");
 	return car_get_var(vbnv_initialized);
 }
 
 static inline uint8_t *vbnv_data_addr(int index)
 {
+printk(BIOS_DEBUG, "vbnv.c: vbnv_data_addr\n");
 	uint8_t *vbnv_arr = car_get_var_ptr(vbnv);
 
 	return &vbnv_arr[index];
@@ -37,6 +40,7 @@ static inline uint8_t *vbnv_data_addr(int index)
 
 static inline uint8_t vbnv_data(int index)
 {
+printk(BIOS_DEBUG, "vbnv.c: vbnv_data\n");
 	return *vbnv_data_addr(index);
 }
 
@@ -46,6 +50,7 @@ static uint8_t crc8_vbnv(const uint8_t *data, int len)
 	unsigned crc = 0;
 	int i, j;
 
+printk(BIOS_DEBUG, "vbnv.c: crc8_vbnv\n");
 	for (j = len; j; j--, data++) {
 		crc ^= (*data << 8);
 		for (i = 8; i; i--) {
@@ -60,12 +65,14 @@ static uint8_t crc8_vbnv(const uint8_t *data, int len)
 
 static void reset_vbnv(uint8_t *vbnv_copy)
 {
+printk(BIOS_DEBUG, "vbnv.c: reset_vbnv\n");
 	memset(vbnv_copy, 0, VBOOT_VBNV_BLOCK_SIZE);
 }
 
 /* Read VBNV data into cache. */
 static void vbnv_setup(void)
 {
+printk(BIOS_DEBUG, "vbnv.c: vbnv_setup\n");
 	if (!is_vbnv_initialized()) {
 		read_vbnv(vbnv_data_addr(0));
 		car_set_var(vbnv_initialized, 1);
@@ -75,6 +82,7 @@ static void vbnv_setup(void)
 /* Verify VBNV header and checksum. */
 int verify_vbnv(uint8_t *vbnv_copy)
 {
+printk(BIOS_DEBUG, "vbnv.c: verify_vbnv\n");
 	return (HEADER_SIGNATURE == (vbnv_copy[HEADER_OFFSET] & HEADER_MASK)) &&
 		(crc8_vbnv(vbnv_copy, CRC_OFFSET) == vbnv_copy[CRC_OFFSET]);
 }
@@ -82,6 +90,7 @@ int verify_vbnv(uint8_t *vbnv_copy)
 /* Re-generate VBNV checksum. */
 void regen_vbnv_crc(uint8_t *vbnv_copy)
 {
+printk(BIOS_DEBUG, "vbnv.c: regen_vbnv_crc\n");
 	vbnv_copy[CRC_OFFSET] = crc8_vbnv(vbnv_copy, CRC_OFFSET);
 }
 
@@ -91,6 +100,7 @@ void regen_vbnv_crc(uint8_t *vbnv_copy)
  */
 void read_vbnv(uint8_t *vbnv_copy)
 {
+printk(BIOS_DEBUG, "vbnv.c: read_vbnv\n");
 	if (IS_ENABLED(CONFIG_VBOOT_VBNV_CMOS))
 		read_vbnv_cmos(vbnv_copy);
 	else if (IS_ENABLED(CONFIG_VBOOT_VBNV_EC))
@@ -109,6 +119,7 @@ void read_vbnv(uint8_t *vbnv_copy)
  */
 void save_vbnv(const uint8_t *vbnv_copy)
 {
+printk(BIOS_DEBUG, "vbnv.c: save_vbnv\n");
 	if (IS_ENABLED(CONFIG_VBOOT_VBNV_CMOS))
 		save_vbnv_cmos(vbnv_copy);
 	else if (IS_ENABLED(CONFIG_VBOOT_VBNV_EC))
@@ -123,6 +134,7 @@ void save_vbnv(const uint8_t *vbnv_copy)
 /* Save a recovery reason into VBNV. */
 void set_recovery_mode_into_vbnv(int recovery_reason)
 {
+printk(BIOS_DEBUG, "vbnv.c: set_recovery_mode_into_vbnv\n");
 	uint8_t vbnv_copy[VBOOT_VBNV_BLOCK_SIZE];
 
 	read_vbnv(vbnv_copy);
@@ -136,6 +148,7 @@ void set_recovery_mode_into_vbnv(int recovery_reason)
 /* Read the recovery reason from VBNV. */
 int get_recovery_mode_from_vbnv(void)
 {
+printk(BIOS_DEBUG, "vbnv.c: get_recovery_mode_from_vbnv\n");
 	vbnv_setup();
 	return vbnv_data(RECOVERY_OFFSET);
 }
@@ -143,6 +156,7 @@ int get_recovery_mode_from_vbnv(void)
 /* Read the BOOT_OPROM_NEEDED flag from VBNV. */
 int vboot_wants_oprom(void)
 {
+printk(BIOS_DEBUG, "vbnv.c: vboot_wants_oprom\n");
 	vbnv_setup();
 	return (vbnv_data(BOOT_OFFSET) & BOOT_OPROM_NEEDED) ? 1 : 0;
 }
diff --git a/src/vboot/vboot_loader.c b/src/vboot/vboot_loader.c
index 207aada..0d760bb 100644
--- a/src/vboot/vboot_loader.c
+++ b/src/vboot/vboot_loader.c
@@ -31,6 +31,7 @@
 
 static int verification_should_run(void)
 {
+printk(BIOS_DEBUG, "verification_should_run\n" );
 	if (ENV_VERSTAGE && IS_ENABLED(CONFIG_SEPARATE_VERSTAGE))
 		return 1;
 
@@ -43,11 +44,13 @@ static int verification_should_run(void)
 			return 1;
 	}
 
+printk(BIOS_DEBUG, "verification_should_run returning 0\n" );
 	return 0;
 }
 
 static int verstage_should_load(void)
 {
+printk(BIOS_DEBUG, "verstage_should_load\n" );
 	if (!IS_ENABLED(CONFIG_SEPARATE_VERSTAGE))
 		return 0;
 
@@ -57,6 +60,7 @@ static int verstage_should_load(void)
 	if (ENV_BOOTBLOCK && IS_ENABLED(CONFIG_VBOOT_STARTS_IN_BOOTBLOCK))
 		return 1;
 
+printk(BIOS_DEBUG, "verstage_should_load returning 0\n" );
 	return 0;
 }
 
@@ -64,6 +68,7 @@ static int vboot_executed CAR_GLOBAL;
 
 int vb2_logic_executed(void)
 {
+printk(BIOS_DEBUG, "vb2_logic_executed\n" );
 	/* If this stage is supposed to run the vboot logic ensure it has been
 	 * executed. */
 	if (verification_should_run() && car_get_var(vboot_executed))
@@ -84,18 +89,24 @@ int vb2_logic_executed(void)
 			return 1;
 	}
 
+printk(BIOS_DEBUG, "vb2_logic_executed returning 0\n" );
 	return 0;
 }
 
 static void vboot_prepare(void)
 {
+printk(BIOS_DEBUG, "vboot_prepare\n" );
+printk(BIOS_DEBUG, "verification_should_run\n" );
 	if (verification_should_run()) {
 		/*
 		 * Note that this path isn't taken when
 		 * CONFIG_RETURN_FROM_VERSTAGE is employed.
 		 */
+printk(BIOS_DEBUG, "verstage_main\n" );
 		verstage_main();
+printk(BIOS_DEBUG, "car_set_var\n" );
 		car_set_var(vboot_executed, 1);
+printk(BIOS_DEBUG, "vb2_save_recovery_reason_vbnv\n" );
 		vb2_save_recovery_reason_vbnv();
 
 		/*
@@ -122,15 +133,19 @@ static void vboot_prepare(void)
 		printk(BIOS_DEBUG, "VBOOT: Loading verstage.\n");
 
 		/* load verstage from RO */
+printk(BIOS_DEBUG, "cbfs_boot_locate\n" );
 		if (cbfs_boot_locate(&file, prog_name(&verstage), NULL))
 			die("failed to load verstage");
 
+printk(BIOS_DEBUG, "cbfs_file_data\n" );
 		cbfs_file_data(prog_rdev(&verstage), &file);
 
+printk(BIOS_DEBUG, "cbfs_prog_stage_load\n" );
 		if (cbfs_prog_stage_load(&verstage))
 			die("failed to load verstage");
 
 		/* verify and select a slot */
+printk(BIOS_DEBUG, "prog_run\n" );
 		prog_run(&verstage);
 
 		/* This is not actually possible to hit this condition at
@@ -139,6 +154,7 @@ static void vboot_prepare(void)
 		if (!IS_ENABLED(CONFIG_RETURN_FROM_VERSTAGE))
 			return;
 
+printk(BIOS_DEBUG, "car_set_var\n" );
 		car_set_var(vboot_executed, 1);
 	}
 
@@ -160,16 +176,21 @@ static int vboot_locate(struct cbfs_props *props)
 {
 	struct region selected_region;
 
+printk(BIOS_DEBUG, "vboot_locate\n" );
 	/* Don't honor vboot results until the vboot logic has run. */
 	if (!vb2_logic_executed())
 		return -1;
 
+printk(BIOS_DEBUG, "vb2_get_selected_region\n" );
 	if (vb2_get_selected_region(&selected_region))
 		return -1;
 
+printk(BIOS_DEBUG, "0x%08lx: props->offset\n", props->offset );
 	props->offset = region_offset(&selected_region);
+printk(BIOS_DEBUG, "0x%08lx: props->size\n", props->size );
 	props->size = region_sz(&selected_region);
 
+printk(BIOS_DEBUG, "vboot_locate returning 0\n" );
 	return 0;
 }
 
diff --git a/src/vboot/vboot_logic.c b/src/vboot/vboot_logic.c
index bfed7d4..42ee9d2 100644
--- a/src/vboot/vboot_logic.c
+++ b/src/vboot/vboot_logic.c
@@ -306,15 +306,18 @@ void verstage_main(void)
 	timestamp_add_now(TS_START_VBOOT);
 
 	/* Set up context and work buffer */
+printk(BIOS_DEBUG, "vb2_init_work_context\n" );
 	vb2_init_work_context(&ctx);
 
 	/* Read nvdata from a non-volatile storage. */
+printk(BIOS_DEBUG, "read_vbnv\n" );
 	read_vbnv(ctx.nvdata);
 
 	/* Set S3 resume flag if vboot should behave differently when selecting
 	 * which slot to boot.  This is only relevant to vboot if the platform
 	 * does verification of memory init and thus must ensure it resumes with
 	 * the same slot that it booted from. */
+printk(BIOS_DEBUG, "vboot_platform_is_resuming\n" );
 	if (IS_ENABLED(CONFIG_RESUME_PATH_SAME_AS_BOOT) &&
 	    IS_ENABLED(CONFIG_VBOOT_STARTS_IN_BOOTBLOCK) &&
 	    vboot_platform_is_resuming())
@@ -324,19 +327,23 @@ void verstage_main(void)
 	 * check the return value here because vb2api_fw_phase1 will catch
 	 * invalid secdata and tell us what to do (=reboot). */
 	timestamp_add_now(TS_START_TPMINIT);
+printk(BIOS_DEBUG, "antirollback_read_space_firmware\n" );
 	antirollback_read_space_firmware(&ctx);
 	timestamp_add_now(TS_END_TPMINIT);
 
+printk(BIOS_DEBUG, "get_developer_mode_switch\n" );
 	if (!IS_ENABLED(CONFIG_VIRTUAL_DEV_SWITCH) &&
 	    get_developer_mode_switch())
 		ctx.flags |= VB2_CONTEXT_FORCE_DEVELOPER_MODE;
 
+printk(BIOS_DEBUG, "get_wipeout_mode_switch\n" );
 	if (get_recovery_mode_switch()) {
 		ctx.flags |= VB2_CONTEXT_FORCE_RECOVERY_MODE;
 		if (IS_ENABLED(CONFIG_VBOOT_DISABLE_DEV_ON_RECOVERY))
 			ctx.flags |= VB2_DISABLE_DEVELOPER_MODE;
 	}
 
+printk(BIOS_DEBUG, "boot_device_ro\n" );
 	if (IS_ENABLED(CONFIG_WIPEOUT_SUPPORTED) && get_wipeout_mode_switch())
 		ctx.flags |= VB2_CONTEXT_FORCE_WIPEOUT_MODE;
 
@@ -345,6 +352,7 @@ void verstage_main(void)
 
 	/* Do early init (set up secdata and NVRAM, load GBB) */
 	printk(BIOS_INFO, "Phase 1\n");
+printk(BIOS_DEBUG, "vb2api_fw_phase1\n" );
 	rv = vb2api_fw_phase1(&ctx);
 
 	if (rv) {
@@ -356,29 +364,36 @@ void verstage_main(void)
 		 */
 		if (rv == VB2_ERROR_API_PHASE1_RECOVERY) {
 			printk(BIOS_INFO, "Recovery requested (%x)\n", rv);
+printk(BIOS_DEBUG, "save_if_needed\n" );
 			save_if_needed(&ctx);
+printk(BIOS_DEBUG, "extend_pcrs\n" );
 			extend_pcrs(&ctx);	/* ignore failures */
 			timestamp_add_now(TS_END_VBOOT);
 			return;
 		}
 
 		printk(BIOS_INFO, "Reboot reqested (%x)\n", rv);
+printk(BIOS_DEBUG, "save_if_needed\n" );
 		save_if_needed(&ctx);
 		vboot_reboot();
 	}
 
 	/* Determine which firmware slot to boot (based on NVRAM) */
 	printk(BIOS_INFO, "Phase 2\n");
+printk(BIOS_DEBUG, "vb2api_fw_phase2\n" );
 	rv = vb2api_fw_phase2(&ctx);
 	if (rv) {
 		printk(BIOS_INFO, "Reboot requested (%x)\n", rv);
+printk(BIOS_DEBUG, "save_if_needed\n" );
 		save_if_needed(&ctx);
+printk(BIOS_DEBUG, "vboot_reboot\n" );
 		vboot_reboot();
 	}
 
 	/* Try that slot (verify its keyblock and preamble) */
 	printk(BIOS_INFO, "Phase 3\n");
 	timestamp_add_now(TS_START_VERIFY_SLOT);
+printk(BIOS_DEBUG, "vb2api_fw_phase3\n" );
 	rv = vb2api_fw_phase3(&ctx);
 	timestamp_add_now(TS_END_VERIFY_SLOT);
 	if (rv) {
diff --git a/src/vboot/verstage.c b/src/vboot/verstage.c
index 0ec9ca6..dec2564 100644
--- a/src/vboot/verstage.c
+++ b/src/vboot/verstage.c
@@ -22,6 +22,7 @@
 void __attribute__((weak)) verstage_mainboard_init(void)
 {
 	/* Default empty implementation. */
+printk(BIOS_DEBUG, "verstage_mainboard_init()\n");
 }
 
 void verstage(void)
@@ -31,8 +32,10 @@ void verstage(void)
 	verstage_mainboard_init();
 
 	if (IS_ENABLED(CONFIG_RETURN_FROM_VERSTAGE)) {
+printk(BIOS_DEBUG, "verstage_main()\n");
 		verstage_main();
 	} else {
+printk(BIOS_DEBUG, "run_romstage()\n");
 		run_romstage();
 		hlt();
 	}



More information about the coreboot-gerrit mailing list