Re: [PATCH v2 2/4] vfio: selftests: Introduce vfio_dma_mapping_perf_test

[David Matlack <dmatlack@google.com>]

On 2026-08-04 05:15 PM, sashiko-bot@kernel.org wrote:
> Thank you for your contribution! Sashiko AI review found 2 potential issue(s) to consider:
> - [Medium] The `TIME` macro can clobber `errno` before the caller evaluates it.
> - [Low] Diagnostic output uses `printf` instead of `TH_LOG` or `ksft_print_msg`, violating the Test Anything Protocol (TAP) format.
> --
> 
> --- Patch [2]: [PATCH v2 2/4] vfio: selftests: Introduce vfio_dma_mapping_perf_test ---
> commit 3d215ae55639b2f45faac3bfc752e16beff09489
> Author: Aaron Lewis <aaronlewis@google.com>
> 
> vfio: selftests: Introduce vfio_dma_mapping_perf_test
>     
> Introduce vfio_dma_mapping_perf_test to aid in latency testing. Rather
> than a traditional pass/fail test, which tends to be flaky when
> enforcing latency bounds, this test directly reports the latency of
> various stages in the mapping and unmapping process.
> 
> > diff --git a/tools/testing/selftests/vfio/lib/include/libvfio.h b/tools/testing/selftests/vfio/lib/include/libvfio.h
> > index 07862b470777b..cf322b499cfba 100644
> > --- a/tools/testing/selftests/vfio/lib/include/libvfio.h
> > +++ b/tools/testing/selftests/vfio/lib/include/libvfio.h
> 
> [ ... ]
> 
> > @@ -9,6 +9,34 @@
> >  #include <libvfio/vfio_pci_device.h>
> >  #include <libvfio/vfio_pci_driver.h>
> >  
> > +#include <stdint.h>
> > +#include <time.h>
> > +#include <linux/time64.h>
> 
> [ ... ]
> 
> > +static inline uint64_t timer_elapsed_ns(struct timespec start)
> > +{
> > +	struct timespec end;
> > +
> > +	clock_gettime(CLOCK_MONOTONIC, &end);
> > +
> > +	return (uint64_t)(end.tv_sec - start.tv_sec) * NSEC_PER_SEC +
> > +	       (uint64_t)(end.tv_nsec - start.tv_nsec);
> > +}
> > +
> > +#define TIME(_name, _expression) do {				   \
> > +	struct timespec __start;				   \
> > +								   \
> > +	timer_start(&__start);					   \
> > +	_expression;						   \
> > +	printf(_name " = %.2lfms\n",				   \
> 
> [Severity: Medium]
> Can this TIME macro clobber errno before the caller evaluates it?
> 
> If the target _expression (like mmap) fails and sets errno, the macro then
> calls clock_gettime() inside timer_elapsed_ns() and printf(). These libc
> functions can modify errno, causing the caller to read an incorrect errno
> value.
> 
> For example, this happens in dma_map_unmap(), where the SKIP() check reads
> errno after mmap() is executed through this macro:
> 
> tools/testing/selftests/vfio/vfio_dma_mapping_perf_test.c:dma_map_unmap() {
>     ...
>     TIME("mmap",
>          region.vaddr = mmap(NULL, size, PROT_READ | PROT_WRITE, flags, -1, 0));
> 
>     /* Skip the test if there aren't enough HugeTLB pages available. */
>     if (flags & MAP_HUGETLB && region.vaddr == MAP_FAILED)
>         SKIP(return, "mmap() failed: %s (%d)\n", strerror(errno), errno);
>     ...
> }

Please fix this. Something like this?

#define TIME(_name, _expression) do {				   \
	struct timespec __start;				   \
	int __errno;						   \
								   \
	timer_start(&__start);					   \
	_expression;						   \
	__errno = errno;					   \
	printf(_name " = %.2lfms\n",				   \
	       (double)timer_elapsed_ns(__start) / NSEC_PER_MSEC); \
	errno = __errno;					   \
} while (0)

> [Severity: Low]
> Does this output violate the Test Anything Protocol (TAP) format?
> 
> Since it outputs directly to stdout without the TAP diagnostic prefix
> ("# "), it might confuse TAP parsers. Would it be better to use TH_LOG() or
> ksft_print_msg() here?

TH_LOG() requires defining TH_LOG_ENABLED to get the logs. I don't think
we need that kind of on/off switch for the timing logs; they should
always be on. ksft_print_msg() looks like it would work for getting
these results printed without breaking TAP parsers.

> 
> > +	       (double)timer_elapsed_ns(__start) / NSEC_PER_MSEC); \
> > +} while (0)
> > +
> 
> > diff --git a/tools/testing/selftests/vfio/vfio_dma_mapping_perf_test.c b/tools/testing/selftests/vfio/vfio_dma_mapping_perf_test.c
> > new file mode 100644
> > index 0000000000000..26c04cabef616
> > --- /dev/null
> > +++ b/tools/testing/selftests/vfio/vfio_dma_mapping_perf_test.c
> 
> [ ... ]
> 
> > +TEST_F(vfio_dma_mapping_perf_test, dma_map_unmap)
> > +{
> > +	const u64 size = SZ_1G;
> > +	const int flags = variant->mmap_flags;
> > +	struct dma_region region;
> > +
> > +	printf("mmap size = %lluG\n", (unsigned long long)(size / SZ_1G));
> 
> [Severity: Low]
> Similar to the TIME macro above, does this directly output to stdout without
> the TAP diagnostic prefix?
> 
> Using ksft_print_msg() or TH_LOG() instead would ensure the diagnostic output
> complies with the TAP specification.

Let's use ksft_print_msg().

> > +
> > +	TIME("mmap",
> > +	     region.vaddr = mmap(NULL, size, PROT_READ | PROT_WRITE, flags, -1, 0));
> > +
> 
> -- 
> Sashiko AI review · https://sashiko.dev/#/patchset/20260804165748.1060476-1-aaronlewis@google.com?part=2
>