Re: [RFC PATCH 3/3] vfio: selftests: Include a BPF script to pair with the selftest vfio_flr_test

[David Matlack <dmatlack@google.com>]

On 2025-06-26 06:04 PM, Aaron Lewis wrote:
> This BPF script is included as a way of verifying where the latency issues are
> coming from in the kernel.
> 
> The test will print how long it took to initialize each device, E.g.:
>   [0x7f61bb888700] '0000:17:0c.2' initialized in 108.6ms.
>   [0x7f61bc089700] '0000:17:0c.1' initialized in 212.3ms.
> 
> That then pairs with the results from this script to show where the latency
> issues are coming from.
> 
>   [pcie_flr] duration = 108ms
>   [vfio_df_ioctl_bind_iommufd] duration = 108ms
>   [pcie_flr] duration = 104ms
>   [vfio_df_ioctl_bind_iommufd] duration = 212ms
> 
> Of note, the second call to vfio_df_ioctl_bind_iommufd() takes >200ms,
> yet both calls to pcie_flr() only take ~100ms.  That indicates the latency
> issue occurs between these two calls.
> 
> Looking further, one of the attempts to lock the mutex in
> vfio_df_ioctl_bind_iommufd() takes ~100ms.
> 
>   [__mutex_lock] duration = 103ms
> 
> And has the callstack.
> 
>   __mutex_lock+5
>   vfio_df_ioctl_bind_iommufd+171
>   __se_sys_ioctl+110
>   do_syscall_64+109
>   entry_SYSCALL_64_after_hwframe+120

Very slick. Can you share the sequence of commands you ran to load this
script, run the test, and get the latency data out of the kernel?

> 
> Signed-off-by: Aaron Lewis <aaronlewis@google.com>
> ---
>  .../testing/selftests/vfio/vfio_flr_trace.bt  | 83 +++++++++++++++++++
>  1 file changed, 83 insertions(+)
>  create mode 100644 tools/testing/selftests/vfio/vfio_flr_trace.bt

I'm not sure where we should put this to be honest. Did you want to get
this merged or is this just in the series for visibility?

It would be nice to have a corpus of BPF traces checked in that people
can easily use to debug issues and time things while running VFIO
selftests.

Perhaps just put it in its own directory, e.g.
tools/testing/selftests/vfio/bpf?