* [edk2-devel] [PATCH v2 1/1] OvmfPkg/VirtNorFlashDxe: sanity-check variables
@ 2023-12-07 9:44 Gerd Hoffmann
2023-12-07 16:16 ` Ard Biesheuvel
2023-12-11 23:25 ` Laszlo Ersek
0 siblings, 2 replies; 7+ messages in thread
From: Gerd Hoffmann @ 2023-12-07 9:44 UTC (permalink / raw)
To: devel; +Cc: mike.maslenkin, Jiewen Yao, Ard Biesheuvel, oliver, Gerd Hoffmann
Extend the ValidateFvHeader function, additionally to the header checks
walk over the list of variables and sanity check them.
In case we find inconsistencies indicating variable store corruption
return EFI_NOT_FOUND so the variable store will be re-initialized.
Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
---
OvmfPkg/VirtNorFlashDxe/VirtNorFlashFvb.c | 82 +++++++++++++++++++++--
1 file changed, 77 insertions(+), 5 deletions(-)
diff --git a/OvmfPkg/VirtNorFlashDxe/VirtNorFlashFvb.c b/OvmfPkg/VirtNorFlashDxe/VirtNorFlashFvb.c
index 5ee98e9b595a..1bfb14495abd 100644
--- a/OvmfPkg/VirtNorFlashDxe/VirtNorFlashFvb.c
+++ b/OvmfPkg/VirtNorFlashDxe/VirtNorFlashFvb.c
@@ -185,11 +185,16 @@ ValidateFvHeader (
IN NOR_FLASH_INSTANCE *Instance
)
{
- UINT16 Checksum;
- EFI_FIRMWARE_VOLUME_HEADER *FwVolHeader;
- VARIABLE_STORE_HEADER *VariableStoreHeader;
- UINTN VariableStoreLength;
- UINTN FvLength;
+ UINT16 Checksum;
+ EFI_FIRMWARE_VOLUME_HEADER *FwVolHeader;
+ VARIABLE_STORE_HEADER *VariableStoreHeader;
+ UINTN VarOffset;
+ AUTHENTICATED_VARIABLE_HEADER *VarHeader;
+ UINTN VarSize;
+ CHAR16 *VarName;
+ CHAR8 *VarState;
+ UINTN VariableStoreLength;
+ UINTN FvLength;
FwVolHeader = (EFI_FIRMWARE_VOLUME_HEADER *)Instance->RegionBaseAddress;
@@ -260,6 +265,73 @@ ValidateFvHeader (
return EFI_NOT_FOUND;
}
+ // check variables
+ DEBUG ((DEBUG_INFO, "%a: checking variables\n", __func__));
+ VarOffset = sizeof (*VariableStoreHeader);
+ while (VarOffset + sizeof (*VarHeader) < VariableStoreHeader->Size) {
+ VarHeader = (VOID *)((UINTN)VariableStoreHeader + VarOffset);
+ if (VarHeader->StartId != 0x55aa) {
+ DEBUG ((DEBUG_INFO, "%a: end of var list\n", __func__));
+ break;
+ }
+
+ VarSize = sizeof (*VarHeader) + VarHeader->NameSize + VarHeader->DataSize;
+ if (VarOffset + VarSize > VariableStoreHeader->Size) {
+ DEBUG ((
+ DEBUG_ERROR,
+ "%a: invalid variable size: 0x%x + 0x%x + 0x%x + 0x%x > 0x%x\n",
+ __func__,
+ VarOffset,
+ sizeof (*VarHeader),
+ VarHeader->NameSize,
+ VarHeader->DataSize,
+ VariableStoreHeader->Size
+ ));
+ return EFI_NOT_FOUND;
+ }
+
+ VarName = (VOID *)((UINTN)VariableStoreHeader + VarOffset
+ + sizeof (*VarHeader));
+ switch (VarHeader->State) {
+ case VAR_HEADER_VALID_ONLY:
+ VarState = "header-ok";
+ VarName = L"<unknown>";
+ break;
+ case VAR_ADDED:
+ VarState = "ok";
+ break;
+ case VAR_ADDED &VAR_IN_DELETED_TRANSITION:
+ VarState = "del-in-transition";
+ break;
+ case VAR_ADDED &VAR_DELETED:
+ case VAR_ADDED &VAR_DELETED &VAR_IN_DELETED_TRANSITION:
+ VarState = "deleted";
+ break;
+ default:
+ DEBUG ((
+ DEBUG_ERROR,
+ "%a: invalid variable state: 0x%x\n",
+ __func__,
+ VarHeader->State
+ ));
+ return EFI_NOT_FOUND;
+ }
+
+ DEBUG ((
+ DEBUG_VERBOSE,
+ "%a: +0x%04x: name=0x%x data=0x%x '%s' (%a)\n",
+ __func__,
+ VarOffset,
+ VarHeader->NameSize,
+ VarHeader->DataSize,
+ VarName,
+ VarState
+ ));
+
+ VarSize = (VarSize + 3) & ~3; // align
+ VarOffset += VarSize;
+ }
+
return EFI_SUCCESS;
}
--
2.43.0
-=-=-=-=-=-=-=-=-=-=-=-
Groups.io Links: You receive all messages sent to this group.
View/Reply Online (#112177): https://edk2.groups.io/g/devel/message/112177
Mute This Topic: https://groups.io/mt/103031342/7686176
Group Owner: devel+owner@edk2.groups.io
Unsubscribe: https://edk2.groups.io/g/devel/unsub [rebecca@openfw.io]
-=-=-=-=-=-=-=-=-=-=-=-
^ permalink raw reply related [flat|nested] 7+ messages in thread
* Re: [edk2-devel] [PATCH v2 1/1] OvmfPkg/VirtNorFlashDxe: sanity-check variables
2023-12-07 9:44 [edk2-devel] [PATCH v2 1/1] OvmfPkg/VirtNorFlashDxe: sanity-check variables Gerd Hoffmann
@ 2023-12-07 16:16 ` Ard Biesheuvel
2023-12-08 12:04 ` Gerd Hoffmann
2023-12-11 23:25 ` Laszlo Ersek
1 sibling, 1 reply; 7+ messages in thread
From: Ard Biesheuvel @ 2023-12-07 16:16 UTC (permalink / raw)
To: Gerd Hoffmann; +Cc: devel, mike.maslenkin, Jiewen Yao, Ard Biesheuvel, oliver
Hi Gerd,
On Thu, 7 Dec 2023 at 10:44, Gerd Hoffmann <kraxel@redhat.com> wrote:
>
> Extend the ValidateFvHeader function, additionally to the header checks
> walk over the list of variables and sanity check them.
>
> In case we find inconsistencies indicating variable store corruption
> return EFI_NOT_FOUND so the variable store will be re-initialized.
>
> Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
This seems like a good idea to me, and the change looks generally
fine, except for one nit below:
> ---
> OvmfPkg/VirtNorFlashDxe/VirtNorFlashFvb.c | 82 +++++++++++++++++++++--
> 1 file changed, 77 insertions(+), 5 deletions(-)
>
> diff --git a/OvmfPkg/VirtNorFlashDxe/VirtNorFlashFvb.c b/OvmfPkg/VirtNorFlashDxe/VirtNorFlashFvb.c
> index 5ee98e9b595a..1bfb14495abd 100644
> --- a/OvmfPkg/VirtNorFlashDxe/VirtNorFlashFvb.c
> +++ b/OvmfPkg/VirtNorFlashDxe/VirtNorFlashFvb.c
> @@ -185,11 +185,16 @@ ValidateFvHeader (
> IN NOR_FLASH_INSTANCE *Instance
> )
> {
> - UINT16 Checksum;
> - EFI_FIRMWARE_VOLUME_HEADER *FwVolHeader;
> - VARIABLE_STORE_HEADER *VariableStoreHeader;
> - UINTN VariableStoreLength;
> - UINTN FvLength;
> + UINT16 Checksum;
> + EFI_FIRMWARE_VOLUME_HEADER *FwVolHeader;
> + VARIABLE_STORE_HEADER *VariableStoreHeader;
> + UINTN VarOffset;
> + AUTHENTICATED_VARIABLE_HEADER *VarHeader;
> + UINTN VarSize;
> + CHAR16 *VarName;
> + CHAR8 *VarState;
> + UINTN VariableStoreLength;
> + UINTN FvLength;
>
> FwVolHeader = (EFI_FIRMWARE_VOLUME_HEADER *)Instance->RegionBaseAddress;
>
> @@ -260,6 +265,73 @@ ValidateFvHeader (
> return EFI_NOT_FOUND;
> }
>
> + // check variables
> + DEBUG ((DEBUG_INFO, "%a: checking variables\n", __func__));
> + VarOffset = sizeof (*VariableStoreHeader);
> + while (VarOffset + sizeof (*VarHeader) < VariableStoreHeader->Size) {
> + VarHeader = (VOID *)((UINTN)VariableStoreHeader + VarOffset);
> + if (VarHeader->StartId != 0x55aa) {
> + DEBUG ((DEBUG_INFO, "%a: end of var list\n", __func__));
> + break;
> + }
> +
> + VarSize = sizeof (*VarHeader) + VarHeader->NameSize + VarHeader->DataSize;
> + if (VarOffset + VarSize > VariableStoreHeader->Size) {
> + DEBUG ((
> + DEBUG_ERROR,
> + "%a: invalid variable size: 0x%x + 0x%x + 0x%x + 0x%x > 0x%x\n",
> + __func__,
> + VarOffset,
> + sizeof (*VarHeader),
> + VarHeader->NameSize,
> + VarHeader->DataSize,
> + VariableStoreHeader->Size
> + ));
> + return EFI_NOT_FOUND;
> + }
> +
> + VarName = (VOID *)((UINTN)VariableStoreHeader + VarOffset
> + + sizeof (*VarHeader));
> + switch (VarHeader->State) {
> + case VAR_HEADER_VALID_ONLY:
> + VarState = "header-ok";
> + VarName = L"<unknown>";
> + break;
> + case VAR_ADDED:
> + VarState = "ok";
> + break;
> + case VAR_ADDED &VAR_IN_DELETED_TRANSITION:
This looks odd, so please add a comment explaining why these constants
are constructed this way.
> + VarState = "del-in-transition";
> + break;
> + case VAR_ADDED &VAR_DELETED:
> + case VAR_ADDED &VAR_DELETED &VAR_IN_DELETED_TRANSITION:
> + VarState = "deleted";
> + break;
> + default:
> + DEBUG ((
> + DEBUG_ERROR,
> + "%a: invalid variable state: 0x%x\n",
> + __func__,
> + VarHeader->State
> + ));
> + return EFI_NOT_FOUND;
> + }
> +
> + DEBUG ((
> + DEBUG_VERBOSE,
> + "%a: +0x%04x: name=0x%x data=0x%x '%s' (%a)\n",
> + __func__,
> + VarOffset,
> + VarHeader->NameSize,
> + VarHeader->DataSize,
> + VarName,
> + VarState
> + ));
> +
> + VarSize = (VarSize + 3) & ~3; // align
> + VarOffset += VarSize;
> + }
> +
> return EFI_SUCCESS;
> }
>
> --
> 2.43.0
>
-=-=-=-=-=-=-=-=-=-=-=-
Groups.io Links: You receive all messages sent to this group.
View/Reply Online (#112202): https://edk2.groups.io/g/devel/message/112202
Mute This Topic: https://groups.io/mt/103031342/7686176
Group Owner: devel+owner@edk2.groups.io
Unsubscribe: https://edk2.groups.io/g/devel/unsub [rebecca@openfw.io]
-=-=-=-=-=-=-=-=-=-=-=-
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [edk2-devel] [PATCH v2 1/1] OvmfPkg/VirtNorFlashDxe: sanity-check variables
2023-12-07 16:16 ` Ard Biesheuvel
@ 2023-12-08 12:04 ` Gerd Hoffmann
2023-12-11 23:37 ` Laszlo Ersek
0 siblings, 1 reply; 7+ messages in thread
From: Gerd Hoffmann @ 2023-12-08 12:04 UTC (permalink / raw)
To: Ard Biesheuvel; +Cc: devel, mike.maslenkin, Jiewen Yao, Ard Biesheuvel, oliver
On Thu, Dec 07, 2023 at 05:16:10PM +0100, Ard Biesheuvel wrote:
> Hi Gerd,
>
> On Thu, 7 Dec 2023 at 10:44, Gerd Hoffmann <kraxel@redhat.com> wrote:
> >
> > Extend the ValidateFvHeader function, additionally to the header checks
> > walk over the list of variables and sanity check them.
> >
> > In case we find inconsistencies indicating variable store corruption
> > return EFI_NOT_FOUND so the variable store will be re-initialized.
> >
> > Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
>
> This seems like a good idea to me, and the change looks generally
> fine, except for one nit below:
> > + case VAR_HEADER_VALID_ONLY:
> > + VarState = "header-ok";
> > + VarName = L"<unknown>";
> > + break;
> > + case VAR_ADDED:
> > + VarState = "ok";
> > + break;
> > + case VAR_ADDED &VAR_IN_DELETED_TRANSITION:
>
> This looks odd, so please add a comment explaining why these constants
> are constructed this way.
The VAR_HEADER_VALID_ONLY and VAR_ADDED states are applied using an
assignment, i.e. "State = VAR_...".
The other two are used to clear bits, i.e. "State &= VAR_...".
So the usual livecycle for the State field is:
(1) 0x7f (VAR_HEADER_VALID_ONLY)
(2) 0x3f (VAR_ADDED)
(3) 0x3e (VAR_ADDED & VAR_IN_DELETED_TRANSITION)
(4) 0x3c (VAR_ADDED & VAR_IN_DELETED_TRANSITION & VAR_DELETED)
Seems it can also happen that variable entries jump directly from (2) to
(4), resulting in 0x3d (VAR_ADDED & VAR_DELETED) being an possible
alternative value for (4).
I'm not fully sure what happens to VAR_HEADER_VALID_ONLY entries, i.e.
whenever they go through the (3) + (4) deletion cycles too or whenever
they are garbage-collected in some other way. I suspect the latter,
given that the reclaim logic in the variable driver looks at the
variable names, but VAR_HEADER_VALID_ONLY entries don't have a valid
variable name.
BTW: Is there any good documentation on the design of the variable
driver and the fault tolerant flash writes? Is the variable flash
supposed to be in a consistent state at any given time, even if
interrupted in the middle of some update operation?
The qemu flash emulation is a bit sloppy, specifically block writes can
be half-completed when a reset happens in the middle of the operation.
Which maybe is the root cause for varstore corruption.
On the other hand the edk2 flash code does not look like it carefully
chooses blocks when updating flash, so I'm not sure it actually depends
on atomic block updates to ensure consistency.
take care,
Gerd
-=-=-=-=-=-=-=-=-=-=-=-
Groups.io Links: You receive all messages sent to this group.
View/Reply Online (#112226): https://edk2.groups.io/g/devel/message/112226
Mute This Topic: https://groups.io/mt/103031342/7686176
Group Owner: devel+owner@edk2.groups.io
Unsubscribe: https://edk2.groups.io/g/devel/unsub [rebecca@openfw.io]
-=-=-=-=-=-=-=-=-=-=-=-
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [edk2-devel] [PATCH v2 1/1] OvmfPkg/VirtNorFlashDxe: sanity-check variables
2023-12-07 9:44 [edk2-devel] [PATCH v2 1/1] OvmfPkg/VirtNorFlashDxe: sanity-check variables Gerd Hoffmann
2023-12-07 16:16 ` Ard Biesheuvel
@ 2023-12-11 23:25 ` Laszlo Ersek
2023-12-14 15:31 ` Gerd Hoffmann
1 sibling, 1 reply; 7+ messages in thread
From: Laszlo Ersek @ 2023-12-11 23:25 UTC (permalink / raw)
To: devel, kraxel; +Cc: mike.maslenkin, Jiewen Yao, Ard Biesheuvel, oliver
On 12/7/23 10:44, Gerd Hoffmann wrote:
> Extend the ValidateFvHeader function, additionally to the header checks
> walk over the list of variables and sanity check them.
>
> In case we find inconsistencies indicating variable store corruption
> return EFI_NOT_FOUND so the variable store will be re-initialized.
>
> Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
> ---
> OvmfPkg/VirtNorFlashDxe/VirtNorFlashFvb.c | 82 +++++++++++++++++++++--
> 1 file changed, 77 insertions(+), 5 deletions(-)
>
> diff --git a/OvmfPkg/VirtNorFlashDxe/VirtNorFlashFvb.c b/OvmfPkg/VirtNorFlashDxe/VirtNorFlashFvb.c
> index 5ee98e9b595a..1bfb14495abd 100644
> --- a/OvmfPkg/VirtNorFlashDxe/VirtNorFlashFvb.c
> +++ b/OvmfPkg/VirtNorFlashDxe/VirtNorFlashFvb.c
> @@ -185,11 +185,16 @@ ValidateFvHeader (
> IN NOR_FLASH_INSTANCE *Instance
> )
> {
> - UINT16 Checksum;
> - EFI_FIRMWARE_VOLUME_HEADER *FwVolHeader;
> - VARIABLE_STORE_HEADER *VariableStoreHeader;
> - UINTN VariableStoreLength;
> - UINTN FvLength;
> + UINT16 Checksum;
> + EFI_FIRMWARE_VOLUME_HEADER *FwVolHeader;
> + VARIABLE_STORE_HEADER *VariableStoreHeader;
> + UINTN VarOffset;
> + AUTHENTICATED_VARIABLE_HEADER *VarHeader;
> + UINTN VarSize;
> + CHAR16 *VarName;
> + CHAR8 *VarState;
> + UINTN VariableStoreLength;
> + UINTN FvLength;
>
> FwVolHeader = (EFI_FIRMWARE_VOLUME_HEADER *)Instance->RegionBaseAddress;
>
> @@ -260,6 +265,73 @@ ValidateFvHeader (
> return EFI_NOT_FOUND;
> }
>
> + // check variables
(1) Comment style -- should be preceded and succeeded by otherwise empty // lines
> + DEBUG ((DEBUG_INFO, "%a: checking variables\n", __func__));
> + VarOffset = sizeof (*VariableStoreHeader);
> + while (VarOffset + sizeof (*VarHeader) < VariableStoreHeader->Size) {
(2) The addition is not checked for overflow. When it is evaluated for the first time, it cannot overflow, but I can't easily find a proof that it cannot overflow in further iterations on 32-bit platforms.
(The strict "<" relop in itself seems justified; we always expect *some* data after the variable header.)
I suggest rewriting as follows:
for (;;) {
RETURN_STATUS Status;
UINTN VarHeaderEnd;
Status = SafeUintnAdd (VarOffset, sizeof (*VarHeader), &VarHeaderEnd);
if (RETURN_ERROR (Status)) {
return EFI_NOT_FOUND;
}
if (VarHeaderEnd >= VariableStoreHeader->Size) {
break;
}
Perhaps even the second check should return EFI_NOT_FOUND, assuming we require (StartId != 0x55aa) as the only successful termination condition.
> + VarHeader = (VOID *)((UINTN)VariableStoreHeader + VarOffset);
> + if (VarHeader->StartId != 0x55aa) {
> + DEBUG ((DEBUG_INFO, "%a: end of var list\n", __func__));
> + break;
> + }
> +
> + VarSize = sizeof (*VarHeader) + VarHeader->NameSize + VarHeader->DataSize;
(3) Given that we expect that the varstore may be corrupt, this addition can definitely overflow on 32-bit platforms (where the additions are performed in UINT32). I suggest using SafeUintnAdd() from SafeIntLib again.
> + if (VarOffset + VarSize > VariableStoreHeader->Size) {
(4) This addition should be checked for overflow too.
Alternatively -- given that, from previous checks, here we know for sure that VarOffset is strictly smaller than VariableStoreHeader->Size --, the expression can be rearranged as follows (by subtracting VarOffset from both sides):
if (VarSize > VariableStoreHeader->Size - VarOffset) {
Mathematically this means the same thing, but the subtraction on the right hand side cannot underflow.
> + DEBUG ((
> + DEBUG_ERROR,
> + "%a: invalid variable size: 0x%x + 0x%x + 0x%x + 0x%x > 0x%x\n",
> + __func__,
> + VarOffset,
(5) VarOffset is of type UINTN, which may be UINT32 or UINT64. %x is not a proper format specifier for printing UINT64.
PrintLib offers no format specifier for UINTN, only for UINT32 (%x, %u) and UINT64 (%lx / %Lx, %lu / %Lu).
Therefore, the best way to format a UINTN value is:
- convert it to UINT64 explicitly,
- print it with one of the format specifiers matching UINT64.
For example,
DEBUG ((DEBUG_ERROR, "%Lx\n", (UINT64)VarOffset));
> + sizeof (*VarHeader),
(6) same issue, sizeof evals to a UINTN.
> + VarHeader->NameSize,
> + VarHeader->DataSize,
> + VariableStoreHeader->Size
these are good (all three are UINT32)
> + ));
> + return EFI_NOT_FOUND;
> + }
> +
> + VarName = (VOID *)((UINTN)VariableStoreHeader + VarOffset
> + + sizeof (*VarHeader));
(7) This seems premature. We should first check that NameSize is (a) nonzero and (b) divisible by 2.
> + switch (VarHeader->State) {
> + case VAR_HEADER_VALID_ONLY:
> + VarState = "header-ok";
(8) Then better make VarState point to a CONST CHAR8, not just a CHAR8.
> + VarName = L"<unknown>";
(9) Ditto.
(10) If VarName is invalid here when State is VAR_HEADER_VALID_ONLY, then we should calculate VarName only when the State says it's going to be valid. Creating and invalid pointer value first and then overwriting it with something else is "cart before horse".
> + break;
> + case VAR_ADDED:
> + VarState = "ok";
> + break;
> + case VAR_ADDED &VAR_IN_DELETED_TRANSITION:
> + VarState = "del-in-transition";
> + break;
> + case VAR_ADDED &VAR_DELETED:
> + case VAR_ADDED &VAR_DELETED &VAR_IN_DELETED_TRANSITION:
> + VarState = "deleted";
> + break;
> + default:
> + DEBUG ((
> + DEBUG_ERROR,
> + "%a: invalid variable state: 0x%x\n",
> + __func__,
> + VarHeader->State
> + ));
This is fine. The State field is UINT8, so it's getting promoted to "int" (INT32). "%x" is fine for printing UINT32 ("unsigned int"), and it's fine to reinterpret nonnegative "int"s as "unsigned int"s, per C std.
> + return EFI_NOT_FOUND;
> + }
> +
> + DEBUG ((
> + DEBUG_VERBOSE,
> + "%a: +0x%04x: name=0x%x data=0x%x '%s' (%a)\n",
> + __func__,
> + VarOffset,
(10) same comment as (5)
> + VarHeader->NameSize,
> + VarHeader->DataSize,
> + VarName,
(11) regarding VarName, we have not checked whether it was NUL-terminated; %s relies on that.
Alternatively, you can provide the precision as a separate UINTN argument:
DEBUG ((DEBUG_VERBOSE, "%.*s\n", (UINTN)(VarHeader->NameSize / 2), VarName));
> + VarState
> + ));
> +
> + VarSize = (VarSize + 3) & ~3; // align
Two problems:
(12) Unchecked addition.
(13) The bitwise negation operator applied to a signed integer is exceeding ugly:
(a) It inverts the sign bit, which *happens* to produce a negative value.
(b) That negative value is then converted to UINTN (for the bitwise AND), by adding -- mathematically speaking -- (MAX_UINTN+1) to it. This only produces the expected result because the original negative value uses two's complement representation in the first place.
It's (almost) better to use the ALIGN_VALUE() macro from "MdePkg/Include/Base.h"; but that too would not check for overflow. Suggestion:
UINTN LowBits;
LowBits = VarSize & (BIT0 | BIT1);
if (LowBits > 0) {
Status = SafeUintnAdd (VarSize, BIT2 - LowBits, &VarSize);
if (RETURN_ERROR (Status)) {
return EFI_NOT_FOUND;
}
}
(14) However, even *this* should be performed at the top, where we check (VarOffset + VarSize > VariableStoreHeader->Size). More precisely, that check should consider the aligned-up variable size. That's because:
> + VarOffset += VarSize;
this addition here uses the aligned-up VarSize as increment, which may be larger than the previously checked VarSize value -- and so it can land us outside of VariableStoreHeader->Size at once.
> + }
> +
> return EFI_SUCCESS;
> }
>
The general idea is, once we don't trust the varstore, there cannot be a *single* unchecked addition in the code. (Unless we can *prove* that overflow is impossible.)
Laszlo
-=-=-=-=-=-=-=-=-=-=-=-
Groups.io Links: You receive all messages sent to this group.
View/Reply Online (#112340): https://edk2.groups.io/g/devel/message/112340
Mute This Topic: https://groups.io/mt/103031342/7686176
Group Owner: devel+owner@edk2.groups.io
Unsubscribe: https://edk2.groups.io/g/devel/leave/12367111/7686176/1913456212/xyzzy [rebecca@openfw.io]
-=-=-=-=-=-=-=-=-=-=-=-
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [edk2-devel] [PATCH v2 1/1] OvmfPkg/VirtNorFlashDxe: sanity-check variables
2023-12-08 12:04 ` Gerd Hoffmann
@ 2023-12-11 23:37 ` Laszlo Ersek
0 siblings, 0 replies; 7+ messages in thread
From: Laszlo Ersek @ 2023-12-11 23:37 UTC (permalink / raw)
To: devel, kraxel, Ard Biesheuvel
Cc: mike.maslenkin, Jiewen Yao, Ard Biesheuvel, oliver
[-- Attachment #1: Type: text/plain, Size: 3880 bytes --]
On 12/8/23 13:04, Gerd Hoffmann wrote:
> On Thu, Dec 07, 2023 at 05:16:10PM +0100, Ard Biesheuvel wrote:
>> Hi Gerd,
>>
>> On Thu, 7 Dec 2023 at 10:44, Gerd Hoffmann <kraxel@redhat.com> wrote:
>>>
>>> Extend the ValidateFvHeader function, additionally to the header checks
>>> walk over the list of variables and sanity check them.
>>>
>>> In case we find inconsistencies indicating variable store corruption
>>> return EFI_NOT_FOUND so the variable store will be re-initialized.
>>>
>>> Signed-off-by: Gerd Hoffmann <kraxel@redhat.com>
>>
>> This seems like a good idea to me, and the change looks generally
>> fine, except for one nit below:
>
>>> + case VAR_HEADER_VALID_ONLY:
>>> + VarState = "header-ok";
>>> + VarName = L"<unknown>";
>>> + break;
>>> + case VAR_ADDED:
>>> + VarState = "ok";
>>> + break;
>>> + case VAR_ADDED &VAR_IN_DELETED_TRANSITION:
>>
>> This looks odd, so please add a comment explaining why these constants
>> are constructed this way.
>
> The VAR_HEADER_VALID_ONLY and VAR_ADDED states are applied using an
> assignment, i.e. "State = VAR_...".
>
> The other two are used to clear bits, i.e. "State &= VAR_...".
>
> So the usual livecycle for the State field is:
>
> (1) 0x7f (VAR_HEADER_VALID_ONLY)
> (2) 0x3f (VAR_ADDED)
> (3) 0x3e (VAR_ADDED & VAR_IN_DELETED_TRANSITION)
> (4) 0x3c (VAR_ADDED & VAR_IN_DELETED_TRANSITION & VAR_DELETED)
>
> Seems it can also happen that variable entries jump directly from (2) to
> (4), resulting in 0x3d (VAR_ADDED & VAR_DELETED) being an possible
> alternative value for (4).
>
> I'm not fully sure what happens to VAR_HEADER_VALID_ONLY entries, i.e.
> whenever they go through the (3) + (4) deletion cycles too or whenever
> they are garbage-collected in some other way. I suspect the latter,
> given that the reclaim logic in the variable driver looks at the
> variable names, but VAR_HEADER_VALID_ONLY entries don't have a valid
> variable name.
>
>
> BTW: Is there any good documentation on the design of the variable
> driver and the fault tolerant flash writes? Is the variable flash
> supposed to be in a consistent state at any given time, even if
> interrupted in the middle of some update operation?
I have two references:
(1) A Tour Beyond BIOS:
Implementing UEFI Authenticated Variables in SMM with EDKII
Part III - Variable
https://github.com/tianocore/tianocore.github.io/wiki/EDK-II-white-papers
https://github.com/tianocore-docs/Docs/raw/master/White_Papers/A_Tour_Beyond_BIOS_Implementing_UEFI_Authenticated_Variables_in_SMM_with_EDKII_V2.pdf
It discusses Fault Tolerant Write too. And yes, in theory, FTW is supposed to protect against power loss at any particular stage.
(2) Some messages from 2013-2014, when the list was still on sourceforge.net. I think the public archives from that time are all lost, but I'm attaching the one relevant message I could find locally.
>
> The qemu flash emulation is a bit sloppy, specifically block writes can
> be half-completed when a reset happens in the middle of the operation.
> Which maybe is the root cause for varstore corruption.
>
> On the other hand the edk2 flash code does not look like it carefully
> chooses blocks when updating flash, so I'm not sure it actually depends
> on atomic block updates to ensure consistency.
Can't comment on these, alas.
Laszlo
-=-=-=-=-=-=-=-=-=-=-=-
Groups.io Links: You receive all messages sent to this group.
View/Reply Online (#112341): https://edk2.groups.io/g/devel/message/112341
Mute This Topic: https://groups.io/mt/103031342/7686176
Group Owner: devel+owner@edk2.groups.io
Unsubscribe: https://edk2.groups.io/g/devel/leave/12367111/7686176/1913456212/xyzzy [rebecca@openfw.io]
-=-=-=-=-=-=-=-=-=-=-=-
[-- Attachment #2: [edk2] Firmware Volume Block and Fault Tolerant Write question..eml --]
[-- Type: message/rfc822, Size: 151656 bytes --]
[-- Attachment #2.1.1: Type: text/plain, Size: 2104 bytes --]
On 04/18/14 21:32, Kirkendall, Garrett wrote:
> Is there any good documentation for how the Fault Tolerant Write is
> supposed to work?
>
> I understand that NV storage, FTW working space and FTW spare space are
> supposed to be in the same Firmware Volume.
>
> I’m having trouble deciphering how big the FTW working and spare areas
> should be in relation to the NV storage space.
>
> Also, in a bunch of places, it looks like the code was written such that
> the working space must fit within one block size. What happens if need
> space spanning multiple blocks? Below are parts from two functions that
> end in an ASSERT because only one block gets read and returns an error
> when the requested FVB->Read input size is larger than one block of data.
If it's any help, here's a diagram I derived last December, while I was
hunting down <https://github.com/tianocore/edk2/commit/06f1982a>:
On 12/17/13 07:16, Laszlo Ersek wrote:
> During reclaim, the following data movements take place (I'm skipping
> the erasures and the in-memory buffer manipulations):
>
> +-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+ L: event log
> LIVE | varstore |L|W| W: working block
> +-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+
>
> +-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+
> SPARE | |
> +-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+
>
> (1) copy LIVE to MyBuffer
> (2) copy SPARE to SpareBuffer
> (3) copy MyBuffer to SPARE
> (4) copy SPARE to Buffer
> (5) copy Buffer to LIVE
> (6) copy SpareBuffer to SPARE
(MyBuffer, SpareBuffer, and Buffer are temporary memory buffers.)
In OVMF, the block size is 4K. The varstore is 14 blocks (56K), plus we
got one block (4K) for the event log and one block (4K) for the working
block. In total, 64K in the live half. The spare half is the same size,
giving 128K total for the firmware volume.
I'm also attaching the debug patch I wrote at that time for the FTW and
auth variable services, plus its output (which I annotated during
analysis) that helped me understand what was happening. Maybe you can
reuse something from them.
Laszlo
[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2.1.2: debug.diff --]
[-- Type: text/x-patch; name="debug.diff", Size: 66793 bytes --]
diff --git a/MdeModulePkg/Universal/FaultTolerantWriteDxe/FaultTolerantWrite.c b/MdeModulePkg/Universal/FaultTolerantWriteDxe/FaultTolerantWrite.c
index 714b5d8..2918d58 100644
--- a/MdeModulePkg/Universal/FaultTolerantWriteDxe/FaultTolerantWrite.c
+++ b/MdeModulePkg/Universal/FaultTolerantWriteDxe/FaultTolerantWrite.c
@@ -39,7 +39,10 @@ FtwGetMaxBlockSize (
{
EFI_FTW_DEVICE *FtwDevice;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
if (!FeaturePcdGet(PcdFullFtwServiceEnable)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1\n", __FUNCTION__));
return EFI_UNSUPPORTED;
}
@@ -47,6 +50,8 @@ FtwGetMaxBlockSize (
*BlockSize = FtwDevice->SpareAreaLength;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2, BlockSize=0x%Lx\n", __FUNCTION__,
+ (UINT64) *BlockSize));
return EFI_SUCCESS;
}
@@ -86,10 +91,15 @@ FtwAllocate (
EFI_FTW_DEVICE *FtwDevice;
EFI_FAULT_TOLERANT_WRITE_HEADER *FtwHeader;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, CallerId=%g, PrivateDataSize=0x%Lx, "
+ "NumberOfWrites=0x%Lx\n", __FUNCTION__, CallerId, (UINT64)PrivateDataSize,
+ (UINT64)NumberOfWrites));
+
FtwDevice = FTW_CONTEXT_FROM_THIS (This);
Status = WorkSpaceRefresh (FtwDevice);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
//
@@ -97,6 +107,7 @@ FtwAllocate (
//
if (FTW_WRITE_TOTAL_SIZE (NumberOfWrites, PrivateDataSize) > FtwDevice->FtwWorkSpaceHeader->WriteQueueSize) {
DEBUG ((EFI_D_ERROR, "Ftw: Allocate() request exceed Workspace, Caller: %g\n", CallerId));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2\n", __FUNCTION__));
return EFI_BUFFER_TOO_SMALL;
}
//
@@ -109,6 +120,7 @@ FtwAllocate (
// Previous write has not completed, access denied.
//
if ((FtwHeader->HeaderAllocated == FTW_VALID_STATE) || (FtwHeader->WritesAllocated == FTW_VALID_STATE)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 3\n", __FUNCTION__));
return EFI_ACCESS_DENIED;
}
//
@@ -118,6 +130,7 @@ FtwAllocate (
if (Offset + FTW_WRITE_TOTAL_SIZE (NumberOfWrites, PrivateDataSize) > FtwDevice->FtwWorkSpaceSize) {
Status = FtwReclaimWorkSpace (FtwDevice, TRUE);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 4: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -143,6 +156,7 @@ FtwAllocate (
(UINT8 *) FtwHeader
);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 5: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
//
@@ -155,6 +169,7 @@ FtwAllocate (
WRITES_ALLOCATED
);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 6: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -165,6 +180,7 @@ FtwAllocate (
NumberOfWrites)
);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 7\n", __FUNCTION__));
return EFI_SUCCESS;
}
@@ -195,6 +211,8 @@ FtwWriteRecord (
UINTN Offset;
EFI_LBA WorkSpaceLbaOffset;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
FtwDevice = FTW_CONTEXT_FROM_THIS (This);
WorkSpaceLbaOffset = FtwDevice->FtwWorkSpaceLba - FtwDevice->FtwWorkBlockLba;
@@ -223,6 +241,7 @@ FtwWriteRecord (
SPARE_COMPLETED
);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -240,6 +259,7 @@ FtwWriteRecord (
}
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
//
@@ -253,6 +273,7 @@ FtwWriteRecord (
DEST_COMPLETED
);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 3: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -272,10 +293,12 @@ FtwWriteRecord (
);
Header->Complete = FTW_VALID_STATE;
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 4: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
}
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 5\n", __FUNCTION__));
return EFI_SUCCESS;
}
@@ -331,10 +354,15 @@ FtwWrite (
UINT8 *Ptr;
EFI_PHYSICAL_ADDRESS FvbPhysicalAddress;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Lba=0x%Lx Offset=0x%Lx Length=0x%Lx "
+ "PrivateData=%p FvBlockHandle=%p Buffer=%p\n", __FUNCTION__, (UINT64)Lba,
+ (UINT64)Offset, (UINT64)Length, PrivateData, FvBlockHandle, Buffer));
+
FtwDevice = FTW_CONTEXT_FROM_THIS (This);
Status = WorkSpaceRefresh (FtwDevice);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -349,6 +377,7 @@ FtwWrite (
//
Status = FtwAllocate (This, &gEfiCallerIdGuid, 0, 1);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2: %r\n", __FUNCTION__, Status));
return Status;
}
} else {
@@ -358,6 +387,7 @@ FtwWrite (
//
DEBUG ((EFI_D_ERROR, "Ftw: no allocates space for write record!\n"));
DEBUG ((EFI_D_ERROR, "Ftw: Allocate service should be called before Write service!\n"));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 3\n", __FUNCTION__));
return EFI_NOT_READY;
}
}
@@ -366,6 +396,7 @@ FtwWrite (
// If Record is out of the range of Header, return access denied.
//
if (((UINTN)((UINT8 *) Record - (UINT8 *) Header)) > FTW_WRITE_TOTAL_SIZE (Header->NumberOfWrites - 1, Header->PrivateDataSize)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 4\n", __FUNCTION__));
return EFI_ACCESS_DENIED;
}
@@ -373,20 +404,24 @@ FtwWrite (
// Check the COMPLETE flag of last write header
//
if (Header->Complete == FTW_VALID_STATE) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 5\n", __FUNCTION__));
return EFI_ACCESS_DENIED;
}
if (Record->DestinationComplete == FTW_VALID_STATE) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 6\n", __FUNCTION__));
return EFI_ACCESS_DENIED;
}
if ((Record->SpareComplete == FTW_VALID_STATE) && (Record->DestinationComplete != FTW_VALID_STATE)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 7\n", __FUNCTION__));
return EFI_NOT_READY;
}
//
// Check if the input data can fit within the target block
//
if ((Offset + Length) > FtwDevice->SpareAreaLength) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 8\n", __FUNCTION__));
return EFI_BAD_BUFFER_SIZE;
}
//
@@ -394,12 +429,14 @@ FtwWrite (
//
Status = FtwGetFvbByHandle (FvBlockHandle, &Fvb);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 9: %r\n", __FUNCTION__, Status));
return EFI_NOT_FOUND;
}
Status = Fvb->GetPhysicalAddress (Fvb, &FvbPhysicalAddress);
if (EFI_ERROR (Status)) {
DEBUG ((EFI_D_ERROR, "FtwLite: Get FVB physical address - %r\n", Status));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 10: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -431,6 +468,7 @@ FtwWrite (
(UINT8 *) Record
);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 11: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
//
@@ -442,6 +480,7 @@ FtwWrite (
MyBufferSize = FtwDevice->SpareAreaLength;
MyBuffer = AllocatePool (MyBufferSize);
if (MyBuffer == NULL) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 12\n", __FUNCTION__));
return EFI_OUT_OF_RESOURCES;
}
//
@@ -453,6 +492,7 @@ FtwWrite (
Status = Fvb->Read (Fvb, Lba + Index, 0, &MyLength, Ptr);
if (EFI_ERROR (Status)) {
FreePool (MyBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 13: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -472,6 +512,7 @@ FtwWrite (
SpareBuffer = AllocatePool (SpareBufferSize);
if (SpareBuffer == NULL) {
FreePool (MyBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 14\n", __FUNCTION__));
return EFI_OUT_OF_RESOURCES;
}
@@ -488,6 +529,7 @@ FtwWrite (
if (EFI_ERROR (Status)) {
FreePool (MyBuffer);
FreePool (SpareBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 15: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -510,6 +552,7 @@ FtwWrite (
if (EFI_ERROR (Status)) {
FreePool (MyBuffer);
FreePool (SpareBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 16: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -532,6 +575,7 @@ FtwWrite (
);
if (EFI_ERROR (Status)) {
FreePool (SpareBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 17: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -544,6 +588,7 @@ FtwWrite (
Status = FtwWriteRecord (This, Fvb);
if (EFI_ERROR (Status)) {
FreePool (SpareBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 18: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
//
@@ -562,6 +607,7 @@ FtwWrite (
);
if (EFI_ERROR (Status)) {
FreePool (SpareBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 19: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -580,6 +626,7 @@ FtwWrite (
Length)
);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 20\n", __FUNCTION__));
return EFI_SUCCESS;
}
@@ -610,10 +657,14 @@ FtwRestart (
EFI_FAULT_TOLERANT_WRITE_RECORD *Record;
EFI_FIRMWARE_VOLUME_BLOCK_PROTOCOL *Fvb;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, FvBlockHandle=%p\n", __FUNCTION__,
+ FvBlockHandle));
+
FtwDevice = FTW_CONTEXT_FROM_THIS (This);
Status = WorkSpaceRefresh (FtwDevice);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -626,6 +677,7 @@ FtwRestart (
//
Status = FtwGetFvbByHandle (FvBlockHandle, &Fvb);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2: %r\n", __FUNCTION__, Status));
return EFI_NOT_FOUND;
}
@@ -633,6 +685,7 @@ FtwRestart (
// Check the COMPLETE flag of last write header
//
if (Header->Complete == FTW_VALID_STATE) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 3\n", __FUNCTION__));
return EFI_ACCESS_DENIED;
}
@@ -640,10 +693,12 @@ FtwRestart (
// Check the flags of last write record
//
if (Record->DestinationComplete == FTW_VALID_STATE) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 4\n", __FUNCTION__));
return EFI_ACCESS_DENIED;
}
if ((Record->SpareComplete != FTW_VALID_STATE)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 5\n", __FUNCTION__));
return EFI_ABORTED;
}
@@ -653,6 +708,7 @@ FtwRestart (
//
Status = FtwWriteRecord (This, Fvb);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 6: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -663,6 +719,7 @@ FtwRestart (
FtwEraseSpareBlock (FtwDevice);
DEBUG ((EFI_D_ERROR, "Ftw: Restart() success \n"));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 7\n", __FUNCTION__));
return EFI_SUCCESS;
}
@@ -686,18 +743,23 @@ FtwAbort (
UINTN Offset;
EFI_FTW_DEVICE *FtwDevice;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
FtwDevice = FTW_CONTEXT_FROM_THIS (This);
Status = WorkSpaceRefresh (FtwDevice);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
if (FtwDevice->FtwLastWriteHeader->HeaderAllocated != FTW_VALID_STATE) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2\n", __FUNCTION__));
return EFI_NOT_FOUND;
}
if (FtwDevice->FtwLastWriteHeader->Complete == FTW_VALID_STATE) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 3\n", __FUNCTION__));
return EFI_NOT_FOUND;
}
//
@@ -711,12 +773,14 @@ FtwAbort (
WRITES_COMPLETED
);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 4: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
FtwDevice->FtwLastWriteHeader->Complete = FTW_VALID_STATE;
DEBUG ((EFI_D_ERROR, "Ftw: Abort() success \n"));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 5\n", __FUNCTION__));
return EFI_SUCCESS;
}
@@ -761,7 +825,11 @@ FtwGetLastWrite (
EFI_FAULT_TOLERANT_WRITE_HEADER *Header;
EFI_FAULT_TOLERANT_WRITE_RECORD *Record;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, PrivateDataSize=0x%Lx\n", __FUNCTION__,
+ (UINT64)*PrivateDataSize));
+
if (!FeaturePcdGet(PcdFullFtwServiceEnable)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1\n", __FUNCTION__));
return EFI_UNSUPPORTED;
}
@@ -769,6 +837,7 @@ FtwGetLastWrite (
Status = WorkSpaceRefresh (FtwDevice);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -786,6 +855,7 @@ FtwGetLastWrite (
Status = FtwAbort (This);
*Complete = TRUE;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 3\n", __FUNCTION__));
return EFI_NOT_FOUND;
}
//
@@ -793,6 +863,7 @@ FtwGetLastWrite (
//
if (Header->HeaderAllocated != FTW_VALID_STATE) {
*Complete = TRUE;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 4\n", __FUNCTION__));
return EFI_NOT_FOUND;
}
//
@@ -803,6 +874,7 @@ FtwGetLastWrite (
if (EFI_ERROR (Status)) {
FtwAbort (This);
*Complete = TRUE;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 5: %r\n", __FUNCTION__, Status));
return EFI_NOT_FOUND;
}
ASSERT (Record != NULL);
@@ -829,6 +901,11 @@ FtwGetLastWrite (
DEBUG ((EFI_D_ERROR, "Ftw: GetLasetWrite() success\n"));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 6, CallerId=%g Lba=0x%Lx Offset=0x%Lx "
+ "Length=0x%Lx PrivateDataSize=0x%Lx PrivateData=%p Complete=%d\n",
+ __FUNCTION__, CallerId, (UINT64)*Lba, (UINT64)*Offset, (UINT64)*Length,
+ (UINT64)*PrivateDataSize, PrivateData, *Complete));
+
return Status;
}
diff --git a/MdeModulePkg/Universal/FaultTolerantWriteDxe/FaultTolerantWriteDxe.c b/MdeModulePkg/Universal/FaultTolerantWriteDxe/FaultTolerantWriteDxe.c
index 1235bd8..caece56 100644
--- a/MdeModulePkg/Universal/FaultTolerantWriteDxe/FaultTolerantWriteDxe.c
+++ b/MdeModulePkg/Universal/FaultTolerantWriteDxe/FaultTolerantWriteDxe.c
@@ -73,14 +73,19 @@ FtwGetFvbByHandle (
OUT EFI_FIRMWARE_VOLUME_BLOCK_PROTOCOL **FvBlock
)
{
+ EFI_STATUS Status;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
//
// To get the FVB protocol interface on the handle
//
- return gBS->HandleProtocol (
+ Status = gBS->HandleProtocol (
FvBlockHandle,
&gEfiFirmwareVolumeBlockProtocolGuid,
(VOID **) FvBlock
);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit: %r\n", __FUNCTION__, Status));
+ return Status;
}
/**
@@ -100,6 +105,7 @@ FtwGetSarProtocol (
{
EFI_STATUS Status;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
//
// Locate Swap Address Range protocol
//
@@ -108,6 +114,7 @@ FtwGetSarProtocol (
NULL,
SarProtocol
);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit: %r\n", __FUNCTION__, Status));
return Status;
}
@@ -134,6 +141,7 @@ GetFvbCountAndBuffer (
{
EFI_STATUS Status;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
//
// Locate all handles of Fvb protocol
//
@@ -144,6 +152,7 @@ GetFvbCountAndBuffer (
NumberHandles,
Buffer
);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit: %r\n", __FUNCTION__, Status));
return Status;
}
@@ -166,6 +175,9 @@ FvbNotificationEvent (
EFI_FAULT_TOLERANT_WRITE_PROTOCOL *FtwProtocol;
EFI_FTW_DEVICE *FtwDevice;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Event=%p Context=%p\n", __FUNCTION__,
+ Event, Context));
+
//
// Just return to avoid installing FaultTolerantWriteProtocol again
// if Fault Tolerant Write protocol has been installed.
@@ -176,6 +188,7 @@ FvbNotificationEvent (
(VOID **) &FtwProtocol
);
if (!EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1: %r\n", __FUNCTION__, Status));
return ;
}
@@ -185,6 +198,7 @@ FvbNotificationEvent (
FtwDevice = (EFI_FTW_DEVICE *)Context;
Status = InitFtwProtocol (FtwDevice);
if (EFI_ERROR(Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2: %r\n", __FUNCTION__, Status));
return ;
}
@@ -202,6 +216,7 @@ FvbNotificationEvent (
Status = gBS->CloseEvent (Event);
ASSERT_EFI_ERROR (Status);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 3: %r\n", __FUNCTION__, Status));
return;
}
@@ -227,11 +242,14 @@ FaultTolerantWriteInitialize (
EFI_STATUS Status;
EFI_FTW_DEVICE *FtwDevice;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
//
// Allocate private data structure for FTW protocol and do some initialization
//
Status = InitFtwDevice (&FtwDevice);
if (EFI_ERROR(Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1: %r\n", __FUNCTION__, Status));
return Status;
}
@@ -246,5 +264,6 @@ FaultTolerantWriteInitialize (
&mFvbRegistration
);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2\n", __FUNCTION__));
return EFI_SUCCESS;
}
diff --git a/MdeModulePkg/Universal/FaultTolerantWriteDxe/FtwMisc.c b/MdeModulePkg/Universal/FaultTolerantWriteDxe/FtwMisc.c
index b3352bb..436de4c 100644
--- a/MdeModulePkg/Universal/FaultTolerantWriteDxe/FtwMisc.c
+++ b/MdeModulePkg/Universal/FaultTolerantWriteDxe/FtwMisc.c
@@ -35,6 +35,9 @@ IsErasedFlashBuffer (
UINT8 *Ptr;
UINTN Index;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Buffer=%p BufferSize=0x%Lx\n",
+ __FUNCTION__, Buffer, (UINT64)BufferSize));
+
Ptr = Buffer;
IsEmpty = TRUE;
for (Index = 0; Index < BufferSize; Index += 1) {
@@ -44,6 +47,7 @@ IsErasedFlashBuffer (
}
}
+ DEBUG ((DEBUG_VERBOSE, "%a: exit, IsEmpty=%d\n", __FUNCTION__, IsEmpty));
return IsEmpty;
}
@@ -66,12 +70,17 @@ FtwEraseBlock (
EFI_LBA Lba
)
{
- return FvBlock->EraseBlocks (
+ EFI_STATUS Status;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Lba=0x%Lx\n", __FUNCTION__, (UINT64)Lba));
+ Status = FvBlock->EraseBlocks (
FvBlock,
Lba,
FtwDevice->NumberOfSpareBlock,
EFI_LBA_LIST_TERMINATOR
);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit: %r\n", __FUNCTION__, Status));
+ return Status;
}
/**
@@ -96,12 +105,17 @@ FtwEraseSpareBlock (
IN EFI_FTW_DEVICE *FtwDevice
)
{
- return FtwDevice->FtwBackupFvb->EraseBlocks (
+ EFI_STATUS Status;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+ Status = FtwDevice->FtwBackupFvb->EraseBlocks (
FtwDevice->FtwBackupFvb,
FtwDevice->FtwSpareLba,
FtwDevice->NumberOfSpareBlock,
EFI_LBA_LIST_TERMINATOR
);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit: %r\n", __FUNCTION__, Status));
+ return Status;
}
/**
@@ -122,17 +136,22 @@ IsWorkingBlock (
EFI_LBA Lba
)
{
+ BOOLEAN Ret;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Lba=0x%Lx\n", __FUNCTION__, (UINT64)Lba));
//
// If matching the following condition, the target block is in working block.
// 1. Target block is on the FV of working block (Using the same FVB protocol instance).
// 2. Lba falls into the range of working block.
//
- return (BOOLEAN)
+ Ret = (BOOLEAN)
(
(FvBlock == FtwDevice->FtwFvBlock) &&
(Lba >= FtwDevice->FtwWorkBlockLba) &&
(Lba <= FtwDevice->FtwWorkSpaceLba)
);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit: %d\n", __FUNCTION__, Ret));
+ return Ret;
}
/**
@@ -162,6 +181,9 @@ GetFvbByAddress (
EFI_FIRMWARE_VOLUME_HEADER *FwVolHeader;
EFI_HANDLE FvbHandle;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Address=0x%Lx\n", __FUNCTION__,
+ (UINT64)Address));
+
*FvBlock = NULL;
FvbHandle = NULL;
//
@@ -169,6 +191,7 @@ GetFvbByAddress (
//
Status = GetFvbCountAndBuffer (&HandleCount, &HandleBuffer);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1: %r\n", __FUNCTION__, Status));
return NULL;
}
//
@@ -196,6 +219,7 @@ GetFvbByAddress (
}
FreePool (HandleBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2\n", __FUNCTION__));
return FvbHandle;
}
@@ -227,12 +251,16 @@ IsBootBlock (
BOOLEAN IsSwapped;
EFI_HANDLE FvbHandle;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Lba=0x%Lx\n", __FUNCTION__, (UINT64)Lba));
+
if (!FeaturePcdGet(PcdFullFtwServiceEnable)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1\n", __FUNCTION__));
return FALSE;
}
Status = FtwGetSarProtocol ((VOID **) &SarProtocol);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2: %r\n", __FUNCTION__, Status));
return FALSE;
}
//
@@ -246,11 +274,13 @@ IsBootBlock (
&BackupBlockSize
);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 3: %r\n", __FUNCTION__, Status));
return FALSE;
}
Status = SarProtocol->GetSwapState (SarProtocol, &IsSwapped);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 4: %r\n", __FUNCTION__, Status));
return FALSE;
}
//
@@ -263,11 +293,14 @@ IsBootBlock (
}
if (FvbHandle == NULL) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 5\n", __FUNCTION__));
return FALSE;
}
//
// Compare the Fvb
//
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 6: %d\n", __FUNCTION__,
+ FvBlock == BootFvb));
return (BOOLEAN) (FvBlock == BootFvb);
}
@@ -313,7 +346,10 @@ FlushSpareBlockToBootBlock (
EFI_FIRMWARE_VOLUME_BLOCK_PROTOCOL *BootFvb;
EFI_LBA BootLba;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
if (!FeaturePcdGet(PcdFullFtwServiceEnable)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1\n", __FUNCTION__));
return EFI_UNSUPPORTED;
}
@@ -322,6 +358,7 @@ FlushSpareBlockToBootBlock (
//
Status = FtwGetSarProtocol ((VOID **) &SarProtocol);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2: %r\n", __FUNCTION__, Status));
return Status;
}
//
@@ -330,6 +367,7 @@ FlushSpareBlockToBootBlock (
Length = FtwDevice->SpareAreaLength;
Buffer = AllocatePool (Length);
if (Buffer == NULL) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 3\n", __FUNCTION__));
return EFI_OUT_OF_RESOURCES;
}
//
@@ -339,6 +377,7 @@ FlushSpareBlockToBootBlock (
if (EFI_ERROR (Status)) {
DEBUG ((EFI_D_ERROR, "Ftw: Get Top Swapped status - %r\n", Status));
FreePool (Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 4: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -348,6 +387,7 @@ FlushSpareBlockToBootBlock (
//
if (GetFvbByAddress (FtwDevice->SpareAreaAddress + FtwDevice->SpareAreaLength, &BootFvb) == NULL) {
FreePool (Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 5\n", __FUNCTION__));
return EFI_ABORTED;
}
//
@@ -366,6 +406,7 @@ FlushSpareBlockToBootBlock (
);
if (EFI_ERROR (Status)) {
FreePool (Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 6: %r\n", __FUNCTION__, Status));
return Status;
}
@@ -387,6 +428,7 @@ FlushSpareBlockToBootBlock (
);
if (EFI_ERROR (Status)) {
FreePool (Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 7: %r\n", __FUNCTION__, Status));
return Status;
}
@@ -398,6 +440,7 @@ FlushSpareBlockToBootBlock (
Status = SarProtocol->SetSwapState (SarProtocol, TRUE);
if (EFI_ERROR (Status)) {
FreePool (Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 8: %r\n", __FUNCTION__, Status));
return Status;
}
}
@@ -408,6 +451,7 @@ FlushSpareBlockToBootBlock (
Status = FtwEraseSpareBlock (FtwDevice);
if (EFI_ERROR (Status)) {
FreePool (Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 9: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
//
@@ -426,6 +470,7 @@ FlushSpareBlockToBootBlock (
if (EFI_ERROR (Status)) {
DEBUG ((EFI_D_ERROR, "Ftw: FVB Write boot block - %r\n", Status));
FreePool (Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 10: %r\n", __FUNCTION__, Status));
return Status;
}
@@ -439,6 +484,7 @@ FlushSpareBlockToBootBlock (
//
Status = SarProtocol->SetSwapState (SarProtocol, FALSE);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 11: %r\n", __FUNCTION__, Status));
return Status;
}
@@ -472,7 +518,10 @@ FlushSpareBlockToTargetBlock (
UINT8 *Ptr;
UINTN Index;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Lba=0x%Lx\n", __FUNCTION__, (UINT64)Lba));
+
if ((FtwDevice == NULL) || (FvBlock == NULL)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1\n", __FUNCTION__));
return EFI_INVALID_PARAMETER;
}
//
@@ -481,6 +530,7 @@ FlushSpareBlockToTargetBlock (
Length = FtwDevice->SpareAreaLength;
Buffer = AllocatePool (Length);
if (Buffer == NULL) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2\n", __FUNCTION__));
return EFI_OUT_OF_RESOURCES;
}
//
@@ -498,6 +548,7 @@ FlushSpareBlockToTargetBlock (
);
if (EFI_ERROR (Status)) {
FreePool (Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 3: %r\n", __FUNCTION__, Status));
return Status;
}
@@ -509,6 +560,7 @@ FlushSpareBlockToTargetBlock (
Status = FtwEraseBlock (FtwDevice, FvBlock, Lba);
if (EFI_ERROR (Status)) {
FreePool (Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 4: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
//
@@ -521,6 +573,7 @@ FlushSpareBlockToTargetBlock (
if (EFI_ERROR (Status)) {
DEBUG ((EFI_D_ERROR, "Ftw: FVB Write block - %r\n", Status));
FreePool (Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 5: %r\n", __FUNCTION__, Status));
return Status;
}
@@ -529,6 +582,7 @@ FlushSpareBlockToTargetBlock (
FreePool (Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 6: %r\n", __FUNCTION__, Status));
return Status;
}
@@ -564,12 +618,17 @@ FlushSpareBlockToWorkingBlock (
UINTN Index;
EFI_LBA WorkSpaceLbaOffset;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+ Status = EFI_SUCCESS;
+
//
// Allocate a memory buffer
//
Length = FtwDevice->SpareAreaLength;
Buffer = AllocatePool (Length);
if (Buffer == NULL) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_OUT_OF_RESOURCES;
}
@@ -603,6 +662,8 @@ FlushSpareBlockToWorkingBlock (
);
if (EFI_ERROR (Status)) {
FreePool (Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return Status;
}
@@ -634,6 +695,8 @@ FlushSpareBlockToWorkingBlock (
);
if (EFI_ERROR (Status)) {
FreePool (Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_ABORTED;
}
@@ -645,6 +708,8 @@ FlushSpareBlockToWorkingBlock (
Status = FtwEraseBlock (FtwDevice, FtwDevice->FtwFvBlock, FtwDevice->FtwWorkBlockLba);
if (EFI_ERROR (Status)) {
FreePool (Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_ABORTED;
}
//
@@ -663,6 +728,8 @@ FlushSpareBlockToWorkingBlock (
if (EFI_ERROR (Status)) {
DEBUG ((EFI_D_ERROR, "Ftw: FVB Write block - %r\n", Status));
FreePool (Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return Status;
}
@@ -686,12 +753,16 @@ FlushSpareBlockToWorkingBlock (
WORKING_BLOCK_VALID
);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_ABORTED;
}
FtwDevice->FtwWorkSpaceHeader->WorkingBlockInvalid = FTW_INVALID_STATE;
FtwDevice->FtwWorkSpaceHeader->WorkingBlockValid = FTW_VALID_STATE;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_SUCCESS;
}
@@ -725,12 +796,17 @@ FtwUpdateFvState (
UINT8 State;
UINTN Length;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Lba=0x%Lx Offset=0x%Lx NewBit=%d\n",
+ __FUNCTION__, (UINT64)Lba, (UINT64)Offset, NewBit));
+
//
// Read state from device, assume State is only one byte.
//
Length = sizeof (UINT8);
Status = FvBlock->Read (FvBlock, Lba, Offset, &Length, &State);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_ABORTED;
}
@@ -744,6 +820,8 @@ FtwUpdateFvState (
Length = sizeof (UINT8);
Status = FvBlock->Write (FvBlock, Lba, Offset, &Length, &State);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return Status;
}
@@ -770,6 +848,11 @@ FtwGetLastWriteHeader (
{
UINTN Offset;
EFI_FAULT_TOLERANT_WRITE_HEADER *FtwHeader;
+ EFI_STATUS Status;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, FtwWorkSpaceSize=0x%Lx\n", __FUNCTION__,
+ (UINT64)FtwWorkSpaceSize));
+ Status = EFI_SUCCESS;
*FtwWriteHeader = NULL;
FtwHeader = (EFI_FAULT_TOLERANT_WRITE_HEADER *) (FtwWorkSpaceHeader + 1);
@@ -782,6 +865,8 @@ FtwGetLastWriteHeader (
//
if (Offset >= FtwWorkSpaceSize) {
*FtwWriteHeader = FtwHeader;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_ABORTED;
}
@@ -792,6 +877,8 @@ FtwGetLastWriteHeader (
//
*FtwWriteHeader = FtwHeader;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_SUCCESS;
}
@@ -816,6 +903,10 @@ FtwGetLastWriteRecord (
{
UINTN Index;
EFI_FAULT_TOLERANT_WRITE_RECORD *FtwRecord;
+ EFI_STATUS Status;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+ Status = EFI_SUCCESS;
*FtwWriteRecord = NULL;
FtwRecord = (EFI_FAULT_TOLERANT_WRITE_RECORD *) (FtwWriteHeader + 1);
@@ -829,6 +920,8 @@ FtwGetLastWriteRecord (
// The last write record is found
//
*FtwWriteRecord = FtwRecord;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_SUCCESS;
}
@@ -846,9 +939,13 @@ FtwGetLastWriteRecord (
//
if (Index == FtwWriteHeader->NumberOfWrites) {
*FtwWriteRecord = (EFI_FAULT_TOLERANT_WRITE_RECORD *) ((UINTN) FtwRecord - FTW_RECORD_SIZE (FtwWriteHeader->PrivateDataSize));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_SUCCESS;
}
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_ABORTED;
}
@@ -899,10 +996,13 @@ IsLastRecordOfWrites (
UINT8 *Head;
UINT8 *Ptr;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
Head = (UINT8 *) FtwHeader;
Ptr = (UINT8 *) FtwRecord;
Head += FTW_WRITE_TOTAL_SIZE (FtwHeader->NumberOfWrites - 1, FtwHeader->PrivateDataSize);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit: %d\n", __FUNCTION__, Head == Ptr));
return (BOOLEAN) (Head == Ptr);
}
@@ -923,15 +1023,22 @@ GetPreviousRecordOfWrites (
)
{
UINT8 *Ptr;
+ EFI_STATUS Status = EFI_SUCCESS;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
if (IsFirstRecordOfWrites (FtwHeader, *FtwRecord)) {
*FtwRecord = NULL;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_ACCESS_DENIED;
}
Ptr = (UINT8 *) (*FtwRecord);
Ptr -= FTW_RECORD_SIZE (FtwHeader->PrivateDataSize);
*FtwRecord = (EFI_FAULT_TOLERANT_WRITE_RECORD *) Ptr;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_SUCCESS;
}
@@ -951,13 +1058,18 @@ InitFtwDevice (
)
{
EFI_FTW_DEVICE *FtwDevice;
-
+ EFI_STATUS Status = EFI_SUCCESS;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
//
// Allocate private data of this driver,
// Including the FtwWorkSpace[FTW_WORK_SPACE_SIZE].
//
FtwDevice = AllocateZeroPool (sizeof (EFI_FTW_DEVICE) + PcdGet32 (PcdFlashNvStorageFtwWorkingSize));
if (FtwDevice == NULL) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_OUT_OF_RESOURCES;
}
@@ -969,6 +1081,8 @@ InitFtwDevice (
if ((FtwDevice->WorkSpaceLength == 0) || (FtwDevice->SpareAreaLength == 0)) {
DEBUG ((EFI_D_ERROR, "Ftw: Workspace or Spare block does not exist!\n"));
FreePool (FtwDevice);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_INVALID_PARAMETER;
}
@@ -989,6 +1103,8 @@ InitFtwDevice (
}
*FtwData = FtwDevice;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_SUCCESS;
}
@@ -1019,11 +1135,15 @@ FindFvbForFtw (
EFI_FV_BLOCK_MAP_ENTRY *FvbMapEntry;
UINT32 LbaIndex;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
//
// Get all FVB handle.
//
Status = GetFvbCountAndBuffer (&HandleCount, &HandleBuffer);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_NOT_FOUND;
}
@@ -1135,9 +1255,13 @@ FindFvbForFtw (
if ((FtwDevice->FtwBackupFvb == NULL) || (FtwDevice->FtwFvBlock == NULL) ||
(FtwDevice->FtwWorkSpaceLba == (EFI_LBA) (-1)) || (FtwDevice->FtwSpareLba == (EFI_LBA) (-1))) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_ABORTED;
}
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_SUCCESS;
}
@@ -1164,11 +1288,15 @@ InitFtwProtocol (
EFI_HANDLE FvbHandle;
EFI_LBA WorkSpaceLbaOffset;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
//
// Find the right SMM Fvb protocol instance for FTW.
//
Status = FindFvbForFtw (FtwDevice);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_NOT_FOUND;
}
@@ -1317,6 +1445,8 @@ InitFtwProtocol (
FtwDevice->FtwInstance.Abort = FtwAbort;
FtwDevice->FtwInstance.GetLastWrite = FtwGetLastWrite;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_SUCCESS;
}
diff --git a/MdeModulePkg/Universal/FaultTolerantWriteDxe/UpdateWorkingBlock.c b/MdeModulePkg/Universal/FaultTolerantWriteDxe/UpdateWorkingBlock.c
index a5fa12b..85a3a2d 100644
--- a/MdeModulePkg/Universal/FaultTolerantWriteDxe/UpdateWorkingBlock.c
+++ b/MdeModulePkg/Universal/FaultTolerantWriteDxe/UpdateWorkingBlock.c
@@ -31,6 +31,7 @@ InitializeLocalWorkSpaceHeader (
{
EFI_STATUS Status;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
//
// Check signature with gEdkiiWorkingBlockSignatureGuid.
//
@@ -38,6 +39,7 @@ InitializeLocalWorkSpaceHeader (
//
// The local work space header has been initialized.
//
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1\n", __FUNCTION__));
return;
}
@@ -73,6 +75,8 @@ InitializeLocalWorkSpaceHeader (
mWorkingBlockHeader.WorkingBlockValid = FTW_VALID_STATE;
mWorkingBlockHeader.WorkingBlockInvalid = FTW_INVALID_STATE;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2\n", __FUNCTION__));
}
/**
@@ -90,15 +94,20 @@ IsValidWorkSpace (
IN EFI_FAULT_TOLERANT_WORKING_BLOCK_HEADER *WorkingHeader
)
{
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
if (WorkingHeader == NULL) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1\n", __FUNCTION__));
return FALSE;
}
if (CompareMem (WorkingHeader, &mWorkingBlockHeader, sizeof (EFI_FAULT_TOLERANT_WORKING_BLOCK_HEADER)) == 0) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2\n", __FUNCTION__));
return TRUE;
}
DEBUG ((EFI_D_ERROR, "Ftw: Work block header check error\n"));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 3\n", __FUNCTION__));
return FALSE;
}
@@ -116,12 +125,15 @@ InitWorkSpaceHeader (
IN EFI_FAULT_TOLERANT_WORKING_BLOCK_HEADER *WorkingHeader
)
{
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
if (WorkingHeader == NULL) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1\n", __FUNCTION__));
return EFI_INVALID_PARAMETER;
}
CopyMem (WorkingHeader, &mWorkingBlockHeader, sizeof (EFI_FAULT_TOLERANT_WORKING_BLOCK_HEADER));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2\n", __FUNCTION__));
return EFI_SUCCESS;
}
@@ -143,6 +155,7 @@ WorkSpaceRefresh (
UINTN Length;
UINTN RemainingSpaceSize;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
//
// Initialize WorkSpace as FTW_ERASED_BYTE
//
@@ -164,6 +177,7 @@ WorkSpaceRefresh (
FtwDevice->FtwWorkSpace
);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
//
@@ -189,6 +203,7 @@ WorkSpaceRefresh (
Status = FtwReclaimWorkSpace (FtwDevice, TRUE);
if (EFI_ERROR (Status)) {
DEBUG ((EFI_D_ERROR, "Ftw: Reclaim workspace - %r\n", Status));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
//
@@ -203,6 +218,7 @@ WorkSpaceRefresh (
FtwDevice->FtwWorkSpace
);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 3: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -212,6 +228,7 @@ WorkSpaceRefresh (
&FtwDevice->FtwLastWriteHeader
);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 4: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
}
@@ -223,9 +240,11 @@ WorkSpaceRefresh (
&FtwDevice->FtwLastWriteRecord
);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 5: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 6\n", __FUNCTION__));
return EFI_SUCCESS;
}
@@ -258,6 +277,8 @@ FtwReclaimWorkSpace (
UINT8 *Ptr;
EFI_LBA WorkSpaceLbaOffset;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, PreserveRecord=%d\n", __FUNCTION__,
+ PreserveRecord));
DEBUG ((EFI_D_INFO, "Ftw: start to reclaim work space\n"));
WorkSpaceLbaOffset = FtwDevice->FtwWorkSpaceLba - FtwDevice->FtwWorkBlockLba;
@@ -268,6 +289,7 @@ FtwReclaimWorkSpace (
TempBufferSize = FtwDevice->SpareAreaLength;
TempBuffer = AllocateZeroPool (TempBufferSize);
if (TempBuffer == NULL) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1\n", __FUNCTION__));
return EFI_OUT_OF_RESOURCES;
}
@@ -283,6 +305,7 @@ FtwReclaimWorkSpace (
);
if (EFI_ERROR (Status)) {
FreePool (TempBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -361,6 +384,7 @@ FtwReclaimWorkSpace (
SpareBuffer = AllocatePool (SpareBufferSize);
if (SpareBuffer == NULL) {
FreePool (TempBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 3\n", __FUNCTION__));
return EFI_OUT_OF_RESOURCES;
}
@@ -377,6 +401,7 @@ FtwReclaimWorkSpace (
if (EFI_ERROR (Status)) {
FreePool (TempBuffer);
FreePool (SpareBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 4: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -399,6 +424,7 @@ FtwReclaimWorkSpace (
if (EFI_ERROR (Status)) {
FreePool (TempBuffer);
FreePool (SpareBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 5: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -420,6 +446,7 @@ FtwReclaimWorkSpace (
);
if (EFI_ERROR (Status)) {
FreePool (SpareBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 6: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
//
@@ -436,6 +463,7 @@ FtwReclaimWorkSpace (
);
if (EFI_ERROR (Status)) {
FreePool (SpareBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 7: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -447,6 +475,7 @@ FtwReclaimWorkSpace (
Status = FlushSpareBlockToWorkingBlock (FtwDevice);
if (EFI_ERROR (Status)) {
FreePool (SpareBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 8: %r\n", __FUNCTION__, Status));
return Status;
}
//
@@ -465,6 +494,7 @@ FtwReclaimWorkSpace (
);
if (EFI_ERROR (Status)) {
FreePool (SpareBuffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 9: %r\n", __FUNCTION__, Status));
return EFI_ABORTED;
}
@@ -475,5 +505,6 @@ FtwReclaimWorkSpace (
DEBUG ((EFI_D_INFO, "Ftw: reclaim work space successfully\n"));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 10\n", __FUNCTION__));
return EFI_SUCCESS;
}
diff --git a/OvmfPkg/QemuFlashFvbServicesRuntimeDxe/FvbInfo.c b/OvmfPkg/QemuFlashFvbServicesRuntimeDxe/FvbInfo.c
index 72845f9..e9f4254 100644
--- a/OvmfPkg/QemuFlashFvbServicesRuntimeDxe/FvbInfo.c
+++ b/OvmfPkg/QemuFlashFvbServicesRuntimeDxe/FvbInfo.c
@@ -112,6 +112,10 @@ GetFvbInfo (
{
STATIC BOOLEAN Checksummed = FALSE;
UINTN Index;
+ EFI_STATUS Status = EFI_SUCCESS;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, FvLength=0x%Lx\n", __FUNCTION__,
+ FvLength));
if (!Checksummed) {
for (Index = 0; Index < sizeof (mPlatformFvbMediaInfo) / sizeof (EFI_FVB_MEDIA_INFO); Index += 1) {
@@ -129,9 +133,13 @@ GetFvbInfo (
for (Index = 0; Index < sizeof (mPlatformFvbMediaInfo) / sizeof (EFI_FVB_MEDIA_INFO); Index += 1) {
if (mPlatformFvbMediaInfo[Index].FvLength == FvLength) {
*FvbInfo = &mPlatformFvbMediaInfo[Index].FvbInfo;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_SUCCESS;
}
}
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_NOT_FOUND;
}
diff --git a/OvmfPkg/QemuFlashFvbServicesRuntimeDxe/FwBlockService.c b/OvmfPkg/QemuFlashFvbServicesRuntimeDxe/FwBlockService.c
index 7d26c41..56d1b73 100644
--- a/OvmfPkg/QemuFlashFvbServicesRuntimeDxe/FwBlockService.c
+++ b/OvmfPkg/QemuFlashFvbServicesRuntimeDxe/FwBlockService.c
@@ -147,6 +147,8 @@ Returns:
EFI_FW_VOL_INSTANCE *FwhInstance;
UINTN Index;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
EfiConvertPointer (0x0, (VOID **) &mFvbModuleGlobal->FvInstance[FVB_VIRTUAL]);
//
@@ -167,6 +169,8 @@ Returns:
EfiConvertPointer (0x0, (VOID **) &mFvbModuleGlobal->FvbScratchSpace[FVB_VIRTUAL]);
EfiConvertPointer (0x0, (VOID **) &mFvbModuleGlobal);
QemuFlashConvertPointers ();
+
+ DEBUG ((DEBUG_VERBOSE, "%a: exit\n", __FUNCTION__));
}
EFI_STATUS
@@ -196,8 +200,14 @@ Returns:
--*/
{
EFI_FW_VOL_INSTANCE *FwhRecord;
+ EFI_STATUS Status = EFI_SUCCESS;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Instance=0x%Lx, Global=%p, Virtual=%d\n",
+ __FUNCTION__, (UINT64)Instance, Global, Virtual));
if (Instance >= Global->NumFv) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_INVALID_PARAMETER;
}
//
@@ -215,6 +225,8 @@ Returns:
*FwhInstance = FwhRecord;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_SUCCESS;
}
@@ -249,6 +261,9 @@ Returns:
EFI_FW_VOL_INSTANCE *FwhInstance;
EFI_STATUS Status;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Instance=0x%Lx, Global=%p, Virtual=%d\n",
+ __FUNCTION__, (UINT64)Instance, Global, Virtual));
+
//
// Find the right instance of the FVB private data
//
@@ -256,6 +271,8 @@ Returns:
ASSERT_EFI_ERROR (Status);
*Address = FwhInstance->FvBase[Virtual];
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r, Address=0x%Lx\n",
+ __FUNCTION__, __LINE__, Status, (UINT64)*Address));
return EFI_SUCCESS;
}
@@ -289,6 +306,9 @@ Returns:
EFI_FW_VOL_INSTANCE *FwhInstance;
EFI_STATUS Status;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Instance=0x%Lx, Global=%p, Virtual=%d\n",
+ __FUNCTION__, (UINT64)Instance, Global, Virtual));
+
//
// Find the right instance of the FVB private data
//
@@ -296,6 +316,8 @@ Returns:
ASSERT_EFI_ERROR (Status);
*Attributes = FwhInstance->VolumeHeader.Attributes;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r, Attributes=0x%Lx\n",
+ __FUNCTION__, __LINE__, Status, (UINT64)*Attributes));
return EFI_SUCCESS;
}
@@ -343,6 +365,10 @@ Returns:
EFI_FV_BLOCK_MAP_ENTRY *BlockMap;
EFI_STATUS Status;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Instance=0x%Lx, Global=%p, Virtual=%d, "
+ "Lba=0x%Lx\n", __FUNCTION__, (UINT64)Instance, Global, Virtual,
+ (UINT64)Lba));
+
//
// Find the right instance of the FVB private data
//
@@ -361,6 +387,8 @@ Returns:
BlockLength = BlockMap->Length;
if (NumBlocks == 0 || BlockLength == 0) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_INVALID_PARAMETER;
}
@@ -373,16 +401,24 @@ Returns:
Offset = Offset + (UINTN) MultU64x32 ((Lba - StartLba), BlockLength);
if (LbaAddress != NULL) {
*LbaAddress = FwhInstance->FvBase[Virtual] + Offset;
+ DEBUG ((DEBUG_VERBOSE, "%a: LbaAddress=0x%Lx\n", __FUNCTION__,
+ (UINT64)*LbaAddress));
}
if (LbaLength != NULL) {
*LbaLength = BlockLength;
+ DEBUG ((DEBUG_VERBOSE, "%a: LbaLength=0x%Lx\n", __FUNCTION__,
+ (UINT64)*LbaLength));
}
if (NumOfBlocks != NULL) {
*NumOfBlocks = (UINTN) (NextLba - Lba);
+ DEBUG ((DEBUG_VERBOSE, "%a: NumOfBlocks=0x%Lx\n", __FUNCTION__,
+ (UINT64)*NumOfBlocks));
}
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_SUCCESS;
}
@@ -434,6 +470,10 @@ Returns:
EFI_STATUS Status;
EFI_FVB_ATTRIBUTES_2 UnchangedAttributes;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Instance=0x%Lx, Global=%p, Virtual=%d, "
+ "Attributes=0x%Lx\n", __FUNCTION__, (UINT64)Instance, Global, Virtual,
+ (UINTN)*Attributes));
+
//
// Find the right instance of the FVB private data
//
@@ -467,6 +507,8 @@ Returns:
// Some attributes of FV is read only can *not* be set
//
if ((OldAttributes & UnchangedAttributes) ^ (*Attributes & UnchangedAttributes)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_INVALID_PARAMETER;
}
//
@@ -474,6 +516,8 @@ Returns:
//
if (OldAttributes & EFI_FVB2_LOCK_STATUS) {
if (OldStatus ^ NewStatus) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_ACCESS_DENIED;
}
}
@@ -482,6 +526,8 @@ Returns:
//
if ((Capabilities & EFI_FVB2_READ_DISABLED_CAP) == 0) {
if ((NewStatus & EFI_FVB2_READ_STATUS) == 0) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_INVALID_PARAMETER;
}
}
@@ -490,6 +536,8 @@ Returns:
//
if ((Capabilities & EFI_FVB2_READ_ENABLED_CAP) == 0) {
if (NewStatus & EFI_FVB2_READ_STATUS) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_INVALID_PARAMETER;
}
}
@@ -498,6 +546,8 @@ Returns:
//
if ((Capabilities & EFI_FVB2_WRITE_DISABLED_CAP) == 0) {
if ((NewStatus & EFI_FVB2_WRITE_STATUS) == 0) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_INVALID_PARAMETER;
}
}
@@ -506,6 +556,8 @@ Returns:
//
if ((Capabilities & EFI_FVB2_WRITE_ENABLED_CAP) == 0) {
if (NewStatus & EFI_FVB2_WRITE_STATUS) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_INVALID_PARAMETER;
}
}
@@ -514,6 +566,8 @@ Returns:
//
if ((Capabilities & EFI_FVB2_LOCK_CAP) == 0) {
if (NewStatus & EFI_FVB2_LOCK_STATUS) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_INVALID_PARAMETER;
}
}
@@ -522,6 +576,8 @@ Returns:
*AttribPtr = (*AttribPtr) | NewStatus;
*Attributes = *AttribPtr;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r, Attributes=0x%Lx\n",
+ __FUNCTION__, __LINE__, Status, (UINTN)*Attributes));
return EFI_SUCCESS;
}
@@ -553,10 +609,16 @@ Returns:
--*/
{
EFI_FW_VOL_BLOCK_DEVICE *FvbDevice;
+ EFI_STATUS Status;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
FvbDevice = FVB_DEVICE_FROM_THIS (This);
- return FvbGetPhysicalAddress (FvbDevice->Instance, Address, mFvbModuleGlobal, EfiGoneVirtual ());
+ Status = FvbGetPhysicalAddress (FvbDevice->Instance, Address, mFvbModuleGlobal, EfiGoneVirtual ());
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
+ return Status;
}
EFI_STATUS
@@ -589,10 +651,13 @@ Returns:
--*/
{
EFI_FW_VOL_BLOCK_DEVICE *FvbDevice;
+ EFI_STATUS Status;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Lba=0x%Lx\n", __FUNCTION__, (UINT64)Lba));
FvbDevice = FVB_DEVICE_FROM_THIS (This);
- return FvbGetLbaAddress (
+ Status = FvbGetLbaAddress (
FvbDevice->Instance,
Lba,
NULL,
@@ -601,6 +666,10 @@ Returns:
mFvbModuleGlobal,
EfiGoneVirtual ()
);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r BlockSize=0x%Lx "
+ "NumOfBlocks=0x%Lx\n", __FUNCTION__, __LINE__, Status, (UINT64)*BlockSize,
+ (UINT64)*NumOfBlocks));
+ return Status;
}
EFI_STATUS
@@ -624,10 +693,16 @@ Returns:
--*/
{
EFI_FW_VOL_BLOCK_DEVICE *FvbDevice;
+ EFI_STATUS Status;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
FvbDevice = FVB_DEVICE_FROM_THIS (This);
- return FvbGetVolumeAttributes (FvbDevice->Instance, Attributes, mFvbModuleGlobal, EfiGoneVirtual ());
+ Status = FvbGetVolumeAttributes (FvbDevice->Instance, Attributes, mFvbModuleGlobal, EfiGoneVirtual ());
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
+ return Status;
}
EFI_STATUS
@@ -651,10 +726,16 @@ Returns:
--*/
{
EFI_FW_VOL_BLOCK_DEVICE *FvbDevice;
+ EFI_STATUS Status;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
FvbDevice = FVB_DEVICE_FROM_THIS (This);
- return FvbSetVolumeAttributes (FvbDevice->Instance, Attributes, mFvbModuleGlobal, EfiGoneVirtual ());
+ Status = FvbSetVolumeAttributes (FvbDevice->Instance, Attributes, mFvbModuleGlobal, EfiGoneVirtual ());
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r, Attributes=0x%Lx\n",
+ __FUNCTION__, __LINE__, Status, (UINT64)*Attributes));
+ return Status;
}
EFI_STATUS
@@ -696,6 +777,8 @@ Returns:
UINTN NumOfLba;
EFI_STATUS Status;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
FvbDevice = FVB_DEVICE_FROM_THIS (This);
Status = GetFvbInstance (FvbDevice->Instance, mFvbModuleGlobal, &FwhInstance, EfiGoneVirtual ());
@@ -718,6 +801,8 @@ Returns:
//
if ((NumOfLba == 0) || ((StartingLba + NumOfLba) > NumOfBlocks)) {
VA_END (args);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_INVALID_PARAMETER;
}
} while (1);
@@ -737,6 +822,8 @@ Returns:
Status = QemuFlashEraseBlock (StartingLba);
if (EFI_ERROR (Status)) {
VA_END (args);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return Status;
}
@@ -748,6 +835,8 @@ Returns:
VA_END (args);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_SUCCESS;
}
@@ -791,7 +880,16 @@ Returns:
--*/
{
- return QemuFlashWrite ((EFI_LBA)Lba, (UINTN)Offset, NumBytes, (UINT8 *)Buffer);
+ EFI_STATUS Status;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Lba=0x%Lx Offset=0x%Lx NumBytes=0x%Lx "
+ "Buffer=%p\n", __FUNCTION__, (UINT64)Lba, (UINT64)Offset,
+ (UINT64)*NumBytes, Buffer));
+
+ Status = QemuFlashWrite ((EFI_LBA)Lba, (UINTN)Offset, NumBytes, (UINT8 *)Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r, NumBytes=0x%Lx\n",
+ __FUNCTION__, __LINE__, Status, (UINT64)*NumBytes));
+ return Status;
}
EFI_STATUS
@@ -835,7 +933,16 @@ Returns:
--*/
{
- return QemuFlashRead ((EFI_LBA)Lba, (UINTN)Offset, NumBytes, (UINT8 *)Buffer);
+ EFI_STATUS Status;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Lba=0x%Lx Offset=0x%Lx NumBytes=0x%Lx "
+ "Buffer=%p\n", __FUNCTION__, (UINT64)Lba, (UINT64)Offset,
+ (UINT64)*NumBytes, Buffer));
+
+ Status = QemuFlashRead ((EFI_LBA)Lba, (UINTN)Offset, NumBytes, (UINT8 *)Buffer);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r, NumBytes=0x%Lx\n",
+ __FUNCTION__, __LINE__, Status, (UINT64)*NumBytes));
+ return Status;
}
EFI_STATUS
@@ -857,6 +964,9 @@ Returns:
--*/
{
UINT16 Checksum;
+ EFI_STATUS Status = EFI_SUCCESS;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
//
// Verify the header revision, header signature, length
@@ -868,6 +978,8 @@ Returns:
(FwVolHeader->FvLength == ((UINTN) -1)) ||
((FwVolHeader->HeaderLength & 0x01) != 0)
) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_NOT_FOUND;
}
@@ -883,9 +995,13 @@ Returns:
DEBUG ((EFI_D_INFO, "FV@%p Checksum is 0x%x, expected 0x%x\n",
FwVolHeader, FwVolHeader->Checksum, Expected));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_NOT_FOUND;
}
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_SUCCESS;
}
@@ -898,6 +1014,9 @@ MarkMemoryRangeForRuntimeAccess (
{
EFI_STATUS Status;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, BaseAddress=0x%Lx Length=0x%Lx\n",
+ __FUNCTION__, (UINT64)BaseAddress, Length));
+
//
// Mark flash region as runtime memory
//
@@ -922,6 +1041,8 @@ MarkMemoryRangeForRuntimeAccess (
);
ASSERT_EFI_ERROR (Status);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return Status;
}
@@ -938,6 +1059,8 @@ InitializeVariableFvHeader (
UINTN WriteLength;
UINTN BlockSize;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
FwVolHeader =
(EFI_FIRMWARE_VOLUME_HEADER *) (UINTN)
PcdGet32 (PcdOvmfFlashNvStorageVariableBase);
@@ -994,6 +1117,8 @@ InitializeVariableFvHeader (
ASSERT (WriteLength == GoodFwVolHeader->HeaderLength);
}
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return Status;
}
@@ -1028,11 +1153,15 @@ Returns:
UINTN NumOfBlocks;
EFI_EVENT VirtualAddressChangeEvent;
- if (EFI_ERROR (QemuFlashInitialize ())) {
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
+ if (EFI_ERROR ((Status = QemuFlashInitialize ()))) {
//
// Return an error so image will be unloaded
//
DEBUG ((EFI_D_INFO, "QEMU flash was not detected. Writable FVB is not being installed.\n"));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_WRITE_PROTECTED;
}
@@ -1049,6 +1178,8 @@ Returns:
Status = InitializeVariableFvHeader ();
if (EFI_ERROR (Status)) {
DEBUG ((EFI_D_INFO, "QEMU Flash: Unable to initialize variable FV header\n"));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_WRITE_PROTECTED;
}
@@ -1061,6 +1192,8 @@ Returns:
Status = GetFvbInfo (Length, &FwVolHeader);
if (EFI_ERROR (Status)) {
DEBUG ((EFI_D_INFO, "EFI_ERROR (GetFvbInfo (Length, &FwVolHeader))\n"));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_WRITE_PROTECTED;
}
}
@@ -1223,5 +1356,7 @@ Returns:
ASSERT_EFI_ERROR (Status);
PcdSetBool (PcdOvmfFlashVariablesEnable, TRUE);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_SUCCESS;
}
diff --git a/OvmfPkg/QemuFlashFvbServicesRuntimeDxe/QemuFlash.c b/OvmfPkg/QemuFlashFvbServicesRuntimeDxe/QemuFlash.c
index a3fe7d8..32e07e3 100644
--- a/OvmfPkg/QemuFlashFvbServicesRuntimeDxe/QemuFlash.c
+++ b/OvmfPkg/QemuFlashFvbServicesRuntimeDxe/QemuFlash.c
@@ -43,7 +43,9 @@ QemuFlashConvertPointers (
VOID
)
{
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
EfiConvertPointer (0x0, (VOID **) &mFlashBase);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit\n", __FUNCTION__));
}
@@ -54,7 +56,13 @@ QemuFlashPtr (
IN UINTN Offset
)
{
- return mFlashBase + (Lba * mFdBlockSize) + Offset;
+ UINT8 *Ret;
+
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Lba=0x%Lx Offset=0x%Lx\n", __FUNCTION__,
+ (UINT64)Lba, (UINT64)Offset));
+ Ret = mFlashBase + (Lba * mFdBlockSize) + Offset;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit, Ret=%p\n", __FUNCTION__, Ret));
+ return Ret;
}
@@ -78,6 +86,8 @@ QemuFlashDetected (
UINT8 OriginalUint8;
UINT8 ProbeUint8;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
FlashDetected = FALSE;
Ptr = QemuFlashPtr (0, 0);
@@ -93,6 +103,7 @@ QemuFlashDetected (
if (Offset >= mFdBlockSize) {
DEBUG ((EFI_D_INFO, "QEMU Flash: Failed to find probe location\n"));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1\n", __FUNCTION__));
return FALSE;
}
@@ -122,6 +133,7 @@ QemuFlashDetected (
DEBUG ((EFI_D_INFO, "QemuFlashDetected => %a\n",
FlashDetected ? "Yes" : "No"));
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2\n", __FUNCTION__));
return FlashDetected;
}
@@ -146,11 +158,16 @@ QemuFlashRead (
{
UINT8 *Ptr;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Lba=0x%Lx Offset=0x%Lx NumBytes=0x%Lx "
+ "Buffer=%p\n", __FUNCTION__, (UINT64)Lba, (UINT64)Offset,
+ (UINT64)*NumBytes, Buffer));
+
//
// Only write to the first 64k. We don't bother saving the FTW Spare
// block into the flash memory.
//
if (Lba >= mFdBlockCount) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1\n", __FUNCTION__));
return EFI_INVALID_PARAMETER;
}
@@ -161,6 +178,7 @@ QemuFlashRead (
CopyMem (Buffer, Ptr, *NumBytes);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2\n", __FUNCTION__));
return EFI_SUCCESS;
}
@@ -186,11 +204,16 @@ QemuFlashWrite (
volatile UINT8 *Ptr;
UINTN Loop;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Lba=0x%Lx Offset=0x%Lx NumBytes=0x%Lx "
+ "Buffer=%p\n", __FUNCTION__, (UINT64)Lba, (UINT64)Offset,
+ (UINT64)*NumBytes, Buffer));
+
//
// Only write to the first 64k. We don't bother saving the FTW Spare
// block into the flash memory.
//
if (Lba >= mFdBlockCount) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1\n", __FUNCTION__));
return EFI_INVALID_PARAMETER;
}
@@ -211,6 +234,7 @@ QemuFlashWrite (
*Ptr = READ_ARRAY_CMD;
}
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2\n", __FUNCTION__));
return EFI_SUCCESS;
}
@@ -228,13 +252,17 @@ QemuFlashEraseBlock (
{
volatile UINT8 *Ptr;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, Lba=0x%Lx\n", __FUNCTION__, (UINT64)Lba));
+
if (Lba >= mFdBlockCount) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1\n", __FUNCTION__));
return EFI_INVALID_PARAMETER;
}
Ptr = QemuFlashPtr (Lba, 0);
*Ptr = BLOCK_ERASE_CMD;
*Ptr = BLOCK_ERASE_CONFIRM_CMD;
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2\n", __FUNCTION__));
return EFI_SUCCESS;
}
@@ -251,15 +279,19 @@ QemuFlashInitialize (
VOID
)
{
+ DEBUG ((DEBUG_VERBOSE, "%a: enter\n", __FUNCTION__));
+
mFlashBase = (UINT8*)(UINTN) PcdGet32 (PcdOvmfFdBaseAddress);
mFdBlockSize = PcdGet32 (PcdOvmfFirmwareBlockSize);
ASSERT(PcdGet32 (PcdOvmfFirmwareFdSize) % mFdBlockSize == 0);
mFdBlockCount = PcdGet32 (PcdOvmfFirmwareFdSize) / mFdBlockSize;
if (!QemuFlashDetected ()) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 1\n", __FUNCTION__));
return EFI_WRITE_PROTECTED;
}
+ DEBUG ((DEBUG_VERBOSE, "%a: exit 2\n", __FUNCTION__));
return EFI_SUCCESS;
}
diff --git a/SecurityPkg/VariableAuthenticated/RuntimeDxe/Reclaim.c b/SecurityPkg/VariableAuthenticated/RuntimeDxe/Reclaim.c
index b20facd..fc85b18 100644
--- a/SecurityPkg/VariableAuthenticated/RuntimeDxe/Reclaim.c
+++ b/SecurityPkg/VariableAuthenticated/RuntimeDxe/Reclaim.c
@@ -118,11 +118,14 @@ FtwVariableSpace (
UINTN FtwBufferSize;
EFI_FAULT_TOLERANT_WRITE_PROTOCOL *FtwProtocol;
+ DEBUG ((DEBUG_VERBOSE, "%a:%a: enter\n", __FUNCTION__, __FILE__));
//
// Locate fault tolerant write protocol.
//
Status = GetFtwProtocol((VOID **) &FtwProtocol);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_NOT_FOUND;
}
//
@@ -130,6 +133,8 @@ FtwVariableSpace (
//
Status = GetFvbInfoByAddress (VariableBase, &FvbHandle, NULL);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return Status;
}
//
@@ -137,6 +142,8 @@ FtwVariableSpace (
//
Status = GetLbaAndOffsetByAddress (VariableBase, &VarLba, &VarOffset);
if (EFI_ERROR (Status)) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_ABORTED;
}
@@ -156,5 +163,7 @@ FtwVariableSpace (
(VOID *) VariableBuffer // write buffer
);
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return Status;
}
diff --git a/SecurityPkg/VariableAuthenticated/RuntimeDxe/Variable.c b/SecurityPkg/VariableAuthenticated/RuntimeDxe/Variable.c
index 28d026a..369e7bb 100644
--- a/SecurityPkg/VariableAuthenticated/RuntimeDxe/Variable.c
+++ b/SecurityPkg/VariableAuthenticated/RuntimeDxe/Variable.c
@@ -776,6 +776,12 @@ Reclaim (
VARIABLE_HEADER *UpdatingVariable;
VARIABLE_HEADER *UpdatingInDeletedTransition;
+ DEBUG ((DEBUG_VERBOSE, "%a: enter, VariableBase=0x%Lx, IsVolatile=%d, "
+ "NewVariableSize=0x%Lx, ReclaimPubKeyStore=%d\n", __FUNCTION__,
+ (UINT64)VariableBase, IsVolatile, (UINTN)NewVariableSize,
+ ReclaimPubKeyStore));
+ Status = EFI_SUCCESS;
+
UpdatingVariable = NULL;
UpdatingInDeletedTransition = NULL;
if (UpdatingPtrTrack != NULL) {
@@ -826,6 +832,8 @@ Reclaim (
MaximumBufferSize += 1;
ValidBuffer = AllocatePool (MaximumBufferSize);
if (ValidBuffer == NULL) {
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return EFI_OUT_OF_RESOURCES;
}
} else {
@@ -1067,6 +1075,8 @@ Done:
}
}
+ DEBUG ((DEBUG_VERBOSE, "%a: exit @ %d, Status=%r\n",
+ __FUNCTION__, __LINE__, Status));
return Status;
}
[-- Attachment #2.1.3: direct.txt --]
[-- Type: text/plain, Size: 58143 bytes --]
Reclaim: enter, VariableBase=0xFFE00048, IsVolatile=0, NewVariableSize=0x0, ReclaimPubKeyStore=0
FtwVariableSpace:/home/lacos/src/upstream/edk2-git-svn/SecurityPkg/VariableAuthenticated/RuntimeDxe/Reclaim.c: enter
FvbProtocolGetAttributes: enter
FvbGetVolumeAttributes: enter, Instance=0x0, Global=9F7DAF18, Virtual=0
GetFvbInstance: enter, Instance=0x0, Global=9F7DAF18, Virtual=0
GetFvbInstance: exit @ 229, Status=Success
FvbGetVolumeAttributes: exit @ 320, Status=Success, Attributes=0x4FEFF
FvbProtocolGetAttributes: exit @ 704, Status=Success
FvbProtocolGetPhysicalAddress: enter
FvbGetPhysicalAddress: enter, Instance=0x0, Global=9F7DAF18, Virtual=0
GetFvbInstance: enter, Instance=0x0, Global=9F7DAF18, Virtual=0
GetFvbInstance: exit @ 229, Status=Success
FvbGetPhysicalAddress: exit @ 275, Status=Success, Address=0xFFE00000
FvbProtocolGetPhysicalAddress: exit @ 620, Status=Success
FvbProtocolGetAttributes: enter
FvbGetVolumeAttributes: enter, Instance=0x0, Global=9F7DAF18, Virtual=0
GetFvbInstance: enter, Instance=0x0, Global=9F7DAF18, Virtual=0
GetFvbInstance: exit @ 229, Status=Success
FvbGetVolumeAttributes: exit @ 320, Status=Success, Attributes=0x4FEFF
FvbProtocolGetAttributes: exit @ 704, Status=Success
FvbProtocolGetPhysicalAddress: enter
FvbGetPhysicalAddress: enter, Instance=0x0, Global=9F7DAF18, Virtual=0
GetFvbInstance: enter, Instance=0x0, Global=9F7DAF18, Virtual=0
GetFvbInstance: exit @ 229, Status=Success
FvbGetPhysicalAddress: exit @ 275, Status=Success, Address=0xFFE00000
FvbProtocolGetPhysicalAddress: exit @ 620, Status=Success
FvbProtocolGetPhysicalAddress: enter
FvbGetPhysicalAddress: enter, Instance=0x0, Global=9F7DAF18, Virtual=0
GetFvbInstance: enter, Instance=0x0, Global=9F7DAF18, Virtual=0
GetFvbInstance: exit @ 229, Status=Success
FvbGetPhysicalAddress: exit @ 275, Status=Success, Address=0xFFE00000
FvbProtocolGetPhysicalAddress: exit @ 620, Status=Success
FtwWrite: enter, Lba=0x0 Offset=0x48 Length=0xDFB8 PrivateData=0 FvBlockHandle=9F58E798 Buffer=9F7BE060
WorkSpaceRefresh: enter
FvbProtocolRead: enter, Lba=0xF Offset=0x0 NumBytes=0x1000 Buffer=9EBEF0E0
QemuFlashRead: enter, Lba=0xF Offset=0x0 NumBytes=0x1000 Buffer=9EBEF0E0
QemuFlashPtr: enter, Lba=0xF Offset=0x0
QemuFlashPtr: exit, Ret=FFE0F000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FtwGetLastWriteHeader: enter, FtwWorkSpaceSize=0x1000
FtwGetLastWriteHeader: exit @ 881, Status=Success
Ftw: Remaining work space size - 590
FtwGetLastWriteRecord: enter
FtwGetLastWriteRecord: exit @ 924, Status=Success
WorkSpaceRefresh: exit 6
IsErasedFlashBuffer: enter, Buffer=9EBEFB50 BufferSize=0x28
IsErasedFlashBuffer: exit, IsEmpty=1
FtwAllocate: enter, CallerId=FE5CEA76-4F72-49E8-986F-2CD899DFFE5D, PrivateDataSize=0x0, NumberOfWrites=0x1
WorkSpaceRefresh: enter
FvbProtocolRead: enter, Lba=0xF Offset=0x0 NumBytes=0x1000 Buffer=9EBEF0E0
QemuFlashRead: enter, Lba=0xF Offset=0x0 NumBytes=0x1000 Buffer=9EBEF0E0
QemuFlashPtr: enter, Lba=0xF Offset=0x0
QemuFlashPtr: exit, Ret=FFE0F000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FtwGetLastWriteHeader: enter, FtwWorkSpaceSize=0x1000
FtwGetLastWriteHeader: exit @ 881, Status=Success
Ftw: Remaining work space size - 590
FtwGetLastWriteRecord: enter
FtwGetLastWriteRecord: exit @ 924, Status=Success
WorkSpaceRefresh: exit 6
FvbProtocolWrite: enter, Lba=0xF Offset=0xA70 NumBytes=0x28 Buffer=9EBEFB50
QemuFlashWrite: enter, Lba=0xF Offset=0xA70 NumBytes=0x28 Buffer=9EBEFB50
QemuFlashPtr: enter, Lba=0xF Offset=0xA70
QemuFlashPtr: exit, Ret=FFE0FA70
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x28
FtwUpdateFvState: enter, Lba=0xF Offset=0xA70 NewBit=2
FvbProtocolRead: enter, Lba=0xF Offset=0xA70 NumBytes=0x1 Buffer=9F852647
QemuFlashRead: enter, Lba=0xF Offset=0xA70 NumBytes=0x1 Buffer=9F852647
QemuFlashPtr: enter, Lba=0xF Offset=0xA70
QemuFlashPtr: exit, Ret=FFE0FA70
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1
FvbProtocolWrite: enter, Lba=0xF Offset=0xA70 NumBytes=0x1 Buffer=9F852647
QemuFlashWrite: enter, Lba=0xF Offset=0xA70 NumBytes=0x1 Buffer=9F852647
QemuFlashPtr: enter, Lba=0xF Offset=0xA70
QemuFlashPtr: exit, Ret=FFE0FA70
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1
FtwUpdateFvState: exit @ 824, Status=Success
Ftw: Allocate() success, Caller:FE5CEA76-4F72-49E8-986F-2CD899DFFE5D, # 1
FtwAllocate: exit 7
FtwGetFvbByHandle: enter
FtwGetFvbByHandle: exit: Success
FvbProtocolGetPhysicalAddress: enter
FvbGetPhysicalAddress: enter, Instance=0x0, Global=9F7DAF18, Virtual=0
GetFvbInstance: enter, Instance=0x0, Global=9F7DAF18, Virtual=0
GetFvbInstance: exit @ 229, Status=Success
FvbGetPhysicalAddress: exit @ 275, Status=Success, Address=0xFFE00000
FvbProtocolGetPhysicalAddress: exit @ 620, Status=Success
IsBootBlock: enter, Lba=0x0
FtwGetSarProtocol: enter
FtwGetSarProtocol: exit: Not Found
IsBootBlock: exit 2: Not Found
FvbProtocolWrite: enter, Lba=0xF Offset=0xA98 NumBytes=0x28 Buffer=9EBEFB78
QemuFlashWrite: enter, Lba=0xF Offset=0xA98 NumBytes=0x28 Buffer=9EBEFB78
QemuFlashPtr: enter, Lba=0xF Offset=0xA98
QemuFlashPtr: exit, Ret=FFE0FA98
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x28
//
// Read all original data from target block to memory buffer
//
FvbProtocolRead: enter, Lba=0x0 Offset=0x0 NumBytes=0x1000 Buffer=9C806018
QemuFlashRead: enter, Lba=0x0 Offset=0x0 NumBytes=0x1000 Buffer=9C806018
QemuFlashPtr: enter, Lba=0x0 Offset=0x0
QemuFlashPtr: exit, Ret=FFE00000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x1 Offset=0x0 NumBytes=0x1000 Buffer=9C807018
QemuFlashRead: enter, Lba=0x1 Offset=0x0 NumBytes=0x1000 Buffer=9C807018
QemuFlashPtr: enter, Lba=0x1 Offset=0x0
QemuFlashPtr: exit, Ret=FFE01000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x2 Offset=0x0 NumBytes=0x1000 Buffer=9C808018
QemuFlashRead: enter, Lba=0x2 Offset=0x0 NumBytes=0x1000 Buffer=9C808018
QemuFlashPtr: enter, Lba=0x2 Offset=0x0
QemuFlashPtr: exit, Ret=FFE02000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x3 Offset=0x0 NumBytes=0x1000 Buffer=9C809018
QemuFlashRead: enter, Lba=0x3 Offset=0x0 NumBytes=0x1000 Buffer=9C809018
QemuFlashPtr: enter, Lba=0x3 Offset=0x0
QemuFlashPtr: exit, Ret=FFE03000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x4 Offset=0x0 NumBytes=0x1000 Buffer=9C80A018
QemuFlashRead: enter, Lba=0x4 Offset=0x0 NumBytes=0x1000 Buffer=9C80A018
QemuFlashPtr: enter, Lba=0x4 Offset=0x0
QemuFlashPtr: exit, Ret=FFE04000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x5 Offset=0x0 NumBytes=0x1000 Buffer=9C80B018
QemuFlashRead: enter, Lba=0x5 Offset=0x0 NumBytes=0x1000 Buffer=9C80B018
QemuFlashPtr: enter, Lba=0x5 Offset=0x0
QemuFlashPtr: exit, Ret=FFE05000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x6 Offset=0x0 NumBytes=0x1000 Buffer=9C80C018
QemuFlashRead: enter, Lba=0x6 Offset=0x0 NumBytes=0x1000 Buffer=9C80C018
QemuFlashPtr: enter, Lba=0x6 Offset=0x0
QemuFlashPtr: exit, Ret=FFE06000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x7 Offset=0x0 NumBytes=0x1000 Buffer=9C80D018
QemuFlashRead: enter, Lba=0x7 Offset=0x0 NumBytes=0x1000 Buffer=9C80D018
QemuFlashPtr: enter, Lba=0x7 Offset=0x0
QemuFlashPtr: exit, Ret=FFE07000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x8 Offset=0x0 NumBytes=0x1000 Buffer=9C80E018
QemuFlashRead: enter, Lba=0x8 Offset=0x0 NumBytes=0x1000 Buffer=9C80E018
QemuFlashPtr: enter, Lba=0x8 Offset=0x0
QemuFlashPtr: exit, Ret=FFE08000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x9 Offset=0x0 NumBytes=0x1000 Buffer=9C80F018
QemuFlashRead: enter, Lba=0x9 Offset=0x0 NumBytes=0x1000 Buffer=9C80F018
QemuFlashPtr: enter, Lba=0x9 Offset=0x0
QemuFlashPtr: exit, Ret=FFE09000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0xA Offset=0x0 NumBytes=0x1000 Buffer=9C810018
QemuFlashRead: enter, Lba=0xA Offset=0x0 NumBytes=0x1000 Buffer=9C810018
QemuFlashPtr: enter, Lba=0xA Offset=0x0
QemuFlashPtr: exit, Ret=FFE0A000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0xB Offset=0x0 NumBytes=0x1000 Buffer=9C811018
QemuFlashRead: enter, Lba=0xB Offset=0x0 NumBytes=0x1000 Buffer=9C811018
QemuFlashPtr: enter, Lba=0xB Offset=0x0
QemuFlashPtr: exit, Ret=FFE0B000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0xC Offset=0x0 NumBytes=0x1000 Buffer=9C812018
QemuFlashRead: enter, Lba=0xC Offset=0x0 NumBytes=0x1000 Buffer=9C812018
QemuFlashPtr: enter, Lba=0xC Offset=0x0
QemuFlashPtr: exit, Ret=FFE0C000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0xD Offset=0x0 NumBytes=0x1000 Buffer=9C813018
QemuFlashRead: enter, Lba=0xD Offset=0x0 NumBytes=0x1000 Buffer=9C813018
QemuFlashPtr: enter, Lba=0xD Offset=0x0
QemuFlashPtr: exit, Ret=FFE0D000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0xE Offset=0x0 NumBytes=0x1000 Buffer=9C814018
QemuFlashRead: enter, Lba=0xE Offset=0x0 NumBytes=0x1000 Buffer=9C814018
QemuFlashPtr: enter, Lba=0xE Offset=0x0
QemuFlashPtr: exit, Ret=FFE0E000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0xF Offset=0x0 NumBytes=0x1000 Buffer=9C815018
QemuFlashRead: enter, Lba=0xF Offset=0x0 NumBytes=0x1000 Buffer=9C815018
QemuFlashPtr: enter, Lba=0xF Offset=0x0
QemuFlashPtr: exit, Ret=FFE0F000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
//
// Try to keep the content of spare block
// Save spare block into a spare backup memory buffer (Sparebuffer)
//
FvbProtocolRead: enter, Lba=0x10 Offset=0x0 NumBytes=0x1000 Buffer=9C7F5018
QemuFlashRead: enter, Lba=0x10 Offset=0x0 NumBytes=0x1000 Buffer=9C7F5018
QemuFlashPtr: enter, Lba=0x10 Offset=0x0
QemuFlashPtr: exit, Ret=FFE10000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x11 Offset=0x0 NumBytes=0x1000 Buffer=9C7F6018
QemuFlashRead: enter, Lba=0x11 Offset=0x0 NumBytes=0x1000 Buffer=9C7F6018
QemuFlashPtr: enter, Lba=0x11 Offset=0x0
QemuFlashPtr: exit, Ret=FFE11000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x12 Offset=0x0 NumBytes=0x1000 Buffer=9C7F7018
QemuFlashRead: enter, Lba=0x12 Offset=0x0 NumBytes=0x1000 Buffer=9C7F7018
QemuFlashPtr: enter, Lba=0x12 Offset=0x0
QemuFlashPtr: exit, Ret=FFE12000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x13 Offset=0x0 NumBytes=0x1000 Buffer=9C7F8018
QemuFlashRead: enter, Lba=0x13 Offset=0x0 NumBytes=0x1000 Buffer=9C7F8018
QemuFlashPtr: enter, Lba=0x13 Offset=0x0
QemuFlashPtr: exit, Ret=FFE13000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x14 Offset=0x0 NumBytes=0x1000 Buffer=9C7F9018
QemuFlashRead: enter, Lba=0x14 Offset=0x0 NumBytes=0x1000 Buffer=9C7F9018
QemuFlashPtr: enter, Lba=0x14 Offset=0x0
QemuFlashPtr: exit, Ret=FFE14000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x15 Offset=0x0 NumBytes=0x1000 Buffer=9C7FA018
QemuFlashRead: enter, Lba=0x15 Offset=0x0 NumBytes=0x1000 Buffer=9C7FA018
QemuFlashPtr: enter, Lba=0x15 Offset=0x0
QemuFlashPtr: exit, Ret=FFE15000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x16 Offset=0x0 NumBytes=0x1000 Buffer=9C7FB018
QemuFlashRead: enter, Lba=0x16 Offset=0x0 NumBytes=0x1000 Buffer=9C7FB018
QemuFlashPtr: enter, Lba=0x16 Offset=0x0
QemuFlashPtr: exit, Ret=FFE16000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x17 Offset=0x0 NumBytes=0x1000 Buffer=9C7FC018
QemuFlashRead: enter, Lba=0x17 Offset=0x0 NumBytes=0x1000 Buffer=9C7FC018
QemuFlashPtr: enter, Lba=0x17 Offset=0x0
QemuFlashPtr: exit, Ret=FFE17000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x18 Offset=0x0 NumBytes=0x1000 Buffer=9C7FD018
QemuFlashRead: enter, Lba=0x18 Offset=0x0 NumBytes=0x1000 Buffer=9C7FD018
QemuFlashPtr: enter, Lba=0x18 Offset=0x0
QemuFlashPtr: exit, Ret=FFE18000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x19 Offset=0x0 NumBytes=0x1000 Buffer=9C7FE018
QemuFlashRead: enter, Lba=0x19 Offset=0x0 NumBytes=0x1000 Buffer=9C7FE018
QemuFlashPtr: enter, Lba=0x19 Offset=0x0
QemuFlashPtr: exit, Ret=FFE19000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x1A Offset=0x0 NumBytes=0x1000 Buffer=9C7FF018
QemuFlashRead: enter, Lba=0x1A Offset=0x0 NumBytes=0x1000 Buffer=9C7FF018
QemuFlashPtr: enter, Lba=0x1A Offset=0x0
QemuFlashPtr: exit, Ret=FFE1A000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x1B Offset=0x0 NumBytes=0x1000 Buffer=9C800018
QemuFlashRead: enter, Lba=0x1B Offset=0x0 NumBytes=0x1000 Buffer=9C800018
QemuFlashPtr: enter, Lba=0x1B Offset=0x0
QemuFlashPtr: exit, Ret=FFE1B000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x1C Offset=0x0 NumBytes=0x1000 Buffer=9C801018
QemuFlashRead: enter, Lba=0x1C Offset=0x0 NumBytes=0x1000 Buffer=9C801018
QemuFlashPtr: enter, Lba=0x1C Offset=0x0
QemuFlashPtr: exit, Ret=FFE1C000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x1D Offset=0x0 NumBytes=0x1000 Buffer=9C802018
QemuFlashRead: enter, Lba=0x1D Offset=0x0 NumBytes=0x1000 Buffer=9C802018
QemuFlashPtr: enter, Lba=0x1D Offset=0x0
QemuFlashPtr: exit, Ret=FFE1D000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x1E Offset=0x0 NumBytes=0x1000 Buffer=9C803018
QemuFlashRead: enter, Lba=0x1E Offset=0x0 NumBytes=0x1000 Buffer=9C803018
QemuFlashPtr: enter, Lba=0x1E Offset=0x0
QemuFlashPtr: exit, Ret=FFE1E000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x1F Offset=0x0 NumBytes=0x1000 Buffer=9C804018
QemuFlashRead: enter, Lba=0x1F Offset=0x0 NumBytes=0x1000 Buffer=9C804018
QemuFlashPtr: enter, Lba=0x1F Offset=0x0
QemuFlashPtr: exit, Ret=FFE1F000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
//
// Write the memory buffer to spare block
//
FtwEraseSpareBlock: enter
FvbProtocolEraseBlocks: enter
GetFvbInstance: enter, Instance=0x0, Global=9F7DAF18, Virtual=0
GetFvbInstance: exit @ 229, Status=Success
QemuFlashEraseBlock: enter, Lba=0x10
QemuFlashPtr: enter, Lba=0x10 Offset=0x0
QemuFlashPtr: exit, Ret=FFE10000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x11
QemuFlashPtr: enter, Lba=0x11 Offset=0x0
QemuFlashPtr: exit, Ret=FFE11000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x12
QemuFlashPtr: enter, Lba=0x12 Offset=0x0
QemuFlashPtr: exit, Ret=FFE12000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x13
QemuFlashPtr: enter, Lba=0x13 Offset=0x0
QemuFlashPtr: exit, Ret=FFE13000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x14
QemuFlashPtr: enter, Lba=0x14 Offset=0x0
QemuFlashPtr: exit, Ret=FFE14000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x15
QemuFlashPtr: enter, Lba=0x15 Offset=0x0
QemuFlashPtr: exit, Ret=FFE15000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x16
QemuFlashPtr: enter, Lba=0x16 Offset=0x0
QemuFlashPtr: exit, Ret=FFE16000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x17
QemuFlashPtr: enter, Lba=0x17 Offset=0x0
QemuFlashPtr: exit, Ret=FFE17000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x18
QemuFlashPtr: enter, Lba=0x18 Offset=0x0
QemuFlashPtr: exit, Ret=FFE18000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x19
QemuFlashPtr: enter, Lba=0x19 Offset=0x0
QemuFlashPtr: exit, Ret=FFE19000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x1A
QemuFlashPtr: enter, Lba=0x1A Offset=0x0
QemuFlashPtr: exit, Ret=FFE1A000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x1B
QemuFlashPtr: enter, Lba=0x1B Offset=0x0
QemuFlashPtr: exit, Ret=FFE1B000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x1C
QemuFlashPtr: enter, Lba=0x1C Offset=0x0
QemuFlashPtr: exit, Ret=FFE1C000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x1D
QemuFlashPtr: enter, Lba=0x1D Offset=0x0
QemuFlashPtr: exit, Ret=FFE1D000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x1E
QemuFlashPtr: enter, Lba=0x1E Offset=0x0
QemuFlashPtr: exit, Ret=FFE1E000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x1F
QemuFlashPtr: enter, Lba=0x1F Offset=0x0
QemuFlashPtr: exit, Ret=FFE1F000
QemuFlashEraseBlock: exit 2
FvbProtocolEraseBlocks: exit @ 839, Status=Success
FtwEraseSpareBlock: exit: Success
FvbProtocolWrite: enter, Lba=0x10 Offset=0x0 NumBytes=0x1000 Buffer=9C806018
QemuFlashWrite: enter, Lba=0x10 Offset=0x0 NumBytes=0x1000 Buffer=9C806018
QemuFlashPtr: enter, Lba=0x10 Offset=0x0
QemuFlashPtr: exit, Ret=FFE10000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x11 Offset=0x0 NumBytes=0x1000 Buffer=9C807018
QemuFlashWrite: enter, Lba=0x11 Offset=0x0 NumBytes=0x1000 Buffer=9C807018
QemuFlashPtr: enter, Lba=0x11 Offset=0x0
QemuFlashPtr: exit, Ret=FFE11000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x12 Offset=0x0 NumBytes=0x1000 Buffer=9C808018
QemuFlashWrite: enter, Lba=0x12 Offset=0x0 NumBytes=0x1000 Buffer=9C808018
QemuFlashPtr: enter, Lba=0x12 Offset=0x0
QemuFlashPtr: exit, Ret=FFE12000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x13 Offset=0x0 NumBytes=0x1000 Buffer=9C809018
QemuFlashWrite: enter, Lba=0x13 Offset=0x0 NumBytes=0x1000 Buffer=9C809018
QemuFlashPtr: enter, Lba=0x13 Offset=0x0
QemuFlashPtr: exit, Ret=FFE13000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x14 Offset=0x0 NumBytes=0x1000 Buffer=9C80A018
QemuFlashWrite: enter, Lba=0x14 Offset=0x0 NumBytes=0x1000 Buffer=9C80A018
QemuFlashPtr: enter, Lba=0x14 Offset=0x0
QemuFlashPtr: exit, Ret=FFE14000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x15 Offset=0x0 NumBytes=0x1000 Buffer=9C80B018
QemuFlashWrite: enter, Lba=0x15 Offset=0x0 NumBytes=0x1000 Buffer=9C80B018
QemuFlashPtr: enter, Lba=0x15 Offset=0x0
QemuFlashPtr: exit, Ret=FFE15000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x16 Offset=0x0 NumBytes=0x1000 Buffer=9C80C018
QemuFlashWrite: enter, Lba=0x16 Offset=0x0 NumBytes=0x1000 Buffer=9C80C018
QemuFlashPtr: enter, Lba=0x16 Offset=0x0
QemuFlashPtr: exit, Ret=FFE16000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x17 Offset=0x0 NumBytes=0x1000 Buffer=9C80D018
QemuFlashWrite: enter, Lba=0x17 Offset=0x0 NumBytes=0x1000 Buffer=9C80D018
QemuFlashPtr: enter, Lba=0x17 Offset=0x0
QemuFlashPtr: exit, Ret=FFE17000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x18 Offset=0x0 NumBytes=0x1000 Buffer=9C80E018
QemuFlashWrite: enter, Lba=0x18 Offset=0x0 NumBytes=0x1000 Buffer=9C80E018
QemuFlashPtr: enter, Lba=0x18 Offset=0x0
QemuFlashPtr: exit, Ret=FFE18000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x19 Offset=0x0 NumBytes=0x1000 Buffer=9C80F018
QemuFlashWrite: enter, Lba=0x19 Offset=0x0 NumBytes=0x1000 Buffer=9C80F018
QemuFlashPtr: enter, Lba=0x19 Offset=0x0
QemuFlashPtr: exit, Ret=FFE19000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x1A Offset=0x0 NumBytes=0x1000 Buffer=9C810018
QemuFlashWrite: enter, Lba=0x1A Offset=0x0 NumBytes=0x1000 Buffer=9C810018
QemuFlashPtr: enter, Lba=0x1A Offset=0x0
QemuFlashPtr: exit, Ret=FFE1A000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x1B Offset=0x0 NumBytes=0x1000 Buffer=9C811018
QemuFlashWrite: enter, Lba=0x1B Offset=0x0 NumBytes=0x1000 Buffer=9C811018
QemuFlashPtr: enter, Lba=0x1B Offset=0x0
QemuFlashPtr: exit, Ret=FFE1B000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x1C Offset=0x0 NumBytes=0x1000 Buffer=9C812018
QemuFlashWrite: enter, Lba=0x1C Offset=0x0 NumBytes=0x1000 Buffer=9C812018
QemuFlashPtr: enter, Lba=0x1C Offset=0x0
QemuFlashPtr: exit, Ret=FFE1C000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x1D Offset=0x0 NumBytes=0x1000 Buffer=9C813018
QemuFlashWrite: enter, Lba=0x1D Offset=0x0 NumBytes=0x1000 Buffer=9C813018
QemuFlashPtr: enter, Lba=0x1D Offset=0x0
QemuFlashPtr: exit, Ret=FFE1D000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x1E Offset=0x0 NumBytes=0x1000 Buffer=9C814018
QemuFlashWrite: enter, Lba=0x1E Offset=0x0 NumBytes=0x1000 Buffer=9C814018
QemuFlashPtr: enter, Lba=0x1E Offset=0x0
QemuFlashPtr: exit, Ret=FFE1E000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
!!! out-of-varstore write !!!
FvbProtocolWrite: enter, Lba=0x1F Offset=0x0 NumBytes=0x1000 Buffer=9C815018
QemuFlashWrite: enter, Lba=0x1F Offset=0x0 NumBytes=0x1000 Buffer=9C815018
QemuFlashPtr: enter, Lba=0x1F Offset=0x0
QemuFlashPtr: exit, Ret=FFE1F000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
//
// Set the SpareComplete in the FTW record,
//
FtwUpdateFvState: enter, Lba=0xF Offset=0xA98 NewBit=2
FvbProtocolRead: enter, Lba=0xF Offset=0xA98 NumBytes=0x1 Buffer=9F8526C7
QemuFlashRead: enter, Lba=0xF Offset=0xA98 NumBytes=0x1 Buffer=9F8526C7
QemuFlashPtr: enter, Lba=0xF Offset=0xA98
QemuFlashPtr: exit, Ret=FFE0FA98
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1
FvbProtocolWrite: enter, Lba=0xF Offset=0xA98 NumBytes=0x1 Buffer=9F8526C7
QemuFlashWrite: enter, Lba=0xF Offset=0xA98 NumBytes=0x1 Buffer=9F8526C7
QemuFlashPtr: enter, Lba=0xF Offset=0xA98
QemuFlashPtr: exit, Ret=FFE0FA98
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1
FtwUpdateFvState: exit @ 824, Status=Success
//
// Since the content has already backuped in spare block, the write is
// guaranteed to be completed with fault tolerant manner.
//
FtwWriteRecord: enter
//
// IF target block is working block, THEN Flush Spare Block To Working Block;
// ELSE flush spare block to target block, which may be boot block after all.
//
IsWorkingBlock: enter, Lba=0x0
IsWorkingBlock: exit: 1
FtwUpdateFvState: enter, Lba=0x1F Offset=0xA98 NewBit=2
FvbProtocolRead: enter, Lba=0x1F Offset=0xA98 NumBytes=0x1 Buffer=9F852657
QemuFlashRead: enter, Lba=0x1F Offset=0xA98 NumBytes=0x1 Buffer=9F852657
QemuFlashPtr: enter, Lba=0x1F Offset=0xA98
QemuFlashPtr: exit, Ret=FFE1FA98
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1
FvbProtocolWrite: enter, Lba=0x1F Offset=0xA98 NumBytes=0x1 Buffer=9F852657
QemuFlashWrite: enter, Lba=0x1F Offset=0xA98 NumBytes=0x1 Buffer=9F852657
QemuFlashPtr: enter, Lba=0x1F Offset=0xA98
QemuFlashPtr: exit, Ret=FFE1FA98
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1
FtwUpdateFvState: exit @ 824, Status=Success
FlushSpareBlockToWorkingBlock: enter
FtwUpdateFvState: enter, Lba=0x1F Offset=0x14 NewBit=1
FvbProtocolRead: enter, Lba=0x1F Offset=0x14 NumBytes=0x1 Buffer=9F8525D7
QemuFlashRead: enter, Lba=0x1F Offset=0x14 NumBytes=0x1 Buffer=9F8525D7
QemuFlashPtr: enter, Lba=0x1F Offset=0x14
QemuFlashPtr: exit, Ret=FFE1F014
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1
FvbProtocolWrite: enter, Lba=0x1F Offset=0x14 NumBytes=0x1 Buffer=9F8525D7
QemuFlashWrite: enter, Lba=0x1F Offset=0x14 NumBytes=0x1 Buffer=9F8525D7
QemuFlashPtr: enter, Lba=0x1F Offset=0x14
QemuFlashPtr: exit, Ret=FFE1F014
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1
FtwUpdateFvState: exit @ 824, Status=Success
//
// Read from spare block to memory buffer
//
FvbProtocolRead: enter, Lba=0x10 Offset=0x0 NumBytes=0x1000 Buffer=9C806018
QemuFlashRead: enter, Lba=0x10 Offset=0x0 NumBytes=0x1000 Buffer=9C806018
QemuFlashPtr: enter, Lba=0x10 Offset=0x0
QemuFlashPtr: exit, Ret=FFE10000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x11 Offset=0x0 NumBytes=0x1000 Buffer=9C807018
QemuFlashRead: enter, Lba=0x11 Offset=0x0 NumBytes=0x1000 Buffer=9C807018
QemuFlashPtr: enter, Lba=0x11 Offset=0x0
QemuFlashPtr: exit, Ret=FFE11000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x12 Offset=0x0 NumBytes=0x1000 Buffer=9C808018
QemuFlashRead: enter, Lba=0x12 Offset=0x0 NumBytes=0x1000 Buffer=9C808018
QemuFlashPtr: enter, Lba=0x12 Offset=0x0
QemuFlashPtr: exit, Ret=FFE12000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x13 Offset=0x0 NumBytes=0x1000 Buffer=9C809018
QemuFlashRead: enter, Lba=0x13 Offset=0x0 NumBytes=0x1000 Buffer=9C809018
QemuFlashPtr: enter, Lba=0x13 Offset=0x0
QemuFlashPtr: exit, Ret=FFE13000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x14 Offset=0x0 NumBytes=0x1000 Buffer=9C80A018
QemuFlashRead: enter, Lba=0x14 Offset=0x0 NumBytes=0x1000 Buffer=9C80A018
QemuFlashPtr: enter, Lba=0x14 Offset=0x0
QemuFlashPtr: exit, Ret=FFE14000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x15 Offset=0x0 NumBytes=0x1000 Buffer=9C80B018
QemuFlashRead: enter, Lba=0x15 Offset=0x0 NumBytes=0x1000 Buffer=9C80B018
QemuFlashPtr: enter, Lba=0x15 Offset=0x0
QemuFlashPtr: exit, Ret=FFE15000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x16 Offset=0x0 NumBytes=0x1000 Buffer=9C80C018
QemuFlashRead: enter, Lba=0x16 Offset=0x0 NumBytes=0x1000 Buffer=9C80C018
QemuFlashPtr: enter, Lba=0x16 Offset=0x0
QemuFlashPtr: exit, Ret=FFE16000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x17 Offset=0x0 NumBytes=0x1000 Buffer=9C80D018
QemuFlashRead: enter, Lba=0x17 Offset=0x0 NumBytes=0x1000 Buffer=9C80D018
QemuFlashPtr: enter, Lba=0x17 Offset=0x0
QemuFlashPtr: exit, Ret=FFE17000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x18 Offset=0x0 NumBytes=0x1000 Buffer=9C80E018
QemuFlashRead: enter, Lba=0x18 Offset=0x0 NumBytes=0x1000 Buffer=9C80E018
QemuFlashPtr: enter, Lba=0x18 Offset=0x0
QemuFlashPtr: exit, Ret=FFE18000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x19 Offset=0x0 NumBytes=0x1000 Buffer=9C80F018
QemuFlashRead: enter, Lba=0x19 Offset=0x0 NumBytes=0x1000 Buffer=9C80F018
QemuFlashPtr: enter, Lba=0x19 Offset=0x0
QemuFlashPtr: exit, Ret=FFE19000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x1A Offset=0x0 NumBytes=0x1000 Buffer=9C810018
QemuFlashRead: enter, Lba=0x1A Offset=0x0 NumBytes=0x1000 Buffer=9C810018
QemuFlashPtr: enter, Lba=0x1A Offset=0x0
QemuFlashPtr: exit, Ret=FFE1A000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x1B Offset=0x0 NumBytes=0x1000 Buffer=9C811018
QemuFlashRead: enter, Lba=0x1B Offset=0x0 NumBytes=0x1000 Buffer=9C811018
QemuFlashPtr: enter, Lba=0x1B Offset=0x0
QemuFlashPtr: exit, Ret=FFE1B000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x1C Offset=0x0 NumBytes=0x1000 Buffer=9C812018
QemuFlashRead: enter, Lba=0x1C Offset=0x0 NumBytes=0x1000 Buffer=9C812018
QemuFlashPtr: enter, Lba=0x1C Offset=0x0
QemuFlashPtr: exit, Ret=FFE1C000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x1D Offset=0x0 NumBytes=0x1000 Buffer=9C813018
QemuFlashRead: enter, Lba=0x1D Offset=0x0 NumBytes=0x1000 Buffer=9C813018
QemuFlashPtr: enter, Lba=0x1D Offset=0x0
QemuFlashPtr: exit, Ret=FFE1D000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x1E Offset=0x0 NumBytes=0x1000 Buffer=9C814018
QemuFlashRead: enter, Lba=0x1E Offset=0x0 NumBytes=0x1000 Buffer=9C814018
QemuFlashPtr: enter, Lba=0x1E Offset=0x0
QemuFlashPtr: exit, Ret=FFE1E000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
FvbProtocolRead: enter, Lba=0x1F Offset=0x0 NumBytes=0x1000 Buffer=9C815018
QemuFlashRead: enter, Lba=0x1F Offset=0x0 NumBytes=0x1000 Buffer=9C815018
QemuFlashPtr: enter, Lba=0x1F Offset=0x0
QemuFlashPtr: exit, Ret=FFE1F000
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1000
//
// Clear the CRC and STATE, copy data from spare to working block.
//
InitWorkSpaceHeader: enter
InitWorkSpaceHeader: exit 2
//
// target block is working block, then
// Set WorkingBlockInvalid in EFI_FAULT_TOLERANT_WORKING_BLOCK_HEADER
// before erase the working block.
//
FtwUpdateFvState: enter, Lba=0xF Offset=0x14 NewBit=2
FvbProtocolRead: enter, Lba=0xF Offset=0x14 NumBytes=0x1 Buffer=9F8525D7
QemuFlashRead: enter, Lba=0xF Offset=0x14 NumBytes=0x1 Buffer=9F8525D7
QemuFlashPtr: enter, Lba=0xF Offset=0x14
QemuFlashPtr: exit, Ret=FFE0F014
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1
FvbProtocolWrite: enter, Lba=0xF Offset=0x14 NumBytes=0x1 Buffer=9F8525D7
QemuFlashWrite: enter, Lba=0xF Offset=0x14 NumBytes=0x1 Buffer=9F8525D7
QemuFlashPtr: enter, Lba=0xF Offset=0x14
QemuFlashPtr: exit, Ret=FFE0F014
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1
FtwUpdateFvState: exit @ 824, Status=Success
//
// Erase the working block
//
FtwEraseBlock: enter, Lba=0x0
FvbProtocolEraseBlocks: enter
GetFvbInstance: enter, Instance=0x0, Global=9F7DAF18, Virtual=0
GetFvbInstance: exit @ 229, Status=Success
QemuFlashEraseBlock: enter, Lba=0x0
QemuFlashPtr: enter, Lba=0x0 Offset=0x0
QemuFlashPtr: exit, Ret=FFE00000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x1
QemuFlashPtr: enter, Lba=0x1 Offset=0x0
QemuFlashPtr: exit, Ret=FFE01000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x2
QemuFlashPtr: enter, Lba=0x2 Offset=0x0
QemuFlashPtr: exit, Ret=FFE02000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x3
QemuFlashPtr: enter, Lba=0x3 Offset=0x0
QemuFlashPtr: exit, Ret=FFE03000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x4
QemuFlashPtr: enter, Lba=0x4 Offset=0x0
QemuFlashPtr: exit, Ret=FFE04000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x5
QemuFlashPtr: enter, Lba=0x5 Offset=0x0
QemuFlashPtr: exit, Ret=FFE05000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x6
QemuFlashPtr: enter, Lba=0x6 Offset=0x0
QemuFlashPtr: exit, Ret=FFE06000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x7
QemuFlashPtr: enter, Lba=0x7 Offset=0x0
QemuFlashPtr: exit, Ret=FFE07000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x8
QemuFlashPtr: enter, Lba=0x8 Offset=0x0
QemuFlashPtr: exit, Ret=FFE08000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x9
QemuFlashPtr: enter, Lba=0x9 Offset=0x0
QemuFlashPtr: exit, Ret=FFE09000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0xA
QemuFlashPtr: enter, Lba=0xA Offset=0x0
QemuFlashPtr: exit, Ret=FFE0A000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0xB
QemuFlashPtr: enter, Lba=0xB Offset=0x0
QemuFlashPtr: exit, Ret=FFE0B000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0xC
QemuFlashPtr: enter, Lba=0xC Offset=0x0
QemuFlashPtr: exit, Ret=FFE0C000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0xD
QemuFlashPtr: enter, Lba=0xD Offset=0x0
QemuFlashPtr: exit, Ret=FFE0D000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0xE
QemuFlashPtr: enter, Lba=0xE Offset=0x0
QemuFlashPtr: exit, Ret=FFE0E000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0xF
QemuFlashPtr: enter, Lba=0xF Offset=0x0
QemuFlashPtr: exit, Ret=FFE0F000
QemuFlashEraseBlock: exit 2
FvbProtocolEraseBlocks: exit @ 839, Status=Success
FtwEraseBlock: exit: Success
//
// Write memory buffer to working block, using the FvbBlock protocol interface
//
FvbProtocolWrite: enter, Lba=0x0 Offset=0x0 NumBytes=0x1000 Buffer=9C806018
QemuFlashWrite: enter, Lba=0x0 Offset=0x0 NumBytes=0x1000 Buffer=9C806018
QemuFlashPtr: enter, Lba=0x0 Offset=0x0
QemuFlashPtr: exit, Ret=FFE00000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x1 Offset=0x0 NumBytes=0x1000 Buffer=9C807018
QemuFlashWrite: enter, Lba=0x1 Offset=0x0 NumBytes=0x1000 Buffer=9C807018
QemuFlashPtr: enter, Lba=0x1 Offset=0x0
QemuFlashPtr: exit, Ret=FFE01000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x2 Offset=0x0 NumBytes=0x1000 Buffer=9C808018
QemuFlashWrite: enter, Lba=0x2 Offset=0x0 NumBytes=0x1000 Buffer=9C808018
QemuFlashPtr: enter, Lba=0x2 Offset=0x0
QemuFlashPtr: exit, Ret=FFE02000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x3 Offset=0x0 NumBytes=0x1000 Buffer=9C809018
QemuFlashWrite: enter, Lba=0x3 Offset=0x0 NumBytes=0x1000 Buffer=9C809018
QemuFlashPtr: enter, Lba=0x3 Offset=0x0
QemuFlashPtr: exit, Ret=FFE03000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x4 Offset=0x0 NumBytes=0x1000 Buffer=9C80A018
QemuFlashWrite: enter, Lba=0x4 Offset=0x0 NumBytes=0x1000 Buffer=9C80A018
QemuFlashPtr: enter, Lba=0x4 Offset=0x0
QemuFlashPtr: exit, Ret=FFE04000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x5 Offset=0x0 NumBytes=0x1000 Buffer=9C80B018
QemuFlashWrite: enter, Lba=0x5 Offset=0x0 NumBytes=0x1000 Buffer=9C80B018
QemuFlashPtr: enter, Lba=0x5 Offset=0x0
QemuFlashPtr: exit, Ret=FFE05000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x6 Offset=0x0 NumBytes=0x1000 Buffer=9C80C018
QemuFlashWrite: enter, Lba=0x6 Offset=0x0 NumBytes=0x1000 Buffer=9C80C018
QemuFlashPtr: enter, Lba=0x6 Offset=0x0
QemuFlashPtr: exit, Ret=FFE06000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x7 Offset=0x0 NumBytes=0x1000 Buffer=9C80D018
QemuFlashWrite: enter, Lba=0x7 Offset=0x0 NumBytes=0x1000 Buffer=9C80D018
QemuFlashPtr: enter, Lba=0x7 Offset=0x0
QemuFlashPtr: exit, Ret=FFE07000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x8 Offset=0x0 NumBytes=0x1000 Buffer=9C80E018
QemuFlashWrite: enter, Lba=0x8 Offset=0x0 NumBytes=0x1000 Buffer=9C80E018
QemuFlashPtr: enter, Lba=0x8 Offset=0x0
QemuFlashPtr: exit, Ret=FFE08000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x9 Offset=0x0 NumBytes=0x1000 Buffer=9C80F018
QemuFlashWrite: enter, Lba=0x9 Offset=0x0 NumBytes=0x1000 Buffer=9C80F018
QemuFlashPtr: enter, Lba=0x9 Offset=0x0
QemuFlashPtr: exit, Ret=FFE09000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0xA Offset=0x0 NumBytes=0x1000 Buffer=9C810018
QemuFlashWrite: enter, Lba=0xA Offset=0x0 NumBytes=0x1000 Buffer=9C810018
QemuFlashPtr: enter, Lba=0xA Offset=0x0
QemuFlashPtr: exit, Ret=FFE0A000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0xB Offset=0x0 NumBytes=0x1000 Buffer=9C811018
QemuFlashWrite: enter, Lba=0xB Offset=0x0 NumBytes=0x1000 Buffer=9C811018
QemuFlashPtr: enter, Lba=0xB Offset=0x0
QemuFlashPtr: exit, Ret=FFE0B000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0xC Offset=0x0 NumBytes=0x1000 Buffer=9C812018
QemuFlashWrite: enter, Lba=0xC Offset=0x0 NumBytes=0x1000 Buffer=9C812018
QemuFlashPtr: enter, Lba=0xC Offset=0x0
QemuFlashPtr: exit, Ret=FFE0C000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0xD Offset=0x0 NumBytes=0x1000 Buffer=9C813018
QemuFlashWrite: enter, Lba=0xD Offset=0x0 NumBytes=0x1000 Buffer=9C813018
QemuFlashPtr: enter, Lba=0xD Offset=0x0
QemuFlashPtr: exit, Ret=FFE0D000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0xE Offset=0x0 NumBytes=0x1000 Buffer=9C814018
QemuFlashWrite: enter, Lba=0xE Offset=0x0 NumBytes=0x1000 Buffer=9C814018
QemuFlashPtr: enter, Lba=0xE Offset=0x0
QemuFlashPtr: exit, Ret=FFE0E000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0xF Offset=0x0 NumBytes=0x1000 Buffer=9C815018
QemuFlashWrite: enter, Lba=0xF Offset=0x0 NumBytes=0x1000 Buffer=9C815018
QemuFlashPtr: enter, Lba=0xF Offset=0x0
QemuFlashPtr: exit, Ret=FFE0F000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
//
// Update the VALID of the working block
//
FtwUpdateFvState: enter, Lba=0xF Offset=0x14 NewBit=1
FvbProtocolRead: enter, Lba=0xF Offset=0x14 NumBytes=0x1 Buffer=9F8525D7
QemuFlashRead: enter, Lba=0xF Offset=0x14 NumBytes=0x1 Buffer=9F8525D7
QemuFlashPtr: enter, Lba=0xF Offset=0x14
QemuFlashPtr: exit, Ret=FFE0F014
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1
FvbProtocolWrite: enter, Lba=0xF Offset=0x14 NumBytes=0x1 Buffer=9F8525D7
QemuFlashWrite: enter, Lba=0xF Offset=0x14 NumBytes=0x1 Buffer=9F8525D7
QemuFlashPtr: enter, Lba=0xF Offset=0x14
QemuFlashPtr: exit, Ret=FFE0F014
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1
FtwUpdateFvState: exit @ 824, Status=Success
FlushSpareBlockToWorkingBlock: exit @ 765, Status=Success
//
// Record the DestionationComplete in record
//
FtwUpdateFvState: enter, Lba=0xF Offset=0xA98 NewBit=4
FvbProtocolRead: enter, Lba=0xF Offset=0xA98 NumBytes=0x1 Buffer=9F852657
QemuFlashRead: enter, Lba=0xF Offset=0xA98 NumBytes=0x1 Buffer=9F852657
QemuFlashPtr: enter, Lba=0xF Offset=0xA98
QemuFlashPtr: exit, Ret=FFE0FA98
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1
FvbProtocolWrite: enter, Lba=0xF Offset=0xA98 NumBytes=0x1 Buffer=9F852657
QemuFlashWrite: enter, Lba=0xF Offset=0xA98 NumBytes=0x1 Buffer=9F852657
QemuFlashPtr: enter, Lba=0xF Offset=0xA98
QemuFlashPtr: exit, Ret=FFE0FA98
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1
FtwUpdateFvState: exit @ 824, Status=Success
//
// If this is the last Write in these write sequence,
// set the complete flag of write header.
//
IsLastRecordOfWrites: enter
IsLastRecordOfWrites: exit: 1
FtwUpdateFvState: enter, Lba=0xF Offset=0xA70 NewBit=4
FvbProtocolRead: enter, Lba=0xF Offset=0xA70 NumBytes=0x1 Buffer=9F852657
QemuFlashRead: enter, Lba=0xF Offset=0xA70 NumBytes=0x1 Buffer=9F852657
QemuFlashPtr: enter, Lba=0xF Offset=0xA70
QemuFlashPtr: exit, Ret=FFE0FA70
QemuFlashRead: exit 2
FvbProtocolRead: exit @ 944, Status=Success, NumBytes=0x1
FvbProtocolWrite: enter, Lba=0xF Offset=0xA70 NumBytes=0x1 Buffer=9F852657
QemuFlashWrite: enter, Lba=0xF Offset=0xA70 NumBytes=0x1 Buffer=9F852657
QemuFlashPtr: enter, Lba=0xF Offset=0xA70
QemuFlashPtr: exit, Ret=FFE0FA70
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1
FtwUpdateFvState: exit @ 824, Status=Success
FtwWriteRecord: exit 5
//
// Restore spare backup buffer into spare block , if no failure happened during FtwWrite.
//
FtwEraseSpareBlock: enter
FvbProtocolEraseBlocks: enter
GetFvbInstance: enter, Instance=0x0, Global=9F7DAF18, Virtual=0
GetFvbInstance: exit @ 229, Status=Success
QemuFlashEraseBlock: enter, Lba=0x10
QemuFlashPtr: enter, Lba=0x10 Offset=0x0
QemuFlashPtr: exit, Ret=FFE10000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x11
QemuFlashPtr: enter, Lba=0x11 Offset=0x0
QemuFlashPtr: exit, Ret=FFE11000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x12
QemuFlashPtr: enter, Lba=0x12 Offset=0x0
QemuFlashPtr: exit, Ret=FFE12000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x13
QemuFlashPtr: enter, Lba=0x13 Offset=0x0
QemuFlashPtr: exit, Ret=FFE13000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x14
QemuFlashPtr: enter, Lba=0x14 Offset=0x0
QemuFlashPtr: exit, Ret=FFE14000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x15
QemuFlashPtr: enter, Lba=0x15 Offset=0x0
QemuFlashPtr: exit, Ret=FFE15000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x16
QemuFlashPtr: enter, Lba=0x16 Offset=0x0
QemuFlashPtr: exit, Ret=FFE16000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x17
QemuFlashPtr: enter, Lba=0x17 Offset=0x0
QemuFlashPtr: exit, Ret=FFE17000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x18
QemuFlashPtr: enter, Lba=0x18 Offset=0x0
QemuFlashPtr: exit, Ret=FFE18000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x19
QemuFlashPtr: enter, Lba=0x19 Offset=0x0
QemuFlashPtr: exit, Ret=FFE19000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x1A
QemuFlashPtr: enter, Lba=0x1A Offset=0x0
QemuFlashPtr: exit, Ret=FFE1A000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x1B
QemuFlashPtr: enter, Lba=0x1B Offset=0x0
QemuFlashPtr: exit, Ret=FFE1B000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x1C
QemuFlashPtr: enter, Lba=0x1C Offset=0x0
QemuFlashPtr: exit, Ret=FFE1C000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x1D
QemuFlashPtr: enter, Lba=0x1D Offset=0x0
QemuFlashPtr: exit, Ret=FFE1D000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x1E
QemuFlashPtr: enter, Lba=0x1E Offset=0x0
QemuFlashPtr: exit, Ret=FFE1E000
QemuFlashEraseBlock: exit 2
QemuFlashEraseBlock: enter, Lba=0x1F
QemuFlashPtr: enter, Lba=0x1F Offset=0x0
QemuFlashPtr: exit, Ret=FFE1F000
QemuFlashEraseBlock: exit 2
FvbProtocolEraseBlocks: exit @ 839, Status=Success
FtwEraseSpareBlock: exit: Success
FvbProtocolWrite: enter, Lba=0x10 Offset=0x0 NumBytes=0x1000 Buffer=9C7F5018
QemuFlashWrite: enter, Lba=0x10 Offset=0x0 NumBytes=0x1000 Buffer=9C7F5018
QemuFlashPtr: enter, Lba=0x10 Offset=0x0
QemuFlashPtr: exit, Ret=FFE10000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x11 Offset=0x0 NumBytes=0x1000 Buffer=9C7F6018
QemuFlashWrite: enter, Lba=0x11 Offset=0x0 NumBytes=0x1000 Buffer=9C7F6018
QemuFlashPtr: enter, Lba=0x11 Offset=0x0
QemuFlashPtr: exit, Ret=FFE11000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x12 Offset=0x0 NumBytes=0x1000 Buffer=9C7F7018
QemuFlashWrite: enter, Lba=0x12 Offset=0x0 NumBytes=0x1000 Buffer=9C7F7018
QemuFlashPtr: enter, Lba=0x12 Offset=0x0
QemuFlashPtr: exit, Ret=FFE12000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x13 Offset=0x0 NumBytes=0x1000 Buffer=9C7F8018
QemuFlashWrite: enter, Lba=0x13 Offset=0x0 NumBytes=0x1000 Buffer=9C7F8018
QemuFlashPtr: enter, Lba=0x13 Offset=0x0
QemuFlashPtr: exit, Ret=FFE13000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x14 Offset=0x0 NumBytes=0x1000 Buffer=9C7F9018
QemuFlashWrite: enter, Lba=0x14 Offset=0x0 NumBytes=0x1000 Buffer=9C7F9018
QemuFlashPtr: enter, Lba=0x14 Offset=0x0
QemuFlashPtr: exit, Ret=FFE14000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x15 Offset=0x0 NumBytes=0x1000 Buffer=9C7FA018
QemuFlashWrite: enter, Lba=0x15 Offset=0x0 NumBytes=0x1000 Buffer=9C7FA018
QemuFlashPtr: enter, Lba=0x15 Offset=0x0
QemuFlashPtr: exit, Ret=FFE15000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x16 Offset=0x0 NumBytes=0x1000 Buffer=9C7FB018
QemuFlashWrite: enter, Lba=0x16 Offset=0x0 NumBytes=0x1000 Buffer=9C7FB018
QemuFlashPtr: enter, Lba=0x16 Offset=0x0
QemuFlashPtr: exit, Ret=FFE16000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x17 Offset=0x0 NumBytes=0x1000 Buffer=9C7FC018
QemuFlashWrite: enter, Lba=0x17 Offset=0x0 NumBytes=0x1000 Buffer=9C7FC018
QemuFlashPtr: enter, Lba=0x17 Offset=0x0
QemuFlashPtr: exit, Ret=FFE17000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x18 Offset=0x0 NumBytes=0x1000 Buffer=9C7FD018
QemuFlashWrite: enter, Lba=0x18 Offset=0x0 NumBytes=0x1000 Buffer=9C7FD018
QemuFlashPtr: enter, Lba=0x18 Offset=0x0
QemuFlashPtr: exit, Ret=FFE18000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x19 Offset=0x0 NumBytes=0x1000 Buffer=9C7FE018
QemuFlashWrite: enter, Lba=0x19 Offset=0x0 NumBytes=0x1000 Buffer=9C7FE018
QemuFlashPtr: enter, Lba=0x19 Offset=0x0
QemuFlashPtr: exit, Ret=FFE19000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x1A Offset=0x0 NumBytes=0x1000 Buffer=9C7FF018
QemuFlashWrite: enter, Lba=0x1A Offset=0x0 NumBytes=0x1000 Buffer=9C7FF018
QemuFlashPtr: enter, Lba=0x1A Offset=0x0
QemuFlashPtr: exit, Ret=FFE1A000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x1B Offset=0x0 NumBytes=0x1000 Buffer=9C800018
QemuFlashWrite: enter, Lba=0x1B Offset=0x0 NumBytes=0x1000 Buffer=9C800018
QemuFlashPtr: enter, Lba=0x1B Offset=0x0
QemuFlashPtr: exit, Ret=FFE1B000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x1C Offset=0x0 NumBytes=0x1000 Buffer=9C801018
QemuFlashWrite: enter, Lba=0x1C Offset=0x0 NumBytes=0x1000 Buffer=9C801018
QemuFlashPtr: enter, Lba=0x1C Offset=0x0
QemuFlashPtr: exit, Ret=FFE1C000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x1D Offset=0x0 NumBytes=0x1000 Buffer=9C802018
QemuFlashWrite: enter, Lba=0x1D Offset=0x0 NumBytes=0x1000 Buffer=9C802018
QemuFlashPtr: enter, Lba=0x1D Offset=0x0
QemuFlashPtr: exit, Ret=FFE1D000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
FvbProtocolWrite: enter, Lba=0x1E Offset=0x0 NumBytes=0x1000 Buffer=9C803018
QemuFlashWrite: enter, Lba=0x1E Offset=0x0 NumBytes=0x1000 Buffer=9C803018
QemuFlashPtr: enter, Lba=0x1E Offset=0x0
QemuFlashPtr: exit, Ret=FFE1E000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
!!! out-of-varstore write !!!
FvbProtocolWrite: enter, Lba=0x1F Offset=0x0 NumBytes=0x1000 Buffer=9C804018
QemuFlashWrite: enter, Lba=0x1F Offset=0x0 NumBytes=0x1000 Buffer=9C804018
QemuFlashPtr: enter, Lba=0x1F Offset=0x0
QemuFlashPtr: exit, Ret=FFE1F000
QemuFlashWrite: exit 2
FvbProtocolWrite: exit @ 891, Status=Success, NumBytes=0x1000
//
// All success.
//
Ftw: Write() success, (Lba:Offset)=(0:0x48), Length: 0xDFB8
FtwWrite: exit 20
FtwVariableSpace: exit @ 167, Status=Success
^ permalink raw reply related [flat|nested] 7+ messages in thread
* Re: [edk2-devel] [PATCH v2 1/1] OvmfPkg/VirtNorFlashDxe: sanity-check variables
2023-12-11 23:25 ` Laszlo Ersek
@ 2023-12-14 15:31 ` Gerd Hoffmann
2023-12-14 16:18 ` Laszlo Ersek
0 siblings, 1 reply; 7+ messages in thread
From: Gerd Hoffmann @ 2023-12-14 15:31 UTC (permalink / raw)
To: Laszlo Ersek; +Cc: devel, mike.maslenkin, Jiewen Yao, Ard Biesheuvel, oliver
Hi,
> The general idea is, once we don't trust the varstore, there cannot be
> a *single* unchecked addition in the code. (Unless we can *prove* that
> overflow is impossible.)
There are some cases where we add a small, constant number to a value we
know is smaller than VariableStoreHeader->Size. I don't see how those
can overflow, given that varstore flash typically is an order of
magnitude smaller than MAX_UINT32 (unless VariableStoreHeader->Size is
corrupted, but then we have bigger problems anyway ...).
take care,
Gerd
-=-=-=-=-=-=-=-=-=-=-=-
Groups.io Links: You receive all messages sent to this group.
View/Reply Online (#112540): https://edk2.groups.io/g/devel/message/112540
Mute This Topic: https://groups.io/mt/103031342/7686176
Group Owner: devel+owner@edk2.groups.io
Unsubscribe: https://edk2.groups.io/g/devel/unsub [rebecca@openfw.io]
-=-=-=-=-=-=-=-=-=-=-=-
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [edk2-devel] [PATCH v2 1/1] OvmfPkg/VirtNorFlashDxe: sanity-check variables
2023-12-14 15:31 ` Gerd Hoffmann
@ 2023-12-14 16:18 ` Laszlo Ersek
0 siblings, 0 replies; 7+ messages in thread
From: Laszlo Ersek @ 2023-12-14 16:18 UTC (permalink / raw)
To: Gerd Hoffmann; +Cc: devel, mike.maslenkin, Jiewen Yao, Ard Biesheuvel, oliver
On 12/14/23 16:31, Gerd Hoffmann wrote:
> Hi,
>
>> The general idea is, once we don't trust the varstore, there cannot be
>> a *single* unchecked addition in the code. (Unless we can *prove* that
>> overflow is impossible.)
>
> There are some cases where we add a small, constant number to a value we
> know is smaller than VariableStoreHeader->Size. I don't see how those
> can overflow, given that varstore flash typically is an order of
> magnitude smaller than MAX_UINT32
OK. Please add comments about these though, possibly expressed as ASSERT()s.
> (unless VariableStoreHeader->Size is
> corrupted, but then we have bigger problems anyway ...).
Right... I had given some thought to that as well. If there's an easy --
albeit perhaps arbitrary -- range check for that up-front, maybe we
should do it. Maybe.
But I'm certainly not asking for armoring existent code in the affected
function. That's too much work -- ridding all existent code of overflows
is just a special case of eliminating technical debt, and there is
enough technical debt in edk2 to spend a lifetime fixing. The only
reasonable approach I can imagine is to stop introducing technical debt,
or *at least* to fix technical debt at a higher rate than adding it.
(This is no small challenge.)
Thanks,
Laszlo
-=-=-=-=-=-=-=-=-=-=-=-
Groups.io Links: You receive all messages sent to this group.
View/Reply Online (#112545): https://edk2.groups.io/g/devel/message/112545
Mute This Topic: https://groups.io/mt/103031342/7686176
Group Owner: devel+owner@edk2.groups.io
Unsubscribe: https://edk2.groups.io/g/devel/leave/12367111/7686176/1913456212/xyzzy [rebecca@openfw.io]
-=-=-=-=-=-=-=-=-=-=-=-
^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2023-12-14 16:18 UTC | newest]
Thread overview: 7+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2023-12-07 9:44 [edk2-devel] [PATCH v2 1/1] OvmfPkg/VirtNorFlashDxe: sanity-check variables Gerd Hoffmann
2023-12-07 16:16 ` Ard Biesheuvel
2023-12-08 12:04 ` Gerd Hoffmann
2023-12-11 23:37 ` Laszlo Ersek
2023-12-11 23:25 ` Laszlo Ersek
2023-12-14 15:31 ` Gerd Hoffmann
2023-12-14 16:18 ` Laszlo Ersek
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox