[v2,01/15] genirq/devres: Add error information printing for devm_request_threaded_irq()

Message ID 20230627101215.58798-1-frank.li@vivo.com
State New
Headers
Series [v2,01/15] genirq/devres: Add error information printing for devm_request_threaded_irq() |

Commit Message

李扬韬 June 27, 2023, 10:12 a.m. UTC
  Ensure that all error handling branches print error information. In this
way, when this function fails, the upper-layer functions can directly
return an error code without missing debugging information. Otherwise,
the error message will be printed redundantly or missing.

There are more than 700 calls to the devm_request_threaded_irq method.
Most drivers only request one interrupt resource, and these error
messages are basically the same. If error messages are printed
everywhere, more than 1000 lines of code can be saved by removing the
msg in the driver.

Signed-off-by: Yangtao Li <frank.li@vivo.com>
---
 kernel/irq/devres.c | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)
  

Comments

Krzysztof Kozlowski June 27, 2023, 10:28 a.m. UTC | #1
On 27/06/2023 12:12, Yangtao Li wrote:
> Ensure that all error handling branches print error information. In this
> way, when this function fails, the upper-layer functions can directly
> return an error code without missing debugging information. Otherwise,
> the error message will be printed redundantly or missing.
> 
> There are more than 700 calls to the devm_request_threaded_irq method.
> Most drivers only request one interrupt resource, and these error
> messages are basically the same. If error messages are printed
> everywhere, more than 1000 lines of code can be saved by removing the
> msg in the driver.
> 
> Signed-off-by: Yangtao Li <frank.li@vivo.com>
> ---
>  kernel/irq/devres.c | 5 ++++-
>  1 file changed, 4 insertions(+), 1 deletion(-)
> 
> diff --git a/kernel/irq/devres.c b/kernel/irq/devres.c
> index f6e5515ee077..fcb946ffb7ec 100644
> --- a/kernel/irq/devres.c
> +++ b/kernel/irq/devres.c
> @@ -58,8 +58,10 @@ int devm_request_threaded_irq(struct device *dev, unsigned int irq,
>  
>  	dr = devres_alloc(devm_irq_release, sizeof(struct irq_devres),
>  			  GFP_KERNEL);
> -	if (!dr)
> +	if (!dr) {
> +		dev_err(dev, "Failed to allocate device resource data\n");

I don't understand why did you send v2:
1. Without responding to my comments - either by implementing them or
continuing the discussion
2. Without changelog explaining what happened here

My comments for v1 stand. Please do not ignore them, respond. If sending
new version, then usually one per day is max and of course provide
changelog.

>  		return -ENOMEM;
> +	}
>  
>  	if (!devname)
>  		devname = dev_name(dev);
> @@ -67,6 +69,7 @@ int devm_request_threaded_irq(struct device *dev, unsigned int irq,
>  	rc = request_threaded_irq(irq, handler, thread_fn, irqflags, devname,
>  				  dev_id);
>  	if (rc) {
> +		dev_err_probe(dev, rc, "Failed to request threaded irq%d: %d\n", irq, rc);

Why printing rc twice? Did you test this patch? Does not look like.

Best regards,
Krzysztof
  
Uwe Kleine-König June 27, 2023, 11 a.m. UTC | #2
Hello,

On Tue, Jun 27, 2023 at 06:12:01PM +0800, Yangtao Li wrote:
> Ensure that all error handling branches print error information. In this
> way, when this function fails, the upper-layer functions can directly
> return an error code without missing debugging information. Otherwise,
> the error message will be printed redundantly or missing.
> 
> There are more than 700 calls to the devm_request_threaded_irq method.
> Most drivers only request one interrupt resource, and these error
> messages are basically the same. If error messages are printed
> everywhere, more than 1000 lines of code can be saved by removing the
> msg in the driver.
> 
> Signed-off-by: Yangtao Li <frank.li@vivo.com>
> ---
>  kernel/irq/devres.c | 5 ++++-
>  1 file changed, 4 insertions(+), 1 deletion(-)
> 
> diff --git a/kernel/irq/devres.c b/kernel/irq/devres.c
> index f6e5515ee077..fcb946ffb7ec 100644
> --- a/kernel/irq/devres.c
> +++ b/kernel/irq/devres.c
> @@ -58,8 +58,10 @@ int devm_request_threaded_irq(struct device *dev, unsigned int irq,
>  
>  	dr = devres_alloc(devm_irq_release, sizeof(struct irq_devres),
>  			  GFP_KERNEL);
> -	if (!dr)
> +	if (!dr) {
> +		dev_err(dev, "Failed to allocate device resource data\n");
>  		return -ENOMEM;
> +	}
>  
>  	if (!devname)
>  		devname = dev_name(dev);
> @@ -67,6 +69,7 @@ int devm_request_threaded_irq(struct device *dev, unsigned int irq,
>  	rc = request_threaded_irq(irq, handler, thread_fn, irqflags, devname,
>  				  dev_id);
>  	if (rc) {
> +		dev_err_probe(dev, rc, "Failed to request threaded irq%d: %d\n", irq, rc);

This changes semantics because dev_err_probe() is only supposed to be
called in probe functions. Not sure about devm_request_threaded_irq, but
its friend request_irq is called in the setup_irq (or open IIRC)
callback of serial drivers.

While I assume changing to dev_err_probe is a result of my concern that
no error should be printed when rc=-EPROBEDEFER, my other concern that
adding an error message to a generic allocation function is a bad idea
still stands.

Best regards
Uwe
  
Thomas Gleixner June 30, 2023, 11:11 a.m. UTC | #3
On Tue, Jun 27 2023 at 13:00, Uwe Kleine-König wrote:
> On Tue, Jun 27, 2023 at 06:12:01PM +0800, Yangtao Li wrote:
>
> While I assume changing to dev_err_probe is a result of my concern that
> no error should be printed when rc=-EPROBEDEFER, my other concern that
> adding an error message to a generic allocation function is a bad idea
> still stands.

I agree in general, but if you actually look at the call sites of
devm_request_threaded_irq() then the vast majority of them print more or
less lousy error messages. A quick grep/sed/awk/sort/uniq revealed

     519 messages total (there are probably more)

     352 unique messages

     323 unique messages after lower casing

         Those 323 are mostly just variants of the same patterns with slight
         modifications in formatting and information provided.

     186 of these messages do not deliver any useful information,
         e.g. "no irq", "

     The most useful one of all is: "could request wakeup irq: %d"

So there is certainly an argument to be made that this particular
function should print a well formatted and informative error message.

It's not a general allocator like kmalloc(). It's specialized and in the
vast majority of cases failing to request the interrupt causes the
device probe to fail. So having proper and consistent information why
the device cannot be used _is_ useful.

Yangtao: The way how this is attempted is not useful at all.

    1) The changelog is word salad and provides 0 rationale

       Also such series require a cover letter...

    2) The dev_err() which is added is not informative at all and cannot
       replace actually useful error messages. It's not that hard to
       make it useful.

    2) Adding the printks unconditionally first will emit two messages
       with different content.

       This is not how such changes are done.

       The proper approach is to create a wrapper function which emits
       the error message:

       wrapper(....., const char *info)
       {
            ret = devm_request_threaded_irq(....);
            if (ret < 0) {
               dev_err(dev, "Failed to request %sinterrupt %u %s %s: %d\n,
                       thread_fn ? "threaded " : "",
                       irq, devname, info ? : "", ret);
            }
            return ret;
       }

       Then convert the callsites over one by one with proper
       changelogs and justification.

       See?

Thanks,

        tglx
  
李扬韬 July 3, 2023, 9:13 a.m. UTC | #4
Hi,

On 2023/6/30 19:11, Thomas Gleixner wrote:
> On Tue, Jun 27 2023 at 13:00, Uwe Kleine-König wrote:
>> On Tue, Jun 27, 2023 at 06:12:01PM +0800, Yangtao Li wrote:
>>
>> While I assume changing to dev_err_probe is a result of my concern that
>> no error should be printed when rc=-EPROBEDEFER, my other concern that
>> adding an error message to a generic allocation function is a bad idea
>> still stands.
> I agree in general, but if you actually look at the call sites of
> devm_request_threaded_irq() then the vast majority of them print more or
> less lousy error messages. A quick grep/sed/awk/sort/uniq revealed
>
>       519 messages total (there are probably more)
>
>       352 unique messages
>
>       323 unique messages after lower casing
>
>           Those 323 are mostly just variants of the same patterns with slight
>           modifications in formatting and information provided.
>
>       186 of these messages do not deliver any useful information,
>           e.g. "no irq", "
>
>       The most useful one of all is: "could request wakeup irq: %d"
>
> So there is certainly an argument to be made that this particular
> function should print a well formatted and informative error message.
>
> It's not a general allocator like kmalloc(). It's specialized and in the
> vast majority of cases failing to request the interrupt causes the
> device probe to fail. So having proper and consistent information why
> the device cannot be used _is_ useful.
>
> Yangtao: The way how this is attempted is not useful at all.
>
>      1) The changelog is word salad and provides 0 rationale
>
>         Also such series require a cover letter...
>
>      2) The dev_err() which is added is not informative at all and cannot
>         replace actually useful error messages. It's not that hard to
>         make it useful.
>
>      2) Adding the printks unconditionally first will emit two messages
>         with different content.
>
>         This is not how such changes are done.
>
>         The proper approach is to create a wrapper function which emits
>         the error message:
>
>         wrapper(....., const char *info)
>         {
>              ret = devm_request_threaded_irq(....);
>              if (ret < 0) {
>                 dev_err(dev, "Failed to request %sinterrupt %u %s %s: %d\n,
>                         thread_fn ? "threaded " : "",
>                         irq, devname, info ? : "", ret);
>              }
>              return ret;
>         }
>
>         Then convert the callsites over one by one with proper
>         changelogs and justification.
>
>         See?


Yes, thanks a lot for the suggestion, and v3 has been sent.


MBR,

Yangtao


>
> Thanks,
>
>          tglx
  
Uwe Kleine-König July 3, 2023, 9:53 a.m. UTC | #5
Hello,

On Mon, Jul 03, 2023 at 05:13:29PM +0800, Yangtao Li wrote:
> [...] v3 has been sent.

Please make sure that you send a v3 patch series (at least) to the
people who gave you feedback for v2. If you skip people who had general
concerns about the whole series, this might help you in the short run
because they might miss to also criticise v3, but in the long run it
might result in a loss of trust in you.

Best regards
Uwe
  
李扬韬 July 3, 2023, 11:37 a.m. UTC | #6
Hi Uwe,

On 2023/7/3 17:53, Uwe Kleine-König wrote:
> Hello,
>
> On Mon, Jul 03, 2023 at 05:13:29PM +0800, Yangtao Li wrote:
>> [...] v3 has been sent.
> Please make sure that you send a v3 patch series (at least) to the
> people who gave you feedback for v2. If you skip people who had general
> concerns about the whole series, this might help you in the short run
> because they might miss to also criticise v3, but in the long run it
> might result in a loss of trust in you.


Sorry, I'm a little busy. I just added you and Krzysztof Kozlowski in v3.

If others are interested in the follow-up series, please refer to the 
following link:


https://lore.kernel.org/lkml/20230703090455.62101-1-frank.li@vivo.com/


Thx,

Yangtao


>
> Best regards
> Uwe
>
  
李扬韬 July 3, 2023, 12:15 p.m. UTC | #7
Hi Krzysztof,

Here. V3 was modified according to tglx's suggestion, if there is any problem, please point out.

Thx,
Yangtao
  
李扬韬 July 3, 2023, 12:19 p.m. UTC | #8
+cc krzysztof.kozlowski@linaro.org
  
Krzysztof Kozlowski July 3, 2023, 12:28 p.m. UTC | #9
On 03/07/2023 13:54, Yangtao Li wrote:
> Hi Krzysztof,
> 
> On 2023/6/30 19:11, Thomas Gleixner wrote:
>> On Tue, Jun 27 2023 at 13:00, Uwe Kleine-König wrote:
>>> On Tue, Jun 27, 2023 at 06:12:01PM +0800, Yangtao Li wrote:
>>>
>>> While I assume changing to dev_err_probe is a result of my concern that
>>> no error should be printed when rc=-EPROBEDEFER, my other concern that
>>> adding an error message to a generic allocation function is a bad idea
>>> still stands.
>> I agree in general, but if you actually look at the call sites of
>> devm_request_threaded_irq() then the vast majority of them print more or
>> less lousy error messages. A quick grep/sed/awk/sort/uniq revealed
>>
>>       519 messages total (there are probably more)
>>
>>       352 unique messages
>>
>>       323 unique messages after lower casing
>>
>>           Those 323 are mostly just variants of the same patterns with slight
>>           modifications in formatting and information provided.
>>
>>       186 of these messages do not deliver any useful information,
>>           e.g. "no irq", "
>>
>>       The most useful one of all is: "could request wakeup irq: %d"
>>
>> So there is certainly an argument to be made that this particular
>> function should print a well formatted and informative error message.
>>
>> It's not a general allocator like kmalloc(). It's specialized and in the
>> vast majority of cases failing to request the interrupt causes the
>> device probe to fail. So having proper and consistent information why
>> the device cannot be used _is_ useful.
>>
>> Yangtao: The way how this is attempted is not useful at all.
>>
>>      1) The changelog is word salad and provides 0 rationale
>>
>>         Also such series require a cover letter...
>>
>>      2) The dev_err() which is added is not informative at all and cannot
>>         replace actually useful error messages. It's not that hard to
>>         make it useful.
>>
>>      2) Adding the printks unconditionally first will emit two messages
>>         with different content.
>>
>>         This is not how such changes are done.
>>
>>         The proper approach is to create a wrapper function which emits
>>         the error message:
>>
>>         wrapper(....., const char *info)
>>         {
>>              ret = devm_request_threaded_irq(....);
>>              if (ret < 0) {
>>                 dev_err(dev, "Failed to request %sinterrupt %u %s %s: %d\n,
>>                         thread_fn ? "threaded " : "",
>>                         irq, devname, info ? : "", ret);
>>              }
>>              return ret;
>>         }
> 
> 
> Here.
> 
> V3 was modified according to tglx's suggestion, if there is any problem, 
> please point out.

The comment was about request_thread_irq, not about devres alloc. Don't
mix the places. Really, since when do we print any errors on ENOMEM?

Best regards,
Krzysztof
  
Ahmad Fatoum July 3, 2023, 4:07 p.m. UTC | #10
On 27.06.23 12:12, Yangtao Li wrote:
> Ensure that all error handling branches print error information. In this
> way, when this function fails, the upper-layer functions can directly
> return an error code without missing debugging information. Otherwise,
> the error message will be printed redundantly or missing.
> 
> There are more than 700 calls to the devm_request_threaded_irq method.
> Most drivers only request one interrupt resource, and these error
> messages are basically the same. If error messages are printed
> everywhere, more than 1000 lines of code can be saved by removing the
> msg in the driver.
> 
> Signed-off-by: Yangtao Li <frank.li@vivo.com>
> ---
>  kernel/irq/devres.c | 5 ++++-
>  1 file changed, 4 insertions(+), 1 deletion(-)
> 
> diff --git a/kernel/irq/devres.c b/kernel/irq/devres.c
> index f6e5515ee077..fcb946ffb7ec 100644
> --- a/kernel/irq/devres.c
> +++ b/kernel/irq/devres.c
> @@ -58,8 +58,10 @@ int devm_request_threaded_irq(struct device *dev, unsigned int irq,
>  
>  	dr = devres_alloc(devm_irq_release, sizeof(struct irq_devres),
>  			  GFP_KERNEL);
> -	if (!dr)
> +	if (!dr) {
> +		dev_err(dev, "Failed to allocate device resource data\n");

Why not use dev_err_probe too? Could turn this block into a oneliner.

>  		return -ENOMEM;
> +	}
>  
>  	if (!devname)
>  		devname = dev_name(dev);
> @@ -67,6 +69,7 @@ int devm_request_threaded_irq(struct device *dev, unsigned int irq,
>  	rc = request_threaded_irq(irq, handler, thread_fn, irqflags, devname,
>  				  dev_id);
>  	if (rc) {
> +		dev_err_probe(dev, rc, "Failed to request threaded irq%d: %d\n", irq, rc);

No need to format rc with %d. dev_err_probe will already do this for you.

>  		devres_free(dr);
>  		return rc;
>  	}
  

Patch

diff --git a/kernel/irq/devres.c b/kernel/irq/devres.c
index f6e5515ee077..fcb946ffb7ec 100644
--- a/kernel/irq/devres.c
+++ b/kernel/irq/devres.c
@@ -58,8 +58,10 @@  int devm_request_threaded_irq(struct device *dev, unsigned int irq,
 
 	dr = devres_alloc(devm_irq_release, sizeof(struct irq_devres),
 			  GFP_KERNEL);
-	if (!dr)
+	if (!dr) {
+		dev_err(dev, "Failed to allocate device resource data\n");
 		return -ENOMEM;
+	}
 
 	if (!devname)
 		devname = dev_name(dev);
@@ -67,6 +69,7 @@  int devm_request_threaded_irq(struct device *dev, unsigned int irq,
 	rc = request_threaded_irq(irq, handler, thread_fn, irqflags, devname,
 				  dev_id);
 	if (rc) {
+		dev_err_probe(dev, rc, "Failed to request threaded irq%d: %d\n", irq, rc);
 		devres_free(dr);
 		return rc;
 	}