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

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

[ulf-rS3t9PEbhQ0OIzVOb1FTxg]

From: Ulf Winkelvos <ulf-rS3t9PEbhQ0OIzVOb1FTxg@public.gmane.org>

Hopefully this will enable us to better debug:
https://bugzilla.kernel.org/show_bug.cgi?id=68761

Signed-off-by: Ulf Winkelvos <ulf-rS3t9PEbhQ0OIzVOb1FTxg@public.gmane.org>
---
 arch/x86/boot/compressed/eboot.c | 14 +++++++++++---
 1 file changed, 11 insertions(+), 3 deletions(-)

diff --git a/arch/x86/boot/compressed/eboot.c b/arch/x86/boot/compressed/eboot.c
index 3b5c66c..f277184 100644
--- a/arch/x86/boot/compressed/eboot.c
+++ b/arch/x86/boot/compressed/eboot.c
@@ -1376,7 +1376,10 @@ 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");
+	}

	status = efi_call_early(allocate_pool, EFI_LOADER_DATA,
				sizeof(*gdt), (void **)&gdt);
@@ -1403,16 +1406,20 @@ struct boot_params *efi_main(struct efi_config *c,
					     hdr->init_size, hdr->init_size,
					     hdr->pref_address,
					     hdr->kernel_alignment);
-		if (status != EFI_SUCCESS)
+		if (status != EFI_SUCCESS) {
+			efi_printk(sys_table, "efi_relocate_kernel() failed!\n");
			goto fail;
+		}

		hdr->pref_address = hdr->code32_start;
		hdr->code32_start = bzimage_addr;
	}

	status = exit_boot(boot_params, handle, is64);
-	if (status != EFI_SUCCESS)
+	if (status != EFI_SUCCESS) {
+		efi_printk(sys_table, "exit_boot() failed!\n");
		goto fail;
+	}

	memset((char *)gdt->address, 0x0, gdt->size);
	desc = (struct desc_struct *)gdt->address;
@@ -1472,5 +1479,6 @@ struct boot_params *efi_main(struct efi_config *c,

	return boot_params;
 fail:
+	efi_printk(sys_table, "efi_main() failed!\n");
	return NULL;
 }
--
2.0.1

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

[Matt Fleming]

On Thu, 10 Jul, at 02:12:41AM, ulf-rS3t9PEbhQ0OIzVOb1FTxg@public.gmane.org wrote:
> From: Ulf Winkelvos <ulf-rS3t9PEbhQ0OIzVOb1FTxg@public.gmane.org>
> 
> Hopefully this will enable us to better debug:
> https://bugzilla.kernel.org/show_bug.cgi?id=68761
> 
> Signed-off-by: Ulf Winkelvos <ulf-rS3t9PEbhQ0OIzVOb1FTxg@public.gmane.org>
> ---
>  arch/x86/boot/compressed/eboot.c | 14 +++++++++++---
>  1 file changed, 11 insertions(+), 3 deletions(-)

Thanks Ulf, applied.

-- 
Matt Fleming, Intel Open Source Technology Center

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

[Matt Fleming]

On Thu, 10 Jul, at 02:12:41AM, ulf-rS3t9PEbhQ0OIzVOb1FTxg@public.gmane.org wrote:
> @@ -1376,7 +1376,10 @@ 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?

---

diff --git a/arch/x86/boot/compressed/eboot.c b/arch/x86/boot/compressed/eboot.c
index f4bdab1dbf66..37743459d089 100644
--- a/arch/x86/boot/compressed/eboot.c
+++ b/arch/x86/boot/compressed/eboot.c
@@ -534,8 +534,15 @@ static efi_status_t setup_efi_pci(struct boot_params *params)
 					NULL, &size, pci_handle);
 	}
 
-	if (status != EFI_SUCCESS)
+	if (status != EFI_SUCCESS) {
+		/*
+		 * We must have encountered a non-fatal error condition,
+		 * such as being unable to locate pci_proto. Return, but
+		 * don't report an error.
+		 */
+		status = EFI_SUCCESS;
 		goto free_handle;
+	}
 
 	if (efi_early->is64)
 		status = setup_efi_pci64(params, pci_handle, size);

-- 
Matt Fleming, Intel Open Source Technology Center

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

[Ulf Winkelvos]

> On August 13, 2014 at 7:56 PM Matt Fleming <matt-HNK1S37rvNbeXh+fF434Mdi2O/JbrIOy@public.gmane.org> wrote:
> 
> 
> On Thu, 10 Jul, at 02:12:41AM, ulf-rS3t9PEbhQ0OIzVOb1FTxg@public.gmane.org wrote:
> > @@ -1376,7 +1376,10 @@ 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?
> 
> ---
> 
> diff --git a/arch/x86/boot/compressed/eboot.c
> b/arch/x86/boot/compressed/eboot.c
> index f4bdab1dbf66..37743459d089 100644
> --- a/arch/x86/boot/compressed/eboot.c
> +++ b/arch/x86/boot/compressed/eboot.c
> @@ -534,8 +534,15 @@ static efi_status_t setup_efi_pci(struct boot_params
> *params)
>  					NULL, &size, pci_handle);
>  	}
> 
> -	if (status != EFI_SUCCESS)
> +	if (status != EFI_SUCCESS) {
> +		/*
> +		 * We must have encountered a non-fatal error condition,
> +		 * such as being unable to locate pci_proto. Return, but
> +		 * don't report an error.
> +		 */
> +		status = EFI_SUCCESS;
>  		goto free_handle;
> +	}
> 
>  	if (efi_early->is64)
>  		status = setup_efi_pci64(params, pci_handle, size);
> 
> --
> Matt Fleming, Intel Open Source Technology Center

Hi Matt,

still getting ""setup_efi_pci() failed!" on my Dell XPS 13 with that patch. But
so far no bad efi kernel image boot any more since
https://bugzilla.kernel.org/show_bug.cgi?id=68761 has been fixed.

Cheers, Ulf

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