Re: [PATCH] PCI/AER: Rate limit the reporting of the correctable errors
Hi Leon, Thanks for the ack. On 1/4/2023 12:16 PM, Leon Romanovsky wrote: On Wed, Jan 04, 2023 at 10:27:33AM +0530, Rajat Khandelwal wrote: Hi Bjorn, Thanks for the acknowledgement. On 1/4/2023 12:44 AM, Bjorn Helgaas wrote: [+cc Paul, Sasha, Leon, Frederick] (Please cc folks who have commented on previous versions of your patch.) On Tue, Jan 03, 2023 at 10:25:48PM +0530, Rajat Khandelwal wrote: There are many instances where correctable errors tend to inundate the message buffer. We observe such instances during thunderbolt PCIe tunneling. <...> [54982.838808] igc :2b:00.0: device [8086:5502] error status/mask=1000/2000 [54982.838817] igc :2b:00.0:[12] Timeout Please remove the timestamps; they don't contribute to understanding the problem. --> Sure. Please don't add "-->" or any marker to replies. It breaks mail color scheme. This gets repeated continuously, thus inundating the buffer. Did you verify that we actually clear the Correctable Error Status register? --> This patch targets only rate limiting the correctable errors since they are non-fatal, and they kind of inundate the CPU logs, particularly during thunderbolt connections. It doesn't have an impact anywhere else. As per your suggestion in the igc patch, I found rate limiting as a doable option currently. Have eradicated any kind of masking the bits. You didn't answer on the asked question. "Did you verify that we actually clear the Correctable Error Status register?". Yes, I have verified. The status is cleared successfully. Thanks
Re: [PATCH] PCI/AER: Rate limit the reporting of the correctable errors
On Wed, Jan 04, 2023 at 10:27:33AM +0530, Rajat Khandelwal wrote: > Hi Bjorn, > > Thanks for the acknowledgement. > > On 1/4/2023 12:44 AM, Bjorn Helgaas wrote: > > [+cc Paul, Sasha, Leon, Frederick] > > > > (Please cc folks who have commented on previous versions of your > > patch.) > > > > On Tue, Jan 03, 2023 at 10:25:48PM +0530, Rajat Khandelwal wrote: > > > There are many instances where correctable errors tend to inundate > > > the message buffer. We observe such instances during thunderbolt PCIe > > > tunneling. <...> > > > [54982.838808] igc :2b:00.0: device [8086:5502] error > > > status/mask=1000/2000 > > > [54982.838817] igc :2b:00.0:[12] Timeout > > Please remove the timestamps; they don't contribute to understanding > > the problem. > > --> Sure. Please don't add "-->" or any marker to replies. It breaks mail color scheme. > > > > > > This gets repeated continuously, thus inundating the buffer. > > Did you verify that we actually clear the Correctable Error Status > > register? > > --> This patch targets only rate limiting the correctable errors since they > are > non-fatal, and they kind of inundate the CPU logs, particularly during > thunderbolt > connections. It doesn't have an impact anywhere else. > As per your suggestion in the igc patch, I found rate limiting as a doable > option > currently. Have eradicated any kind of masking the bits. You didn't answer on the asked question. "Did you verify that we actually clear the Correctable Error Status register?". Thanks
Re: [PATCH] PCI/AER: Rate limit the reporting of the correctable errors
Hi Bjorn, Thanks for the acknowledgement. On 1/4/2023 12:44 AM, Bjorn Helgaas wrote: [+cc Paul, Sasha, Leon, Frederick] (Please cc folks who have commented on previous versions of your patch.) On Tue, Jan 03, 2023 at 10:25:48PM +0530, Rajat Khandelwal wrote: There are many instances where correctable errors tend to inundate the message buffer. We observe such instances during thunderbolt PCIe tunneling. It's true that they are mitigated by the hardware and are non-fatal but we shouldn't be spamming the logs with such correctable errors as it confuses other kernel developers less familiar with PCI errors, support staff, and users who happen to look at the logs, hence rate limit them. I want a better understanding of why we have so many errors before rate-limiting everybody. --> So, we are debugging this inside Intel along with the thunderbolt/PCIe team. Apparently, it will take some time to reach to a conclusion. Since I witness these errors in other thunderbolt devices also, I am currently segregating all the TBT devices so that we have proper data to debug. A typical example log inside an HP TBT4 dock: [54912.661142] pcieport :00:07.0: AER: Multiple Corrected error received: :2b:00.0 [54912.661194] igc :2b:00.0: PCIe Bus Error: severity=Corrected, type=Data Link Layer, (Transmitter ID) [54912.661203] igc :2b:00.0: device [8086:5502] error status/mask=1100/2000 [54912.661211] igc :2b:00.0:[ 8] Rollover [54912.661219] igc :2b:00.0:[12] Timeout [54982.838760] pcieport :00:07.0: AER: Corrected error received: :2b:00.0 [54982.838798] igc :2b:00.0: PCIe Bus Error: severity=Corrected, type=Data Link Layer, (Transmitter ID) [54982.838808] igc :2b:00.0: device [8086:5502] error status/mask=1000/2000 [54982.838817] igc :2b:00.0:[12] Timeout Please remove the timestamps; they don't contribute to understanding the problem. --> Sure. This gets repeated continuously, thus inundating the buffer. Did you verify that we actually clear the Correctable Error Status register? --> This patch targets only rate limiting the correctable errors since they are non-fatal, and they kind of inundate the CPU logs, particularly during thunderbolt connections. It doesn't have an impact anywhere else. As per your suggestion in the igc patch, I found rate limiting as a doable option currently. Have eradicated any kind of masking the bits. https://bugzilla.kernel.org/show_bug.cgi?id=216863 looks like a similar issue. The issue Frederick is seeing happens when resuming from sleep. Is there some event that triggers the correctable errors you see? --> The signatures look similar but there is no such event which triggers these errors. I witness them in many situations (hot plug, cold boot, warm boot, s0ix, etc.). Further, I think the replay correctable errors arise in thunderbolt PCIe devices because the timeout values are not adjusted properly concerning thunderbolt daisy chains. Not sure, but since these PCIe devices work directly on the motherboard, and only give issues when they are inside thunderbolt devices, I think the addition of PCIe bridges in the daisy chain is not synced with proper timeout values. Bjorn
Re: [PATCH] PCI/AER: Rate limit the reporting of the correctable errors
[+cc Paul, Sasha, Leon, Frederick] (Please cc folks who have commented on previous versions of your patch.) On Tue, Jan 03, 2023 at 10:25:48PM +0530, Rajat Khandelwal wrote: > There are many instances where correctable errors tend to inundate > the message buffer. We observe such instances during thunderbolt PCIe > tunneling. > > It's true that they are mitigated by the hardware and are non-fatal > but we shouldn't be spamming the logs with such correctable errors as it > confuses other kernel developers less familiar with PCI errors, support > staff, and users who happen to look at the logs, hence rate limit them. I want a better understanding of why we have so many errors before rate-limiting everybody. > A typical example log inside an HP TBT4 dock: > [54912.661142] pcieport :00:07.0: AER: Multiple Corrected error received: > :2b:00.0 > [54912.661194] igc :2b:00.0: PCIe Bus Error: severity=Corrected, > type=Data Link Layer, (Transmitter ID) > [54912.661203] igc :2b:00.0: device [8086:5502] error > status/mask=1100/2000 > [54912.661211] igc :2b:00.0:[ 8] Rollover > [54912.661219] igc :2b:00.0:[12] Timeout > [54982.838760] pcieport :00:07.0: AER: Corrected error received: > :2b:00.0 > [54982.838798] igc :2b:00.0: PCIe Bus Error: severity=Corrected, > type=Data Link Layer, (Transmitter ID) > [54982.838808] igc :2b:00.0: device [8086:5502] error > status/mask=1000/2000 > [54982.838817] igc :2b:00.0:[12] Timeout Please remove the timestamps; they don't contribute to understanding the problem. > This gets repeated continuously, thus inundating the buffer. Did you verify that we actually clear the Correctable Error Status register? https://bugzilla.kernel.org/show_bug.cgi?id=216863 looks like a similar issue. The issue Frederick is seeing happens when resuming from sleep. Is there some event that triggers the correctable errors you see? Bjorn
[PATCH] PCI/AER: Rate limit the reporting of the correctable errors
There are many instances where correctable errors tend to inundate
the message buffer. We observe such instances during thunderbolt PCIe
tunneling.
It's true that they are mitigated by the hardware and are non-fatal
but we shouldn't be spamming the logs with such correctable errors as it
confuses other kernel developers less familiar with PCI errors, support
staff, and users who happen to look at the logs, hence rate limit them.
A typical example log inside an HP TBT4 dock:
[54912.661142] pcieport :00:07.0: AER: Multiple Corrected error received:
:2b:00.0
[54912.661194] igc :2b:00.0: PCIe Bus Error: severity=Corrected, type=Data
Link Layer, (Transmitter ID)
[54912.661203] igc :2b:00.0: device [8086:5502] error
status/mask=1100/2000
[54912.661211] igc :2b:00.0:[ 8] Rollover
[54912.661219] igc :2b:00.0:[12] Timeout
[54982.838760] pcieport :00:07.0: AER: Corrected error received:
:2b:00.0
[54982.838798] igc :2b:00.0: PCIe Bus Error: severity=Corrected, type=Data
Link Layer, (Transmitter ID)
[54982.838808] igc :2b:00.0: device [8086:5502] error
status/mask=1000/2000
[54982.838817] igc :2b:00.0:[12] Timeout
This gets repeated continuously, thus inundating the buffer.
Signed-off-by: Rajat Khandelwal
---
drivers/pci/pcie/aer.c | 54 +++---
include/linux/pci.h| 3 +++
2 files changed, 38 insertions(+), 19 deletions(-)
diff --git a/drivers/pci/pcie/aer.c b/drivers/pci/pcie/aer.c
index e2d8a74f83c3..7ae6761a8e59 100644
--- a/drivers/pci/pcie/aer.c
+++ b/drivers/pci/pcie/aer.c
@@ -684,23 +684,24 @@ static void __aer_print_error(struct pci_dev *dev,
{
const char **strings;
unsigned long status = info->status & ~info->mask;
- const char *level, *errmsg;
+ const char *errmsg;
int i;
- if (info->severity == AER_CORRECTABLE) {
+ if (info->severity == AER_CORRECTABLE)
strings = aer_correctable_error_string;
- level = KERN_WARNING;
- } else {
+ else
strings = aer_uncorrectable_error_string;
- level = KERN_ERR;
- }
for_each_set_bit(i, , 32) {
errmsg = strings[i];
if (!errmsg)
errmsg = "Unknown Error Bit";
- pci_printk(level, dev, " [%2d] %-22s%s\n", i, errmsg,
+ if (info->severity == AER_CORRECTABLE)
+ pci_warn_ratelimited(dev, " [%2d] %-22s%s\n", i,
errmsg,
+info->first_error == i ? "
(First)" : "");
+ else
+ pci_err(dev, " [%2d] %-22s%s\n", i, errmsg,
info->first_error == i ? " (First)" : "");
}
pci_dev_aer_stats_incr(dev, info);
@@ -710,7 +711,6 @@ void aer_print_error(struct pci_dev *dev, struct
aer_err_info *info)
{
int layer, agent;
int id = ((dev->bus->number << 8) | dev->devfn);
- const char *level;
if (!info->status) {
pci_err(dev, "PCIe Bus Error: severity=%s, type=Inaccessible,
(Unregistered Agent ID)\n",
@@ -721,14 +718,21 @@ void aer_print_error(struct pci_dev *dev, struct
aer_err_info *info)
layer = AER_GET_LAYER_ERROR(info->severity, info->status);
agent = AER_GET_AGENT(info->severity, info->status);
- level = (info->severity == AER_CORRECTABLE) ? KERN_WARNING : KERN_ERR;
+ if (info->severity == AER_CORRECTABLE) {
+ pci_warn_ratelimited(dev, "PCIe Bus Error: severity=%s,
type=%s, (%s)\n",
+aer_error_severity_string[info->severity],
+aer_error_layer[layer],
aer_agent_string[agent]);
- pci_printk(level, dev, "PCIe Bus Error: severity=%s, type=%s, (%s)\n",
- aer_error_severity_string[info->severity],
- aer_error_layer[layer], aer_agent_string[agent]);
+ pci_warn_ratelimited(dev, " device [%04x:%04x] error
status/mask=%08x/%08x\n",
+dev->vendor, dev->device, info->status,
info->mask);
+ } else {
+ pci_err(dev, "PCIe Bus Error: severity=%s, type=%s, (%s)\n",
+ aer_error_severity_string[info->severity],
+ aer_error_layer[layer], aer_agent_string[agent]);
- pci_printk(level, dev, " device [%04x:%04x] error
status/mask=%08x/%08x\n",
- dev->vendor, dev->device, info->status, info->mask);
+ pci_err(dev, " device [%04x:%04x] error
status/mask=%08x/%08x\n",
+ dev->vendor, dev->device, info->status, info->mask);
+ }
__aer_print_error(dev, info);
@@ -748,11 +755,19 @@ 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;
