Re: [coreboot] CBMEM Console corruption with fsp_baytrail in coreboot 4.2

Nov. 20, 2015

      On Fri, Nov 20, 2015 at 1:23 PM, Ben Gardner <gardner.ben@gmail.com> wrote:
...
On Fri, Nov 20, 2015 at 12:17 PM, Aaron Durbin <adurbin@google.com> wrote:
...
On Fri, Nov 20, 2015 at 7:30 AM, Ben Gardner <gardner.ben@gmail.com> wrote:
...
Hi Aaron,
That patch didn't make a difference that I could see. The console
buffer is still filled with garbage that cbmemc_reinit() copies into
the final buffer.
The issue was also with the timestamps, so special handling of the
console may not do the trick.
I'm not sure if it is helpful, but here is my logging function (gmail
eats the tabs):
void log_current_console(const char *func)
{
struct cbmem_console *cbm_cons_p = current_console();
#ifdef __PRE_RAM__
    hexdump(BIOS_ERR, _car_data_start, _car_data_end - _car_data_start);
#endif
if (cbm_cons_p) {
printk(BIOS_ERR, "%s: cbm_cons_p: %p size=%d cur=%d\n", func,
      cbm_cons_p,
      cbm_cons_p->buffer_size,
      cbm_cons_p->buffer_cursor);
        hexdump(BIOS_ERR, cbm_cons_p, 64);
} else {
printk(BIOS_ERR, "%s: cbm_cons_p: NULL\n", func);
}
}
Logs with your patch:
fef00c00: 00 00 00 00 00 00 f0 fe                          ........
romstage_fsp_rt_buffer_callback: cbm_cons_p: fef00000 size=3064 cur=2434
fef00000: f8 0b 00 00 e0 09 00 00 66 65 66 30 30 63 30 30  ........fef00c00
fef00010: 3a 20 30 30 20 30 30 20 30 30 20 30 30 20 30 30  : 00 00 00 00 00
fef00020: 20 30 30 20 66 30 20 66 65 20 20 20 20 20 20 20   00 f0 fe
fef00030: 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20
fef00c00: 00 00 00 00 00 00 f0 fe                          ........
fsp_early_init: cbm_cons_p: fef00000 size=3064 cur=2879
fef00000: f8 0b 00 00 8c 0b 00 00 66 65 66 30 30 63 30 30  ........fef00c00
fef00010: 3a 20 30 30 20 30 30 20 30 30 20 30 30 20 30 30  : 00 00 00 00 00
fef00020: 20 30 30 20 66 30 20 66 65 20 20 20 20 20 20 20   00 f0 fe
fef00030: 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20
fef00c00: ff ff ff ff ff ff ff ff                          ........
romstage_main_continue: cbm_cons_p: 00000ca7 size=1241003328 cur=1794134956
00000ca7: 40 35 f8 49 0d 54 f0 6a c6 bc 50 1e 75 07 7c 2c  @5.I7T.j..P.u.|,
00000cb7: 6b 85 35 98 82 cf 75 97 1b 55 8e 5c c9 1f 85 ad  k.5...u..U.\....
00000cc7: 32 1e df fc 10 ef e0 81 46 73 b5 cf b1 f5 3b b5  2.......Fs....;.
00000cd7: af 95 2c 32 16 25 75 2a 14 a4 42 46 bf 62 93 6a  ..,2.%u*..BF.b.j
romstage_main_continue status: 0  hob_list_ptr: 7ae20000
Logs with my modification to car.ld:
fef00000: 00 00 00 00 08 00 f0 fe                          ........
romstage_fsp_rt_buffer_callback: cbm_cons_p: fef00008 size=3064 cur=2434
fef00008: f8 0b 00 00 e0 09 00 00 66 65 66 30 30 30 30 30  ........fef00000
fef00018: 3a 20 30 30 20 30 30 20 30 30 20 30 30 20 30 38  : 00 00 00 00 08
fef00028: 20 30 30 20 66 30 20 66 65 20 20 20 20 20 20 20   00 f0 fe
fef00038: 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20
fef00000: 00 00 00 00 08 00 f0 fe                          ........
fsp_early_init: cbm_cons_p: fef00008 size=3064 cur=2879
fef00008: f8 0b 00 00 8c 0b 00 00 66 65 66 30 30 30 30 30  ........fef00000
fef00018: 3a 20 30 30 20 30 30 20 30 30 20 30 30 20 30 38  : 00 00 00 00 08
fef00028: 20 30 30 20 66 30 20 66 65 20 20 20 20 20 20 20   00 f0 fe
fef00038: 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20
fef00000: ff ff ff ff ff ff ff ff                          ........
romstage_main_continue: cbm_cons_p: 7ae230a8 size=3064 cur=3307
7ae230a8: f8 0b 00 00 40 0d 00 00 66 65 66 30 30 30 30 30  ....j...fef00000
7ae230b8: 3a 20 30 30 20 30 30 20 30 30 20 30 30 20 30 38  : 00 00 00 00 08
7ae230c8: 20 30 30 20 66 30 20 66 65 20 20 20 20 20 20 20   00 f0 fe
7ae230d8: 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20
romstage_main_continue status: 0  hob_list_ptr: 7ae20000
The only difference is in the _car_data_start output, byte 4. 0x00 vs 0x08.
The romstage.map files I think are quite interesting.
romstage.map snipppet with your patch:
fef00000 B _preram_cbmem_console
fef00001 b _
fef00c00 B _car_data_start
fef00c00 B _car_global_start
fef00c00 B _epreram_cbmem_console
fef00c00 b car_migrated
fef00c04 b cbmem_console_p
fef00c08 B _car_data_end
fef00c08 B _car_global_end
romstage.map snipppet with the change to car.ld:
fef00000 B _car_data_start
fef00000 B _car_global_start
fef00000 b car_migrated
fef00001 b _
fef00004 b cbmem_console_p
fef00008 B _car_data_end
fef00008 B _car_global_end
fef00008 B _preram_cbmem_console
fef00c08 B _epreram_cbmem_console
It looks like the _preram_cbmem_console is overlapping the car data!
It's not overlapping in either map. The *_end' and
_epreram_cbmem_console symbols are exclusive of the range.
cbm_cons_p: 00000ca7  <- that is the biggest issue. The
cbmem_console_p is being updated to a not so great value.
current_console() returns the console using car_sync_var(cbmem_console_p);
car_sync_var() is a macro which is expanded to:
*(typeof (var) *)car_sync_var_ptr(&(var))
which would be *(struct cbmem_console **)car_sync_var_ptr(&cbmem_console_p);
So we are calling car_sync_var_ptr(0xfef00c04);
At the beginning of car_sync_var_ptr() we call this: car_get_var_ptr(var);
Which is car_get_var_ptr(0xfef00c04);
It would be interesting to see the migrated_base value in
car_get_var_ptr(), but that will be impossible w/ cbmem console proper
since it will recursively call back down this sequence. Assuming
migrated base is correct we should be seeing the value in that area
for cbmem_console_p to be 0xfef00000 which is _preram_cbmem_console.
I added a version of printk that only sends data to the UART.
migrated_base is either 0 or 0x7ae230a0.
It becomes 0x7ae230a0 right after the FSP call.
...
The symbols are all relative to one another so I'd expect the
migration adjustment to be valid. When I said assuming migrated base
is correct I am probably wrong because we're getting whacky pointers.
I'm still not clear how FSP 1.0 does memory migration. But it might be
interesting to dump the contents of the region found in
find_saved_temp_mem(), but I'm not sure how big it is.
I'll start by logging 64 bytes and see what that gets us.
Added to the top of romstage_main_continue():
   printk_uart(BIOS_ERR, "CBMEM_FSP_HOB_PTR=%p\n", ptr);
   hexdump(BIOS_ERR, (char *)find_saved_temp_mem(*(void
**)CBMEM_FSP_HOB_PTR), 64);

Result:
CBMEM_FSP_HOB_PTR=00000614
7ae230a0: f8 0b 00 00 f9 10 00 00 63 62 6d 65 6d 63 5f 69  ........cbmemc_i
7ae230b0: 6e 69 74 3a 20 63 62 6d 5f 63 6f 6e 73 5f 70 3a  nit: cbm_cons_p:
7ae230c0: 20 66 65 66 30 30 30 30 30 20 73 69 7a 65 3d 33   fef00000 size=3
7ae230d0: 30 36 34 20 63 75 72 3d 30 0a 66 65 66 30 30 30  064 cur=0.fef000

That looks like "struct cbmem_console" data.
The address matches the migrated_base variable and the content looks
to be what should be in _preram_cbmem_console.

fef00000 B _preram_cbmem_console
fef00001 b _
fef00c00 B _car_data_start
fef00c00 B _epreram_cbmem_console
fef00c00 B _timestamp
fef00d00 B _car_global_start
fef00d00 B _etimestamp
fef00d00 b car_migrated
fef00d04 b cbmem_console_p
fef00d08 B _car_data_end
fef00d08 B _car_global_end

So what I don't get is how this Cache-as-RAM global stuff is supposed
to work with FSP 1.0.
The FSP's TempRamInitEntry() function returns the range of valid
addresses that we can write to in ECX (start) & EDX (end).
I see that EDX is used to init ESP and EBP and ECX is used to clear the stack.
How does that work with the hard-coded address (0xfef00000) of the CAR data?
Wouldn't any CAR data need to be on the stack?

I added a log to romstage main() that prints the address of some stack vars:
   printk(BIOS_ERR, "Stack: %p or %p\n", &func_dis, &fd2_mask);

Output:
CAR data @ fef00c00 .. fef00d08

Are my eyes tricking me again or is the stack right on top of _car_data_start ?
That would be the problem!

Ben

Ben Gardner

tags

participants (1)