[coreboot] CBMEM Console corruption with fsp_baytrail in coreboot 4.2
Ben Gardner
gardner.ben at gmail.com
Fri Nov 20 23:56:00 CET 2015
Ug. I was looking at the wrong log. Time for a break.
The output from the log was:
Stack: fef03fc4 or fef03fcc
That seems to match the settings:
CONFIG_DCACHE_RAM_BASE=0xfef00000
CONFIG_DCACHE_RAM_SIZE=0x4000
On Fri, Nov 20, 2015 at 4:07 PM, Ben Gardner <gardner.ben at gmail.com> wrote:
> 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