MSI-X cleanup(?) issue with passthrough after domU restart

MSI-X cleanup(?) issue with passthrough after domU restart

[Marek Marczykowski-Górecki]

[-- Attachment #1: Type: text/plain, Size: 2475 bytes --]

Hi,

I'm hitting an MSI-X issue after rebooting the domU. The symptoms are
rather boring: on initial domU start the device (realtek eth card) works
fine, but after domU restart, the link doesn't come up (there is no
"Link is Up" message anymore). No errors from domU driver or Xen. I
tracked it down to MSI-X - if I force INTx (via pci=nomsi on domU
cmdline) it works fine. Convincing the driver to poll instead of waiting
for an interrupt also workarounds the issue.

I noticed also some interrupts are not cleaned up on restart. The list
of MSIs in 'Q' debug key output grows:

    (XEN) 0000:03:00.0 - d22 - node -1  - MSIs < 41 42 43 44 45 46 47 >
    restart sys-net domU
    (XEN) 0000:03:00.0 - d24 - node -1  - MSIs < 41 42 43 44 45 46 47 48 >
    restart sys-net domU
    (XEN) 0000:03:00.0 - d26 - node -1  - MSIs < 41 42 43 44 45 46 47 48 49 >

and 'M' output is:

    (XEN)  MSI-X   41 vec=b1 lowest  edge   assert  log lowest dest=00000001 mask=1/H /1
    (XEN)  MSI-X   42 vec=b9 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
    (XEN)  MSI-X   43 vec=c1 lowest  edge   assert  log lowest dest=00000010 mask=1/HG/1
    (XEN)  MSI-X   44 vec=d9 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
    (XEN)  MSI-X   45 vec=e1 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
    (XEN)  MSI-X   46 vec=e9 lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
    (XEN)  MSI-X   47 vec=32 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
    (XEN)  MSI-X   48 vec=3a lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
    (XEN)  MSI-X   49 vec=42 lowest  edge   assert  log lowest dest=00000010 mask=1/ G/1

And also, after starting and stopping the domU, `xl pci-assignable-remove 03:00.0`
makes pciback to complain:

    [ 1180.919874] pciback 0000:03:00.0: xen_pciback: MSI-X release failed (-16)

This is all running on Xen 4.19.3, but I don't see much changes in this
area since then.

Some more info collected at https://github.com/QubesOS/qubes-issues/issues/9335

My question is: what should be responsible for this cleanup on domain
destroy? Xen, or maybe device model (which is QEMU in stubdomain here)?
I see some cleanup (apparently not enough) happening via QEMU when the
domU driver is unloaded, but logically correct cleanup shouldn't depend
on correct domU operation...

-- 
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 488 bytes --]

Re: MSI-X cleanup(?) issue with passthrough after domU restart

[Jan Beulich]

On 26.08.2025 03:49, Marek Marczykowski-Górecki wrote:
> Hi,
> 
> I'm hitting an MSI-X issue after rebooting the domU. The symptoms are
> rather boring: on initial domU start the device (realtek eth card) works
> fine, but after domU restart, the link doesn't come up (there is no
> "Link is Up" message anymore). No errors from domU driver or Xen. I
> tracked it down to MSI-X - if I force INTx (via pci=nomsi on domU
> cmdline) it works fine. Convincing the driver to poll instead of waiting
> for an interrupt also workarounds the issue.
> 
> I noticed also some interrupts are not cleaned up on restart. The list
> of MSIs in 'Q' debug key output grows:
> 
>     (XEN) 0000:03:00.0 - d22 - node -1  - MSIs < 41 42 43 44 45 46 47 >
>     restart sys-net domU
>     (XEN) 0000:03:00.0 - d24 - node -1  - MSIs < 41 42 43 44 45 46 47 48 >
>     restart sys-net domU
>     (XEN) 0000:03:00.0 - d26 - node -1  - MSIs < 41 42 43 44 45 46 47 48 49 >
> 
> and 'M' output is:
> 
>     (XEN)  MSI-X   41 vec=b1 lowest  edge   assert  log lowest dest=00000001 mask=1/H /1
>     (XEN)  MSI-X   42 vec=b9 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
>     (XEN)  MSI-X   43 vec=c1 lowest  edge   assert  log lowest dest=00000010 mask=1/HG/1
>     (XEN)  MSI-X   44 vec=d9 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
>     (XEN)  MSI-X   45 vec=e1 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
>     (XEN)  MSI-X   46 vec=e9 lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
>     (XEN)  MSI-X   47 vec=32 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
>     (XEN)  MSI-X   48 vec=3a lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
>     (XEN)  MSI-X   49 vec=42 lowest  edge   assert  log lowest dest=00000010 mask=1/ G/1
> 
> And also, after starting and stopping the domU, `xl pci-assignable-remove 03:00.0`
> makes pciback to complain:
> 
>     [ 1180.919874] pciback 0000:03:00.0: xen_pciback: MSI-X release failed (-16)
> 
> This is all running on Xen 4.19.3, but I don't see much changes in this
> area since then.
> 
> Some more info collected at https://github.com/QubesOS/qubes-issues/issues/9335
> 
> My question is: what should be responsible for this cleanup on domain
> destroy? Xen, or maybe device model (which is QEMU in stubdomain here)?

The expectation is that qemu invokes the necessary cleanup, but of course ...

> I see some cleanup (apparently not enough) happening via QEMU when the
> domU driver is unloaded, but logically correct cleanup shouldn't depend
> on correct domU operation...

... Xen may not make itself dependent upon either DomU or QEMU.

What I find puzzling (assuming I can take the quoted output plus your annotations
verbatim) is that the device apparently uses multiple vectors, and we're leaking
exactly one of them. Also, since reboot is generally nothing else than shutdown
and immediate relaunch, is there a leak also after shutdown? I ask because it
might help to know which of the multiple vectors is leaked (first, last, random).

Jan

Re: MSI-X cleanup(?) issue with passthrough after domU restart

[Roger Pau Monné]

On Tue, Aug 26, 2025 at 08:16:56AM +0200, Jan Beulich wrote:
> On 26.08.2025 03:49, Marek Marczykowski-Górecki wrote:
> > Hi,
> > 
> > I'm hitting an MSI-X issue after rebooting the domU. The symptoms are
> > rather boring: on initial domU start the device (realtek eth card) works
> > fine, but after domU restart, the link doesn't come up (there is no
> > "Link is Up" message anymore). No errors from domU driver or Xen. I
> > tracked it down to MSI-X - if I force INTx (via pci=nomsi on domU
> > cmdline) it works fine. Convincing the driver to poll instead of waiting
> > for an interrupt also workarounds the issue.
> > 
> > I noticed also some interrupts are not cleaned up on restart. The list
> > of MSIs in 'Q' debug key output grows:
> > 
> >     (XEN) 0000:03:00.0 - d22 - node -1  - MSIs < 41 42 43 44 45 46 47 >
> >     restart sys-net domU
> >     (XEN) 0000:03:00.0 - d24 - node -1  - MSIs < 41 42 43 44 45 46 47 48 >
> >     restart sys-net domU
> >     (XEN) 0000:03:00.0 - d26 - node -1  - MSIs < 41 42 43 44 45 46 47 48 49 >
> > 
> > and 'M' output is:
> > 
> >     (XEN)  MSI-X   41 vec=b1 lowest  edge   assert  log lowest dest=00000001 mask=1/H /1
> >     (XEN)  MSI-X   42 vec=b9 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
> >     (XEN)  MSI-X   43 vec=c1 lowest  edge   assert  log lowest dest=00000010 mask=1/HG/1
> >     (XEN)  MSI-X   44 vec=d9 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
> >     (XEN)  MSI-X   45 vec=e1 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
> >     (XEN)  MSI-X   46 vec=e9 lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
> >     (XEN)  MSI-X   47 vec=32 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
> >     (XEN)  MSI-X   48 vec=3a lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
> >     (XEN)  MSI-X   49 vec=42 lowest  edge   assert  log lowest dest=00000010 mask=1/ G/1
> > 
> > And also, after starting and stopping the domU, `xl pci-assignable-remove 03:00.0`
> > makes pciback to complain:
> > 
> >     [ 1180.919874] pciback 0000:03:00.0: xen_pciback: MSI-X release failed (-16)
> > 
> > This is all running on Xen 4.19.3, but I don't see much changes in this
> > area since then.
> > 
> > Some more info collected at https://github.com/QubesOS/qubes-issues/issues/9335
> > 
> > My question is: what should be responsible for this cleanup on domain
> > destroy? Xen, or maybe device model (which is QEMU in stubdomain here)?
> 
> The expectation is that qemu invokes the necessary cleanup, but of course ...
> 
> > I see some cleanup (apparently not enough) happening via QEMU when the
> > domU driver is unloaded, but logically correct cleanup shouldn't depend
> > on correct domU operation...
> 
> ... Xen may not make itself dependent upon either DomU or QEMU.

AFAICT free_domain_pirqs() called by arch_domain_destroy() should take
care of unbinding and freeing pirqs (but obviously not in this case).
Can you repeat the test with a debug=y hypervisor and post the
resulting serial or dmesg here?  Some of the errors on those paths are
printed with dprintk() and won't be visible unless using a Xen debug
build.

> What I find puzzling (assuming I can take the quoted output plus your annotations
> verbatim) is that the device apparently uses multiple vectors, and we're leaking
> exactly one of them. Also, since reboot is generally nothing else than shutdown
> and immediate relaunch, is there a leak also after shutdown? I ask because it
> might help to know which of the multiple vectors is leaked (first, last, random).

Can we maybe get the output of `lspci -vv` when the device is
attached?

Thanks, Roger.

Re: MSI-X cleanup(?) issue with passthrough after domU restart

[Marek Marczykowski-Górecki]

[-- Attachment #1: Type: text/plain, Size: 11469 bytes --]

On Tue, Aug 26, 2025 at 10:28:56AM +0200, Roger Pau Monné wrote:
> On Tue, Aug 26, 2025 at 08:16:56AM +0200, Jan Beulich wrote:
> > On 26.08.2025 03:49, Marek Marczykowski-Górecki wrote:
> > > Hi,
> > > 
> > > I'm hitting an MSI-X issue after rebooting the domU. The symptoms are
> > > rather boring: on initial domU start the device (realtek eth card) works
> > > fine, but after domU restart, the link doesn't come up (there is no
> > > "Link is Up" message anymore). No errors from domU driver or Xen. I
> > > tracked it down to MSI-X - if I force INTx (via pci=nomsi on domU
> > > cmdline) it works fine. Convincing the driver to poll instead of waiting
> > > for an interrupt also workarounds the issue.
> > > 
> > > I noticed also some interrupts are not cleaned up on restart. The list
> > > of MSIs in 'Q' debug key output grows:
> > > 
> > >     (XEN) 0000:03:00.0 - d22 - node -1  - MSIs < 41 42 43 44 45 46 47 >
> > >     restart sys-net domU
> > >     (XEN) 0000:03:00.0 - d24 - node -1  - MSIs < 41 42 43 44 45 46 47 48 >
> > >     restart sys-net domU
> > >     (XEN) 0000:03:00.0 - d26 - node -1  - MSIs < 41 42 43 44 45 46 47 48 49 >
> > > 
> > > and 'M' output is:
> > > 
> > >     (XEN)  MSI-X   41 vec=b1 lowest  edge   assert  log lowest dest=00000001 mask=1/H /1
> > >     (XEN)  MSI-X   42 vec=b9 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
> > >     (XEN)  MSI-X   43 vec=c1 lowest  edge   assert  log lowest dest=00000010 mask=1/HG/1
> > >     (XEN)  MSI-X   44 vec=d9 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
> > >     (XEN)  MSI-X   45 vec=e1 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
> > >     (XEN)  MSI-X   46 vec=e9 lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
> > >     (XEN)  MSI-X   47 vec=32 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
> > >     (XEN)  MSI-X   48 vec=3a lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
> > >     (XEN)  MSI-X   49 vec=42 lowest  edge   assert  log lowest dest=00000010 mask=1/ G/1
> > > 
> > > And also, after starting and stopping the domU, `xl pci-assignable-remove 03:00.0`
> > > makes pciback to complain:
> > > 
> > >     [ 1180.919874] pciback 0000:03:00.0: xen_pciback: MSI-X release failed (-16)
> > > 
> > > This is all running on Xen 4.19.3, but I don't see much changes in this
> > > area since then.
> > > 
> > > Some more info collected at https://github.com/QubesOS/qubes-issues/issues/9335
> > > 
> > > My question is: what should be responsible for this cleanup on domain
> > > destroy? Xen, or maybe device model (which is QEMU in stubdomain here)?
> > 
> > The expectation is that qemu invokes the necessary cleanup, but of course ...
> > 
> > > I see some cleanup (apparently not enough) happening via QEMU when the
> > > domU driver is unloaded, but logically correct cleanup shouldn't depend
> > > on correct domU operation...
> > 
> > ... Xen may not make itself dependent upon either DomU or QEMU.
> 
> AFAICT free_domain_pirqs() called by arch_domain_destroy() should take
> care of unbinding and freeing pirqs (but obviously not in this case).
> Can you repeat the test with a debug=y hypervisor and post the
> resulting serial or dmesg here?  Some of the errors on those paths are
> printed with dprintk() and won't be visible unless using a Xen debug
> build.

Sure, will do.

> > What I find puzzling (assuming I can take the quoted output plus your annotations
> > verbatim) is that the device apparently uses multiple vectors, 

No, that was not the first domU restart before I started collecting this
output. At fresh boot there is just one vector.

> > and we're leaking
> > exactly one of them. Also, since reboot is generally nothing else than shutdown
> > and immediate relaunch, is there a leak also after shutdown? I ask because it
> > might help to know which of the multiple vectors is leaked (first, last, random).
> 
> Can we maybe get the output of `lspci -vv` when the device is
> attached?

Both below on first domU start, when the device still works, but when it
breaks it's identical.

Collected in dom0:
03:00.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL8111/8168/8211/8411 PCI Express Gigabit Ethernet Controller (rev 06)
	Subsystem: Gigabyte Technology Co., Ltd Onboard Ethernet
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0, Cache Line Size: 64 bytes
	Interrupt: pin A routed to IRQ 18
	Region 0: I/O ports at e000 [size=256]
	Region 2: Memory at f7c00000 (64-bit, non-prefetchable) [size=4K]
	Region 4: Memory at f0000000 (64-bit, prefetchable) [size=16K]
	Capabilities: [40] Power Management version 3
		Flags: PMEClk- DSI- D1+ D2+ AuxCurrent=375mA PME(D0+,D1+,D2+,D3hot+,D3cold+)
		Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME-
	Capabilities: [50] MSI: Enable- Count=1/1 Maskable- 64bit+
		Address: 0000000000000000  Data: 0000
	Capabilities: [70] Express (v2) Endpoint, IntMsgNum 1
		DevCap:	MaxPayload 128 bytes, PhantFunc 0, Latency L0s <512ns, L1 <64us
			ExtTag- AttnBtn- AttnInd- PwrInd- RBE+ FLReset- SlotPowerLimit 10W TEE-IO-
		DevCtl:	CorrErr+ NonFatalErr+ FatalErr+ UnsupReq+
			RlxdOrd- ExtTag- PhantFunc- AuxPwr- NoSnoop-
			MaxPayload 128 bytes, MaxReadReq 4096 bytes
		DevSta:	CorrErr- NonFatalErr- FatalErr- UnsupReq- AuxPwr+ TransPend-
		LnkCap:	Port #0, Speed 2.5GT/s, Width x1, ASPM L0s L1, Exit Latency L0s unlimited, L1 <64us
			ClockPM+ Surprise- LLActRep- BwNot- ASPMOptComp-
		LnkCtl:	ASPM Disabled; RCB 64 bytes, LnkDisable- CommClk+
			ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt- FltModeDis-
		LnkSta:	Speed 2.5GT/s, Width x1
			TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt-
		DevCap2: Completion Timeout: Range ABCD, TimeoutDis+ NROPrPrP- LTR-
			 10BitTagComp- 10BitTagReq- OBFF Not Supported, ExtFmt- EETLPPrefix-
			 EmergencyPowerReduction Not Supported, EmergencyPowerReductionInit-
			 FRS- TPHComp- ExtTPHComp-
			 AtomicOpsCap: 32bit- 64bit- 128bitCAS-
		DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-
			 AtomicOpsCtl: ReqEn-
			 IDOReq- IDOCompl- LTR- EmergencyPowerReductionReq-
			 10BitTagReq- OBFF Disabled, EETLPPrefixBlk-
		LnkCtl2: Target Link Speed: 2.5GT/s, EnterCompliance- SpeedDis-
			 Transmit Margin: Normal Operating Range, EnterModifiedCompliance- ComplianceSOS-
			 Compliance Preset/De-emphasis: -6dB de-emphasis, 0dB preshoot
		LnkSta2: Current De-emphasis Level: -6dB, EqualizationComplete- EqualizationPhase1-
			 EqualizationPhase2- EqualizationPhase3- LinkEqualizationRequest-
			 Retimer- 2Retimers- CrosslinkRes: unsupported, FltMode-
	Capabilities: [b0] MSI-X: Enable+ Count=4 Masked-
		Vector table: BAR=4 offset=00000000
		PBA: BAR=4 offset=00000800
	Capabilities: [d0] Vital Product Data
		Not readable
	Capabilities: [100 v1] Advanced Error Reporting
		UESta:	DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP-
			ECRC- UnsupReq- ACSViol- UncorrIntErr- BlockedTLP- AtomicOpBlocked- TLPBlockedErr-
			PoisonTLPBlocked- DMWrReqBlocked- IDECheck- MisIDETLP- PCRC_CHECK- TLPXlatBlocked-
		UEMsk:	DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP-
			ECRC- UnsupReq- ACSViol- UncorrIntErr- BlockedTLP- AtomicOpBlocked- TLPBlockedErr-
			PoisonTLPBlocked- DMWrReqBlocked- IDECheck- MisIDETLP- PCRC_CHECK- TLPXlatBlocked-
		UESvrt:	DLP+ SDES+ TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt- RxOF+ MalfTLP+
			ECRC- UnsupReq- ACSViol- UncorrIntErr- BlockedTLP- AtomicOpBlocked- TLPBlockedErr-
			PoisonTLPBlocked- DMWrReqBlocked- IDECheck- MisIDETLP- PCRC_CHECK- TLPXlatBlocked-
		CESta:	RxErr- BadTLP- BadDLLP- Rollover- Timeout- AdvNonFatalErr- CorrIntErr- HeaderOF-
		CEMsk:	RxErr- BadTLP- BadDLLP- Rollover- Timeout- AdvNonFatalErr+ CorrIntErr- HeaderOF-
		AERCap:	First Error Pointer: 00, ECRCGenCap+ ECRCGenEn- ECRCChkCap+ ECRCChkEn-
			MultHdrRecCap- MultHdrRecEn- TLPPfxPres- HdrLogCap-
		HeaderLog: 00000000 00000000 00000000 00000000
	Capabilities: [140 v1] Virtual Channel
		Caps:	LPEVC=0 RefClk=100ns PATEntryBits=1
		Arb:	Fixed- WRR32- WRR64- WRR128-
		Ctrl:	ArbSelect=Fixed
		Status:	InProgress-
		VC0:	Caps:	PATOffset=00 MaxTimeSlots=1 RejSnoopTrans-
			Arb:	Fixed- WRR32- WRR64- WRR128- TWRR128- WRR256-
			Ctrl:	Enable+ ID=0 ArbSelect=Fixed TC/VC=01
			Status:	NegoPending- InProgress-
	Capabilities: [160 v1] Device Serial Number 01-00-00-00-68-4c-e0-00
	Kernel driver in use: pciback
	Kernel modules: r8169


and the domU view:

00:06.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL8111/8168/8211/8411 PCI Express Gigabit Ethernet Controller (rev 06)
	Subsystem: Gigabyte Technology Co., Ltd Onboard Ethernet
	Physical Slot: 6
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0, Cache Line Size: 64 bytes
	Interrupt: pin A routed to IRQ 40
	Region 0: I/O ports at c200 [size=256]
	Region 2: Memory at f2018000 (64-bit, non-prefetchable) [size=4K]
	Region 4: Memory at f2010000 (64-bit, prefetchable) [size=16K]
	Capabilities: [40] Power Management version 3
		Flags: PMEClk- DSI- D1+ D2+ AuxCurrent=0mA PME(D0-,D1-,D2-,D3hot-,D3cold-)
		Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME-
	Capabilities: [50] MSI: Enable- Count=1/1 Maskable- 64bit+
		Address: 0000000000000000  Data: 0000
	Capabilities: [70] Express (v2) Endpoint, IntMsgNum 1
		DevCap:	MaxPayload 128 bytes, PhantFunc 0, Latency L0s <512ns, L1 <64us
			ExtTag- AttnBtn- AttnInd- PwrInd- RBE+ FLReset- SlotPowerLimit 10W TEE-IO-
		DevCtl:	CorrErr+ NonFatalErr+ FatalErr+ UnsupReq+
			RlxdOrd- ExtTag- PhantFunc- AuxPwr- NoSnoop-
			MaxPayload 128 bytes, MaxReadReq 4096 bytes
		DevSta:	CorrErr- NonFatalErr- FatalErr- UnsupReq- AuxPwr+ TransPend-
		LnkCap:	Port #0, Speed 2.5GT/s, Width x1, ASPM L0s L1, Exit Latency L0s unlimited, L1 <64us
			ClockPM+ Surprise- LLActRep- BwNot- ASPMOptComp-
		LnkCtl:	ASPM Disabled; RCB 64 bytes, LnkDisable- CommClk+
			ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt- FltModeDis-
		LnkSta:	Speed 2.5GT/s, Width x1
			TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt-
		DevCap2: Completion Timeout: Range ABCD, TimeoutDis+ NROPrPrP- LTR-
			 10BitTagComp- 10BitTagReq- OBFF Not Supported, ExtFmt- EETLPPrefix-
			 EmergencyPowerReduction Not Supported, EmergencyPowerReductionInit-
			 FRS- TPHComp- ExtTPHComp-
			 AtomicOpsCap: 32bit- 64bit- 128bitCAS-
		DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-
			 AtomicOpsCtl: ReqEn-
			 IDOReq- IDOCompl- LTR- EmergencyPowerReductionReq-
			 10BitTagReq- OBFF Disabled, EETLPPrefixBlk-
		LnkSta2: Current De-emphasis Level: -6dB, EqualizationComplete- EqualizationPhase1-
			 EqualizationPhase2- EqualizationPhase3- LinkEqualizationRequest-
			 Retimer- 2Retimers- CrosslinkRes: unsupported, FltMode-
	Capabilities: [b0] MSI-X: Enable+ Count=4 Masked-
		Vector table: BAR=4 offset=00000000
		PBA: BAR=4 offset=00000800
	Capabilities: [d0] Vital Product Data
		Not readable
	Kernel driver in use: r8169
	Kernel modules: r8169


-- 
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 488 bytes --]

Re: MSI-X cleanup(?) issue with passthrough after domU restart

[Marek Marczykowski-Górecki]

[-- Attachment #1: Type: text/plain, Size: 19897 bytes --]

On Tue, Aug 26, 2025 at 12:57:50PM +0200, Marek Marczykowski-Górecki wrote:
> On Tue, Aug 26, 2025 at 10:28:56AM +0200, Roger Pau Monné wrote:
> > On Tue, Aug 26, 2025 at 08:16:56AM +0200, Jan Beulich wrote:
> > > On 26.08.2025 03:49, Marek Marczykowski-Górecki wrote:
> > > > Hi,
> > > > 
> > > > I'm hitting an MSI-X issue after rebooting the domU. The symptoms are
> > > > rather boring: on initial domU start the device (realtek eth card) works
> > > > fine, but after domU restart, the link doesn't come up (there is no
> > > > "Link is Up" message anymore). No errors from domU driver or Xen. I
> > > > tracked it down to MSI-X - if I force INTx (via pci=nomsi on domU
> > > > cmdline) it works fine. Convincing the driver to poll instead of waiting
> > > > for an interrupt also workarounds the issue.
> > > > 
> > > > I noticed also some interrupts are not cleaned up on restart. The list
> > > > of MSIs in 'Q' debug key output grows:
> > > > 
> > > >     (XEN) 0000:03:00.0 - d22 - node -1  - MSIs < 41 42 43 44 45 46 47 >
> > > >     restart sys-net domU
> > > >     (XEN) 0000:03:00.0 - d24 - node -1  - MSIs < 41 42 43 44 45 46 47 48 >
> > > >     restart sys-net domU
> > > >     (XEN) 0000:03:00.0 - d26 - node -1  - MSIs < 41 42 43 44 45 46 47 48 49 >
> > > > 
> > > > and 'M' output is:
> > > > 
> > > >     (XEN)  MSI-X   41 vec=b1 lowest  edge   assert  log lowest dest=00000001 mask=1/H /1
> > > >     (XEN)  MSI-X   42 vec=b9 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
> > > >     (XEN)  MSI-X   43 vec=c1 lowest  edge   assert  log lowest dest=00000010 mask=1/HG/1
> > > >     (XEN)  MSI-X   44 vec=d9 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
> > > >     (XEN)  MSI-X   45 vec=e1 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
> > > >     (XEN)  MSI-X   46 vec=e9 lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
> > > >     (XEN)  MSI-X   47 vec=32 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
> > > >     (XEN)  MSI-X   48 vec=3a lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
> > > >     (XEN)  MSI-X   49 vec=42 lowest  edge   assert  log lowest dest=00000010 mask=1/ G/1
> > > > 
> > > > And also, after starting and stopping the domU, `xl pci-assignable-remove 03:00.0`
> > > > makes pciback to complain:
> > > > 
> > > >     [ 1180.919874] pciback 0000:03:00.0: xen_pciback: MSI-X release failed (-16)
> > > > 
> > > > This is all running on Xen 4.19.3, but I don't see much changes in this
> > > > area since then.
> > > > 
> > > > Some more info collected at https://github.com/QubesOS/qubes-issues/issues/9335
> > > > 
> > > > My question is: what should be responsible for this cleanup on domain
> > > > destroy? Xen, or maybe device model (which is QEMU in stubdomain here)?
> > > 
> > > The expectation is that qemu invokes the necessary cleanup, but of course ...
> > > 
> > > > I see some cleanup (apparently not enough) happening via QEMU when the
> > > > domU driver is unloaded, but logically correct cleanup shouldn't depend
> > > > on correct domU operation...
> > > 
> > > ... Xen may not make itself dependent upon either DomU or QEMU.
> > 
> > AFAICT free_domain_pirqs() called by arch_domain_destroy() should take
> > care of unbinding and freeing pirqs (but obviously not in this case).
> > Can you repeat the test with a debug=y hypervisor and post the
> > resulting serial or dmesg here?  Some of the errors on those paths are
> > printed with dprintk() and won't be visible unless using a Xen debug
> > build.
> 
> Sure, will do.

Output collected during domU shutdown and subsequent startup (dom0 logs
to Xen console here too):
https://gist.github.com/marmarek/6dc3ac14d3ba840482e6361fcbd37c30

I don't see any errors there...

As for the domU-triggered cleanup, I just checked - if I unload the
driver in domU before restarting, it works fine on subsequent startup.

Relevant QEMU/stubdomain log parts (initial startup + shutdown, when
device still works):

1. Without unloading the driver:

[2025-08-26 12:57:42] [00:06.0] xen_pt_realize: Assigning real physical device 03:00.0 to devfn 0x30
[2025-08-26 12:57:42] [00:06.0] xen_pt_register_regions: IO region 0 registered (size=0x00000100 base_addr=0x0000e000 type: 0x1)
[2025-08-26 12:57:42] [00:06.0] xen_pt_register_regions: IO region 2 registered (size=0x00001000 base_addr=0xf7c00000 type: 0x4)
[2025-08-26 12:57:42] [00:06.0] xen_pt_register_regions: IO region 4 registered (size=0x00004000 base_addr=0xf0000000 type: 0x4)
[2025-08-26 12:57:42] [00:06.0] xen_pt_config_reg_init: Offset 0x0010 mismatch! Emulated=0x0000, host=0xe001, syncing to 0xe001.
[2025-08-26 12:57:42] [00:06.0] xen_pt_config_reg_init: Offset 0x0018 mismatch! Emulated=0x0000, host=0xf7c00004, syncing to 0xf7c00004.
[2025-08-26 12:57:42] [00:06.0] xen_pt_config_reg_init: Offset 0x0020 mismatch! Emulated=0x0000, host=0xf000000c, syncing to 0xf000000c.
[2025-08-26 12:57:42] [00:06.0] xen_pt_config_reg_init: Offset 0x0042 mismatch! Emulated=0x0000, host=0x07c3, syncing to 0x0603.
[2025-08-26 12:57:42] [00:06.0] xen_pt_pm_ctrl_reg_init_on: PCI power management control passthrough is on
[2025-08-26 12:57:42] [00:06.0] xen_pt_config_reg_init: Offset 0x0052 mismatch! Emulated=0x0000, host=0x0080, syncing to 0x0080.
[2025-08-26 12:57:42] [00:06.0] xen_pt_config_reg_init: Offset 0x0074 mismatch! Emulated=0x0000, host=0x5908cc0, syncing to 0x5908cc0.
[2025-08-26 12:57:42] [00:06.0] xen_pt_config_reg_init: Offset 0x007a mismatch! Emulated=0x0000, host=0x0010, syncing to 0x0010.
[2025-08-26 12:57:42] [00:06.0] xen_pt_config_reg_init: Offset 0x0082 mismatch! Emulated=0x0000, host=0x1011, syncing to 0x1011.
[2025-08-26 12:57:42] [00:06.0] xen_pt_msix_init: get MSI-X table BAR base 0xf0000000
[2025-08-26 12:57:42] [00:06.0] xen_pt_config_reg_init: Offset 0x00b2 mismatch! Emulated=0x0000, host=0x0003, syncing to 0x0003.
[2025-08-26 12:57:42] [00:06.0] xen_pt_pci_intx: intx=1
[2025-08-26 12:57:42] [00:06.0] xen_pt_realize: Real physical device 03:00.0 registered successfully
[2025-08-26 12:57:42] from-unix: {"return": {}, "id": 2020372736}
[2025-08-26 12:57:42] 
[2025-08-26 12:57:42] wrote 34 bytes to vchan
[2025-08-26 12:57:42] from-vchan: {"execute":"query-pci","id":2020372738}
[2025-08-26 12:57:42] 
[2025-08-26 12:57:42] from-unix: {"return": [{"bus": 0, "devices": [{"irq_pin": 0, "bus": 0, "qdev_id": "", "slot": 0, "class_info": {"class": 1536, "desc": "Host bridge"}, "id": {"device": 4663, "subsystem-vendor": 6900, "vendor": 32902, "subsystem": 4352}, "function": 0, "regions": []}, {"irq_pin": 0, "bus": 0, "qdev_id": "", "slot": 1, "class_info": {"class": 1537, "desc": "ISA bridge"}, "id": {"device": 28672, "subsystem-vendor": 6900, "vendor": 32902, "subsystem": 4352}, "function": 0, "regions": []}, {"irq_pin": 0, "bus": 0, "qdev_id": "", "slot": 1, "class_info": {"class": 257, "desc": "IDE controller"}, "id": {"device": 28688, "subsystem-vendor": 6900, "vendor": 32902, "subsystem": 4352}, "function": 1, "regions": [{"bar": 4, "size": 16, "address": -1, "type": "io"}]}, {"irq_pin": 1, "bus": 0, "qdev_id": "", "irq": 0, "slot": 1, "class_info": {"class": 1664, "desc": "Bridge"}, "id": {"device": 28947, "subsystem-vendor": 6900, "vendor": 32902, "subsystem": 4352}, "function": 3, "regions": []}, {"irq_pin": 1, "bus": 0, "qdev_id": "", "irq": 0, "slot": 2, "class_info": {"class": 65408}, "id": {"device": 1, "subsystem-vendor": 22611, "vendor": 22611, "subsystem": 1}, "function": 0, "regions": [{"bar": 0, "size": 256, "address": -1, "type": "io"}, {"prefetch": true, "mem_type_64": false, "bar": 1, "size": 16777216, "address": -1, "type": "memory"}]}, {"irq_pin": 1, "bus": 0, "qdev_id": "", "irq": 0, "slot": 3, "class_info": {"class": 256, "desc": "SCSI controller"}, "id": {"device": 18, "subsystem-vendor": 0, "vendor": 4096, "subsystem": 4096}, "function": 0, "regions": [{"bar": 0, "size": 256, "address": -1, "type": "io"}, {"prefetch": false, "mem_type_64": false, "bar": 1, "size": 1024, "address": -1, "type": "memory"}, {"prefetch": false, "mem_type_64": false, "bar": 2, "size": 8192, "address": -1, "type": "memory"}]}, {"irq_pin": 0, "bus": 0, "qdev_id": "", "slot": 4, "class_info": {"class": 768, "desc": "VGA controller"}, "id": {"device": 4369, "subsystem-vendor": 6900, "vendor": 4660, "subsystem": 4352}, "function": 0, "regions": [{"prefetch": true, "mem_type_64": false, "bar": 0, "size": 16777216, "address": -1, "type": "memory"}, {"prefetch": false, "mem_type_64": false, "bar": 2, "size": 4096, "address": -1, "type": "memory"}, {"prefetch": false, "mem_type_64": false, "bar": 6, "size": 65536, "address": -1, "type": "memory"}]}, {"irq_pin": 4, "bus": 0, "qdev_id": "ehci", "irq": 0, "slot": 5, "class_info": {"class": 3075, "desc": "USB controller"}, "id": {"device": 9421, "subsystem-vendor": 6900, "vendor": 32902, "subsystem": 4352}, "function": 0, "regions": [{"prefetch": false, "mem_type_64": false, "bar": 0, "size": 4096, "address": -1, "type": "memory"}]}, {"irq_pin": 1, "bus": 0, "qdev_id": "pci-pt-03_00.0", "irq": 0, "slot": 6, "class_info": {"class": 0}, "id": {"device": 33128, "subsystem-vendor": 0, "vendor": 4332, "subsystem": 0}, "function": 0, "regions": [{"bar": 0, "size": 256, "address": -1, "type": "io"}, {"prefetch": false, "mem_type_64": true, "bar": 2, "size": 4096, "address": -1, "type": "memory"}, {"prefetch": false, "mem_type_64": true, "bar": 4, "size": 16384, "address": -1, "type": "memory"}]}]}], "id": 2020372738}
[2025-08-26 12:57:42] 
[2025-08-26 12:57:42] wrote 2048 bytes to vchan
[2025-08-26 12:57:42] wrote 1125 bytes to vchan
[2025-08-26 12:57:42] vchan client disconnected
[2025-08-26 12:57:42] [00:06.0] xen_pt_check_bar_overlap: Warning: Overlapped to device [00:02.0] Region: 1 (addr: 0xf0000000, len: 0x1000000)
[2025-08-26 12:57:42] [00:06.0] xen_pt_region_update: Warning: Region: 4 (addr: 0xf0001000, len: 0x3000) is overlapped.
[2025-08-26 12:57:44] {"timestamp": {"seconds": 1756213064, "microseconds": 412107}, "event": "DEVICE_DELETED", "data": {"path": "/machine/unattached/device[8]"}}
[2025-08-26 12:57:44] {"timestamp": {"seconds": 1756213064, "microseconds": 416176}, "event": "DEVICE_DELETED", "data": {"path": "/machine/unattached/device[7]"}}
[2025-08-26 12:57:44] {"timestamp": {"seconds": 1756213064, "microseconds": 416244}, "event": "DEVICE_DELETED", "data": {"path": "/machine/unattached/device[6]"}}
[2025-08-26 12:57:44] {"timestamp": {"seconds": 1756213064, "microseconds": 416653}, "event": "DEVICE_DELETED", "data": {"path": "/machine/peripheral-anon/device[3]"}}
[2025-08-26 12:57:44] {"timestamp": {"seconds": 1756213064, "microseconds": 416694}, "event": "DEVICE_DELETED", "data": {"path": "/machine/peripheral-anon/device[0]"}}
[2025-08-26 12:57:48] [00:06.0] xen_pt_msixctrl_reg_write: enable MSI-X
[2025-08-26 12:57:48] [00:06.0] msi_msix_update: Updating MSI-X with pirq 55 gvec 0xef gflags 0x0 (entry: 0x0)
[2025-08-26 12:57:49] [00:06.0] msi_msix_update: Updating MSI-X with pirq 55 gvec 0x23 gflags 0x0 (entry: 0x0)
[2025-08-26 13:21:03] {"timestamp": {"seconds": 1756214457, "microseconds": 588341}, "event": "SHUTDOWN", "data": {"guest": true, "reason": "guest-shutdown"}}
[2025-08-26 13:21:03] {"timestamp": {"seconds": 1756214457, "microseconds": 588579}, "event": "STOP"}
[2025-08-26 13:21:03] pcifront pci-0: Rescanning PCI Frontend Bus 0000:00
[2025-08-26 13:21:03] pci_bus 0000:00: busn_res: [bus 00-ff] is released
[2025-08-26 13:21:03] ------------[ cut here ]------------
[2025-08-26 13:21:03] sysfs group 'power' not found for kobject '0000:00'
[2025-08-26 13:21:03] WARNING: CPU: 0 PID: 13 at fs/sysfs/group.c:282 sysfs_remove_group+0x3a/0x6f


2. With unloading the driver before shutdown:
[2025-08-26 13:21:07] [00:06.0] xen_pt_realize: Assigning real physical device 03:00.0 to devfn 0x30
[2025-08-26 13:21:07] [00:06.0] xen_pt_register_regions: IO region 0 registered (size=0x00000100 base_addr=0x0000e000 type: 0x1)
[2025-08-26 13:21:07] [00:06.0] xen_pt_register_regions: IO region 2 registered (size=0x00001000 base_addr=0xf7c00000 type: 0x4)
[2025-08-26 13:21:07] [00:06.0] xen_pt_register_regions: IO region 4 registered (size=0x00004000 base_addr=0xf0000000 type: 0x4)
[2025-08-26 13:21:07] [00:06.0] xen_pt_config_reg_init: Offset 0x0010 mismatch! Emulated=0x0000, host=0xe001, syncing to 0xe001.
[2025-08-26 13:21:07] [00:06.0] xen_pt_config_reg_init: Offset 0x0018 mismatch! Emulated=0x0000, host=0xf7c00004, syncing to 0xf7c00004.
[2025-08-26 13:21:07] [00:06.0] xen_pt_config_reg_init: Offset 0x0020 mismatch! Emulated=0x0000, host=0xf000000c, syncing to 0xf000000c.
[2025-08-26 13:21:07] [00:06.0] xen_pt_config_reg_init: Offset 0x0042 mismatch! Emulated=0x0000, host=0x07c3, syncing to 0x0603.
[2025-08-26 13:21:07] [00:06.0] xen_pt_pm_ctrl_reg_init_on: PCI power management control passthrough is on
[2025-08-26 13:21:07] [00:06.0] xen_pt_config_reg_init: Offset 0x0052 mismatch! Emulated=0x0000, host=0x0080, syncing to 0x0080.
[2025-08-26 13:21:07] [00:06.0] xen_pt_config_reg_init: Offset 0x0074 mismatch! Emulated=0x0000, host=0x5908cc0, syncing to 0x5908cc0.
[2025-08-26 13:21:07] [00:06.0] xen_pt_config_reg_init: Offset 0x007a mismatch! Emulated=0x0000, host=0x0010, syncing to 0x0010.
[2025-08-26 13:21:07] [00:06.0] xen_pt_config_reg_init: Offset 0x0082 mismatch! Emulated=0x0000, host=0x1011, syncing to 0x1011.
[2025-08-26 13:21:07] [00:06.0] xen_pt_msix_init: get MSI-X table BAR base 0xf0000000
[2025-08-26 13:21:07] [00:06.0] xen_pt_config_reg_init: Offset 0x00b2 mismatch! Emulated=0x0000, host=0x0003, syncing to 0x0003.
[2025-08-26 13:21:07] [00:06.0] xen_pt_pci_intx: intx=1
[2025-08-26 13:21:07] [00:06.0] xen_pt_realize: Real physical device 03:00.0 registered successfully
[2025-08-26 13:21:07] from-unix: {"return": {}, "id": 2020372736}
[2025-08-26 13:21:07] 
[2025-08-26 13:21:07] wrote 34 bytes to vchan
[2025-08-26 13:21:07] from-vchan: {"execute":"query-pci","id":2020372738}
[2025-08-26 13:21:07] 
[2025-08-26 13:21:07] from-unix: {"return": [{"bus": 0, "devices": [{"irq_pin": 0, "bus": 0, "qdev_id": "", "slot": 0, "class_info": {"class": 1536, "desc": "Host bridge"}, "id": {"device": 4663, "subsystem-vendor": 6900, "vendor": 32902, "subsystem": 4352}, "function": 0, "regions": []}, {"irq_pin": 0, "bus": 0, "qdev_id": "", "slot": 1, "class_info": {"class": 1537, "desc": "ISA bridge"}, "id": {"device": 28672, "subsystem-vendor": 6900, "vendor": 32902, "subsystem": 4352}, "function": 0, "regions": []}, {"irq_pin": 0, "bus": 0, "qdev_id": "", "slot": 1, "class_info": {"class": 257, "desc": "IDE controller"}, "id": {"device": 28688, "subsystem-vendor": 6900, "vendor": 32902, "subsystem": 4352}, "function": 1, "regions": [{"bar": 4, "size": 16, "address": -1, "type": "io"}]}, {"irq_pin": 1, "bus": 0, "qdev_id": "", "irq": 0, "slot": 1, "class_info": {"class": 1664, "desc": "Bridge"}, "id": {"device": 28947, "subsystem-vendor": 6900, "vendor": 32902, "subsystem": 4352}, "function": 3, "regions": []}, {"irq_pin": 1, "bus": 0, "qdev_id": "", "irq": 0, "slot": 2, "class_info": {"class": 65408}, "id": {"device": 1, "subsystem-vendor": 22611, "vendor": 22611, "subsystem": 1}, "function": 0, "regions": [{"bar": 0, "size": 256, "address": -1, "type": "io"}, {"prefetch": true, "mem_type_64": false, "bar": 1, "size": 16777216, "address": -1, "type": "memory"}]}, {"irq_pin": 1, "bus": 0, "qdev_id": "", "irq": 0, "slot": 3, "class_info": {"class": 256, "desc": "SCSI controller"}, "id": {"device": 18, "subsystem-vendor": 0, "vendor": 4096, "subsystem": 4096}, "function": 0, "regions": [{"bar": 0, "size": 256, "address": -1, "type": "io"}, {"prefetch": false, "mem_type_64": false, "bar": 1, "size": 1024, "address": -1, "type": "memory"}, {"prefetch": false, "mem_type_64": false, "bar": 2, "size": 8192, "address": -1, "type": "memory"}]}, {"irq_pin": 0, "bus": 0, "qdev_id": "", "slot": 4, "class_info": {"class": 768, "desc": "VGA controller"}, "id": {"device": 4369, "subsystem-vendor": 6900, "vendor": 4660, "subsystem": 4352}, "function": 0, "regions": [{"prefetch": true, "mem_type_64": false, "bar": 0, "size": 16777216, "address": -1, "type": "memory"}, {"prefetch": false, "mem_type_64": false, "bar": 2, "size": 4096, "address": -1, "type": "memory"}, {"prefetch": false, "mem_type_64": false, "bar": 6, "size": 65536, "address": -1, "type": "memory"}]}, {"irq_pin": 4, "bus": 0, "qdev_id": "ehci", "irq": 0, "slot": 5, "class_info": {"class": 3075, "desc": "USB controller"}, "id": {"device": 9421, "subsystem-vendor": 6900, "vendor": 32902, "subsystem": 4352}, "function": 0, "regions": [{"prefetch": false, "mem_type_64": false, "bar": 0, "size": 4096, "address": -1, "type": "memory"}]}, {"irq_pin": 1, "bus": 0, "qdev_id": "pci-pt-03_00.0", "irq": 0, "slot": 6, "class_info": {"class": 0}, "id": {"device": 33128, "subsystem-vendor": 0, "vendor": 4332, "subsystem": 0}, "function": 0, "regions": [{"bar": 0, "size": 256, "address": -1, "type": "io"}, {"prefetch": false, "mem_type_64": true, "bar": 2, "size": 4096, "address": -1, "type": "memory"}, {"prefetch": false, "mem_type_64": true, "bar": 4, "size": 16384, "address": -1, "type": "memory"}]}]}], "id": 2020372738}
[2025-08-26 13:21:07] 
[2025-08-26 13:21:07] wrote 2048 bytes to vchan
[2025-08-26 13:21:07] wrote 1125 bytes to vchan
[2025-08-26 13:21:07] vchan client disconnected
[2025-08-26 13:21:07] [00:06.0] xen_pt_check_bar_overlap: Warning: Overlapped to device [00:02.0] Region: 1 (addr: 0xf0000000, len: 0x1000000)
[2025-08-26 13:21:07] [00:06.0] xen_pt_region_update: Warning: Region: 4 (addr: 0xf0001000, len: 0x3000) is overlapped.
[2025-08-26 13:21:09] {"timestamp": {"seconds": 1756214469, "microseconds": 28994}, "event": "DEVICE_DELETED", "data": {"path": "/machine/unattached/device[8]"}}
[2025-08-26 13:21:09] {"timestamp": {"seconds": 1756214469, "microseconds": 32958}, "event": "DEVICE_DELETED", "data": {"path": "/machine/unattached/device[7]"}}
[2025-08-26 13:21:09] {"timestamp": {"seconds": 1756214469, "microseconds": 33004}, "event": "DEVICE_DELETED", "data": {"path": "/machine/unattached/device[6]"}}
[2025-08-26 13:21:09] {"timestamp": {"seconds": 1756214469, "microseconds": 33261}, "event": "DEVICE_DELETED", "data": {"path": "/machine/peripheral-anon/device[3]"}}
[2025-08-26 13:21:09] {"timestamp": {"seconds": 1756214469, "microseconds": 33296}, "event": "DEVICE_DELETED", "data": {"path": "/machine/peripheral-anon/device[0]"}}
[2025-08-26 13:21:12] [00:06.0] xen_pt_msixctrl_reg_write: enable MSI-X
[2025-08-26 13:21:12] [00:06.0] msi_msix_update: Updating MSI-X with pirq 55 gvec 0xef gflags 0x0 (entry: 0x0)
[2025-08-26 13:21:13] [00:06.0] msi_msix_update: Updating MSI-X with pirq 55 gvec 0x23 gflags 0x0 (entry: 0x0)
[2025-08-26 13:41:45] [00:06.0] msix_set_enable: disabling MSI-X.
[2025-08-26 13:41:45] [00:06.0] msi_msix_disable: Unbind MSI-X with pirq 55, gvec 0x23
[2025-08-26 13:41:45] [00:06.0] msi_msix_disable: Unmap MSI-X pirq 55
[2025-08-26 13:41:45] [00:06.0] xen_pt_msixctrl_reg_write: disable MSI-X
{"timestamp": {"seconds": 1756215718, "microseconds": 455554}, "event": "SHUTDOWN", "data": {"guest": true, "reason": "guest-shutdown"}}
[2025-08-26 13:41:58] {"timestamp": {"seconds": 1756215718, "microseconds": 456438}, "event": "STOP"}
[2025-08-26 13:41:58] pcifront pci-0: Rescanning PCI Frontend Bus 0000:00
[2025-08-26 13:41:58] pci_bus 0000:00: busn_res: [bus 00-ff] is released
[2025-08-26 13:41:58] ------------[ cut here ]------------
[2025-08-26 13:41:58] sysfs group 'power' not found for kobject '0000:00'
[2025-08-26 13:41:58] WARNING: CPU: 0 PID: 13 at fs/sysfs/group.c:282 sysfs_remove_group+0x3a/0x6f



-- 
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 488 bytes --]

Re: MSI-X cleanup(?) issue with passthrough after domU restart

[Roger Pau Monné]

On Tue, Aug 26, 2025 at 03:55:05PM +0200, Marek Marczykowski-Górecki wrote:
> On Tue, Aug 26, 2025 at 12:57:50PM +0200, Marek Marczykowski-Górecki wrote:
> > On Tue, Aug 26, 2025 at 10:28:56AM +0200, Roger Pau Monné wrote:
> > > On Tue, Aug 26, 2025 at 08:16:56AM +0200, Jan Beulich wrote:
> > > > On 26.08.2025 03:49, Marek Marczykowski-Górecki wrote:
> > > > > Hi,
> > > > > 
> > > > > I'm hitting an MSI-X issue after rebooting the domU. The symptoms are
> > > > > rather boring: on initial domU start the device (realtek eth card) works
> > > > > fine, but after domU restart, the link doesn't come up (there is no
> > > > > "Link is Up" message anymore). No errors from domU driver or Xen. I
> > > > > tracked it down to MSI-X - if I force INTx (via pci=nomsi on domU
> > > > > cmdline) it works fine. Convincing the driver to poll instead of waiting
> > > > > for an interrupt also workarounds the issue.
> > > > > 
> > > > > I noticed also some interrupts are not cleaned up on restart. The list
> > > > > of MSIs in 'Q' debug key output grows:
> > > > > 
> > > > >     (XEN) 0000:03:00.0 - d22 - node -1  - MSIs < 41 42 43 44 45 46 47 >
> > > > >     restart sys-net domU
> > > > >     (XEN) 0000:03:00.0 - d24 - node -1  - MSIs < 41 42 43 44 45 46 47 48 >
> > > > >     restart sys-net domU
> > > > >     (XEN) 0000:03:00.0 - d26 - node -1  - MSIs < 41 42 43 44 45 46 47 48 49 >
> > > > > 
> > > > > and 'M' output is:
> > > > > 
> > > > >     (XEN)  MSI-X   41 vec=b1 lowest  edge   assert  log lowest dest=00000001 mask=1/H /1
> > > > >     (XEN)  MSI-X   42 vec=b9 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
> > > > >     (XEN)  MSI-X   43 vec=c1 lowest  edge   assert  log lowest dest=00000010 mask=1/HG/1
> > > > >     (XEN)  MSI-X   44 vec=d9 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
> > > > >     (XEN)  MSI-X   45 vec=e1 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
> > > > >     (XEN)  MSI-X   46 vec=e9 lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
> > > > >     (XEN)  MSI-X   47 vec=32 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
> > > > >     (XEN)  MSI-X   48 vec=3a lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
> > > > >     (XEN)  MSI-X   49 vec=42 lowest  edge   assert  log lowest dest=00000010 mask=1/ G/1
> > > > > 
> > > > > And also, after starting and stopping the domU, `xl pci-assignable-remove 03:00.0`
> > > > > makes pciback to complain:
> > > > > 
> > > > >     [ 1180.919874] pciback 0000:03:00.0: xen_pciback: MSI-X release failed (-16)
> > > > > 
> > > > > This is all running on Xen 4.19.3, but I don't see much changes in this
> > > > > area since then.
> > > > > 
> > > > > Some more info collected at https://github.com/QubesOS/qubes-issues/issues/9335
> > > > > 
> > > > > My question is: what should be responsible for this cleanup on domain
> > > > > destroy? Xen, or maybe device model (which is QEMU in stubdomain here)?
> > > > 
> > > > The expectation is that qemu invokes the necessary cleanup, but of course ...
> > > > 
> > > > > I see some cleanup (apparently not enough) happening via QEMU when the
> > > > > domU driver is unloaded, but logically correct cleanup shouldn't depend
> > > > > on correct domU operation...
> > > > 
> > > > ... Xen may not make itself dependent upon either DomU or QEMU.
> > > 
> > > AFAICT free_domain_pirqs() called by arch_domain_destroy() should take
> > > care of unbinding and freeing pirqs (but obviously not in this case).
> > > Can you repeat the test with a debug=y hypervisor and post the
> > > resulting serial or dmesg here?  Some of the errors on those paths are
> > > printed with dprintk() and won't be visible unless using a Xen debug
> > > build.
> > 
> > Sure, will do.
> 
> Output collected during domU shutdown and subsequent startup (dom0 logs
> to Xen console here too):
> https://gist.github.com/marmarek/6dc3ac14d3ba840482e6361fcbd37c30
> 
> I don't see any errors there...

Hm, yes, I don't see any errors either.  Do you think you could
instrument unmap_domain_pirq() and figure out whether it gets called,
and if such call to unmap the PIRQ succeeds?

There's one silent error path in the return value of
xsm_unmap_domain_irq(), but that shouldn't be taken since the call to
unmap_domain_pirq() executed when destroying the domain is done with
d->is_dying == true.

> As for the domU-triggered cleanup, I just checked - if I unload the
> driver in domU before restarting, it works fine on subsequent startup.

Yeah, the unbind an unmap is then done by QEMU, and that seems to
work fine.  What doesn't seem to work fine is the cleanup done as part
of domain destroy.

Don't we have any Gitlab tests that do PCI passthrough?  Maybe those
don't do any domU resets?

Thanks, Roger.

Re: MSI-X cleanup(?) issue with passthrough after domU restart

[Marek Marczykowski-Górecki]

[-- Attachment #1: Type: text/plain, Size: 5374 bytes --]

On Tue, Aug 26, 2025 at 04:47:50PM +0200, Roger Pau Monné wrote:
> On Tue, Aug 26, 2025 at 03:55:05PM +0200, Marek Marczykowski-Górecki wrote:
> > On Tue, Aug 26, 2025 at 12:57:50PM +0200, Marek Marczykowski-Górecki wrote:
> > > On Tue, Aug 26, 2025 at 10:28:56AM +0200, Roger Pau Monné wrote:
> > > > On Tue, Aug 26, 2025 at 08:16:56AM +0200, Jan Beulich wrote:
> > > > > On 26.08.2025 03:49, Marek Marczykowski-Górecki wrote:
> > > > > > Hi,
> > > > > > 
> > > > > > I'm hitting an MSI-X issue after rebooting the domU. The symptoms are
> > > > > > rather boring: on initial domU start the device (realtek eth card) works
> > > > > > fine, but after domU restart, the link doesn't come up (there is no
> > > > > > "Link is Up" message anymore). No errors from domU driver or Xen. I
> > > > > > tracked it down to MSI-X - if I force INTx (via pci=nomsi on domU
> > > > > > cmdline) it works fine. Convincing the driver to poll instead of waiting
> > > > > > for an interrupt also workarounds the issue.
> > > > > > 
> > > > > > I noticed also some interrupts are not cleaned up on restart. The list
> > > > > > of MSIs in 'Q' debug key output grows:
> > > > > > 
> > > > > >     (XEN) 0000:03:00.0 - d22 - node -1  - MSIs < 41 42 43 44 45 46 47 >
> > > > > >     restart sys-net domU
> > > > > >     (XEN) 0000:03:00.0 - d24 - node -1  - MSIs < 41 42 43 44 45 46 47 48 >
> > > > > >     restart sys-net domU
> > > > > >     (XEN) 0000:03:00.0 - d26 - node -1  - MSIs < 41 42 43 44 45 46 47 48 49 >
> > > > > > 
> > > > > > and 'M' output is:
> > > > > > 
> > > > > >     (XEN)  MSI-X   41 vec=b1 lowest  edge   assert  log lowest dest=00000001 mask=1/H /1
> > > > > >     (XEN)  MSI-X   42 vec=b9 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
> > > > > >     (XEN)  MSI-X   43 vec=c1 lowest  edge   assert  log lowest dest=00000010 mask=1/HG/1
> > > > > >     (XEN)  MSI-X   44 vec=d9 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
> > > > > >     (XEN)  MSI-X   45 vec=e1 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
> > > > > >     (XEN)  MSI-X   46 vec=e9 lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
> > > > > >     (XEN)  MSI-X   47 vec=32 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
> > > > > >     (XEN)  MSI-X   48 vec=3a lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
> > > > > >     (XEN)  MSI-X   49 vec=42 lowest  edge   assert  log lowest dest=00000010 mask=1/ G/1
> > > > > > 
> > > > > > And also, after starting and stopping the domU, `xl pci-assignable-remove 03:00.0`
> > > > > > makes pciback to complain:
> > > > > > 
> > > > > >     [ 1180.919874] pciback 0000:03:00.0: xen_pciback: MSI-X release failed (-16)
> > > > > > 
> > > > > > This is all running on Xen 4.19.3, but I don't see much changes in this
> > > > > > area since then.
> > > > > > 
> > > > > > Some more info collected at https://github.com/QubesOS/qubes-issues/issues/9335
> > > > > > 
> > > > > > My question is: what should be responsible for this cleanup on domain
> > > > > > destroy? Xen, or maybe device model (which is QEMU in stubdomain here)?
> > > > > 
> > > > > The expectation is that qemu invokes the necessary cleanup, but of course ...
> > > > > 
> > > > > > I see some cleanup (apparently not enough) happening via QEMU when the
> > > > > > domU driver is unloaded, but logically correct cleanup shouldn't depend
> > > > > > on correct domU operation...
> > > > > 
> > > > > ... Xen may not make itself dependent upon either DomU or QEMU.
> > > > 
> > > > AFAICT free_domain_pirqs() called by arch_domain_destroy() should take
> > > > care of unbinding and freeing pirqs (but obviously not in this case).
> > > > Can you repeat the test with a debug=y hypervisor and post the
> > > > resulting serial or dmesg here?  Some of the errors on those paths are
> > > > printed with dprintk() and won't be visible unless using a Xen debug
> > > > build.
> > > 
> > > Sure, will do.
> > 
> > Output collected during domU shutdown and subsequent startup (dom0 logs
> > to Xen console here too):
> > https://gist.github.com/marmarek/6dc3ac14d3ba840482e6361fcbd37c30
> > 
> > I don't see any errors there...
> 
> Hm, yes, I don't see any errors either.  Do you think you could
> instrument unmap_domain_pirq() and figure out whether it gets called,
> and if such call to unmap the PIRQ succeeds?

Sure, now that I know where to look at, I'll try to find out what goes
wrong.

> There's one silent error path in the return value of
> xsm_unmap_domain_irq(), but that shouldn't be taken since the call to
> unmap_domain_pirq() executed when destroying the domain is done with
> d->is_dying == true.
> 
> > As for the domU-triggered cleanup, I just checked - if I unload the
> > driver in domU before restarting, it works fine on subsequent startup.
> 
> Yeah, the unbind an unmap is then done by QEMU, and that seems to
> work fine.  What doesn't seem to work fine is the cleanup done as part
> of domain destroy.
> 
> Don't we have any Gitlab tests that do PCI passthrough?  Maybe those
> don't do any domU resets?

Yeah, it's a single boot and that's it. I can improve that (and double
check if MSI-X is covered too).

-- 
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 488 bytes --]

Re: MSI-X cleanup(?) issue with passthrough after domU restart

[Marek Marczykowski-Górecki]

[-- Attachment #1: Type: text/plain, Size: 5350 bytes --]

On Tue, Aug 26, 2025 at 04:52:17PM +0200, Marek Marczykowski-Górecki wrote:
> On Tue, Aug 26, 2025 at 04:47:50PM +0200, Roger Pau Monné wrote:
> > On Tue, Aug 26, 2025 at 03:55:05PM +0200, Marek Marczykowski-Górecki wrote:
> > > On Tue, Aug 26, 2025 at 12:57:50PM +0200, Marek Marczykowski-Górecki wrote:
> > > > On Tue, Aug 26, 2025 at 10:28:56AM +0200, Roger Pau Monné wrote:
> > > > > On Tue, Aug 26, 2025 at 08:16:56AM +0200, Jan Beulich wrote:
> > > > > > On 26.08.2025 03:49, Marek Marczykowski-Górecki wrote:
> > > > > > > Hi,
> > > > > > > 
> > > > > > > I'm hitting an MSI-X issue after rebooting the domU. The symptoms are
> > > > > > > rather boring: on initial domU start the device (realtek eth card) works
> > > > > > > fine, but after domU restart, the link doesn't come up (there is no
> > > > > > > "Link is Up" message anymore). No errors from domU driver or Xen. I
> > > > > > > tracked it down to MSI-X - if I force INTx (via pci=nomsi on domU
> > > > > > > cmdline) it works fine. Convincing the driver to poll instead of waiting
> > > > > > > for an interrupt also workarounds the issue.
> > > > > > > 
> > > > > > > I noticed also some interrupts are not cleaned up on restart. The list
> > > > > > > of MSIs in 'Q' debug key output grows:
> > > > > > > 
> > > > > > >     (XEN) 0000:03:00.0 - d22 - node -1  - MSIs < 41 42 43 44 45 46 47 >
> > > > > > >     restart sys-net domU
> > > > > > >     (XEN) 0000:03:00.0 - d24 - node -1  - MSIs < 41 42 43 44 45 46 47 48 >
> > > > > > >     restart sys-net domU
> > > > > > >     (XEN) 0000:03:00.0 - d26 - node -1  - MSIs < 41 42 43 44 45 46 47 48 49 >
> > > > > > > 
> > > > > > > and 'M' output is:
> > > > > > > 
> > > > > > >     (XEN)  MSI-X   41 vec=b1 lowest  edge   assert  log lowest dest=00000001 mask=1/H /1
> > > > > > >     (XEN)  MSI-X   42 vec=b9 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
> > > > > > >     (XEN)  MSI-X   43 vec=c1 lowest  edge   assert  log lowest dest=00000010 mask=1/HG/1
> > > > > > >     (XEN)  MSI-X   44 vec=d9 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
> > > > > > >     (XEN)  MSI-X   45 vec=e1 lowest  edge   assert  log lowest dest=00000001 mask=1/HG/1
> > > > > > >     (XEN)  MSI-X   46 vec=e9 lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
> > > > > > >     (XEN)  MSI-X   47 vec=32 lowest  edge   assert  log lowest dest=00000004 mask=1/HG/1
> > > > > > >     (XEN)  MSI-X   48 vec=3a lowest  edge   assert  log lowest dest=00000040 mask=1/HG/1
> > > > > > >     (XEN)  MSI-X   49 vec=42 lowest  edge   assert  log lowest dest=00000010 mask=1/ G/1
> > > > > > > 
> > > > > > > And also, after starting and stopping the domU, `xl pci-assignable-remove 03:00.0`
> > > > > > > makes pciback to complain:
> > > > > > > 
> > > > > > >     [ 1180.919874] pciback 0000:03:00.0: xen_pciback: MSI-X release failed (-16)
> > > > > > > 
> > > > > > > This is all running on Xen 4.19.3, but I don't see much changes in this
> > > > > > > area since then.
> > > > > > > 
> > > > > > > Some more info collected at https://github.com/QubesOS/qubes-issues/issues/9335
> > > > > > > 
> > > > > > > My question is: what should be responsible for this cleanup on domain
> > > > > > > destroy? Xen, or maybe device model (which is QEMU in stubdomain here)?
> > > > > > 
> > > > > > The expectation is that qemu invokes the necessary cleanup, but of course ...
> > > > > > 
> > > > > > > I see some cleanup (apparently not enough) happening via QEMU when the
> > > > > > > domU driver is unloaded, but logically correct cleanup shouldn't depend
> > > > > > > on correct domU operation...
> > > > > > 
> > > > > > ... Xen may not make itself dependent upon either DomU or QEMU.
> > > > > 
> > > > > AFAICT free_domain_pirqs() called by arch_domain_destroy() should take
> > > > > care of unbinding and freeing pirqs (but obviously not in this case).
> > > > > Can you repeat the test with a debug=y hypervisor and post the
> > > > > resulting serial or dmesg here?  Some of the errors on those paths are
> > > > > printed with dprintk() and won't be visible unless using a Xen debug
> > > > > build.
> > > > 
> > > > Sure, will do.
> > > 
> > > Output collected during domU shutdown and subsequent startup (dom0 logs
> > > to Xen console here too):
> > > https://gist.github.com/marmarek/6dc3ac14d3ba840482e6361fcbd37c30
> > > 
> > > I don't see any errors there...
> > 
> > Hm, yes, I don't see any errors either.  Do you think you could
> > instrument unmap_domain_pirq() and figure out whether it gets called,
> > and if such call to unmap the PIRQ succeeds?
> 
> Sure, now that I know where to look at, I'll try to find out what goes
> wrong.

Ok, after adding several debug prints there and looking why it's not
called, I found it's a completely different issue. arch_domain_destroy()
is not called, because there was a dom0 userspace process still having a
page mapped of that domain, and indeed there was a zombie on xl list.
Killing that process fixes it.

Sorry for the noise...

> Yeah, it's a single boot and that's it. I can improve that (and double
> check if MSI-X is covered too).

But this might be a good idea anyway.

-- 
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 488 bytes --]