[coreboot] CBMEM Console corruption with fsp_baytrail in coreboot 4.2

Ben Gardner gardner.ben at gmail.com
Fri Nov 20 23:07:44 CET 2015


On Fri, Nov 20, 2015 at 1:23 PM, Ben Gardner <gardner.ben at gmail.com> wrote:
> On Fri, Nov 20, 2015 at 12:17 PM, Aaron Durbin <adurbin at google.com> wrote:
>> On Fri, Nov 20, 2015 at 7:30 AM, Ben Gardner <gardner.ben at 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



More information about the coreboot mailing list