[coreboot] CBMEM Console corruption with fsp_baytrail in coreboot 4.2
Aaron Durbin
adurbin at google.com
Fri Nov 20 19:17:05 CET 2015
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.
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.
> That is likely the root of the problem.
>
> Ben
>
> On Thu, Nov 19, 2015 at 10:23 PM, Aaron Durbin <adurbin at google.com> wrote:
>> On Thu, Nov 19, 2015 at 4:17 PM, Martin Roth <gaumless at gmail.com> wrote:
>>> Hi Ben, I'm still trying to get to this. I don't know if you saw how
>>> different the fsp cbmem route is from other platforms. The fsp copies the
>>> contents of the car stack to the top of memory when it tears down the cache
>>> as ram. The pointer to that gets saved and passed to the cbmem transfer
>>> code. Something has obviously happened to this sequence. I plan on trying to
>>> bisect the change. The latest I'll be able to get to that is this weekend.
>>
>> Where does that pointer get saved? I'm not seeing that code nor how it
>> does CAR migration. Or do you just mean the hob pointer thing --
>> CBMEM_FSP_HOB_PTR ?
>>
>> For the console backing store it always resided outside of _car_start
>> and _car_end. I don't see how it's breaking down...
>>
>> However, I do see this hard coded assumption in car.c:
>>
>>>-------/* It's already pointing outside car.global_data. */
>>>-------if (*mig_var < _car_start || *mig_var > _car_end)
>>>------->-------return mig_var;
>>
>> #if !IS_ENABLED(CONFIG_PLATFORM_USES_FSP1_0)
>>>-------/* Keep console buffer in CAR until cbmemc_reinit() moves it. */
>>>-------if (*mig_var == _car_end)
>>>------->-------return mig_var;
>> #endif
>>
>> That _car_end check in the conditional should be referencing the
>> _preram_cbmem_console symbol proper.
>>
>> Does this fix the issue?
>>
>> diff --git a/src/cpu/x86/car.c b/src/cpu/x86/car.c
>> index 36c5cf0..b9d2c6e 100644
>> --- a/src/cpu/x86/car.c
>> +++ b/src/cpu/x86/car.c
>> @@ -18,6 +18,7 @@
>> #include <console/console.h>
>> #include <cbmem.h>
>> #include <arch/early_variables.h>
>> +#include <symbols.h>
>>
>> #if IS_ENABLED(CONFIG_PLATFORM_USES_FSP1_0)
>> #include <drivers/intel/fsp1_0/fsp_util.h>
>> @@ -89,15 +90,22 @@ void *car_sync_var_ptr(void *var)
>> if (mig_var == var)
>> return mig_var;
>>
>> + /*
>> + * Migrate the cbmem console pointer for FSP 1.0 platforms. Otherwise,
>> + * keep console buffer in CAR until cbmemc_reinit() moves it.
>> + */
>> + if (*mig_var == _preram_cbmem_console) {
>> + if (IS_ENABLED(CONFIG_PLATFORM_USES_FSP1_0)) {
>> + *mig_var += (char *)mig_var - (char *)var;
>> + return mig_var;
>> + } else
>> + return mig_var;
>> + }
>> +
>> /* It's already pointing outside car.global_data. */
>> if (*mig_var < _car_start || *mig_var > _car_end)
>> return mig_var;
>>
>> -#if !IS_ENABLED(CONFIG_PLATFORM_USES_FSP1_0)
>> - /* Keep console buffer in CAR until cbmemc_reinit() moves it. */
>> - if (*mig_var == _car_end)
>> - return mig_var;
>> -#endif
>>
>> /* Move the pointer by the same amount the variable storing it was
>> * moved by.
>>
>>
>>>
>>> Martin
>>>
>>> On Thu, Nov 19, 2015 at 17:07 Ben Gardner <gardner.ben at gmail.com> wrote:
>>>>
>>>> Hi,
>>>>
>>>> I've narrowed down where the CBMEM console is getting corrupted and
>>>> found a work around that gets it working again.
>>>> It is getting corrupted in the FSP Early Init function. So in the
>>>> Intel blob, not coreboot.
>>>>
>>>> I added logs to cbmemc_init() and cbmrmc_reinit() that show the
>>>> console pointer, size, cursor and the first 64 bytes of the console
>>>> (including size and console).
>>>>
>>>> Right before the call to FspInitApi() in fsp_early_init():
>>>> fsp_early_init: cbm_cons_p: fef00000 size=3064 cur=2606
>>>> fef00000: f8 0b 00 00 7b 0a 00 00 63 62 6d 65 6d 63 5f 69
>>>> ........cbmemc_i
>>>> fef00010: 6e 69 74 3a 20 63 62 6d 5f 63 6f 6e 73 5f 70 3a nit:
>>>> cbm_cons_p:
>>>> fef00020: 20 66 65 66 30 30 30 30 30 20 73 69 7a 65 3d 33 fef00000
>>>> size=3
>>>> fef00030: 30 36 34 20 63 75 72 3d 30 0a 66 65 66 30 30 30 064
>>>> cur=0.fef000
>>>>
>>>> And this is at the top of romstage_main_continue():
>>>> romstage_main_continue: cbm_cons_p: 00000b96 size=2052398204
>>>> cur=1024945500
>>>> 00000b96: 7c 1c 55 7a bd 6d 17 3d 17 a9 76 69 ee 07 d1 b8
>>>> |.Uz.m.=..vi....
>>>> 00000ba6: fa 6b 75 85 ee 7a dd 8f e9 48 59 93 b4 f8 0a ce
>>>> .ku..z...HY.....
>>>> 00000bb6: 1c dc fe a4 09 d6 ba 1d 88 8f 23 e4 40 cc 88 cd
>>>> ..........#. at ...
>>>> 00000bc6: 90 91 53 e4 71 6d 90 1d bd e9 fa 13 a8 16 fd b5
>>>> ..S.qm..........
>>>>
>>>> So, the FSP is trashing the CAR variables.
>>>>
>>>> I looked at the changes to src/arch/x86/car.ld and see that the
>>>> CONSOLE line was moved before _car_data_start.
>>>> That move appears to have been in commit dd6fa93d by Aaron Durbin.
>>>> http://review.coreboot.org/#/c/11740/3/src/arch/x86/car.ld
>>>>
>>>> When I moved that CONSOLE line back to after _car_data_end, the
>>>> console works again.
>>>> That also fixes the timestamp table infinite loop issue.
>>>>
>>>> So, I have a work-around.
>>>> However, I suspect that the root issue of the FSP trashing CAR
>>>> variables persists.
>>>>
>>>> My initial email about the timestamp issue is here:
>>>> http://www.coreboot.org/pipermail/coreboot/2015-November/080719.html
>>>>
>>>> I'm not sure what to do about this.
>>>> The above change seems reasonable and needed for verstage support, so
>>>> sending my 'fix' upstream probably isn't viable.
>>>>
>>>> Suggestions?
>>>>
>>>> Thanks,
>>>> Ben
More information about the coreboot
mailing list