[v3,5/8] PCI/AER: Introduce ratelimit for error logs

Commit Message

Jon Pan-Doh March 19, 2025, 8:40 a.m. UTC

Spammy devices can flood kernel logs with AER errors and slow/stall
execution. Add per-device ratelimits for AER correctable and uncorrectable
errors that use the kernel defaults (10 per 5s).

Tested using aer-inject[1]. Sent 11 AER errors. Observed 10 errors logged
while AER stats (cat /sys/bus/pci/devices/<dev>/aer_dev_correctable) show
true count of 11.

[1] https://git.kernel.org/pub/scm/linux/kernel/git/gong.chen/aer-inject.git

Signed-off-by: Jon Pan-Doh <[e-mail]>
Reviewed-by: Karolina Stolarek <[e-mail]>
---
 drivers/pci/pcie/aer.c | 76 +++++++++++++++++++++++++++++++++---------
 1 file changed, 61 insertions(+), 15 deletions(-)

Comments

Bjorn Helgaas March 19, 2025, 6:47 p.m. UTC | #1

On Wed, Mar 19, 2025 at 01:40:46AM -0700, Jon Pan-Doh wrote:
> Spammy devices can flood kernel logs with AER errors and slow/stall
> execution. Add per-device ratelimits for AER correctable and uncorrectable
> errors that use the kernel defaults (10 per 5s).
> 
> Tested using aer-inject[1]. Sent 11 AER errors. Observed 10 errors logged
> while AER stats (cat /sys/bus/pci/devices/<dev>/aer_dev_correctable) show
> true count of 11.

I think this is really on the right track.  A few minor comments
below.

> @@ -697,6 +711,7 @@ void aer_print_error(struct pci_dev *dev, struct aer_err_info *info,
>  {
>  	int layer, agent;
>  	int id = pci_dev_id(dev);
> +	struct ratelimit_state *ratelimit;
>  
>  	if (!info->status) {
>  		pci_err(dev, "PCIe Bus Error: severity=%s, type=Inaccessible, (Unregistered Agent ID)\n",
> @@ -704,6 +719,17 @@ void aer_print_error(struct pci_dev *dev, struct aer_err_info *info,
>  		goto out;
>  	}
>  
> +	if (info->severity == AER_CORRECTABLE)
> +		ratelimit = &dev->aer_report->cor_log_ratelimit;
> +	else
> +		ratelimit = &dev->aer_report->uncor_log_ratelimit;
> +
> +	trace_aer_event(dev_name(&dev->dev), (info->status & ~info->mask),
> +			info->severity, info->tlp_header_valid, &info->tlp);
> +
> +	if (!__ratelimit(ratelimit))
> +		return;

  - I think the ratelimit lookup and __ratelimit() call should be
    together since there's no need for trace_aer_event() to be in the
    middle.

  - The lookup and __ratelimit() calls are repeated and are probably
    worth factoring out into something like this:

      static int aer_ratelimit(struct pci_dev *dev, unsigned int severity)

  - Previously we *always* called trace_aer_event(), but now we don't
    in the !info->status case.  Maybe an unintentional change?  I
    think we should call trace_aer_event() always, or change that in a
    separate patch if we need to.  This would always have been simpler
    if trace_aer_event() had been the very first thing in the
    function.

  - The !info->status case message is not rate-limited.  Seems like
    maybe it should be?

>  	layer = AER_GET_LAYER_ERROR(info->severity, info->status);
>  	agent = AER_GET_AGENT(info->severity, info->status);
>  
> @@ -722,21 +748,33 @@ void aer_print_error(struct pci_dev *dev, struct aer_err_info *info,
>  out:
>  	if (info->id && info->error_dev_num > 1 && info->id == id)
>  		pci_err(dev, "  Error of this Agent is reported first\n");
> -
> -	trace_aer_event(dev_name(&dev->dev), (info->status & ~info->mask),
> -			info->severity, info->tlp_header_valid, &info->tlp);
>  }

Jon Pan-Doh March 20, 2025, 8:27 a.m. UTC | #2

On Wed, Mar 19, 2025 at 11:47 AM Bjorn Helgaas <[e-mail]> wrote:
>   - I think the ratelimit lookup and __ratelimit() call should be
>     together since there's no need for trace_aer_event() to be in the
>     middle.
>
>   - The lookup and __ratelimit() calls are repeated and are probably
>     worth factoring out into something like this:
>
>       static int aer_ratelimit(struct pci_dev *dev, unsigned int severity)

Changed in v4.

>   - Previously we *always* called trace_aer_event(), but now we don't
>     in the !info->status case.  Maybe an unintentional change?  I
>     think we should call trace_aer_event() always, or change that in a
>     separate patch if we need to.  This would always have been simpler
>     if trace_aer_event() had been the very first thing in the
>     function.

Good catch. That is an unintentional bug. trace_aer_event() should
always be called. Moved it to the first thing in aer_print_error() in
v4 (same patch as I wasn't sure what justification to put for a
separate commit message other than precursor for ratelimit).

>
>   - The !info->status case message is not rate-limited.  Seems like
>     maybe it should be?

Changed in v4.

Thanks,
Jon

Bjorn Helgaas March 20, 2025, 6:23 p.m. UTC | #3

On Thu, Mar 20, 2025 at 01:27:27AM -0700, Jon Pan-Doh wrote:
> On Wed, Mar 19, 2025 at 11:47 AM Bjorn Helgaas <[e-mail]> wrote:

> >   - Previously we *always* called trace_aer_event(), but now we don't
> >     in the !info->status case.  Maybe an unintentional change?  I
> >     think we should call trace_aer_event() always, or change that in a
> >     separate patch if we need to.  This would always have been simpler
> >     if trace_aer_event() had been the very first thing in the
> >     function.
> 
> Good catch. That is an unintentional bug. trace_aer_event() should
> always be called. Moved it to the first thing in aer_print_error() in
> v4 (same patch as I wasn't sure what justification to put for a
> separate commit message other than precursor for ratelimit).

I wonder if trace_aer_event() and pci_dev_aer_stats_incr() should be
part of the same function since we always do both.  But I guess the
trace needs a little more information.  Minor thing we can worry about
later.

Bjorn

Patch

diff --git a/drivers/pci/pcie/aer.c b/drivers/pci/pcie/aer.c
index 3a12980f7dd7..0bd20c4993d4 100644
--- a/drivers/pci/pcie/aer.c
+++ b/drivers/pci/pcie/aer.c
@@ -28,6 +28,7 @@ 
 #include <linux/interrupt.h>
 #include <linux/delay.h>
 #include <linux/kfifo.h>
+#include <linux/ratelimit.h>
 #include <linux/slab.h>
 #include <acpi/apei.h>
 #include <acpi/ghes.h>
@@ -88,6 +89,10 @@  struct aer_report {
 	u64 rootport_total_cor_errs;
 	u64 rootport_total_fatal_errs;
 	u64 rootport_total_nonfatal_errs;
+
+	/* Ratelimits for errors */
+	struct ratelimit_state cor_log_ratelimit;
+	struct ratelimit_state uncor_log_ratelimit;
 };
 
 #define AER_LOG_TLP_MASKS		(PCI_ERR_UNC_POISON_TLP|	\
@@ -379,6 +384,15 @@  void pci_aer_init(struct pci_dev *dev)
 
 	dev->aer_report = kzalloc(sizeof(*dev->aer_report), GFP_KERNEL);
 
+	/*
+	 * Ratelimits are doubled as a given error produces 2 logs (root port
+	 * and endpoint) that should be under same ratelimit.
+	 */
+	ratelimit_state_init(&dev->aer_report->cor_log_ratelimit,
+			     DEFAULT_RATELIMIT_INTERVAL, DEFAULT_RATELIMIT_BURST * 2);
+	ratelimit_state_init(&dev->aer_report->uncor_log_ratelimit,
+			     DEFAULT_RATELIMIT_INTERVAL, DEFAULT_RATELIMIT_BURST * 2);
+
 	/*
 	 * We save/restore PCI_ERR_UNCOR_MASK, PCI_ERR_UNCOR_SEVER,
 	 * PCI_ERR_COR_MASK, and PCI_ERR_CAP.  Root and Root Complex Event
@@ -697,6 +711,7 @@  void aer_print_error(struct pci_dev *dev, struct aer_err_info *info,
 {
 	int layer, agent;
 	int id = pci_dev_id(dev);
+	struct ratelimit_state *ratelimit;
 
 	if (!info->status) {
 		pci_err(dev, "PCIe Bus Error: severity=%s, type=Inaccessible, (Unregistered Agent ID)\n",
@@ -704,6 +719,17 @@  void aer_print_error(struct pci_dev *dev, struct aer_err_info *info,
 		goto out;
 	}
 
+	if (info->severity == AER_CORRECTABLE)
+		ratelimit = &dev->aer_report->cor_log_ratelimit;
+	else
+		ratelimit = &dev->aer_report->uncor_log_ratelimit;
+
+	trace_aer_event(dev_name(&dev->dev), (info->status & ~info->mask),
+			info->severity, info->tlp_header_valid, &info->tlp);
+
+	if (!__ratelimit(ratelimit))
+		return;
+
 	layer = AER_GET_LAYER_ERROR(info->severity, info->status);
 	agent = AER_GET_AGENT(info->severity, info->status);
 
@@ -722,21 +748,33 @@  void aer_print_error(struct pci_dev *dev, struct aer_err_info *info,
 out:
 	if (info->id && info->error_dev_num > 1 && info->id == id)
 		pci_err(dev, "  Error of this Agent is reported first\n");
-
-	trace_aer_event(dev_name(&dev->dev), (info->status & ~info->mask),
-			info->severity, info->tlp_header_valid, &info->tlp);
 }
 
 static void aer_print_port_info(struct pci_dev *dev, struct aer_err_info *info)
 {
 	u8 bus = info->id >> 8;
 	u8 devfn = info->id & 0xff;
+	struct ratelimit_state *ratelimit;
+	struct pci_dev *endpoint;
+	int i;
 
-	pci_info(dev, "%s%s error message received from %04x:%02x:%02x.%d\n",
-		 info->multi_error_valid ? "Multiple " : "",
-		 aer_error_severity_string[info->severity],
-		 pci_domain_nr(dev->bus), bus, PCI_SLOT(devfn),
-		 PCI_FUNC(devfn));
+	/* extract endpoint device ratelimit */
+	for (i = 0; i < info->error_dev_num; i++) {
+		endpoint = info->dev[i];
+		if (info->id == pci_dev_id(endpoint))
+			break;
+	}
+	if (info->severity == AER_CORRECTABLE)
+		ratelimit = &endpoint->aer_report->cor_log_ratelimit;
+	else
+		ratelimit = &endpoint->aer_report->uncor_log_ratelimit;
+
+	if (__ratelimit(ratelimit))
+		pci_info(dev, "%s%s error message received from %04x:%02x:%02x.%d\n",
+			 info->multi_error_valid ? "Multiple " : "",
+			 aer_error_severity_string[info->severity],
+			 pci_domain_nr(dev->bus), bus, PCI_SLOT(devfn),
+			 PCI_FUNC(devfn));
 }
 
 #ifdef CONFIG_ACPI_APEI_PCIEAER
@@ -761,12 +799,15 @@  void pci_print_aer(struct pci_dev *dev, int aer_severity,
 	u32 status, mask;
 	const char *level;
 	struct aer_err_info info;
+	struct ratelimit_state *ratelimit;
 
 	if (aer_severity == AER_CORRECTABLE) {
+		ratelimit = &dev->aer_report->cor_log_ratelimit;
 		status = aer->cor_status;
 		mask = aer->cor_mask;
 		level = KERN_WARNING;
 	} else {
+		ratelimit = &dev->aer_report->uncor_log_ratelimit;
 		status = aer->uncor_status;
 		mask = aer->uncor_mask;
 		tlp_header_valid = status & AER_LOG_TLP_MASKS;
@@ -784,6 +825,12 @@  void pci_print_aer(struct pci_dev *dev, int aer_severity,
 
 	pci_dev_aer_stats_incr(dev, &info);
 
+	trace_aer_event(dev_name(&dev->dev), (status & ~mask),
+			aer_severity, tlp_header_valid, &aer->header_log);
+
+	if (!__ratelimit(ratelimit))
+		return;
+
 	aer_printk(level, dev, "aer_status: 0x%08x, aer_mask: 0x%08x\n", status, mask);
 	__aer_print_error(dev, &info, level);
 	aer_printk(level, dev, "aer_layer=%s, aer_agent=%s\n",
@@ -795,9 +842,6 @@  void pci_print_aer(struct pci_dev *dev, int aer_severity,
 
 	if (tlp_header_valid)
 		pcie_print_tlp_log(dev, &aer->header_log, dev_fmt("  "));
-
-	trace_aer_event(dev_name(&dev->dev), (status & ~mask),
-			aer_severity, tlp_header_valid, &aer->header_log);
 }
 EXPORT_SYMBOL_NS_GPL(pci_print_aer, "CXL");
 
@@ -1301,10 +1345,11 @@  static void aer_isr_one_error(struct aer_rpc *rpc,
 			e_info.multi_error_valid = 1;
 		else
 			e_info.multi_error_valid = 0;
-		aer_print_port_info(pdev, &e_info);
 
-		if (find_source_device(pdev, &e_info))
+		if (find_source_device(pdev, &e_info)) {
+			aer_print_port_info(pdev, &e_info);
 			aer_process_err_devices(&e_info, level);
+		}
 	}
 
 	if (e_src->status & PCI_ERR_ROOT_UNCOR_RCV) {
@@ -1321,10 +1366,11 @@  static void aer_isr_one_error(struct aer_rpc *rpc,
 		else
 			e_info.multi_error_valid = 0;
 
-		aer_print_port_info(pdev, &e_info);
 
-		if (find_source_device(pdev, &e_info))
+		if (find_source_device(pdev, &e_info)) {
+			aer_print_port_info(pdev, &e_info);
 			aer_process_err_devices(&e_info, level);
+		}
 	}
 }