qubes 3.2 - sys-net ath10k_pci swiotlb buffer is full after a couple of s3 suspends (wireless not working)

[Vladimir Lushnikov]

Hello,

Recently my "Killer Wireless-AC 1535" card has been playing up after
resuming from S3. It wasn't 100% stable before but usually I was able to
fix it by either rmmod'ing the driver (ath10k_pci) or restarting sys-net.

Qubes OS: 3.2
dom0: xen 4.6.5, kernel 4.9.35-19
sys-net: fedora-25, kernel cmdline: nopat iommu=soft swiotlb=8192
Wireless card: Qualcomm Atheros QCA6174

This is what a normal kernel log (snippet) looks like on sys-net at startup:


[ 2.471771] ath10k_pci 0000:00:00.0: Xen PCI mapped GSI16 to IRQ26
[ 2.472419] ath10k_pci 0000:00:00.0: pci irq msi oper_irq_mode 2
irq_mode 0 reset_mode 0
[ 2.686863] ath10k_pci 0000:00:00.0: Direct firmware load for
ath10k/pre-cal-pci-0000:00:00.0.bin failed with error -2
[ 2.686887] ath10k_pci 0000:00:00.0: Direct firmware load for
ath10k/cal-pci-0000:00:00.0.bin failed with error -2
[ 2.687344] ath10k_pci 0000:00:00.0: Direct firmware load for
ath10k/QCA6174/hw3.0/firmware-5.bin failed with error -2
[ 2.687362] ath10k_pci 0000:00:00.0: could not fetch firmware file
'ath10k/QCA6174/hw3.0/firmware-5.bin': -2
[ 2.692190] ath10k_pci 0000:00:00.0: qca6174 hw3.2 target 0x05030000
chip_id 0x00340aff sub 1a56:1535
[ 2.692203] ath10k_pci 0000:00:00.0: kconfig debug 0 debugfs 1
tracing 0 dfs 0 testmode 0
[ 2.692700] ath10k_pci 0000:00:00.0: firmware ver
WLAN.RM.2.0-00180-QCARMSWPZ-1 api 4 features
wowlan,ignore-otp,no-4addr-pad crc32 75dee6c5
[ 2.759968] ath10k_pci 0000:00:00.0: board_file api 2 bmi_id N/A
crc32 19644295
[ 4.878008] ath10k_pci 0000:00:00.0: htt-ver 3.26 wmi-op 4 htt-op 3
cal otp max-sta 32 raw 0 hwcrypto 1
[ 4.940376] ath: EEPROM regdomain: 0x6c
[ 4.940379] ath: EEPROM indicates we should expect a direct regpair map
[ 4.940383] ath: Country alpha2 being used: 00
[ 4.940385] ath: Regpair used: 0x6c
[ 4.964842] ath10k_pci 0000:00:00.0 wlp0s0: renamed from wlan0


After a couple of S3 resumes (sometimes it works fine for 4-5 resumes):

[11631.485745] PM: noirq thaw of devices complete after 0.500 msecs
[11631.485745] PM: early thaw of devices complete after 0.137 msecs
[11631.494090] PM: thaw of devices complete after 0.164 msecs
[11631.494168] Restarting tasks ... done.
[11632.215649] xen:events: xen_bind_pirq_gsi_to_irq: returning irq 26
for gsi 16
[11632.215663] ath10k_pci 0000:00:00.0: Xen PCI mapped GSI16 to IRQ26
[11632.216572] ath10k_pci 0000:00:00.0: pci irq msi oper_irq_mode 2
irq_mode 0 reset_mode 0
[11632.428622] ath10k_pci 0000:00:00.0: Direct firmware load for
ath10k/pre-cal-pci-0000:00:00.0.bin failed with error -2
[11632.428648] ath10k_pci 0000:00:00.0: Direct firmware load for
ath10k/cal-pci-0000:00:00.0.bin failed with error -2
[11632.428662] ath10k_pci 0000:00:00.0: Direct firmware load for
ath10k/QCA6174/hw3.0/firmware-5.bin failed with error -2
[11632.428670] ath10k_pci 0000:00:00.0: could not fetch firmware file
'ath10k/QCA6174/hw3.0/firmware-5.bin': -2
[11632.428977] ath10k_pci 0000:00:00.0: qca6174 hw3.2 target 0x050s30000
chip_id 0x00340aff sub 1a56:1535
[11632.428986] ath10k_pci 0000:00:00.0: kconfig debug 0 debugfs 1
tracing 0 dfs 0 testmode 0
[11632.429571] ath10k_pci 0000:00:00.0: firmware ver
WLAN.RM.2.0-00180-QCARMSWPZ-1 api 4 features
wowlan,ignore-otp,no-4addr-pad crc32 75dee6c5
[11632.491890] ath10k_pci 0000:00:00.0: board_file api 2 bmi_id N/A
crc32 19644295
[11635.005126] ath10k_pci 0000:00:00.0: swiotlb buffer is full (sz: 1984
bytes)
[11635.009958] ath10k_pci 0000:00:00.0: swiotlb buffer is full (sz: 2048
bytes)
[11635.009974] ath10k_pci 0000:00:00.0: failed to dma map pci rx buf
[11635.009993] ath10k_pci 0000:00:00.0: failed to post pci rx buf: -5
[11635.010058] ath10k_pci 0000:00:00.0: swiotlb buffer is full (sz: 1984
bytes)
[11635.010142] ath10k_pci 0000:00:00.0: swiotlb buffer is full (sz: 16
bytes)
[11635.010153] ath10k_pci 0000:00:00.0: failed to connect htt (-5)
[11635.060076] ath10k_pci 0000:00:00.0: swiotlb buffer is full (sz: 1984
bytes)
[11635.060160] ath10k_pci 0000:00:00.0: failed to dma map pci rx buf
[11635.060178] ath10k_pci 0000:00:00.0: failed to post pci rx buf: -5
[11635.060259] ath10k_pci 0000:00:00.0: failed to dma map pci rx buf
[11635.060274] ath10k_pci 0000:00:00.0: failed to post pci rx buf: -5
[11635.067301] ath10k_pci 0000:00:00.0: could not init core (-5)
[11635.067679] ath10k_pci 0000:00:00.0: could not probe fw (-5)


The interesting message I think is this one:

ath10k_pci 0000:00:00.0: swiotlb buffer is full (sz: 1984 bytes)

My guess is that there's a memory leak? before sleeping that gets
progressively worse the more you resume.

However, this is after! adding ath10k_pci to
/rw/config/suspend-module-blacklist (and I do not see the module being
removed/readded in dmesg).

Will do more investigation but a quick search on github and qubes-users
didn't yield any relevant results.

Kind regards,
Vladimir

[Vladimir Lushnikov]

After discussing this issue with some other Qubes users that reported
similar problems, I tried downgrading the dom0 kernel to 4.4.67-13 (and
keeping sys-net as 4.9.45-21, xen at 4.6.6)

That seems to resolve the issue between sleeps. Please let me know if
you need logs.

So it looks like it's a kernel bug introduced between 4.4.x and 4.9.x
series, maybe in the xen pci passthrough driver?

I have not had much time to dig into it fully though.

Kind regards,
Vladimir

Vladimir Lushnikov:

--
This message is private and confidential. Storage and automated scanning
of this message for selectors and metadata is strictly prohibited.

SOLID Ninja Ltd. is a limited company registered in England and Wales.
Registration number 9622534. Registered office First Floor, Telecom
House, 125-135 Preston Road, Brighton, East Sussex, BN1 6AF