[Xen-devel] Xen-unstable: AMD-Vi: update_paging_mode Try to access pdev_list without aquiring pcidevs_lock.

[Sander Eikelenboom <linux@xxxxxxxxxxxxxx>]

Hi Jan / Andrew,

While testing the latest xen-unstable and starting an HVM guest with 
pci-passtrough on my AMD machine,
my eye catched the following messages in xl dmesg I haven't seen before:

(XEN) [2019-10-28 10:23:16.372] AMD-Vi: update_paging_mode Try to access 
pdev_list without aquiring pcidevs_lock.
(XEN) [2019-10-28 10:24:08.136] AMD-Vi: INVALID_DEV_REQUEST 00000800 8a000000 
f8000240 000000fd

Probably something from the AMD iommu rework that got committed lately ?
I you need a complete debug log from host boot or want me to run some debug 
patches,
please let me know.

--
Sander




(XEN) [2019-10-28 10:23:16.372] AMD-Vi: update_paging_mode Try to access 
pdev_list without aquiring pcidevs_lock.
(XEN) [2019-10-28 10:23:16.605] HVM d18v0 save: CPU
(XEN) [2019-10-28 10:23:16.605] HVM d18v1 save: CPU
(XEN) [2019-10-28 10:23:16.605] HVM d18v2 save: CPU
(XEN) [2019-10-28 10:23:16.605] HVM d18v3 save: CPU
(XEN) [2019-10-28 10:23:16.605] HVM d18 save: PIC
(XEN) [2019-10-28 10:23:16.605] HVM d18 save: IOAPIC
(XEN) [2019-10-28 10:23:16.605] HVM d18v0 save: LAPIC
(XEN) [2019-10-28 10:23:16.605] HVM d18v1 save: LAPIC
(XEN) [2019-10-28 10:23:16.605] HVM d18v2 save: LAPIC
(XEN) [2019-10-28 10:23:16.605] HVM d18v3 save: LAPIC
(XEN) [2019-10-28 10:23:16.605] HVM d18v0 save: LAPIC_REGS
(XEN) [2019-10-28 10:23:16.605] HVM d18v1 save: LAPIC_REGS
(XEN) [2019-10-28 10:23:16.605] HVM d18v2 save: LAPIC_REGS
(XEN) [2019-10-28 10:23:16.605] HVM d18v3 save: LAPIC_REGS
(XEN) [2019-10-28 10:23:16.605] HVM d18 save: PCI_IRQ
(XEN) [2019-10-28 10:23:16.605] HVM d18 save: ISA_IRQ
(XEN) [2019-10-28 10:23:16.605] HVM d18 save: PCI_LINK
(XEN) [2019-10-28 10:23:16.605] HVM d18 save: PIT
(XEN) [2019-10-28 10:23:16.605] HVM d18 save: RTC
(XEN) [2019-10-28 10:23:16.605] HVM d18 save: HPET
(XEN) [2019-10-28 10:23:16.605] HVM d18 save: PMTIMER
(XEN) [2019-10-28 10:23:16.605] HVM d18v0 save: MTRR
(XEN) [2019-10-28 10:23:16.605] HVM d18v1 save: MTRR
(XEN) [2019-10-28 10:23:16.605] HVM d18v2 save: MTRR
(XEN) [2019-10-28 10:23:16.605] HVM d18v3 save: MTRR
(XEN) [2019-10-28 10:23:16.605] HVM d18 save: VIRIDIAN_DOMAIN
(XEN) [2019-10-28 10:23:16.605] HVM d18v0 save: CPU_XSAVE
(XEN) [2019-10-28 10:23:16.605] HVM d18v1 save: CPU_XSAVE
(XEN) [2019-10-28 10:23:16.605] HVM d18v2 save: CPU_XSAVE
(XEN) [2019-10-28 10:23:16.605] HVM d18v3 save: CPU_XSAVE
(XEN) [2019-10-28 10:23:16.605] HVM d18v0 save: VIRIDIAN_VCPU
(XEN) [2019-10-28 10:23:16.605] HVM d18v1 save: VIRIDIAN_VCPU
(XEN) [2019-10-28 10:23:16.605] HVM d18v2 save: VIRIDIAN_VCPU
(XEN) [2019-10-28 10:23:16.605] HVM d18v3 save: VIRIDIAN_VCPU
(XEN) [2019-10-28 10:23:16.605] HVM d18v0 save: VMCE_VCPU
(XEN) [2019-10-28 10:23:16.605] HVM d18v1 save: VMCE_VCPU
(XEN) [2019-10-28 10:23:16.605] HVM d18v2 save: VMCE_VCPU
(XEN) [2019-10-28 10:23:16.605] HVM d18v3 save: VMCE_VCPU
(XEN) [2019-10-28 10:23:16.605] HVM d18v0 save: TSC_ADJUST
(XEN) [2019-10-28 10:23:16.605] HVM d18v1 save: TSC_ADJUST
(XEN) [2019-10-28 10:23:16.605] HVM d18v2 save: TSC_ADJUST
(XEN) [2019-10-28 10:23:16.605] HVM d18v3 save: TSC_ADJUST
(XEN) [2019-10-28 10:23:16.605] HVM d18v0 save: CPU_MSR
(XEN) [2019-10-28 10:23:16.605] HVM d18v1 save: CPU_MSR
(XEN) [2019-10-28 10:23:16.605] HVM d18v2 save: CPU_MSR
(XEN) [2019-10-28 10:23:16.605] HVM d18v3 save: CPU_MSR
(XEN) [2019-10-28 10:23:16.605] HVM18 restore: CPU 0
(XEN) [2019-10-28 10:23:21.950] d18: bind: m_gsi=37 g_gsi=36 dev=00.00.5 intx=0
(XEN) [2019-10-28 10:23:21.976] AMD-Vi: Disable: device id = 0x800, domain = 0, 
paging mode = 3
(XEN) [2019-10-28 10:23:21.976] AMD-Vi: Setup I/O page table: device id = 
0x800, type = 0x1, root table = 0x40f3c1000, domain = 18, paging mode = 3
(XEN) [2019-10-28 10:23:21.976] AMD-Vi: Re-assign 0000:08:00.0 from dom0 to 
dom18
(d18) [2019-10-28 10:23:22.030] HVM Loader
(d18) [2019-10-28 10:23:22.030] Detected Xen v4.13.0-rc
(d18) [2019-10-28 10:23:22.030] Xenbus rings @0xfeffc000, event channel 1
(d18) [2019-10-28 10:23:22.030] System requested SeaBIOS
(d18) [2019-10-28 10:23:22.030] CPU speed is 3200 MHz
(d18) [2019-10-28 10:23:22.030] Relocating guest memory for lowmem MMIO space 
disabled
(XEN) [2019-10-28 10:23:22.039] irq.c:374: Dom18 PCI link 0 changed 0 -> 5
(d18) [2019-10-28 10:23:22.039] PCI-ISA link 0 routed to IRQ5
(XEN) [2019-10-28 10:23:22.048] irq.c:374: Dom18 PCI link 1 changed 0 -> 10
(d18) [2019-10-28 10:23:22.048] PCI-ISA link 1 routed to IRQ10
(XEN) [2019-10-28 10:23:22.056] irq.c:374: Dom18 PCI link 2 changed 0 -> 11
(d18) [2019-10-28 10:23:22.056] PCI-ISA link 2 routed to IRQ11
(XEN) [2019-10-28 10:23:22.063] irq.c:374: Dom18 PCI link 3 changed 0 -> 5
(d18) [2019-10-28 10:23:22.063] PCI-ISA link 3 routed to IRQ5
(d18) [2019-10-28 10:23:22.101] pci dev 01:3 INTA->IRQ10
(d18) [2019-10-28 10:23:22.103] pci dev 02:0 INTA->IRQ11
(d18) [2019-10-28 10:23:22.107] pci dev 04:0 INTA->IRQ5
(d18) [2019-10-28 10:23:22.109] pci dev 05:0 INTA->IRQ10
(d18) [2019-10-28 10:23:22.122] RAM in high memory; setting high_mem resource 
base to 10f800000
(d18) [2019-10-28 10:23:22.122] pci dev 03:0 bar 10 size 002000000: 0f0000008
(d18) [2019-10-28 10:23:22.122] pci dev 02:0 bar 14 size 001000000: 0f2000008
(d18) [2019-10-28 10:23:22.123] pci dev 04:0 bar 30 size 000040000: 0f3000000
(d18) [2019-10-28 10:23:22.124] pci dev 04:0 bar 10 size 000020000: 0f3040000
(d18) [2019-10-28 10:23:22.124] pci dev 03:0 bar 30 size 000010000: 0f3060000
(d18) [2019-10-28 10:23:22.124] pci dev 05:0 bar 10 size 000002000: 0f3070004
(XEN) [2019-10-28 10:23:22.124] memory_map:add: dom18 gfn=f3070 mfn=fe3fe nr=1
(d18) [2019-10-28 10:23:22.127] pci dev 03:0 bar 14 size 000001000: 0f3072000
(d18) [2019-10-28 10:23:22.127] pci dev 02:0 bar 10 size 000000100: 00000c001
(d18) [2019-10-28 10:23:22.128] pci dev 04:0 bar 14 size 000000040: 00000c101
(d18) [2019-10-28 10:23:22.129] pci dev 01:1 bar 20 size 000000010: 00000c141
(d18) [2019-10-28 10:23:22.129] Multiprocessor initialisation:
(d18) [2019-10-28 10:23:22.131]  - CPU0 ... 48-bit phys ... fixed MTRRs ... var 
MTRRs [1/8] ... done.
(d18) [2019-10-28 10:23:22.133]  - CPU1 ... 48-bit phys ... fixed MTRRs ... var 
MTRRs [1/8] ... done.
(d18) [2019-10-28 10:23:22.136]  - CPU2 ... 48-bit phys ... fixed MTRRs ... var 
MTRRs [1/8] ... done.
(d18) [2019-10-28 10:23:22.138]  - CPU3 ... 48-bit phys ... fixed MTRRs ... var 
MTRRs [1/8] ... done.
(d18) [2019-10-28 10:23:22.138] Testing HVM environment:
(d18) [2019-10-28 10:23:22.138] Using scratch memory at 400000
(d18) [2019-10-28 10:23:22.150]  - REP INSB across page boundaries ... passed
(d18) [2019-10-28 10:23:22.163]  - REP INSW across page boundaries ... passed
(d18) [2019-10-28 10:23:22.174]  - GS base MSRs and SWAPGS ... passed
(d18) [2019-10-28 10:23:22.174] Passed 3 of 3 tests
(d18) [2019-10-28 10:23:22.174] Writing SMBIOS tables ...
(d18) [2019-10-28 10:23:22.176] Loading SeaBIOS ...
(d18) [2019-10-28 10:23:22.176] Creating MP tables ...
(d18) [2019-10-28 10:23:22.176] Loading ACPI ...
(d18) [2019-10-28 10:23:22.177] vm86 TSS at fc00aa00
(d18) [2019-10-28 10:23:22.177] BIOS map:
(d18) [2019-10-28 10:23:22.177]  10000-100e3: Scratch space
(d18) [2019-10-28 10:23:22.177]  c0000-fffff: Main BIOS
(d18) [2019-10-28 10:23:22.177] E820 table:
(d18) [2019-10-28 10:23:22.177]  [00]: 00000000:00000000 - 00000000:000a0000: 
RAM
(d18) [2019-10-28 10:23:22.177]  HOLE: 00000000:000a0000 - 00000000:000c0000
(d18) [2019-10-28 10:23:22.177]  [01]: 00000000:000c0000 - 00000000:00100000: 
RESERVED
(d18) [2019-10-28 10:23:22.178]  [02]: 00000000:00100000 - 00000000:f0000000: 
RAM
(d18) [2019-10-28 10:23:22.178]  HOLE: 00000000:f0000000 - 00000000:fc000000
(d18) [2019-10-28 10:23:22.178]  [03]: 00000000:fc000000 - 00000001:00000000: 
RESERVED
(d18) [2019-10-28 10:23:22.178]  [04]: 00000001:00000000 - 00000001:0f800000: 
RAM
(d18) [2019-10-28 10:23:22.178] Invoking SeaBIOS ...
(d18) [2019-10-28 10:23:22.178] SeaBIOS (version rel-1.12.1-0-ga5cab58-Xen)
(d18) [2019-10-28 10:23:22.178] BUILD: gcc: (Debian 8.3.0-6) 8.3.0 binutils: 
(GNU Binutils for Debian) 2.31.1
(d18) [2019-10-28 10:23:22.178] 
(d18) [2019-10-28 10:23:22.178] Found Xen hypervisor signature at 40000000
(d18) [2019-10-28 10:23:22.178] Running on QEMU (i440fx)
(d18) [2019-10-28 10:23:22.178] xen: copy e820...
(d18) [2019-10-28 10:23:22.178] Relocating init from 0x000d8920 to 0xeffac480 
(size 80608)
(d18) [2019-10-28 10:23:22.179] Found QEMU fw_cfg
(d18) [2019-10-28 10:23:22.180] RamSizeOver4G: 0x000000000f800000 [cmos]
(d18) [2019-10-28 10:23:22.180] boot order:
(d18) [2019-10-28 10:23:22.180] 1: /rom@genroms/linuxboot.bin
(d18) [2019-10-28 10:23:22.182] Found 8 PCI devices (max PCI bus is 00)
(d18) [2019-10-28 10:23:22.183] Allocated Xen hypercall page at effff000
(d18) [2019-10-28 10:23:22.183] Detected Xen v4.13.0-rc
(d18) [2019-10-28 10:23:22.183] xen: copy BIOS tables...
(d18) [2019-10-28 10:23:22.183] Copying SMBIOS entry point from 0x00010020 to 
0x000f5be0
(d18) [2019-10-28 10:23:22.183] Copying MPTABLE from 0xfc0011e0/fc0011f0 to 
0x000f5ac0
(d18) [2019-10-28 10:23:22.183] Copying PIR from 0x00010040 to 0x000f5a40
(d18) [2019-10-28 10:23:22.183] Copying ACPI RSDP from 0x000100c0 to 0x000f5a10
(d18) [2019-10-28 10:23:22.183] Using pmtimer, ioport 0xb008
(d18) [2019-10-28 10:23:22.183] Scan for VGA option rom
(d18) [2019-10-28 10:23:22.193] Running option rom at c000:0003
(XEN) [2019-10-28 10:23:22.193] stdvga.c:173:d18v0 entering stdvga mode
(d18) [2019-10-28 10:23:22.202] pmm call arg1=0
(d18) [2019-10-28 10:23:22.202] Turning on vga text mode console
(d18) [2019-10-28 10:23:22.244] SeaBIOS (version rel-1.12.1-0-ga5cab58-Xen)
(d18) [2019-10-28 10:23:22.248] Machine UUID 
74135651-a6eb-4e9f-966b-b364f0a5bee3
(d18) [2019-10-28 10:23:22.249] XHCI init on dev 00:05.0: regs @ 0xf3070000, 4 
ports, 32 slots, 32 byte contexts
(d18) [2019-10-28 10:23:22.249] XHCI    extcap 0x1 @ 0xf3070500
(d18) [2019-10-28 10:23:22.249] XHCI    protocol USB  3.00, 2 ports (offset 1), 
def 0
(d18) [2019-10-28 10:23:22.249] XHCI    protocol USB  2.00, 2 ports (offset 3), 
def 0
(d18) [2019-10-28 10:23:22.249] ATA controller 1 at 1f0/3f4/c140 (irq 14 dev 9)
(d18) [2019-10-28 10:23:22.250] ATA controller 2 at 170/374/c148 (irq 15 dev 9)
(d18) [2019-10-28 10:23:22.251] Found 0 lpt ports
(d18) [2019-10-28 10:23:22.251] Found 1 serial ports
(d18) [2019-10-28 10:23:22.252] PS2 keyboard initialized
(d18) [2019-10-28 10:23:22.252] ata0-0: QEMU HARDDISK ATA-7 Hard-Disk (10240 
MiBytes)
(d18) [2019-10-28 10:23:22.252] Searching bootorder for: 
/pci@i0cf8/*@1,1/drive@0/disk@0
(d18) [2019-10-28 10:23:22.253] ata0-1: QEMU HARDDISK ATA-7 Hard-Disk (800 
GiBytes)
(d18) [2019-10-28 10:23:22.253] Searching bootorder for: 
/pci@i0cf8/*@1,1/drive@0/disk@1
(d18) [2019-10-28 10:23:22.254] ata1-0: QEMU HARDDISK ATA-7 Hard-Disk (250 
GiBytes)
(d18) [2019-10-28 10:23:22.254] Searching bootorder for: 
/pci@i0cf8/*@1,1/drive@1/disk@0
(d18) [2019-10-28 10:23:22.255] ata1-1: QEMU HARDDISK ATA-7 Hard-Disk (260 
GiBytes)
(d18) [2019-10-28 10:23:22.255] Searching bootorder for: 
/pci@i0cf8/*@1,1/drive@1/disk@1
(d18) [2019-10-28 10:23:22.375] XHCI port #4: 0x00200a03, powered, enabled, pls 
0, speed 2 [Low]
(d18) [2019-10-28 10:23:22.414] XHCI no devices found
(d18) [2019-10-28 10:23:22.421] All threads complete.
(d18) [2019-10-28 10:23:22.421] Scan for option roms
(d18) [2019-10-28 10:23:22.442] Running option rom at c980:0003
(d18) [2019-10-28 10:23:22.448] pmm call arg1=1
(d18) [2019-10-28 10:23:22.448] pmm call arg1=0
(d18) [2019-10-28 10:23:22.449] pmm call arg1=1
(d18) [2019-10-28 10:23:22.449] pmm call arg1=0
(d18) [2019-10-28 10:23:22.465] Running option rom at ca80:0003
(d18) [2019-10-28 10:23:22.465] Searching bootorder for: /pci@i0cf8/*@4
(d18) [2019-10-28 10:23:22.466] Searching bootorder for: 
/rom@genroms/linuxboot.bin
(d18) [2019-10-28 10:23:22.466] Searching bootorder for: HALT
(d18) [2019-10-28 10:23:22.466] drive 0x000f59a0: PCHS=16383/16/63 
translation=lba LCHS=1024/255/63 s=20971520
(d18) [2019-10-28 10:23:22.466] drive 0x000f5970: PCHS=16383/16/63 
translation=lba LCHS=1024/255/63 s=1677721600
(d18) [2019-10-28 10:23:22.466] drive 0x000f5940: PCHS=16383/16/63 
translation=lba LCHS=1024/255/63 s=524288000
(d18) [2019-10-28 10:23:22.466] drive 0x000f5910: PCHS=16383/16/63 
translation=lba LCHS=1024/255/63 s=545259520
(d18) [2019-10-28 10:23:22.466] Space available for UMB: cb000-eb800, 
f5400-f5910
(d18) [2019-10-28 10:23:22.466] Returned 253952 bytes of ZoneHigh
(d18) [2019-10-28 10:23:22.466] e820 map has 7 items:
(d18) [2019-10-28 10:23:22.466]   0: 0000000000000000 - 000000000009fc00 = 1 RAM
(d18) [2019-10-28 10:23:22.466]   1: 000000000009fc00 - 00000000000a0000 = 2 
RESERVED
(d18) [2019-10-28 10:23:22.466]   2: 00000000000f0000 - 0000000000100000 = 2 
RESERVED
(d18) [2019-10-28 10:23:22.467]   3: 0000000000100000 - 00000000efffe000 = 1 RAM
(d18) [2019-10-28 10:23:22.467]   4: 00000000efffe000 - 00000000f0000000 = 2 
RESERVED
(d18) [2019-10-28 10:23:22.467]   5: 00000000fc000000 - 0000000100000000 = 2 
RESERVED
(d18) [2019-10-28 10:23:22.467]   6: 0000000100000000 - 000000010f800000 = 1 RAM
(d18) [2019-10-28 10:23:22.468] enter handle_19:
(d18) [2019-10-28 10:23:22.468]   NULL
(d18) [2019-10-28 10:23:22.471] Booting from ROM...
(d18) [2019-10-28 10:23:22.471] Booting from ca80:003c
(XEN) [2019-10-28 10:24:03.428] Dom18 callback via changed to Direct Vector 0xf3
(XEN) [2019-10-28 10:24:06.103] memory_map:remove: dom18 gfn=f3070 mfn=fe3fe 
nr=1
(XEN) [2019-10-28 10:24:06.106] memory_map:add: dom18 gfn=f3070 mfn=fe3fe nr=1
(XEN) [2019-10-28 10:24:06.117] memory_map:remove: dom18 gfn=f3070 mfn=fe3fe 
nr=1
(XEN) [2019-10-28 10:24:06.120] memory_map:add: dom18 gfn=f3070 mfn=fe3fe nr=1
(XEN) [2019-10-28 10:24:06.123] memory_map:remove: dom18 gfn=f3070 mfn=fe3fe 
nr=1
(XEN) [2019-10-28 10:24:06.125] memory_map:add: dom18 gfn=f3070 mfn=fe3fe nr=1
(XEN) [2019-10-28 10:24:06.128] memory_map:remove: dom18 gfn=f3070 mfn=fe3fe 
nr=1
(XEN) [2019-10-28 10:24:06.130] memory_map:add: dom18 gfn=f3070 mfn=fe3fe nr=1
(XEN) [2019-10-28 10:24:06.132] memory_map:remove: dom18 gfn=f3070 mfn=fe3fe 
nr=1
(XEN) [2019-10-28 10:24:06.135] memory_map:add: dom18 gfn=f3070 mfn=fe3fe nr=1
(XEN) [2019-10-28 10:24:06.137] memory_map:remove: dom18 gfn=f3070 mfn=fe3fe 
nr=1
(XEN) [2019-10-28 10:24:06.140] memory_map:add: dom18 gfn=f3070 mfn=fe3fe nr=1
(XEN) [2019-10-28 10:24:06.155] irq.c:374: Dom18 PCI link 0 changed 5 -> 0
(XEN) [2019-10-28 10:24:06.162] irq.c:374: Dom18 PCI link 1 changed 10 -> 0
(XEN) [2019-10-28 10:24:06.170] irq.c:374: Dom18 PCI link 2 changed 11 -> 0
(XEN) [2019-10-28 10:24:06.177] irq.c:374: Dom18 PCI link 3 changed 5 -> 0
(XEN) [2019-10-28 10:24:08.045] grant_table.c:1786:d18v2 Expanding d18 grant 
table from 1 to 2 frames
(XEN) [2019-10-28 10:24:08.045] grant_table.c:1786:d18v2 Expanding d18 grant 
table from 2 to 3 frames
(XEN) [2019-10-28 10:24:08.045] grant_table.c:1786:d18v2 Expanding d18 grant 
table from 3 to 4 frames
(XEN) [2019-10-28 10:24:08.045] grant_table.c:1786:d18v2 Expanding d18 grant 
table from 4 to 5 frames
(XEN) [2019-10-28 10:24:08.136] AMD-Vi: INVALID_DEV_REQUEST 00000800 8a000000 
f8000240 000000fd
(XEN) [2019-10-28 10:24:15.963] grant_table.c:1786:d18v1 Expanding d18 grant 
table from 5 to 6 frames
(XEN) [2019-10-28 10:24:26.342] grant_table.c:1786:d18v1 Expanding d18 grant 
table from 6 to 7 frames

_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxxxxxxxxx
https://lists.xenproject.org/mailman/listinfo/xen-devel