Message-ID: <20250613220950.GA986935@bhelgaas>
Date: Fri, 13 Jun 2025 17:09:50 -0500
From: Bjorn Helgaas <helgaas@...nel.org>
To: Ammar Qadri <ammarq@...gle.com>
Cc: Manivannan Sadhasivam <mani@...nel.org>,
	Bjorn Helgaas <bhelgaas@...gle.com>, linux-pci@...r.kernel.org,
	linux-kernel@...r.kernel.org
Subject: Re: [PATCH] PCI: Reduce verbosity of device enable messages

On Fri, Jun 13, 2025 at 02:40:40PM -0700, Ammar Qadri wrote:
> Hi Mani,
> 
> The issue we are experiencing is not caused from
> removing/reattaching the device driver, so the other messages have
> not been problematic.
> 
> The vfio-pci driver is attached to each VF once. Clients in our
> system call open and close on the vfio-pci driver, respectively, at
> the start and end of their use, with fairly short-term tenancy,
> which ends up triggering these enable messages.  This message is
> proving challenging not only because they are not particularly
> useful,  but because they are causing log files to rotate once every
> 30 minutes or so, and we lose a lot of other more valuable logging
> as a consequence.  I'm open to other solutions, but in my opinion
> this preserves the message, without over-engineering and introducing
> throttling or other behaviour.

Are there any other messages associated with the open/close?  I assume
probably not, or you would want to demote those as well.

I did happen to find some value in this particular message just the
other day because it showed that a config read was successful after
previous ones had failed.

But I agree in general that it's fairly low value and at least the
uninterpreted "%04x -> %04x" part is not really user-friendly.

If people think there's enough value in retaining it at KERN_INFO, I
suppose there's always the option of carrying an out-of-tree patch to
demote it?

> On Thu, Jun 12, 2025 at 11:12 PM Manivannan Sadhasivam <mani@...nel.org> wrote:
> >
> > On Wed, May 07, 2025 at 11:29:19PM +0000, Ammar Qadri wrote:
> > > Excessive logging of PCIe device enable operations can create significant
> > > noise in system logs, especially in environments with a high number of
> > > such devices, especially VFs.
> > >
> > > High-rate logging can cause log files to rotate too quickly, losing
> > > valuable information from other system components.This commit addresses
> > > this issue by downgrading the logging level of "enabling device" messages
> > > from `info` to `dbg`.
> > >
> >
> > While I generally prefer reduced verbosity of the device drivers, demoting an
> > existing log to debug might surprise users. Especially in this case, the message
> > is widely used to identify the enablement of a PCI device. So I don't think it
> > is a good idea to demote it to a debug log.
> >
> > But I'm surprised that this single message is creating much overhead in the
> > logging. I understand that you might have 100s of VFs in cloud environments, but
> > when a VF is added, a bunch of other messages would also get printed (resource,
> > IRQ, device driver etc...). Or you considered that this message is not that
> > important compared to the rest?
> >
> > - Mani
> >
> > > Signed-off-by: Ammar Qadri <ammarq@...gle.com>
> > > ---
> > >  drivers/pci/setup-res.c | 2 +-
> > >  1 file changed, 1 insertion(+), 1 deletion(-)
> > >
> > > diff --git a/drivers/pci/setup-res.c b/drivers/pci/setup-res.c
> > > index c6657cdd06f67..be669ff6ca240 100644
> > > --- a/drivers/pci/setup-res.c
> > > +++ b/drivers/pci/setup-res.c
> > > @@ -516,7 +516,7 @@ int pci_enable_resources(struct pci_dev *dev, int mask)
> > >       }
> > >
> > >       if (cmd != old_cmd) {
> > > -             pci_info(dev, "enabling device (%04x -> %04x)\n", old_cmd, cmd);
> > > +             pci_dbg(dev, "enabling device (%04x -> %04x)\n", old_cmd, cmd);
> > >               pci_write_config_word(dev, PCI_COMMAND, cmd);
> > >       }
> > >       return 0;
> > > --
> > > 2.49.0.987.g0cc8ee98dc-goog
> > >
> >
> > --
> > மணிவண்ணன் சதாசிவம்

Powered by blists - more mailing lists