Re: [PATCH 1/1] arch/x86: Add better error logging to efi main

Re: [PATCH 1/1] arch/x86: Add better error logging to efi main

[Andre]

Matt Fleming <matt@...> writes:
> 
> On Thu, 10 Jul, at 02:12:41AM, ulf@... wrote:
> >  <at>  <at>  -1376,7 +1376,10  <at>  <at>  struct boot_params *efi_main(struct efi_config *c,
> > 
> >     setup_graphics(boot_params);
> > 
> > -   setup_efi_pci(boot_params);
> > +   status = setup_efi_pci(boot_params);
> > +   if (status != EFI_SUCCESS) {
> > +           efi_printk(sys_table, "setup_efi_pci() failed!\n");
> > +   }
> 
> Actually, it turns out that a lot of people are seeing this error
> message in what would be an otherwise quiet boot,
> 
>   https://bugzilla.kernel.org/show_bug.cgi?id=81891
> 
> Maybe we should distinguish between EFI_PCI_IO_PROTOCOL_GUID not being
> found and all other errors, i.e. memory allocation failure. We obviously
> do want to know if we failed to allocate memory, but we're less bothered
> if we've no PCI devices.
> 
> Something like below? Folks on Cc, could you apply this snippet and see
> whether you're still seeing the error message?
> 

With a Thinkpad T420 (pre-2.0 EFI), I do run into the failure condition for another reason:

setup_efi_pci64 gets called,
the loop therein is executed nr_pci=11 (!?) times.
The second call run calls into __setup_efi_pci64 successfully, the memcpy takes place; the free_struct: path is not used. Back in setup_efi_pci64, the non-data path is walked.

For all the other 10 runs of the loop, __setup_efi_pci64 fails at
if (!pci->romimage || !pci->romsize)
        return EFI_INVALID_PARAMETER;
so that is the status here for any run but the second.

So here, I can work around the message by accepting the EFI_INVALID_PARAMETER condition. 
Also, I can work around that by adding break; to the end of the loop in setup_efi_pci64, as it only gets to the end in the successful case. But I guess other machines require to loop successfully through this more than once?

Regards,
Andre Müller

Re: [PATCH 1/1] arch/x86: Add better error logging to efi main

[Andre]

On Sat, 6 Sep 2014 23:02:51 +0200
Andre <andre.muller-S0/GAf8tV78@public.gmane.org> wrote:
> With a Thinkpad T420 (pre-2.0 EFI), I do run into the failure condition for another reason:
> 
> setup_efi_pci64 gets called,
> the loop therein is executed nr_pci=11 (!?) times.
> The second call run calls into __setup_efi_pci64 successfully, the memcpy takes place; the free_struct: path is not used. Back in setup_efi_pci64, the non-data path is walked.
> 
> For all the other 10 runs of the loop, __setup_efi_pci64 fails at
> if (!pci->romimage || !pci->romsize)
>         return EFI_INVALID_PARAMETER;
> so that is the status here for any run but the second.

Following up with code...

If it is OK to just leave the loop in setup_efi_pci64,
this can be done simply by

--- arch/x86/boot/compressed/eboot.c	2014-09-07 01:54:41.761008645 +0200
+++ arch/x86/boot/compressed/eboot_break.c	2014-09-07 01:52:06.321004951 +0200
@@ -504,6 +504,7 @@
 			params->hdr.setup_data = (unsigned long)rom;
 
 		data = (struct setup_data *)rom;
+		break;
 
 	}
 
But I've got severe doubts about this.

A solution limited to this particular failure mode
could look like the below. It has all the charm of 
introducing a helper var. Hmpf.

--- arch/x86/boot/compressed/eboot.c	2014-09-07 01:54:41.761008645 +0200
+++ arch/x86/boot/compressed/eboot_preserve.c	2014-09-07 01:56:18.529010945 +0200
@@ -474,6 +474,7 @@
 	unsigned long nr_pci;
 	struct setup_data *data;
 	int i;
+	int setup_pci_worked_once = 0;
 
 	data = (struct setup_data *)(unsigned long)params->hdr.setup_data;
 
@@ -495,7 +496,13 @@
 			continue;
 
 		status = __setup_efi_pci64(pci, &rom);
-		if (status != EFI_SUCCESS)
+		if (status == EFI_SUCCESS)
+			setup_pci_worked_once = 1;
+		else if (status == EFI_INVALID_PARAMETER && setup_pci_worked_once == 1 && i == nr_pci - 1) {
+			status = EFI_SUCCESS;
+			continue;
+		}
+		else if (status != EFI_SUCCESS)
 			continue;
 
 		if (data)



Regards,
Andre 

Re: [PATCH 1/1] arch/x86: Add better error logging to efi main

[Matt Fleming]

On Sun, 07 Sep, at 02:11:33AM, Andre wrote:
> On Sat, 6 Sep 2014 23:02:51 +0200
> Andre <andre.muller-S0/GAf8tV78@public.gmane.org> wrote:
> > With a Thinkpad T420 (pre-2.0 EFI), I do run into the failure condition for another reason:
> > 
> > setup_efi_pci64 gets called,
> > the loop therein is executed nr_pci=11 (!?) times.
> > The second call run calls into __setup_efi_pci64 successfully, the memcpy takes place; the free_struct: path is not used. Back in setup_efi_pci64, the non-data path is walked.
> > 
> > For all the other 10 runs of the loop, __setup_efi_pci64 fails at
> > if (!pci->romimage || !pci->romsize)
> >         return EFI_INVALID_PARAMETER;
> > so that is the status here for any run but the second.

Thanks for doing the analysis.
 
> Following up with code...
> 
> If it is OK to just leave the loop in setup_efi_pci64,
> this can be done simply by
> 
> --- arch/x86/boot/compressed/eboot.c	2014-09-07 01:54:41.761008645 +0200
> +++ arch/x86/boot/compressed/eboot_break.c	2014-09-07 01:52:06.321004951 +0200
> @@ -504,6 +504,7 @@
>  			params->hdr.setup_data = (unsigned long)rom;
>  
>  		data = (struct setup_data *)rom;
> +		break;
>  
>  	}
>  
> But I've got severe doubts about this.
 
Right, we can't do this because we want to add all the PCI devices that
we can find with EFI, not just the first one.

> A solution limited to this particular failure mode
> could look like the below. It has all the charm of 
> introducing a helper var. Hmpf.
> 
> --- arch/x86/boot/compressed/eboot.c	2014-09-07 01:54:41.761008645 +0200
> +++ arch/x86/boot/compressed/eboot_preserve.c	2014-09-07 01:56:18.529010945 +0200
> @@ -474,6 +474,7 @@
>  	unsigned long nr_pci;
>  	struct setup_data *data;
>  	int i;
> +	int setup_pci_worked_once = 0;
>  
>  	data = (struct setup_data *)(unsigned long)params->hdr.setup_data;
>  
> @@ -495,7 +496,13 @@
>  			continue;
>  
>  		status = __setup_efi_pci64(pci, &rom);
> -		if (status != EFI_SUCCESS)
> +		if (status == EFI_SUCCESS)
> +			setup_pci_worked_once = 1;
> +		else if (status == EFI_INVALID_PARAMETER && setup_pci_worked_once == 1 && i == nr_pci - 1) {
> +			status = EFI_SUCCESS;
> +			continue;
> +		}
> +		else if (status != EFI_SUCCESS)
>  			continue;
>  
>  		if (data)

The code is generally fine as-is. Where I think we could improve things
is by adding efi_printk() message in certain error paths. Clearly, not
all error paths need such messages, e.g. the EFI_INVALID_PARAMETER path
you highlighted above, but it makes sense for memory allocation and PCI
read failures.

Care to take a whack at that?

-- 
Matt Fleming, Intel Open Source Technology Center

Re: [PATCH 1/1] arch/x86: Add better error logging to efi main

[Andre]

On Mon, 8 Sep 2014 22:18:56 +0100 Matt Fleming <matt-HNK1S37rvNbeXh+fF434Mdi2O/JbrIOy@public.gmane.org> wrote:
> On Sun, 07 Sep, at 02:11:33AM, Andre wrote:
> > On Sat, 6 Sep 2014 23:02:51 +0200
> > Andre <andre.muller-S0/GAf8tV78@public.gmane.org> wrote:
> > > With a Thinkpad T420 (pre-2.0 EFI), I do run into the failure condition for another reason:
> > > 
> > > setup_efi_pci64 gets called,
> > > the loop therein is executed nr_pci=11 (!?) times.
> > > The second call run calls into __setup_efi_pci64 successfully, the memcpy takes place; the free_struct: path is not used. Back in setup_efi_pci64, the non-data path is walked.
> > > 
> > > For all the other 10 runs of the loop, __setup_efi_pci64 fails at
> > > if (!pci->romimage || !pci->romsize)
> > >         return EFI_INVALID_PARAMETER;
> > > so that is the status here for any run but the second.
> 
> Thanks for doing the analysis.
>  
> > Following up with code...
> > 
> > If it is OK to just leave the loop in setup_efi_pci64,
> > this can be done simply by
> > 
> > --- arch/x86/boot/compressed/eboot.c	2014-09-07 01:54:41.761008645 +0200
> > +++ arch/x86/boot/compressed/eboot_break.c	2014-09-07 01:52:06.321004951 +0200
> > @@ -504,6 +504,7 @@
> >  			params->hdr.setup_data = (unsigned long)rom;
> >  
> >  		data = (struct setup_data *)rom;
> > +		break;
> >  
> >  	}
> >  
> > But I've got severe doubts about this.
>  
> Right, we can't do this because we want to add all the PCI devices that
> we can find with EFI, not just the first one.
> 

Yes, I expected that to be by design, 
but I'm basically clueless as to the big picture.

> > A solution limited to this particular failure mode
> > could look like the below. It has all the charm of 
> > introducing a helper var. Hmpf.
[Embarrassing Code]
> 
> The code is generally fine as-is. 

Thanks, but no it's not, it's too ugly to live; a severe case of debugging stupor. That code should rather look like this:


--- arch/x86/boot/compressed/eboot.c	2014-09-07 10:37:47.686001561 +0200
+++ arch/x86/boot/compressed/eboot.c	2014-09-07 11:31:38.233078339 +0200
@@ -474,6 +474,7 @@
 	unsigned long nr_pci;
 	struct setup_data *data;
 	int i;
+	int setup_pci_worked_once = 0;
 
 	data = (struct setup_data *)(unsigned long)params->hdr.setup_data;
 
@@ -498,6 +499,8 @@
 		if (status != EFI_SUCCESS)
 			continue;
 
+		setup_pci_worked_once = 1;
+
 		if (data)
 			data->next = (unsigned long)rom;
 		else
@@ -507,6 +510,8 @@
 
 	}
 
+	if (status == EFI_INVALID_PARAMETER && setup_pci_worked_once == 1)
+		status = EFI_SUCCESS;
 	return status;
 }
 

> Where I think we could improve things
> is by adding efi_printk() message in certain error paths. Clearly, not
> all error paths need such messages, e.g. the EFI_INVALID_PARAMETER path
> you highlighted above, but it makes sense for memory allocation and PCI
> read failures.
> 
> Care to take a whack at that?

I gave it a try, will post as a follow-up. The patch adds printks to 
non-success conditions for all pci.read instances and all allocate_pool 
instances within the scope of setup_efi_pci(). 

There are two calls left in the setup_graphics path, one for gop and one 
for uga. Does it make sense to add printks there as well? They won't 
display properly, I guess :-) Also, uga is called as a fallback when 
gop fails. So the uga failure would be the lost final straw to be noisy 
about? 

One more question: In the patch above, I added a helper to print a 
failure only if the __setup_efi_pci64() never succeeded. That's not 
really needed, is it? Because then, the check for setup_efi_pci success, 
the overly noisy bit of Ulf's patch, could go away again, and both your 
and my EFI_SUCCESS tweaks are not needed anymore. 

Thursday ff, I will be offline for a week. I'll happily follow up 
afterwards, but also feel free to run with the bits you see fit.

Regards,
Andre

[RFC] [PATCH] x86/efi: Adding efi_printks on memory allocationa and pci.reads

[Andre]

All other calls to allocate memory seem to make some noise already, with the
exception of two calls (for gop, uga) in the setup_graphics path.

The purpose is to be noisy on worrysome errors immediately.

> commit fb86b2440de0ec10fe0272eb19d262ae7a01adb8
> Author: Ulf Winkelvos <ulf-rS3t9PEbhQ0OIzVOb1FTxg@public.gmane.org>
> Date:   Thu Jul 10 02:12:41 2014 +0200
>
>     x86/efi: Add better error logging to EFI boot stub

introduces printing false alarms for lots of hardware. Rather than playing
Whack a Mole with non-fatal exit conditions, try the other way round.

This is per Matt Fleming's suggestion:

> Where I think we could improve things
> is by adding efi_printk() message in certain error paths. Clearly, not
> all error paths need such messages, e.g. the EFI_INVALID_PARAMETER path
> you highlighted above, but it makes sense for memory allocation and PCI
> read failures.

http://article.gmane.org/gmane.linux.kernel.efi/4628

After this, the status check on the setup_efi_pci() function
can go away again.

Signed-off-by: Andre Müller <andre.muller-S0/GAf8tV78@public.gmane.org>
---
 arch/x86/boot/compressed/eboot.c | 29 ++++++++++++++++++++++-------
 1 file changed, 22 insertions(+), 7 deletions(-)

diff --git a/arch/x86/boot/compressed/eboot.c b/arch/x86/boot/compressed/eboot.c
index f277184..f296ee9 100644
--- a/arch/x86/boot/compressed/eboot.c
+++ b/arch/x86/boot/compressed/eboot.c
@@ -323,8 +323,10 @@ __setup_efi_pci32(efi_pci_io_protocol_32 *pci, struct pci_setup_rom **__rom)
 	size = pci->romsize + sizeof(*rom);
 
 	status = efi_call_early(allocate_pool, EFI_LOADER_DATA, size, &rom);
-	if (status != EFI_SUCCESS)
+	if (status != EFI_SUCCESS) {
+		efi_printk(sys_table, "Failed to alloc mem for rom\n");
 		return status;
+	}	
 
 	memset(rom, 0, sizeof(*rom));
 
@@ -337,14 +339,18 @@ __setup_efi_pci32(efi_pci_io_protocol_32 *pci, struct pci_setup_rom **__rom)
 	status = efi_early->call(pci->pci.read, pci, EfiPciIoWidthUint16,
 				 PCI_VENDOR_ID, 1, &(rom->vendor));
 
-	if (status != EFI_SUCCESS)
+	if (status != EFI_SUCCESS) {
+		efi_printk(sys_table, "Failed to read rom->vendor\n");
 		goto free_struct;
+	}
 
 	status = efi_early->call(pci->pci.read, pci, EfiPciIoWidthUint16,
 				 PCI_DEVICE_ID, 1, &(rom->devid));
 
-	if (status != EFI_SUCCESS)
+	if (status != EFI_SUCCESS) {
+		efi_printk(sys_table, "Failed to read rom->devid\n");
 		goto free_struct;
+	}
 
 	status = efi_early->call(pci->get_location, pci, &(rom->segment),
 				 &(rom->bus), &(rom->device), &(rom->function));
@@ -427,8 +433,10 @@ __setup_efi_pci64(efi_pci_io_protocol_64 *pci, struct pci_setup_rom **__rom)
 	size = pci->romsize + sizeof(*rom);
 
 	status = efi_call_early(allocate_pool, EFI_LOADER_DATA, size, &rom);
-	if (status != EFI_SUCCESS)
+	if (status != EFI_SUCCESS) {
+		efi_printk(sys_table, "Failed to alloc mem for rom\n");
 		return status;
+	}
 
 	rom->data.type = SETUP_PCI;
 	rom->data.len = size - sizeof(struct setup_data);
@@ -439,14 +447,18 @@ __setup_efi_pci64(efi_pci_io_protocol_64 *pci, struct pci_setup_rom **__rom)
 	status = efi_early->call(pci->pci.read, pci, EfiPciIoWidthUint16,
 				 PCI_VENDOR_ID, 1, &(rom->vendor));
 
-	if (status != EFI_SUCCESS)
+	if (status != EFI_SUCCESS) {
+		efi_printk(sys_table, "Failed to read rom->vendor\n");
 		goto free_struct;
+	}
 
 	status = efi_early->call(pci->pci.read, pci, EfiPciIoWidthUint16,
 				 PCI_DEVICE_ID, 1, &(rom->devid));
 
-	if (status != EFI_SUCCESS)
+	if (status != EFI_SUCCESS) {
+		efi_printk(sys_table, "Failed to read rom->devid\n");
 		goto free_struct;
+	}
 
 	status = efi_early->call(pci->get_location, pci, &(rom->segment),
 				 &(rom->bus), &(rom->device), &(rom->function));
@@ -526,8 +538,10 @@ static efi_status_t setup_efi_pci(struct boot_params *params)
 					EFI_LOADER_DATA,
 					size, (void **)&pci_handle);
 
-		if (status != EFI_SUCCESS)
+		if (status != EFI_SUCCESS) {
+			efi_printk(sys_table, "Failed to alloc mem for pci_handle\n");
 			return status;
+		}
 
 		status = efi_call_early(locate_handle,
 					EFI_LOCATE_BY_PROTOCOL, &pci_proto,
-- 
1.8.5.5

Re: [RFC] [PATCH] x86/efi: Adding efi_printks on memory allocationa and pci.reads

[Matt Fleming]

On Wed, 10 Sep, at 01:00:22AM, Andre wrote:
> All other calls to allocate memory seem to make some noise already, with the
> exception of two calls (for gop, uga) in the setup_graphics path.
> 
> The purpose is to be noisy on worrysome errors immediately.
> 
> > commit fb86b2440de0ec10fe0272eb19d262ae7a01adb8
> > Author: Ulf Winkelvos <ulf-rS3t9PEbhQ0OIzVOb1FTxg@public.gmane.org>
> > Date:   Thu Jul 10 02:12:41 2014 +0200
> >
> >     x86/efi: Add better error logging to EFI boot stub
> 
> introduces printing false alarms for lots of hardware. Rather than playing
> Whack a Mole with non-fatal exit conditions, try the other way round.
 
The usual way to reference existing commits is to quote the commit sha1
(abbreviated to 12-characters) with the patch subject in parenthesis and
quotes, i.e. commit fb86b2440de0 ("x86/efi: Add better error logging to
EFI boot stub") - I fixed this up.

> This is per Matt Fleming's suggestion:
> 
> > Where I think we could improve things
> > is by adding efi_printk() message in certain error paths. Clearly, not
> > all error paths need such messages, e.g. the EFI_INVALID_PARAMETER path
> > you highlighted above, but it makes sense for memory allocation and PCI
> > read failures.
> 
> http://article.gmane.org/gmane.linux.kernel.efi/4628
> 
> After this, the status check on the setup_efi_pci() function
> can go away again.
> 
> Signed-off-by: Andre Müller <andre.muller-S0/GAf8tV78@public.gmane.org>
> ---
>  arch/x86/boot/compressed/eboot.c | 29 ++++++++++++++++++++++-------
>  1 file changed, 22 insertions(+), 7 deletions(-)

Patch looks good to me. Applied, thanks!

-- 
Matt Fleming, Intel Open Source Technology Center