* BUG REPORT: vfio_pci driver
@ 2021-08-13 18:34 Russ Weight
2021-08-13 22:09 ` Alex Williamson
0 siblings, 1 reply; 3+ messages in thread
From: Russ Weight @ 2021-08-13 18:34 UTC (permalink / raw)
To: Alex Williamson
Cc: Cornelia Huck, Adler, Michael, Whisonant, Tim, kvm, linux-kernel,
Tom Rix
[-- Attachment #1: Type: text/plain, Size: 3102 bytes --]
Bug Description:
A bug in the vfio_pci driver was reported in junction with work on FPGA
cards. We were able to reproduce and root-cause the bug using system-tap.
The original bug description is below. An understanding of the referenced
dfl and opae tools is not required - it is the sequence of IOCTL calls and
IRQ vectors that matters:
> I’m trying to get an example AFU working that uses 2 IRQs, active at the same
> time. I’m hitting what looks to be a dfl_pci driver bug.
>
> The code tries to allocate two IRQ vectors: 0 and 1. I see opaevfio.c doing the
> right thing, picking the MSIX index. Allocating either IRQ 0 or IRQ 1 works fine
> and I confirm that the VFIO_DEVICE_SET_IRQS looks reasonable, choosing MSIX and
> either start of 0 or 1 and count 1.
>
> Note that opaevfio.c always passes count 1, so it will make separate calls for
> each IRQ vector.
>
> When I try to allocate both, I see the following:
>
> * If the VFIO_DEVICE_SET_IRQS ioctl is called first with start 0 and then
> start 1 (always count 1), the start 1 (second) ioctl trap returns EINVAL.
> * If I set up the vectors in decreasing order, so start 1 followed by start 0,
> the program works!
> * I ruled out OPAE SDK user space problems by setting up my program to
> allocate in increasing order, which would normally fail. I changed only the
> ioctl call in user space opaevfio.c, inverting bit 0 of start so that the
> driver is called in decreasing index order. Of course this binds the wrong
> vectors to the fds, but I don’t care about that for now. This works! From
> this, I conclude that it can’t be a user space problem since the difference
> between working and failing is solely the order in which IRQ vectors are
> bound in ioctl calls.
The EINVAL is coming from vfio_msi_set_block() here:
https://github.com/torvalds/linux/blob/master/drivers/vfio/pci/vfio_pci_intrs.c#L373
vfio_msi_set_block() is being called from vfio_pci_set_msi_trigger() here on
the second IRQ request:
https://github.com/torvalds/linux/blob/master/drivers/vfio/pci/vfio_pci_intrs.c#L530
We believe the bug is in vfio_pci_set_msi_trigger(), in the 2nd parameter to the call
to vfio_msi_enable() here:
https://github.com/torvalds/linux/blob/master/drivers/vfio/pci/vfio_pci_intrs.c#L533
In both the passing and failing cases, the first IRQ request results in a call
to vfio_msi_enable() at line 533 and the second IRQ request results in the
call to vfio_msi_set_block() at line 530. It is during the first IRQ request
that vfio_msi_enable() sets vdev->num_ctx based on the 2nd parameter (nvec).
vdev->num_ctx is part of the conditional that results in the EINVAL for the
failing case.
In the passing case, vdev->num_ctx is 2. In the failing case, it is 1.
I am attaching two text files containing trace information from systemtap: one for
the failing case and one for the passing case. They contain a lot more information
than is needed, but if you search for vfio_pci_set_msi_trigger and vfio_msi_set_block,
you will see values for some of the call parameters.
- Russ
[-- Attachment #2: vfio_pci_pass.txt --]
[-- Type: text/plain, Size: 24082 bytes --]
0 irqtest(103848): -> vfio_pci_match
8 irqtest(103848): -> get_pf_vdev
12 irqtest(103848): <- get_pf_vdev
13 irqtest(103848): <- vfio_pci_match
0 irqtest(103848): -> vfio_pci_open
4 irqtest(103848): -> vfio_pci_set_power_state
7 irqtest(103848): <- vfio_pci_set_power_state
108747 irqtest(103848): -> pci_restore_msi_state
108756 irqtest(103848): <- pci_restore_msi_state
108806 irqtest(103848): -> vfio_config_init
108814 irqtest(103848): -> vfio_fill_vconfig_bytes
108842 irqtest(103848): <- vfio_fill_vconfig_bytes
108853 irqtest(103848): -> vfio_fill_vconfig_bytes
108861 irqtest(103848): <- vfio_fill_vconfig_bytes
108869 irqtest(103848): -> vfio_fill_vconfig_bytes
108891 irqtest(103848): <- vfio_fill_vconfig_bytes
108896 irqtest(103848): -> vfio_fill_vconfig_bytes
108902 irqtest(103848): <- vfio_fill_vconfig_bytes
108906 irqtest(103848): <- vfio_config_init
108914 irqtest(103848): -> vfio_pci_vf_token_user_add
108920 irqtest(103848): -> get_pf_vdev
108925 irqtest(103848): <- get_pf_vdev
108929 irqtest(103848): <- vfio_pci_vf_token_user_add
108934 irqtest(103848): <- vfio_pci_open
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
7 irqtest(103848): <- vfio_pci_ioctl
0 irqtest(103848): -> vfio_pci_read
7 irqtest(103848): -> vfio_pci_rw
13 irqtest(103848): -> vfio_pci_config_rw
21 irqtest(103848): -> vfio_basic_config_read
27 irqtest(103848): -> vfio_default_config_read
34 irqtest(103848): -> vfio_user_config_read
42 irqtest(103848): <- vfio_user_config_read
46 irqtest(103848): <- vfio_default_config_read
51 irqtest(103848): <- vfio_basic_config_read
56 irqtest(103848): <- vfio_pci_config_rw
59 irqtest(103848): <- vfio_pci_rw
63 irqtest(103848): <- vfio_pci_read
0 irqtest(103848): -> vfio_pci_write
18 irqtest(103848): -> vfio_pci_rw
19 irqtest(103848): -> vfio_pci_config_rw
22 irqtest(103848): -> vfio_basic_config_write
27 irqtest(103848): -> vfio_default_config_write
29 irqtest(103848): -> vfio_user_config_read
31 irqtest(103848): <- vfio_user_config_read
33 irqtest(103848): -> vfio_user_config_write
36 irqtest(103848): <- vfio_user_config_write
37 irqtest(103848): <- vfio_default_config_write
39 irqtest(103848): <- vfio_basic_config_write
40 irqtest(103848): <- vfio_pci_config_rw
41 irqtest(103848): <- vfio_pci_rw
43 irqtest(103848): <- vfio_pci_write
vfio_pci_ioctl was called: 15211
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
2 irqtest(103848): <- vfio_pci_ioctl
0 irqtest(103848): -> vfio_pci_mmap
32 irqtest(103848): <- vfio_pci_mmap
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
2 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
0 irqtest(103848): -> vfio_pci_mmap
7 irqtest(103848): <- vfio_pci_mmap
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103848): -> vfio_pci_ioctl
2 irqtest(103848): -> vfio_pci_get_irq_count
4 irqtest(103848): <- vfio_pci_get_irq_count
5 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): -> vfio_pci_get_irq_count
2 irqtest(103848): <- vfio_pci_get_irq_count
3 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): -> vfio_pci_get_irq_count
3 irqtest(103848): <- vfio_pci_get_irq_count
4 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): -> vfio_pci_get_irq_count
2 irqtest(103848): <- vfio_pci_get_irq_count
3 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): -> vfio_pci_get_irq_count
3 irqtest(103848): <- vfio_pci_get_irq_count
4 irqtest(103848): <- vfio_pci_ioctl
0 irqtest(103848): -> vfio_pci_mmap_fault
4 irqtest(103848): -> __vfio_pci_memory_enabled
6 irqtest(103848): <- __vfio_pci_memory_enabled
9 irqtest(103848): <- vfio_pci_mmap_fault
0 irqtest(103848): -> vfio_pci_mmap_fault
1 irqtest(103848): -> __vfio_pci_memory_enabled
2 irqtest(103848): <- __vfio_pci_memory_enabled
4 irqtest(103848): <- vfio_pci_mmap_fault
0 irqtest(103848): -> vfio_pci_mmap_close
2 irqtest(103848): <- vfio_pci_mmap_close
0 irqtest(103848): -> vfio_pci_mmap_close
1 irqtest(103848): <- vfio_pci_mmap_close
0 irqtest(103848): -> vfio_pci_release
2 irqtest(103848): -> vfio_pci_vf_token_user_add
3 irqtest(103848): -> get_pf_vdev
5 irqtest(103848): <- get_pf_vdev
6 irqtest(103848): <- vfio_pci_vf_token_user_add
9 irqtest(103848): -> vfio_pci_set_irqs_ioctl
12 irqtest(103848): <- vfio_pci_set_irqs_ioctl
14 irqtest(103848): -> vfio_config_free
16 irqtest(103848): <- vfio_config_free
103469 irqtest(103848): -> pci_restore_msi_state
103478 irqtest(103848): <- pci_restore_msi_state
103490 irqtest(103848): -> vfio_pci_walk_wrapper
103496 irqtest(103848): -> vfio_pci_count_devs
103502 irqtest(103848): <- vfio_pci_count_devs
103506 irqtest(103848): <- vfio_pci_walk_wrapper
103510 irqtest(103848): -> vfio_pci_walk_wrapper
103515 irqtest(103848): -> vfio_pci_count_devs
103519 irqtest(103848): <- vfio_pci_count_devs
103522 irqtest(103848): <- vfio_pci_walk_wrapper
103526 irqtest(103848): -> vfio_pci_walk_wrapper
103530 irqtest(103848): -> vfio_pci_count_devs
103534 irqtest(103848): <- vfio_pci_count_devs
103538 irqtest(103848): <- vfio_pci_walk_wrapper
103541 irqtest(103848): -> vfio_pci_walk_wrapper
103545 irqtest(103848): -> vfio_pci_count_devs
103549 irqtest(103848): <- vfio_pci_count_devs
103553 irqtest(103848): <- vfio_pci_walk_wrapper
103558 irqtest(103848): -> vfio_pci_walk_wrapper
103563 irqtest(103848): -> vfio_pci_get_unused_devs
103570 irqtest(103848): <- vfio_pci_get_unused_devs
103574 irqtest(103848): <- vfio_pci_walk_wrapper
103579 irqtest(103848): -> vfio_pci_set_power_state
103584 irqtest(103848): <- vfio_pci_set_power_state
103588 irqtest(103848): <- vfio_pci_release
0 irqtest(103848): -> vfio_pci_match
2 irqtest(103848): -> get_pf_vdev
4 irqtest(103848): <- get_pf_vdev
5 irqtest(103848): <- vfio_pci_match
0 irqtest(103848): -> vfio_pci_open
1 irqtest(103848): -> vfio_pci_set_power_state
3 irqtest(103848): <- vfio_pci_set_power_state
103601 irqtest(103848): -> pci_restore_msi_state
103611 irqtest(103848): <- pci_restore_msi_state
103658 irqtest(103848): -> vfio_config_init
103665 irqtest(103848): -> vfio_fill_vconfig_bytes
103693 irqtest(103848): <- vfio_fill_vconfig_bytes
103703 irqtest(103848): -> vfio_fill_vconfig_bytes
103711 irqtest(103848): <- vfio_fill_vconfig_bytes
103719 irqtest(103848): -> vfio_fill_vconfig_bytes
103741 irqtest(103848): <- vfio_fill_vconfig_bytes
103746 irqtest(103848): -> vfio_fill_vconfig_bytes
103752 irqtest(103848): <- vfio_fill_vconfig_bytes
103756 irqtest(103848): <- vfio_config_init
103764 irqtest(103848): -> vfio_pci_vf_token_user_add
103769 irqtest(103848): -> get_pf_vdev
103774 irqtest(103848): <- get_pf_vdev
103778 irqtest(103848): <- vfio_pci_vf_token_user_add
103782 irqtest(103848): <- vfio_pci_open
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
6 irqtest(103848): <- vfio_pci_ioctl
0 irqtest(103848): -> vfio_pci_read
5 irqtest(103848): -> vfio_pci_rw
10 irqtest(103848): -> vfio_pci_config_rw
16 irqtest(103848): -> vfio_basic_config_read
21 irqtest(103848): -> vfio_default_config_read
27 irqtest(103848): -> vfio_user_config_read
33 irqtest(103848): <- vfio_user_config_read
37 irqtest(103848): <- vfio_default_config_read
42 irqtest(103848): <- vfio_basic_config_read
47 irqtest(103848): <- vfio_pci_config_rw
50 irqtest(103848): <- vfio_pci_rw
54 irqtest(103848): <- vfio_pci_read
0 irqtest(103848): -> vfio_pci_write
4 irqtest(103848): -> vfio_pci_rw
8 irqtest(103848): -> vfio_pci_config_rw
13 irqtest(103848): -> vfio_basic_config_write
21 irqtest(103848): -> vfio_default_config_write
26 irqtest(103848): -> vfio_user_config_read
31 irqtest(103848): <- vfio_user_config_read
36 irqtest(103848): -> vfio_user_config_write
42 irqtest(103848): <- vfio_user_config_write
47 irqtest(103848): <- vfio_default_config_write
51 irqtest(103848): <- vfio_basic_config_write
55 irqtest(103848): <- vfio_pci_config_rw
59 irqtest(103848): <- vfio_pci_rw
62 irqtest(103848): <- vfio_pci_write
vfio_pci_ioctl was called: 15211
0 irqtest(103848): -> vfio_pci_ioctl
4 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
4 irqtest(103848): <- vfio_pci_ioctl
0 irqtest(103848): -> vfio_pci_mmap
45 irqtest(103848): <- vfio_pci_mmap
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
0 irqtest(103848): -> vfio_pci_mmap
6 irqtest(103848): <- vfio_pci_mmap
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): -> vfio_pci_get_irq_count
3 irqtest(103848): <- vfio_pci_get_irq_count
4 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): -> vfio_pci_get_irq_count
2 irqtest(103848): <- vfio_pci_get_irq_count
3 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): -> vfio_pci_get_irq_count
3 irqtest(103848): <- vfio_pci_get_irq_count
4 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): -> vfio_pci_get_irq_count
2 irqtest(103848): <- vfio_pci_get_irq_count
3 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): -> vfio_pci_get_irq_count
3 irqtest(103848): <- vfio_pci_get_irq_count
3 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15214
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): -> vfio_pci_get_irq_count
3 irqtest(103848): <- vfio_pci_get_irq_count
4 irqtest(103848): -> vfio_pci_set_irqs_ioctl
vfio_pci_set_msi_trigger: irq_type: index: vector: flags: 0x5 0x2 0x1 0x24
vfio_pci_set_msi_trigger: vdev: 0xffff8ea6bc003200
10 irqtest(103848): -> vfio_pci_set_msi_trigger
12 irqtest(103848): -> vfio_pci_memory_lock_and_enable
16 irqtest(103848): <- vfio_pci_memory_lock_and_enable
18 irqtest(103848): -> pci_alloc_irq_vectors_affinity
20 irqtest(103848): -> __pci_enable_msix_range
23 irqtest(103848): -> pci_msi_supported
25 irqtest(103848): <- pci_msi_supported
27 irqtest(103848): -> pci_msix_vec_count
30 irqtest(103848): <- pci_msix_vec_count
40 irqtest(103848): -> pci_msix_vec_count
42 irqtest(103848): <- pci_msix_vec_count
47 irqtest(103848): -> pci_msi_setup_msi_irqs
55 irqtest(103848): -> pci_msi_domain_check_cap
57 irqtest(103848): <- pci_msi_domain_check_cap
60 irqtest(103848): -> pci_msi_domain_calc_hwirq
62 irqtest(103848): <- pci_msi_domain_calc_hwirq
139 irqtest(103848): -> pci_msi_domain_calc_hwirq
140 irqtest(103848): <- pci_msi_domain_calc_hwirq
181 irqtest(103848): -> pci_msi_domain_write_msg
183 irqtest(103848): -> __pci_write_msi_msg
185 irqtest(103848): <- __pci_write_msi_msg
187 irqtest(103848): <- pci_msi_domain_write_msg
195 irqtest(103848): -> pci_msi_domain_write_msg
196 irqtest(103848): -> __pci_write_msi_msg
197 irqtest(103848): <- __pci_write_msi_msg
198 irqtest(103848): <- pci_msi_domain_write_msg
204 irqtest(103848): <- pci_msi_setup_msi_irqs
206 irqtest(103848): -> msi_verify_entries
208 irqtest(103848): <- msi_verify_entries
212 irqtest(103848): -> __pci_msix_desc_mask_irq
214 irqtest(103848): <- __pci_msix_desc_mask_irq
216 irqtest(103848): -> __pci_msix_desc_mask_irq
217 irqtest(103848): <- __pci_msix_desc_mask_irq
218 irqtest(103848): -> populate_msi_sysfs
223 irqtest(103848): <- populate_msi_sysfs
228 irqtest(103848): <- __pci_enable_msix_range
229 irqtest(103848): <- pci_alloc_irq_vectors_affinity
231 irqtest(103848): -> vfio_pci_memory_unlock_and_restore
234 irqtest(103848): <- vfio_pci_memory_unlock_and_restore
vfio_msi_set_block: start: count: 0x1, 0x1
vfio_msi_set_block: vdev->num_ctx: 0x2
237 irqtest(103848): -> vfio_msi_set_block
vfio_msi_set_vector_signal was called: 1 / 7
241 irqtest(103848): -> vfio_msi_set_vector_signal
244 irqtest(103848): -> pci_irq_vector
246 irqtest(103848): <- pci_irq_vector
248 irqtest(103848): -> vfio_pci_memory_lock_and_enable
251 irqtest(103848): <- vfio_pci_memory_lock_and_enable
256 irqtest(103848): -> pci_write_msi_msg
259 irqtest(103848): -> __pci_write_msi_msg
261 irqtest(103848): <- __pci_write_msi_msg
262 irqtest(103848): <- pci_write_msi_msg
280 irqtest(103848): -> pci_msi_domain_write_msg
281 irqtest(103848): -> __pci_write_msi_msg
282 irqtest(103848): <- __pci_write_msi_msg
283 irqtest(103848): <- pci_msi_domain_write_msg
289 irqtest(103848): -> pci_msi_unmask_irq
292 irqtest(103848): -> msi_set_mask_bit
293 irqtest(103848): -> __pci_msix_desc_mask_irq
295 irqtest(103848): <- __pci_msix_desc_mask_irq
297 irqtest(103848): <- msi_set_mask_bit
298 irqtest(103848): <- pci_msi_unmask_irq
323 irqtest(103848): -> vfio_pci_memory_unlock_and_restore
325 irqtest(103848): <- vfio_pci_memory_unlock_and_restore
327 irqtest(103848): <- vfio_msi_set_vector_signal
vfio_msi_set_vector_signal returned with: 0
330 irqtest(103848): <- vfio_msi_set_block
331 irqtest(103848): <- vfio_pci_set_msi_trigger
332 irqtest(103848): <- vfio_pci_set_irqs_ioctl
334 irqtest(103848): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15214
0 irqtest(103848): -> vfio_pci_ioctl
1 irqtest(103848): -> vfio_pci_get_irq_count
3 irqtest(103848): <- vfio_pci_get_irq_count
5 irqtest(103848): -> vfio_pci_set_irqs_ioctl
vfio_pci_set_msi_trigger: irq_type: index: vector: flags: 0x2 0x2 0x0 0x24
vfio_pci_set_msi_trigger: vdev: 0xffff8ea6bc003200
7 irqtest(103848): -> vfio_pci_set_msi_trigger
vfio_msi_set_block: start: count: 0x0, 0x1
vfio_msi_set_block: vdev->num_ctx: 0x2
9 irqtest(103848): -> vfio_msi_set_block
vfio_msi_set_vector_signal was called: 0 / 8
11 irqtest(103848): -> vfio_msi_set_vector_signal
13 irqtest(103848): -> pci_irq_vector
14 irqtest(103848): <- pci_irq_vector
15 irqtest(103848): -> vfio_pci_memory_lock_and_enable
18 irqtest(103848): <- vfio_pci_memory_lock_and_enable
21 irqtest(103848): -> pci_write_msi_msg
23 irqtest(103848): -> __pci_write_msi_msg
24 irqtest(103848): <- __pci_write_msi_msg
25 irqtest(103848): <- pci_write_msi_msg
34 irqtest(103848): -> pci_msi_domain_write_msg
35 irqtest(103848): -> __pci_write_msi_msg
36 irqtest(103848): <- __pci_write_msi_msg
37 irqtest(103848): <- pci_msi_domain_write_msg
40 irqtest(103848): -> pci_msi_unmask_irq
41 irqtest(103848): -> msi_set_mask_bit
42 irqtest(103848): -> __pci_msix_desc_mask_irq
43 irqtest(103848): <- __pci_msix_desc_mask_irq
45 irqtest(103848): <- msi_set_mask_bit
46 irqtest(103848): <- pci_msi_unmask_irq
62 irqtest(103848): -> vfio_pci_memory_unlock_and_restore
64 irqtest(103848): <- vfio_pci_memory_unlock_and_restore
66 irqtest(103848): <- vfio_msi_set_vector_signal
vfio_msi_set_vector_signal returned with: 0
67 irqtest(103848): <- vfio_msi_set_block
68 irqtest(103848): <- vfio_pci_set_msi_trigger
69 irqtest(103848): <- vfio_pci_set_irqs_ioctl
70 irqtest(103848): <- vfio_pci_ioctl
0 irqtest(103848): -> vfio_pci_mmap_close
1 irqtest(103848): <- vfio_pci_mmap_close
0 irqtest(103848): -> vfio_pci_mmap_close
1 irqtest(103848): <- vfio_pci_mmap_close
0 irqtest(103848): -> vfio_pci_release
1 irqtest(103848): -> vfio_pci_vf_token_user_add
3 irqtest(103848): -> get_pf_vdev
4 irqtest(103848): <- get_pf_vdev
5 irqtest(103848): <- vfio_pci_vf_token_user_add
8 irqtest(103848): -> vfio_pci_set_irqs_ioctl
vfio_pci_set_msi_trigger: irq_type: index: vector: flags: 0x2 0x2 0x0 0x21
vfio_pci_set_msi_trigger: vdev: 0xffff8ea6bc003200
11 irqtest(103848): -> vfio_pci_set_msi_trigger
14 irqtest(103848): -> vfio_msi_disable
vfio_msi_set_block: start: count: 0x0, 0x2
vfio_msi_set_block: vdev->num_ctx: 0x2
18 irqtest(103848): -> vfio_msi_set_block
vfio_msi_set_vector_signal was called: 0 / -1
20 irqtest(103848): -> vfio_msi_set_vector_signal
21 irqtest(103848): -> pci_irq_vector
22 irqtest(103848): <- pci_irq_vector
24 irqtest(103848): -> vfio_pci_memory_lock_and_enable
26 irqtest(103848): <- vfio_pci_memory_lock_and_enable
36 irqtest(103848): -> pci_msi_mask_irq
38 irqtest(103848): -> msi_set_mask_bit
39 irqtest(103848): -> __pci_msix_desc_mask_irq
41 irqtest(103848): <- __pci_msix_desc_mask_irq
43 irqtest(103848): <- msi_set_mask_bit
44 irqtest(103848): <- pci_msi_mask_irq
55 irqtest(103848): -> pci_msi_domain_write_msg
56 irqtest(103848): -> __pci_write_msi_msg
58 irqtest(103848): <- __pci_write_msi_msg
58 irqtest(103848): <- pci_msi_domain_write_msg
68 irqtest(103848): -> vfio_pci_memory_unlock_and_restore
70 irqtest(103848): <- vfio_pci_memory_unlock_and_restore
72 irqtest(103848): <- vfio_msi_set_vector_signal
vfio_msi_set_vector_signal returned with: 0
vfio_msi_set_vector_signal was called: 1 / -1
74 irqtest(103848): -> vfio_msi_set_vector_signal
75 irqtest(103848): -> pci_irq_vector
76 irqtest(103848): <- pci_irq_vector
77 irqtest(103848): -> vfio_pci_memory_lock_and_enable
80 irqtest(103848): <- vfio_pci_memory_lock_and_enable
84 irqtest(103848): -> pci_msi_mask_irq
85 irqtest(103848): -> msi_set_mask_bit
86 irqtest(103848): -> __pci_msix_desc_mask_irq
87 irqtest(103848): <- __pci_msix_desc_mask_irq
89 irqtest(103848): <- msi_set_mask_bit
90 irqtest(103848): <- pci_msi_mask_irq
94 irqtest(103848): -> pci_msi_domain_write_msg
95 irqtest(103848): -> __pci_write_msi_msg
96 irqtest(103848): <- __pci_write_msi_msg
97 irqtest(103848): <- pci_msi_domain_write_msg
102 irqtest(103848): -> vfio_pci_memory_unlock_and_restore
104 irqtest(103848): <- vfio_pci_memory_unlock_and_restore
105 irqtest(103848): <- vfio_msi_set_vector_signal
vfio_msi_set_vector_signal returned with: 0
106 irqtest(103848): <- vfio_msi_set_block
107 irqtest(103848): -> vfio_pci_memory_lock_and_enable
110 irqtest(103848): <- vfio_pci_memory_lock_and_enable
112 irqtest(103848): -> pci_free_irq_vectors
114 irqtest(103848): -> pci_disable_msix
119 irqtest(103848): -> free_msi_irqs
123 irqtest(103848): -> default_teardown_msi_irqs
210 irqtest(103848): <- default_teardown_msi_irqs
218 irqtest(103848): <- free_msi_irqs
219 irqtest(103848): <- pci_disable_msix
220 irqtest(103848): -> pci_disable_msi
222 irqtest(103848): <- pci_disable_msi
223 irqtest(103848): <- pci_free_irq_vectors
224 irqtest(103848): -> vfio_pci_memory_unlock_and_restore
226 irqtest(103848): <- vfio_pci_memory_unlock_and_restore
227 irqtest(103848): <- vfio_msi_disable
228 irqtest(103848): <- vfio_pci_set_msi_trigger
229 irqtest(103848): <- vfio_pci_set_irqs_ioctl
231 irqtest(103848): -> vfio_config_free
232 irqtest(103848): <- vfio_config_free
103062 irqtest(103848): -> pci_restore_msi_state
103071 irqtest(103848): <- pci_restore_msi_state
103082 irqtest(103848): -> vfio_pci_walk_wrapper
103087 irqtest(103848): -> vfio_pci_count_devs
103092 irqtest(103848): <- vfio_pci_count_devs
103096 irqtest(103848): <- vfio_pci_walk_wrapper
103100 irqtest(103848): -> vfio_pci_walk_wrapper
103105 irqtest(103848): -> vfio_pci_count_devs
103108 irqtest(103848): <- vfio_pci_count_devs
103112 irqtest(103848): <- vfio_pci_walk_wrapper
103116 irqtest(103848): -> vfio_pci_walk_wrapper
103120 irqtest(103848): -> vfio_pci_count_devs
103124 irqtest(103848): <- vfio_pci_count_devs
103128 irqtest(103848): <- vfio_pci_walk_wrapper
103132 irqtest(103848): -> vfio_pci_walk_wrapper
103136 irqtest(103848): -> vfio_pci_count_devs
103139 irqtest(103848): <- vfio_pci_count_devs
103143 irqtest(103848): <- vfio_pci_walk_wrapper
103147 irqtest(103848): -> vfio_pci_walk_wrapper
103152 irqtest(103848): -> vfio_pci_get_unused_devs
103157 irqtest(103848): <- vfio_pci_get_unused_devs
103161 irqtest(103848): <- vfio_pci_walk_wrapper
103167 irqtest(103848): -> vfio_pci_set_power_state
103171 irqtest(103848): <- vfio_pci_set_power_state
103176 irqtest(103848): <- vfio_pci_release
[-- Attachment #3: vfio_pci_fail.txt --]
[-- Type: text/plain, Size: 21203 bytes --]
0 irqtest(103741): -> vfio_pci_match
5 irqtest(103741): -> get_pf_vdev
8 irqtest(103741): <- get_pf_vdev
9 irqtest(103741): <- vfio_pci_match
0 irqtest(103741): -> vfio_pci_open
2 irqtest(103741): -> vfio_pci_set_power_state
4 irqtest(103741): <- vfio_pci_set_power_state
102476 irqtest(103741): -> pci_restore_msi_state
102479 irqtest(103741): <- pci_restore_msi_state
102506 irqtest(103741): -> vfio_config_init
102509 irqtest(103741): -> vfio_fill_vconfig_bytes
102523 irqtest(103741): <- vfio_fill_vconfig_bytes
102528 irqtest(103741): -> vfio_fill_vconfig_bytes
102531 irqtest(103741): <- vfio_fill_vconfig_bytes
102535 irqtest(103741): -> vfio_fill_vconfig_bytes
102546 irqtest(103741): <- vfio_fill_vconfig_bytes
102548 irqtest(103741): -> vfio_fill_vconfig_bytes
102551 irqtest(103741): <- vfio_fill_vconfig_bytes
102552 irqtest(103741): <- vfio_config_init
102555 irqtest(103741): -> vfio_pci_vf_token_user_add
102557 irqtest(103741): -> get_pf_vdev
102559 irqtest(103741): <- get_pf_vdev
102560 irqtest(103741): <- vfio_pci_vf_token_user_add
102561 irqtest(103741): <- vfio_pci_open
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
2 irqtest(103741): <- vfio_pci_ioctl
0 irqtest(103741): -> vfio_pci_read
2 irqtest(103741): -> vfio_pci_rw
4 irqtest(103741): -> vfio_pci_config_rw
7 irqtest(103741): -> vfio_basic_config_read
8 irqtest(103741): -> vfio_default_config_read
11 irqtest(103741): -> vfio_user_config_read
14 irqtest(103741): <- vfio_user_config_read
15 irqtest(103741): <- vfio_default_config_read
16 irqtest(103741): <- vfio_basic_config_read
18 irqtest(103741): <- vfio_pci_config_rw
19 irqtest(103741): <- vfio_pci_rw
20 irqtest(103741): <- vfio_pci_read
0 irqtest(103741): -> vfio_pci_write
2 irqtest(103741): -> vfio_pci_rw
3 irqtest(103741): -> vfio_pci_config_rw
5 irqtest(103741): -> vfio_basic_config_write
8 irqtest(103741): -> vfio_default_config_write
9 irqtest(103741): -> vfio_user_config_read
11 irqtest(103741): <- vfio_user_config_read
13 irqtest(103741): -> vfio_user_config_write
15 irqtest(103741): <- vfio_user_config_write
16 irqtest(103741): <- vfio_default_config_write
18 irqtest(103741): <- vfio_basic_config_write
19 irqtest(103741): <- vfio_pci_config_rw
20 irqtest(103741): <- vfio_pci_rw
21 irqtest(103741): <- vfio_pci_write
vfio_pci_ioctl was called: 15211
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
2 irqtest(103741): <- vfio_pci_ioctl
0 irqtest(103741): -> vfio_pci_mmap
34 irqtest(103741): <- vfio_pci_mmap
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
2 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
0 irqtest(103741): -> vfio_pci_mmap
8 irqtest(103741): <- vfio_pci_mmap
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): -> vfio_pci_get_irq_count
3 irqtest(103741): <- vfio_pci_get_irq_count
4 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): -> vfio_pci_get_irq_count
2 irqtest(103741): <- vfio_pci_get_irq_count
3 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): -> vfio_pci_get_irq_count
3 irqtest(103741): <- vfio_pci_get_irq_count
4 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): -> vfio_pci_get_irq_count
2 irqtest(103741): <- vfio_pci_get_irq_count
3 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): -> vfio_pci_get_irq_count
2 irqtest(103741): <- vfio_pci_get_irq_count
3 irqtest(103741): <- vfio_pci_ioctl
0 irqtest(103741): -> vfio_pci_mmap_fault
3 irqtest(103741): -> __vfio_pci_memory_enabled
4 irqtest(103741): <- __vfio_pci_memory_enabled
7 irqtest(103741): <- vfio_pci_mmap_fault
0 irqtest(103741): -> vfio_pci_mmap_fault
1 irqtest(103741): -> __vfio_pci_memory_enabled
2 irqtest(103741): <- __vfio_pci_memory_enabled
4 irqtest(103741): <- vfio_pci_mmap_fault
0 irqtest(103741): -> vfio_pci_mmap_close
2 irqtest(103741): <- vfio_pci_mmap_close
0 irqtest(103741): -> vfio_pci_mmap_close
1 irqtest(103741): <- vfio_pci_mmap_close
0 irqtest(103741): -> vfio_pci_release
1 irqtest(103741): -> vfio_pci_vf_token_user_add
3 irqtest(103741): -> get_pf_vdev
4 irqtest(103741): <- get_pf_vdev
5 irqtest(103741): <- vfio_pci_vf_token_user_add
8 irqtest(103741): -> vfio_pci_set_irqs_ioctl
10 irqtest(103741): <- vfio_pci_set_irqs_ioctl
12 irqtest(103741): -> vfio_config_free
13 irqtest(103741): <- vfio_config_free
103705 irqtest(103741): -> pci_restore_msi_state
103714 irqtest(103741): <- pci_restore_msi_state
103725 irqtest(103741): -> vfio_pci_walk_wrapper
103731 irqtest(103741): -> vfio_pci_count_devs
103736 irqtest(103741): <- vfio_pci_count_devs
103741 irqtest(103741): <- vfio_pci_walk_wrapper
103758 irqtest(103741): -> vfio_pci_walk_wrapper
103759 irqtest(103741): -> vfio_pci_count_devs
103760 irqtest(103741): <- vfio_pci_count_devs
103761 irqtest(103741): <- vfio_pci_walk_wrapper
103762 irqtest(103741): -> vfio_pci_walk_wrapper
103763 irqtest(103741): -> vfio_pci_count_devs
103765 irqtest(103741): <- vfio_pci_count_devs
103766 irqtest(103741): <- vfio_pci_walk_wrapper
103767 irqtest(103741): -> vfio_pci_walk_wrapper
103768 irqtest(103741): -> vfio_pci_count_devs
103769 irqtest(103741): <- vfio_pci_count_devs
103770 irqtest(103741): <- vfio_pci_walk_wrapper
103771 irqtest(103741): -> vfio_pci_walk_wrapper
103773 irqtest(103741): -> vfio_pci_get_unused_devs
103775 irqtest(103741): <- vfio_pci_get_unused_devs
103776 irqtest(103741): <- vfio_pci_walk_wrapper
103778 irqtest(103741): -> vfio_pci_set_power_state
103779 irqtest(103741): <- vfio_pci_set_power_state
103780 irqtest(103741): <- vfio_pci_release
0 irqtest(103741): -> vfio_pci_match
3 irqtest(103741): -> get_pf_vdev
4 irqtest(103741): <- get_pf_vdev
5 irqtest(103741): <- vfio_pci_match
0 irqtest(103741): -> vfio_pci_open
1 irqtest(103741): -> vfio_pci_set_power_state
3 irqtest(103741): <- vfio_pci_set_power_state
103732 irqtest(103741): -> pci_restore_msi_state
103741 irqtest(103741): <- pci_restore_msi_state
103789 irqtest(103741): -> vfio_config_init
103795 irqtest(103741): -> vfio_fill_vconfig_bytes
103822 irqtest(103741): <- vfio_fill_vconfig_bytes
103832 irqtest(103741): -> vfio_fill_vconfig_bytes
103841 irqtest(103741): <- vfio_fill_vconfig_bytes
103848 irqtest(103741): -> vfio_fill_vconfig_bytes
103870 irqtest(103741): <- vfio_fill_vconfig_bytes
103875 irqtest(103741): -> vfio_fill_vconfig_bytes
103881 irqtest(103741): <- vfio_fill_vconfig_bytes
103885 irqtest(103741): <- vfio_config_init
103892 irqtest(103741): -> vfio_pci_vf_token_user_add
103897 irqtest(103741): -> get_pf_vdev
103903 irqtest(103741): <- get_pf_vdev
103918 irqtest(103741): <- vfio_pci_vf_token_user_add
103919 irqtest(103741): <- vfio_pci_open
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
2 irqtest(103741): <- vfio_pci_ioctl
0 irqtest(103741): -> vfio_pci_read
1 irqtest(103741): -> vfio_pci_rw
3 irqtest(103741): -> vfio_pci_config_rw
5 irqtest(103741): -> vfio_basic_config_read
6 irqtest(103741): -> vfio_default_config_read
8 irqtest(103741): -> vfio_user_config_read
10 irqtest(103741): <- vfio_user_config_read
12 irqtest(103741): <- vfio_default_config_read
13 irqtest(103741): <- vfio_basic_config_read
14 irqtest(103741): <- vfio_pci_config_rw
15 irqtest(103741): <- vfio_pci_rw
16 irqtest(103741): <- vfio_pci_read
0 irqtest(103741): -> vfio_pci_write
1 irqtest(103741): -> vfio_pci_rw
2 irqtest(103741): -> vfio_pci_config_rw
3 irqtest(103741): -> vfio_basic_config_write
6 irqtest(103741): -> vfio_default_config_write
8 irqtest(103741): -> vfio_user_config_read
10 irqtest(103741): <- vfio_user_config_read
11 irqtest(103741): -> vfio_user_config_write
13 irqtest(103741): <- vfio_user_config_write
14 irqtest(103741): <- vfio_default_config_write
16 irqtest(103741): <- vfio_basic_config_write
17 irqtest(103741): <- vfio_pci_config_rw
18 irqtest(103741): <- vfio_pci_rw
19 irqtest(103741): <- vfio_pci_write
vfio_pci_ioctl was called: 15211
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
0 irqtest(103741): -> vfio_pci_mmap
16 irqtest(103741): <- vfio_pci_mmap
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
2 irqtest(103741): <- vfio_pci_ioctl
0 irqtest(103741): -> vfio_pci_mmap
8 irqtest(103741): <- vfio_pci_mmap
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15212
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103741): -> vfio_pci_ioctl
2 irqtest(103741): -> vfio_pci_get_irq_count
3 irqtest(103741): <- vfio_pci_get_irq_count
4 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): -> vfio_pci_get_irq_count
2 irqtest(103741): <- vfio_pci_get_irq_count
3 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): -> vfio_pci_get_irq_count
3 irqtest(103741): <- vfio_pci_get_irq_count
4 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): -> vfio_pci_get_irq_count
2 irqtest(103741): <- vfio_pci_get_irq_count
3 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15213
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): -> vfio_pci_get_irq_count
2 irqtest(103741): <- vfio_pci_get_irq_count
3 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15214
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): -> vfio_pci_get_irq_count
3 irqtest(103741): <- vfio_pci_get_irq_count
5 irqtest(103741): -> vfio_pci_set_irqs_ioctl
vfio_pci_set_msi_trigger: irq_type: index: vector: flags: 0x5 0x2 0x0 0x24
vfio_pci_set_msi_trigger: vdev: 0xffff8ea6bc003200
8 irqtest(103741): -> vfio_pci_set_msi_trigger
10 irqtest(103741): -> vfio_pci_memory_lock_and_enable
13 irqtest(103741): <- vfio_pci_memory_lock_and_enable
15 irqtest(103741): -> pci_alloc_irq_vectors_affinity
16 irqtest(103741): -> __pci_enable_msix_range
18 irqtest(103741): -> pci_msi_supported
20 irqtest(103741): <- pci_msi_supported
21 irqtest(103741): -> pci_msix_vec_count
23 irqtest(103741): <- pci_msix_vec_count
33 irqtest(103741): -> pci_msix_vec_count
35 irqtest(103741): <- pci_msix_vec_count
38 irqtest(103741): -> pci_msi_setup_msi_irqs
43 irqtest(103741): -> pci_msi_domain_check_cap
44 irqtest(103741): <- pci_msi_domain_check_cap
46 irqtest(103741): -> pci_msi_domain_calc_hwirq
48 irqtest(103741): <- pci_msi_domain_calc_hwirq
109 irqtest(103741): -> pci_msi_domain_write_msg
111 irqtest(103741): -> __pci_write_msi_msg
113 irqtest(103741): <- __pci_write_msi_msg
114 irqtest(103741): <- pci_msi_domain_write_msg
118 irqtest(103741): <- pci_msi_setup_msi_irqs
119 irqtest(103741): -> msi_verify_entries
120 irqtest(103741): <- msi_verify_entries
124 irqtest(103741): -> __pci_msix_desc_mask_irq
125 irqtest(103741): <- __pci_msix_desc_mask_irq
127 irqtest(103741): -> populate_msi_sysfs
132 irqtest(103741): <- populate_msi_sysfs
136 irqtest(103741): <- __pci_enable_msix_range
137 irqtest(103741): <- pci_alloc_irq_vectors_affinity
139 irqtest(103741): -> vfio_pci_memory_unlock_and_restore
141 irqtest(103741): <- vfio_pci_memory_unlock_and_restore
vfio_msi_set_block: start: count: 0x0, 0x1
vfio_msi_set_block: vdev->num_ctx: 0x1
144 irqtest(103741): -> vfio_msi_set_block
vfio_msi_set_vector_signal was called: 0 / 7
147 irqtest(103741): -> vfio_msi_set_vector_signal
149 irqtest(103741): -> pci_irq_vector
150 irqtest(103741): <- pci_irq_vector
153 irqtest(103741): -> vfio_pci_memory_lock_and_enable
156 irqtest(103741): <- vfio_pci_memory_lock_and_enable
159 irqtest(103741): -> pci_write_msi_msg
162 irqtest(103741): -> __pci_write_msi_msg
163 irqtest(103741): <- __pci_write_msi_msg
164 irqtest(103741): <- pci_write_msi_msg
178 irqtest(103741): -> pci_msi_domain_write_msg
179 irqtest(103741): -> __pci_write_msi_msg
180 irqtest(103741): <- __pci_write_msi_msg
181 irqtest(103741): <- pci_msi_domain_write_msg
186 irqtest(103741): -> pci_msi_unmask_irq
187 irqtest(103741): -> msi_set_mask_bit
188 irqtest(103741): -> __pci_msix_desc_mask_irq
190 irqtest(103741): <- __pci_msix_desc_mask_irq
192 irqtest(103741): <- msi_set_mask_bit
193 irqtest(103741): <- pci_msi_unmask_irq
213 irqtest(103741): -> vfio_pci_memory_unlock_and_restore
216 irqtest(103741): <- vfio_pci_memory_unlock_and_restore
217 irqtest(103741): <- vfio_msi_set_vector_signal
vfio_msi_set_vector_signal returned with: 0
219 irqtest(103741): <- vfio_msi_set_block
221 irqtest(103741): <- vfio_pci_set_msi_trigger
222 irqtest(103741): <- vfio_pci_set_irqs_ioctl
223 irqtest(103741): <- vfio_pci_ioctl
vfio_pci_ioctl was called: 15214
0 irqtest(103741): -> vfio_pci_ioctl
1 irqtest(103741): -> vfio_pci_get_irq_count
3 irqtest(103741): <- vfio_pci_get_irq_count
5 irqtest(103741): -> vfio_pci_set_irqs_ioctl
vfio_pci_set_msi_trigger: irq_type: index: vector: flags: 0x2 0x2 0x1 0x24
vfio_pci_set_msi_trigger: vdev: 0xffff8ea6bc003200
7 irqtest(103741): -> vfio_pci_set_msi_trigger
vfio_msi_set_block: start: count: 0x1, 0x1
vfio_msi_set_block: vdev->num_ctx: 0x1
9 irqtest(103741): -> vfio_msi_set_block
11 irqtest(103741): <- vfio_msi_set_block
12 irqtest(103741): <- vfio_pci_set_msi_trigger
13 irqtest(103741): <- vfio_pci_set_irqs_ioctl
14 irqtest(103741): <- vfio_pci_ioctl
0 irqtest(103741): -> vfio_pci_mmap_close
2 irqtest(103741): <- vfio_pci_mmap_close
0 irqtest(103741): -> vfio_pci_mmap_close
2 irqtest(103741): <- vfio_pci_mmap_close
0 irqtest(103741): -> vfio_pci_release
2 irqtest(103741): -> vfio_pci_vf_token_user_add
3 irqtest(103741): -> get_pf_vdev
5 irqtest(103741): <- get_pf_vdev
6 irqtest(103741): <- vfio_pci_vf_token_user_add
9 irqtest(103741): -> vfio_pci_set_irqs_ioctl
vfio_pci_set_msi_trigger: irq_type: index: vector: flags: 0x2 0x2 0x0 0x21
vfio_pci_set_msi_trigger: vdev: 0xffff8ea6bc003200
12 irqtest(103741): -> vfio_pci_set_msi_trigger
14 irqtest(103741): -> vfio_msi_disable
vfio_msi_set_block: start: count: 0x0, 0x1
vfio_msi_set_block: vdev->num_ctx: 0x1
20 irqtest(103741): -> vfio_msi_set_block
vfio_msi_set_vector_signal was called: 0 / -1
22 irqtest(103741): -> vfio_msi_set_vector_signal
24 irqtest(103741): -> pci_irq_vector
25 irqtest(103741): <- pci_irq_vector
26 irqtest(103741): -> vfio_pci_memory_lock_and_enable
30 irqtest(103741): <- vfio_pci_memory_lock_and_enable
37 irqtest(103741): -> pci_msi_mask_irq
39 irqtest(103741): -> msi_set_mask_bit
40 irqtest(103741): -> __pci_msix_desc_mask_irq
41 irqtest(103741): <- __pci_msix_desc_mask_irq
43 irqtest(103741): <- msi_set_mask_bit
44 irqtest(103741): <- pci_msi_mask_irq
53 irqtest(103741): -> pci_msi_domain_write_msg
54 irqtest(103741): -> __pci_write_msi_msg
56 irqtest(103741): <- __pci_write_msi_msg
57 irqtest(103741): <- pci_msi_domain_write_msg
65 irqtest(103741): -> vfio_pci_memory_unlock_and_restore
67 irqtest(103741): <- vfio_pci_memory_unlock_and_restore
68 irqtest(103741): <- vfio_msi_set_vector_signal
vfio_msi_set_vector_signal returned with: 0
77 irqtest(103741): <- vfio_msi_set_block
78 irqtest(103741): -> vfio_pci_memory_lock_and_enable
81 irqtest(103741): <- vfio_pci_memory_lock_and_enable
83 irqtest(103741): -> pci_free_irq_vectors
84 irqtest(103741): -> pci_disable_msix
88 irqtest(103741): -> free_msi_irqs
91 irqtest(103741): -> default_teardown_msi_irqs
139 irqtest(103741): <- default_teardown_msi_irqs
145 irqtest(103741): <- free_msi_irqs
146 irqtest(103741): <- pci_disable_msix
148 irqtest(103741): -> pci_disable_msi
149 irqtest(103741): <- pci_disable_msi
150 irqtest(103741): <- pci_free_irq_vectors
151 irqtest(103741): -> vfio_pci_memory_unlock_and_restore
154 irqtest(103741): <- vfio_pci_memory_unlock_and_restore
155 irqtest(103741): <- vfio_msi_disable
156 irqtest(103741): <- vfio_pci_set_msi_trigger
158 irqtest(103741): <- vfio_pci_set_irqs_ioctl
159 irqtest(103741): -> vfio_config_free
160 irqtest(103741): <- vfio_config_free
103190 irqtest(103741): -> pci_restore_msi_state
103199 irqtest(103741): <- pci_restore_msi_state
103210 irqtest(103741): -> vfio_pci_walk_wrapper
103215 irqtest(103741): -> vfio_pci_count_devs
103220 irqtest(103741): <- vfio_pci_count_devs
103224 irqtest(103741): <- vfio_pci_walk_wrapper
103228 irqtest(103741): -> vfio_pci_walk_wrapper
103232 irqtest(103741): -> vfio_pci_count_devs
103236 irqtest(103741): <- vfio_pci_count_devs
103240 irqtest(103741): <- vfio_pci_walk_wrapper
103243 irqtest(103741): -> vfio_pci_walk_wrapper
103247 irqtest(103741): -> vfio_pci_count_devs
103251 irqtest(103741): <- vfio_pci_count_devs
103255 irqtest(103741): <- vfio_pci_walk_wrapper
103258 irqtest(103741): -> vfio_pci_walk_wrapper
103262 irqtest(103741): -> vfio_pci_count_devs
103266 irqtest(103741): <- vfio_pci_count_devs
103269 irqtest(103741): <- vfio_pci_walk_wrapper
103274 irqtest(103741): -> vfio_pci_walk_wrapper
103278 irqtest(103741): -> vfio_pci_get_unused_devs
103284 irqtest(103741): <- vfio_pci_get_unused_devs
103288 irqtest(103741): <- vfio_pci_walk_wrapper
103293 irqtest(103741): -> vfio_pci_set_power_state
103297 irqtest(103741): <- vfio_pci_set_power_state
103302 irqtest(103741): <- vfio_pci_release
^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: BUG REPORT: vfio_pci driver
2021-08-13 18:34 BUG REPORT: vfio_pci driver Russ Weight
@ 2021-08-13 22:09 ` Alex Williamson
2021-08-17 17:16 ` Russ Weight
0 siblings, 1 reply; 3+ messages in thread
From: Alex Williamson @ 2021-08-13 22:09 UTC (permalink / raw)
To: Russ Weight
Cc: Cornelia Huck, Adler, Michael, Whisonant, Tim, kvm, linux-kernel,
Tom Rix
On Fri, 13 Aug 2021 11:34:51 -0700
Russ Weight <russell.h.weight@intel.com> wrote:
> Bug Description:
>
> A bug in the vfio_pci driver was reported in junction with work on FPGA
This looks like the documented behavior of an IRQ index reporting the
VFIO_IRQ_INFO_NORESIZE flag. We can certainly work towards trying to
remove the flag from this index, but it seems the userspace driver is
currently ignoring the flag and expecting exactly the behavior the flag
indicates is not available. Thanks,
Alex
> cards. We were able to reproduce and root-cause the bug using system-tap.
> The original bug description is below. An understanding of the referenced
> dfl and opae tools is not required - it is the sequence of IOCTL calls and
> IRQ vectors that matters:
>
> > I’m trying to get an example AFU working that uses 2 IRQs, active at the same
> > time. I’m hitting what looks to be a dfl_pci driver bug.
> >
> > The code tries to allocate two IRQ vectors: 0 and 1. I see opaevfio.c doing the
> > right thing, picking the MSIX index. Allocating either IRQ 0 or IRQ 1 works fine
> > and I confirm that the VFIO_DEVICE_SET_IRQS looks reasonable, choosing MSIX and
> > either start of 0 or 1 and count 1.
> >
> > Note that opaevfio.c always passes count 1, so it will make separate calls for
> > each IRQ vector.
> >
> > When I try to allocate both, I see the following:
> >
> > * If the VFIO_DEVICE_SET_IRQS ioctl is called first with start 0 and then
> > start 1 (always count 1), the start 1 (second) ioctl trap returns EINVAL.
> > * If I set up the vectors in decreasing order, so start 1 followed by start 0,
> > the program works!
> > * I ruled out OPAE SDK user space problems by setting up my program to
> > allocate in increasing order, which would normally fail. I changed only the
> > ioctl call in user space opaevfio.c, inverting bit 0 of start so that the
> > driver is called in decreasing index order. Of course this binds the wrong
> > vectors to the fds, but I don’t care about that for now. This works! From
> > this, I conclude that it can’t be a user space problem since the difference
> > between working and failing is solely the order in which IRQ vectors are
> > bound in ioctl calls.
>
> The EINVAL is coming from vfio_msi_set_block() here:
> https://github.com/torvalds/linux/blob/master/drivers/vfio/pci/vfio_pci_intrs.c#L373
>
> vfio_msi_set_block() is being called from vfio_pci_set_msi_trigger() here on
> the second IRQ request:
> https://github.com/torvalds/linux/blob/master/drivers/vfio/pci/vfio_pci_intrs.c#L530
>
> We believe the bug is in vfio_pci_set_msi_trigger(), in the 2nd parameter to the call
> to vfio_msi_enable() here:
> https://github.com/torvalds/linux/blob/master/drivers/vfio/pci/vfio_pci_intrs.c#L533
>
> In both the passing and failing cases, the first IRQ request results in a call
> to vfio_msi_enable() at line 533 and the second IRQ request results in the
> call to vfio_msi_set_block() at line 530. It is during the first IRQ request
> that vfio_msi_enable() sets vdev->num_ctx based on the 2nd parameter (nvec).
> vdev->num_ctx is part of the conditional that results in the EINVAL for the
> failing case.
>
> In the passing case, vdev->num_ctx is 2. In the failing case, it is 1.
>
> I am attaching two text files containing trace information from systemtap: one for
> the failing case and one for the passing case. They contain a lot more information
> than is needed, but if you search for vfio_pci_set_msi_trigger and vfio_msi_set_block,
> you will see values for some of the call parameters.
>
> - Russ
>
^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: BUG REPORT: vfio_pci driver
2021-08-13 22:09 ` Alex Williamson
@ 2021-08-17 17:16 ` Russ Weight
0 siblings, 0 replies; 3+ messages in thread
From: Russ Weight @ 2021-08-17 17:16 UTC (permalink / raw)
To: Alex Williamson
Cc: Cornelia Huck, Adler, Michael, Whisonant, Tim, kvm, linux-kernel,
Tom Rix
On 8/13/21 3:09 PM, Alex Williamson wrote:
> On Fri, 13 Aug 2021 11:34:51 -0700
> Russ Weight <russell.h.weight@intel.com> wrote:
>
>> Bug Description:
>>
>> A bug in the vfio_pci driver was reported in junction with work on FPGA
> This looks like the documented behavior of an IRQ index reporting the
> VFIO_IRQ_INFO_NORESIZE flag. We can certainly work towards trying to
> remove the flag from this index, but it seems the userspace driver is
> currently ignoring the flag and expecting exactly the behavior the flag
> indicates is not available. Thanks,
Thanks for the quick reply, Alex. Yes, we misunderstood the expected
behavior. We have adapted our library code and everything is
working now.
- Russ
>
> Alex
>
>> cards. We were able to reproduce and root-cause the bug using system-tap.
>> The original bug description is below. An understanding of the referenced
>> dfl and opae tools is not required - it is the sequence of IOCTL calls and
>> IRQ vectors that matters:
>>
>>> I’m trying to get an example AFU working that uses 2 IRQs, active at the same
>>> time. I’m hitting what looks to be a dfl_pci driver bug.
>>>
>>> The code tries to allocate two IRQ vectors: 0 and 1. I see opaevfio.c doing the
>>> right thing, picking the MSIX index. Allocating either IRQ 0 or IRQ 1 works fine
>>> and I confirm that the VFIO_DEVICE_SET_IRQS looks reasonable, choosing MSIX and
>>> either start of 0 or 1 and count 1.
>>>
>>> Note that opaevfio.c always passes count 1, so it will make separate calls for
>>> each IRQ vector.
>>>
>>> When I try to allocate both, I see the following:
>>>
>>> * If the VFIO_DEVICE_SET_IRQS ioctl is called first with start 0 and then
>>> start 1 (always count 1), the start 1 (second) ioctl trap returns EINVAL.
>>> * If I set up the vectors in decreasing order, so start 1 followed by start 0,
>>> the program works!
>>> * I ruled out OPAE SDK user space problems by setting up my program to
>>> allocate in increasing order, which would normally fail. I changed only the
>>> ioctl call in user space opaevfio.c, inverting bit 0 of start so that the
>>> driver is called in decreasing index order. Of course this binds the wrong
>>> vectors to the fds, but I don’t care about that for now. This works! From
>>> this, I conclude that it can’t be a user space problem since the difference
>>> between working and failing is solely the order in which IRQ vectors are
>>> bound in ioctl calls.
>> The EINVAL is coming from vfio_msi_set_block() here:
>> https://github.com/torvalds/linux/blob/master/drivers/vfio/pci/vfio_pci_intrs.c#L373
>>
>> vfio_msi_set_block() is being called from vfio_pci_set_msi_trigger() here on
>> the second IRQ request:
>> https://github.com/torvalds/linux/blob/master/drivers/vfio/pci/vfio_pci_intrs.c#L530
>>
>> We believe the bug is in vfio_pci_set_msi_trigger(), in the 2nd parameter to the call
>> to vfio_msi_enable() here:
>> https://github.com/torvalds/linux/blob/master/drivers/vfio/pci/vfio_pci_intrs.c#L533
>>
>> In both the passing and failing cases, the first IRQ request results in a call
>> to vfio_msi_enable() at line 533 and the second IRQ request results in the
>> call to vfio_msi_set_block() at line 530. It is during the first IRQ request
>> that vfio_msi_enable() sets vdev->num_ctx based on the 2nd parameter (nvec).
>> vdev->num_ctx is part of the conditional that results in the EINVAL for the
>> failing case.
>>
>> In the passing case, vdev->num_ctx is 2. In the failing case, it is 1.
>>
>> I am attaching two text files containing trace information from systemtap: one for
>> the failing case and one for the passing case. They contain a lot more information
>> than is needed, but if you search for vfio_pci_set_msi_trigger and vfio_msi_set_block,
>> you will see values for some of the call parameters.
>>
>> - Russ
>>
^ permalink raw reply [flat|nested] 3+ messages in thread
end of thread, other threads:[~2021-08-17 17:16 UTC | newest]
Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-08-13 18:34 BUG REPORT: vfio_pci driver Russ Weight
2021-08-13 22:09 ` Alex Williamson
2021-08-17 17:16 ` Russ Weight
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).