diff mbox series

[07/12] pci: epf-test: Add debug and error messages

Message ID 20230215032155.74993-8-damien.lemoal@opensource.wdc.com
State New
Headers show
Series PCI endpoint fixes and improvements | expand

Commit Message

Damien Le Moal Feb. 15, 2023, 3:21 a.m. UTC
Make the pci-epf-test driver more verbose with dynamic debug messages
using dev_dbg(). Also add some dev_err() error messages to help
troubleshoot issues.

Signed-off-by: Damien Le Moal <damien.lemoal@opensource.wdc.com>
---
 drivers/pci/endpoint/functions/pci-epf-test.c | 69 +++++++++++++++----
 1 file changed, 56 insertions(+), 13 deletions(-)

Comments

Greg KH Feb. 15, 2023, 11:34 a.m. UTC | #1
On Wed, Feb 15, 2023 at 12:21:50PM +0900, Damien Le Moal wrote:
> Make the pci-epf-test driver more verbose with dynamic debug messages
> using dev_dbg(). Also add some dev_err() error messages to help
> troubleshoot issues.
> 
> Signed-off-by: Damien Le Moal <damien.lemoal@opensource.wdc.com>
> ---
>  drivers/pci/endpoint/functions/pci-epf-test.c | 69 +++++++++++++++----
>  1 file changed, 56 insertions(+), 13 deletions(-)
> 
> diff --git a/drivers/pci/endpoint/functions/pci-epf-test.c b/drivers/pci/endpoint/functions/pci-epf-test.c
> index f630393e8208..9b791f4a7ffb 100644
> --- a/drivers/pci/endpoint/functions/pci-epf-test.c
> +++ b/drivers/pci/endpoint/functions/pci-epf-test.c
> @@ -330,6 +330,10 @@ static int pci_epf_test_copy(struct pci_epf_test *epf_test, bool use_dma)
>  	enum pci_barno test_reg_bar = epf_test->test_reg_bar;
>  	volatile struct pci_epf_test_reg *reg = epf_test->reg[test_reg_bar];
>  
> +	dev_dbg(&epf->dev,
> +		"COPY src addr 0x%llx, dst addr 0x%llx, %u B\n",
> +		reg->src_addr, reg->dst_addr, reg->size);

Again, no, please just use ftrace.

thanks,

greg k-h
Greg KH Feb. 15, 2023, 11:34 a.m. UTC | #2
On Wed, Feb 15, 2023 at 12:21:50PM +0900, Damien Le Moal wrote:
> Make the pci-epf-test driver more verbose with dynamic debug messages
> using dev_dbg(). Also add some dev_err() error messages to help
> troubleshoot issues.
> 
> Signed-off-by: Damien Le Moal <damien.lemoal@opensource.wdc.com>
> ---
>  drivers/pci/endpoint/functions/pci-epf-test.c | 69 +++++++++++++++----
>  1 file changed, 56 insertions(+), 13 deletions(-)
> 
> diff --git a/drivers/pci/endpoint/functions/pci-epf-test.c b/drivers/pci/endpoint/functions/pci-epf-test.c
> index f630393e8208..9b791f4a7ffb 100644
> --- a/drivers/pci/endpoint/functions/pci-epf-test.c
> +++ b/drivers/pci/endpoint/functions/pci-epf-test.c
> @@ -330,6 +330,10 @@ static int pci_epf_test_copy(struct pci_epf_test *epf_test, bool use_dma)
>  	enum pci_barno test_reg_bar = epf_test->test_reg_bar;
>  	volatile struct pci_epf_test_reg *reg = epf_test->reg[test_reg_bar];

note, volatile is almost always wrong, please fix that up.

thanks,

greg k-h
Damien Le Moal Feb. 15, 2023, 11:44 a.m. UTC | #3
On 2/15/23 20:34, Greg Kroah-Hartman wrote:
> On Wed, Feb 15, 2023 at 12:21:50PM +0900, Damien Le Moal wrote:
>> Make the pci-epf-test driver more verbose with dynamic debug messages
>> using dev_dbg(). Also add some dev_err() error messages to help
>> troubleshoot issues.
>>
>> Signed-off-by: Damien Le Moal <damien.lemoal@opensource.wdc.com>
>> ---
>>  drivers/pci/endpoint/functions/pci-epf-test.c | 69 +++++++++++++++----
>>  1 file changed, 56 insertions(+), 13 deletions(-)
>>
>> diff --git a/drivers/pci/endpoint/functions/pci-epf-test.c b/drivers/pci/endpoint/functions/pci-epf-test.c
>> index f630393e8208..9b791f4a7ffb 100644
>> --- a/drivers/pci/endpoint/functions/pci-epf-test.c
>> +++ b/drivers/pci/endpoint/functions/pci-epf-test.c
>> @@ -330,6 +330,10 @@ static int pci_epf_test_copy(struct pci_epf_test *epf_test, bool use_dma)
>>  	enum pci_barno test_reg_bar = epf_test->test_reg_bar;
>>  	volatile struct pci_epf_test_reg *reg = epf_test->reg[test_reg_bar];
>>  
>> +	dev_dbg(&epf->dev,
>> +		"COPY src addr 0x%llx, dst addr 0x%llx, %u B\n",
>> +		reg->src_addr, reg->dst_addr, reg->size);
> 
> Again, no, please just use ftrace.

OK. Got it.

> 
> thanks,
> 
> greg k-h
Damien Le Moal Feb. 15, 2023, 11:45 a.m. UTC | #4
On 2/15/23 20:34, Greg Kroah-Hartman wrote:
> On Wed, Feb 15, 2023 at 12:21:50PM +0900, Damien Le Moal wrote:
>> Make the pci-epf-test driver more verbose with dynamic debug messages
>> using dev_dbg(). Also add some dev_err() error messages to help
>> troubleshoot issues.
>>
>> Signed-off-by: Damien Le Moal <damien.lemoal@opensource.wdc.com>
>> ---
>>  drivers/pci/endpoint/functions/pci-epf-test.c | 69 +++++++++++++++----
>>  1 file changed, 56 insertions(+), 13 deletions(-)
>>
>> diff --git a/drivers/pci/endpoint/functions/pci-epf-test.c b/drivers/pci/endpoint/functions/pci-epf-test.c
>> index f630393e8208..9b791f4a7ffb 100644
>> --- a/drivers/pci/endpoint/functions/pci-epf-test.c
>> +++ b/drivers/pci/endpoint/functions/pci-epf-test.c
>> @@ -330,6 +330,10 @@ static int pci_epf_test_copy(struct pci_epf_test *epf_test, bool use_dma)
>>  	enum pci_barno test_reg_bar = epf_test->test_reg_bar;
>>  	volatile struct pci_epf_test_reg *reg = epf_test->reg[test_reg_bar];
> 
> note, volatile is almost always wrong, please fix that up.

OK. Will think of something else.
Thanks for the feedback.
Greg KH Feb. 15, 2023, 12:01 p.m. UTC | #5
On Wed, Feb 15, 2023 at 08:45:50PM +0900, Damien Le Moal wrote:
> On 2/15/23 20:34, Greg Kroah-Hartman wrote:
> > On Wed, Feb 15, 2023 at 12:21:50PM +0900, Damien Le Moal wrote:
> >> Make the pci-epf-test driver more verbose with dynamic debug messages
> >> using dev_dbg(). Also add some dev_err() error messages to help
> >> troubleshoot issues.
> >>
> >> Signed-off-by: Damien Le Moal <damien.lemoal@opensource.wdc.com>
> >> ---
> >>  drivers/pci/endpoint/functions/pci-epf-test.c | 69 +++++++++++++++----
> >>  1 file changed, 56 insertions(+), 13 deletions(-)
> >>
> >> diff --git a/drivers/pci/endpoint/functions/pci-epf-test.c b/drivers/pci/endpoint/functions/pci-epf-test.c
> >> index f630393e8208..9b791f4a7ffb 100644
> >> --- a/drivers/pci/endpoint/functions/pci-epf-test.c
> >> +++ b/drivers/pci/endpoint/functions/pci-epf-test.c
> >> @@ -330,6 +330,10 @@ static int pci_epf_test_copy(struct pci_epf_test *epf_test, bool use_dma)
> >>  	enum pci_barno test_reg_bar = epf_test->test_reg_bar;
> >>  	volatile struct pci_epf_test_reg *reg = epf_test->reg[test_reg_bar];
> > 
> > note, volatile is almost always wrong, please fix that up.
> 
> OK. Will think of something else.

If this is io memory, use the proper accessors to access it.  If it is
not io memory, then why is it marked volatile at all?

thanks,

greg k-h
Damien Le Moal Feb. 15, 2023, 12:18 p.m. UTC | #6
On 2/15/23 21:01, Greg Kroah-Hartman wrote:
> On Wed, Feb 15, 2023 at 08:45:50PM +0900, Damien Le Moal wrote:
>> On 2/15/23 20:34, Greg Kroah-Hartman wrote:
>>> On Wed, Feb 15, 2023 at 12:21:50PM +0900, Damien Le Moal wrote:
>>>> Make the pci-epf-test driver more verbose with dynamic debug messages
>>>> using dev_dbg(). Also add some dev_err() error messages to help
>>>> troubleshoot issues.
>>>>
>>>> Signed-off-by: Damien Le Moal <damien.lemoal@opensource.wdc.com>
>>>> ---
>>>>  drivers/pci/endpoint/functions/pci-epf-test.c | 69 +++++++++++++++----
>>>>  1 file changed, 56 insertions(+), 13 deletions(-)
>>>>
>>>> diff --git a/drivers/pci/endpoint/functions/pci-epf-test.c b/drivers/pci/endpoint/functions/pci-epf-test.c
>>>> index f630393e8208..9b791f4a7ffb 100644
>>>> --- a/drivers/pci/endpoint/functions/pci-epf-test.c
>>>> +++ b/drivers/pci/endpoint/functions/pci-epf-test.c
>>>> @@ -330,6 +330,10 @@ static int pci_epf_test_copy(struct pci_epf_test *epf_test, bool use_dma)
>>>>  	enum pci_barno test_reg_bar = epf_test->test_reg_bar;
>>>>  	volatile struct pci_epf_test_reg *reg = epf_test->reg[test_reg_bar];
>>>
>>> note, volatile is almost always wrong, please fix that up.
>>
>> OK. Will think of something else.
> 
> If this is io memory, use the proper accessors to access it.  If it is
> not io memory, then why is it marked volatile at all?

This is a PCI bar memory. So I can simply copy the structure locally with
memcpy_fromio() and memcpy_toio().

> 
> thanks,
> 
> greg k-h
Greg KH Feb. 15, 2023, 1:24 p.m. UTC | #7
On Wed, Feb 15, 2023 at 09:18:48PM +0900, Damien Le Moal wrote:
> On 2/15/23 21:01, Greg Kroah-Hartman wrote:
> > On Wed, Feb 15, 2023 at 08:45:50PM +0900, Damien Le Moal wrote:
> >> On 2/15/23 20:34, Greg Kroah-Hartman wrote:
> >>> On Wed, Feb 15, 2023 at 12:21:50PM +0900, Damien Le Moal wrote:
> >>>> Make the pci-epf-test driver more verbose with dynamic debug messages
> >>>> using dev_dbg(). Also add some dev_err() error messages to help
> >>>> troubleshoot issues.
> >>>>
> >>>> Signed-off-by: Damien Le Moal <damien.lemoal@opensource.wdc.com>
> >>>> ---
> >>>>  drivers/pci/endpoint/functions/pci-epf-test.c | 69 +++++++++++++++----
> >>>>  1 file changed, 56 insertions(+), 13 deletions(-)
> >>>>
> >>>> diff --git a/drivers/pci/endpoint/functions/pci-epf-test.c b/drivers/pci/endpoint/functions/pci-epf-test.c
> >>>> index f630393e8208..9b791f4a7ffb 100644
> >>>> --- a/drivers/pci/endpoint/functions/pci-epf-test.c
> >>>> +++ b/drivers/pci/endpoint/functions/pci-epf-test.c
> >>>> @@ -330,6 +330,10 @@ static int pci_epf_test_copy(struct pci_epf_test *epf_test, bool use_dma)
> >>>>  	enum pci_barno test_reg_bar = epf_test->test_reg_bar;
> >>>>  	volatile struct pci_epf_test_reg *reg = epf_test->reg[test_reg_bar];
> >>>
> >>> note, volatile is almost always wrong, please fix that up.
> >>
> >> OK. Will think of something else.
> > 
> > If this is io memory, use the proper accessors to access it.  If it is
> > not io memory, then why is it marked volatile at all?
> 
> This is a PCI bar memory. So I can simply copy the structure locally with
> memcpy_fromio() and memcpy_toio().

Great, please do so instead of trying to access it directly like this,
which will break on some platforms.

thanks,

greg k-h
Arnd Bergmann Feb. 15, 2023, 1:49 p.m. UTC | #8
On Wed, Feb 15, 2023, at 14:24, Greg Kroah-Hartman wrote:
> On Wed, Feb 15, 2023 at 09:18:48PM +0900, Damien Le Moal wrote:
>> On 2/15/23 21:01, Greg Kroah-Hartman wrote:
>> >>>> @@ -330,6 +330,10 @@ static int pci_epf_test_copy(struct pci_epf_test *epf_test, bool use_dma)
>> >>>>  	enum pci_barno test_reg_bar = epf_test->test_reg_bar;
>> >>>>  	volatile struct pci_epf_test_reg *reg = epf_test->reg[test_reg_bar];
>> >>>
>> >>> note, volatile is almost always wrong, please fix that up.
>> >>
>> >> OK. Will think of something else.
>> > 
>> > If this is io memory, use the proper accessors to access it.  If it is
>> > not io memory, then why is it marked volatile at all?
>> 
>> This is a PCI bar memory. So I can simply copy the structure locally with
>> memcpy_fromio() and memcpy_toio().
>
> Great, please do so instead of trying to access it directly like this,
> which will break on some platforms.

I think the reverse is true here: looking at where the pointer comes
from, 'reg' is actually the result of dma_alloc_coherent() in the
memory of the local (endpoint) machine, though it appears as a BAR on
the remote (host) side and gets mapped with ioremap() there.

This means that the host must use readl/write/memcpy_fromio/memcpy_toio
to access the buffer, matching the __iomem token there, while the
endpoint side not use those. On some machines, readl/write take
arguments that are not compatible with normal pointers, and will
do something completely different there.

A volatile access is not the worst option here, though this conflicts
with the '__packed' annotation in the structure definition that
may require bytewise access on architectures without unaligned
access.

I would drop the __packed in the definition, possibly annotating
only the 64-bit src_addr and dst_addr members as __packed to ensure
the layout is unchanged but the structure as a whole is 32-bit
aligned, and then use READ_ONCE()/WRITE_ONCE() to atomically
access each member in the coherent buffer.

If ordering between the accesses is required, you can add
dma_rmb() and dma_wmb() barriers.

     Arnd
Damien Le Moal Feb. 15, 2023, 10:55 p.m. UTC | #9
On 2/15/23 22:49, Arnd Bergmann wrote:
> On Wed, Feb 15, 2023, at 14:24, Greg Kroah-Hartman wrote:
>> On Wed, Feb 15, 2023 at 09:18:48PM +0900, Damien Le Moal wrote:
>>> On 2/15/23 21:01, Greg Kroah-Hartman wrote:
>>>>>>> @@ -330,6 +330,10 @@ static int pci_epf_test_copy(struct pci_epf_test *epf_test, bool use_dma)
>>>>>>>  	enum pci_barno test_reg_bar = epf_test->test_reg_bar;
>>>>>>>  	volatile struct pci_epf_test_reg *reg = epf_test->reg[test_reg_bar];
>>>>>>
>>>>>> note, volatile is almost always wrong, please fix that up.
>>>>>
>>>>> OK. Will think of something else.
>>>>
>>>> If this is io memory, use the proper accessors to access it.  If it is
>>>> not io memory, then why is it marked volatile at all?
>>>
>>> This is a PCI bar memory. So I can simply copy the structure locally with
>>> memcpy_fromio() and memcpy_toio().
>>
>> Great, please do so instead of trying to access it directly like this,
>> which will break on some platforms.
> 
> I think the reverse is true here: looking at where the pointer comes
> from, 'reg' is actually the result of dma_alloc_coherent() in the
> memory of the local (endpoint) machine, though it appears as a BAR on
> the remote (host) side and gets mapped with ioremap() there.
> 
> This means that the host must use readl/write/memcpy_fromio/memcpy_toio
> to access the buffer, matching the __iomem token there, while the
> endpoint side not use those. On some machines, readl/write take
> arguments that are not compatible with normal pointers, and will
> do something completely different there.
> 
> A volatile access is not the worst option here, though this conflicts
> with the '__packed' annotation in the structure definition that
> may require bytewise access on architectures without unaligned
> access.
> 
> I would drop the __packed in the definition, possibly annotating
> only the 64-bit src_addr and dst_addr members as __packed to ensure
> the layout is unchanged but the structure as a whole is 32-bit
> aligned, and then use READ_ONCE()/WRITE_ONCE() to atomically
> access each member in the coherent buffer.

I guess that would work too. But given that there are accesses to individual
members all over the place, I think it would be easier to get a local copy of
the reg structure in pci_epf_test_cmd_handler() and pass a pointer of that local
copy to the pci_epf_test_xxx() functions. The only READ_ONCE() needed would be
to test the command field on entry to pci_epf_test_cmd_handler() to be sure that
we have a valid command.

The host side always sets the reg command field last, which I think kind of
assumes an ordered update on the EP side (all other fields set before the
command field). That does seem a bit fragile to me as my understanding is that
PCI does not necessarily guarantees ordering of IO TLPs. But I may be wrong here.

> If ordering between the accesses is required, you can add
> dma_rmb() and dma_wmb() barriers.

Which I guess is the one thing we need after testing the reg command field in
pci_epf_test_cmd_handler() and before making the local copy, to avoid problems
with ordering of the reg fields writes from the host.

Will use that in v2.
diff mbox series

Patch

diff --git a/drivers/pci/endpoint/functions/pci-epf-test.c b/drivers/pci/endpoint/functions/pci-epf-test.c
index f630393e8208..9b791f4a7ffb 100644
--- a/drivers/pci/endpoint/functions/pci-epf-test.c
+++ b/drivers/pci/endpoint/functions/pci-epf-test.c
@@ -330,6 +330,10 @@  static int pci_epf_test_copy(struct pci_epf_test *epf_test, bool use_dma)
 	enum pci_barno test_reg_bar = epf_test->test_reg_bar;
 	volatile struct pci_epf_test_reg *reg = epf_test->reg[test_reg_bar];
 
+	dev_dbg(&epf->dev,
+		"COPY src addr 0x%llx, dst addr 0x%llx, %u B\n",
+		reg->src_addr, reg->dst_addr, reg->size);
+
 	src_addr = pci_epc_mem_alloc_addr(epc, &src_phys_addr, reg->size);
 	if (!src_addr) {
 		dev_err(dev, "Failed to allocate source address\n");
@@ -380,6 +384,8 @@  static int pci_epf_test_copy(struct pci_epf_test *epf_test, bool use_dma)
 
 		buf = kzalloc(reg->size, GFP_KERNEL);
 		if (!buf) {
+			dev_err(dev, "Alloc %zu B for copy failed\n",
+				(size_t)reg->size);
 			ret = -ENOMEM;
 			goto err_map_addr;
 		}
@@ -424,6 +430,9 @@  static int pci_epf_test_read(struct pci_epf_test *epf_test, bool use_dma)
 	enum pci_barno test_reg_bar = epf_test->test_reg_bar;
 	volatile struct pci_epf_test_reg *reg = epf_test->reg[test_reg_bar];
 
+	dev_dbg(&epf->dev, "READ src addr 0x%llx, %u B\n",
+		reg->src_addr, reg->size);
+
 	src_addr = pci_epc_mem_alloc_addr(epc, &phys_addr, reg->size);
 	if (!src_addr) {
 		dev_err(dev, "Failed to allocate address\n");
@@ -442,6 +451,8 @@  static int pci_epf_test_read(struct pci_epf_test *epf_test, bool use_dma)
 
 	buf = kzalloc(reg->size, GFP_KERNEL);
 	if (!buf) {
+		dev_err(dev, "Alloc %zu B for read failed\n",
+			(size_t)reg->size);
 		ret = -ENOMEM;
 		goto err_map_addr;
 	}
@@ -506,6 +517,9 @@  static int pci_epf_test_write(struct pci_epf_test *epf_test, bool use_dma)
 	enum pci_barno test_reg_bar = epf_test->test_reg_bar;
 	volatile struct pci_epf_test_reg *reg = epf_test->reg[test_reg_bar];
 
+	dev_dbg(&epf->dev, "WRITE dst addr 0x%llx, %u B\n",
+		reg->dst_addr, reg->size);
+
 	dst_addr = pci_epc_mem_alloc_addr(epc, &phys_addr, reg->size);
 	if (!dst_addr) {
 		dev_err(dev, "Failed to allocate address\n");
@@ -524,6 +538,8 @@  static int pci_epf_test_write(struct pci_epf_test *epf_test, bool use_dma)
 
 	buf = kzalloc(reg->size, GFP_KERNEL);
 	if (!buf) {
+		dev_err(dev, "Alloc %zu B for write failed\n",
+			(size_t)reg->size);
 		ret = -ENOMEM;
 		goto err_map_addr;
 	}
@@ -580,7 +596,7 @@  static int pci_epf_test_write(struct pci_epf_test *epf_test, bool use_dma)
 	return ret;
 }
 
-static void pci_epf_test_raise_irq(struct pci_epf_test *epf_test, u8 irq_type,
+static int pci_epf_test_raise_irq(struct pci_epf_test *epf_test, u8 irq_type,
 				   u16 irq)
 {
 	struct pci_epf *epf = epf_test->epf;
@@ -588,26 +604,35 @@  static void pci_epf_test_raise_irq(struct pci_epf_test *epf_test, u8 irq_type,
 	struct pci_epc *epc = epf->epc;
 	enum pci_barno test_reg_bar = epf_test->test_reg_bar;
 	volatile struct pci_epf_test_reg *reg = epf_test->reg[test_reg_bar];
+	int ret;
 
 	reg->status |= STATUS_IRQ_RAISED;
 
 	switch (irq_type) {
 	case IRQ_TYPE_LEGACY:
-		pci_epc_raise_irq(epc, epf->func_no, epf->vfunc_no,
-				  PCI_EPC_IRQ_LEGACY, 0);
+		dev_dbg(&epf->dev, "RAISE legacy IRQ\n");
+		ret = pci_epc_raise_irq(epc, epf->func_no, epf->vfunc_no,
+					PCI_EPC_IRQ_LEGACY, 0);
 		break;
 	case IRQ_TYPE_MSI:
-		pci_epc_raise_irq(epc, epf->func_no, epf->vfunc_no,
-				  PCI_EPC_IRQ_MSI, irq);
+		dev_dbg(&epf->dev, "RAISE MSI IRQ %d\n", (int)irq);
+		ret = pci_epc_raise_irq(epc, epf->func_no, epf->vfunc_no,
+					PCI_EPC_IRQ_MSI, irq);
 		break;
 	case IRQ_TYPE_MSIX:
-		pci_epc_raise_irq(epc, epf->func_no, epf->vfunc_no,
-				  PCI_EPC_IRQ_MSIX, irq);
+		dev_dbg(&epf->dev, "RAISE MSIX IRQ %d\n", (int)irq);
+		ret = pci_epc_raise_irq(epc, epf->func_no, epf->vfunc_no,
+					PCI_EPC_IRQ_MSIX, irq);
 		break;
 	default:
 		dev_err(dev, "Failed to raise IRQ, unknown type\n");
-		break;
+		return -EINVAL;
 	}
+
+	if (ret)
+		dev_err(dev, "Raise IRQ failed %d\n", ret);
+
+	return ret;
 }
 
 static void pci_epf_test_cmd_handler(struct work_struct *work)
@@ -684,8 +709,11 @@  static void pci_epf_test_cmd_handler(struct work_struct *work)
 
 	if (command & COMMAND_RAISE_MSI_IRQ) {
 		count = pci_epc_get_msi(epc, epf->func_no, epf->vfunc_no);
-		if (reg->irq_number > count || count <= 0)
+		if (reg->irq_number > count || count <= 0) {
+			dev_err(dev, "Invalid MSI %d / %d\n",
+				(int)reg->irq_number, (int)count);
 			goto reset_handler;
+		}
 		reg->status = STATUS_IRQ_RAISED;
 		pci_epc_raise_irq(epc, epf->func_no, epf->vfunc_no,
 				  PCI_EPC_IRQ_MSI, reg->irq_number);
@@ -694,14 +722,19 @@  static void pci_epf_test_cmd_handler(struct work_struct *work)
 
 	if (command & COMMAND_RAISE_MSIX_IRQ) {
 		count = pci_epc_get_msix(epc, epf->func_no, epf->vfunc_no);
-		if (reg->irq_number > count || count <= 0)
+		if (reg->irq_number > count || count <= 0) {
+			dev_err(dev, "Invalid MSIX %d / %d\n",
+				(int)reg->irq_number, (int)count);
 			goto reset_handler;
+		}
 		reg->status = STATUS_IRQ_RAISED;
 		pci_epc_raise_irq(epc, epf->func_no, epf->vfunc_no,
 				  PCI_EPC_IRQ_MSIX, reg->irq_number);
 		goto reset_handler;
 	}
 
+	dev_err(dev, "Unknown command 0x%x\n", command);
+
 reset_handler:
 	queue_delayed_work(kpcitest_workqueue, &epf_test->cmd_handler,
 			   msecs_to_jiffies(1));
@@ -828,12 +861,14 @@  static int pci_epf_test_notifier(struct notifier_block *nb, unsigned long val,
 
 	switch (val) {
 	case CORE_INIT:
+		dev_dbg(&epf->dev, "CORE_INIT event\n");
 		ret = pci_epf_test_core_init(epf);
 		if (ret)
 			return NOTIFY_BAD;
 		break;
 
 	case LINK_UP:
+		dev_dbg(&epf->dev, "LINK_UP event\n");
 		queue_delayed_work(kpcitest_workqueue, &epf_test->cmd_handler,
 				   msecs_to_jiffies(1));
 		break;
@@ -875,8 +910,12 @@  static int pci_epf_test_alloc_space(struct pci_epf *epf)
 	test_reg_size = test_reg_bar_size + msix_table_size + pba_size;
 
 	if (epc_features->bar_fixed_size[test_reg_bar]) {
-		if (test_reg_size > bar_size[test_reg_bar])
+		if (test_reg_size > bar_size[test_reg_bar]) {
+			dev_err(&epf->dev, "BAR %d: %zu B > %zu B\n",
+				(int)test_reg_bar, test_reg_size,
+				(size_t)bar_size[test_reg_bar]);
 			return -ENOMEM;
+		}
 		test_reg_size = bar_size[test_reg_bar];
 	}
 
@@ -938,8 +977,10 @@  static int pci_epf_test_bind(struct pci_epf *epf)
 	bool linkup_notifier = false;
 	bool core_init_notifier = false;
 
-	if (WARN_ON_ONCE(!epc))
+	if (WARN_ON_ONCE(!epc)) {
+		dev_err(&epf->dev, "No controller\n");
 		return -EINVAL;
+	}
 
 	epc_features = pci_epc_get_features(epc, epf->func_no, epf->vfunc_no);
 	if (!epc_features) {
@@ -950,8 +991,10 @@  static int pci_epf_test_bind(struct pci_epf *epf)
 	linkup_notifier = epc_features->linkup_notifier;
 	core_init_notifier = epc_features->core_init_notifier;
 	test_reg_bar = pci_epc_get_first_free_bar(epc_features);
-	if (test_reg_bar < 0)
+	if (test_reg_bar < 0) {
+		dev_err(&epf->dev, "No free BAR\n");
 		return -EINVAL;
+	}
 	pci_epf_configure_bar(epf, epc_features);
 
 	epf_test->test_reg_bar = test_reg_bar;