[LTP] LTP test perf_event_open02.c: possible rounding issue on aarch64 KVM

[James Clark]

On 09/12/2021 12:20, Petr Vorel wrote:
> Hi,
> 
> I have problem with LTP test perf_event_open02.c [1] on QEMU using KVM on
> openSUSE aarch64 kernel 5.15.5-1-default (not much different from stable kernel
> from kernel.org):
> 
> # /opt/ltp/testcases/bin/perf_event_open02
> ...
> perf_event_open02.c:104: TINFO: bench_work estimated loops = 8083 in 500 ms
> perf_event_open02.c:149: TINFO: [0] value:2425293761 time_enabled:749092800 time_running:749092800
> perf_event_open02.c:149: TINFO: [1] value:2425287027 time_enabled:749141475 time_running:749141475
> perf_event_open02.c:149: TINFO: [2] value:2433046583 time_enabled:757346300 time_running:757346300
> perf_event_open02.c:149: TINFO: [3] value:2432771537 time_enabled:753369300 time_running:753369300
> perf_event_open02.c:149: TINFO: [4] value:2432551620 time_enabled:753784075 time_running:753784075
> perf_event_open02.c:149: TINFO: [5] value:2432386104 time_enabled:753481750 time_running:753481750
> perf_event_open02.c:149: TINFO: [6] value:2095086137 time_enabled:768866050 time_running:660021525
> perf_event_open02.c:308: TINFO: nhw: 6, overall task clock: 4098138525
> perf_event_open02.c:309: TINFO: hw sum: 116450294745, task clock sum: 24589636350
> perf_event_open02.c:321: TINFO: ratio: 6.000196
> perf_event_open02.c:323: TFAIL: test failed (ratio was greater than 6)
> ...
> 
> The test tries to assert the precision of hardware counters (using struct
> perf_event_attr hw_event.type = PERF_TYPE_HARDWARE), but sometimes it fails with
> slight overrun. We suppose that this is a rounding error, but it'd be nice to
> get this confirmed from kernel developers.
> 

I don't believe this is a rounding error because the test uses long longs for the totals and then
has a single division into a double. A difference of 0.000196 is too big to be explained by
rounding from a single division.

There is at least one other fix (f4bf9ba01802) in the commit history that involves
very close but failing values, and the fix wasn't to change the tolerance. So I'd say there is
probably a bug in the test, or you've found a real bug.

> Related kernel setup (or you need to know something else)
> grep PERF_EVENTS config-5.15.5-1-default # aarch64
> CONFIG_HAVE_PERF_EVENTS=y
> CONFIG_PERF_EVENTS=y
> CONFIG_HW_PERF_EVENTS=y
> 
> Test is running inside testing framework with this setup:
> qemu-system-aarch64 -device virtio-gpu-pci -only-migratable -chardev ringbuf,id=serial0,logfile=serial0,logappend=on -serial chardev:serial0 -audiodev none,id=snd0 -device intel-hda -device hda-output,audiodev=snd0 -m 2048 -machine virt,gic-version=host -cpu host -mem-prealloc -mem-path /dev/hugepages/ -netdev user,id=qanet0 -device virtio-net,netdev=qanet0,mac=52:54:00:12:34:56 -object rng-random,filename=/dev/urandom,id=rng0 -device virtio-rng-pci,rng=rng0 -boot menu=on,splash-time=5000 -device nec-usb-xhci -device usb-tablet -device usb-kbd -smp 2 -enable-kvm -no-shutdown -vnc :97,share=force-shared -device virtio-serial -chardev pipe,id=virtio_console,path=virtio_console,logfile=virtio_console.log,logappend=on -device virtconsole,chardev=virtio_console,name=org.openqa.console.virtio_console -chardev pipe,id=virtio_console1,path=virtio_console1,logfile=virtio_console1.log,logappend=on -device virtconsole,chardev=virtio_console1,name=org.openqa.console.virtio_console1 -chardev socket,path=qmp_socket,server=on,wait=off,id=qmp_socket,logfile=qmp_socket.log,logappend=on -qmp chardev:qmp_socket -S -device virtio-scsi-pci,id=scsi0 -blockdev driver=file,node-name=hd0-overlay0-file,filename=/var/lib/openqa/pool/7/raid/hd0-overlay0,cache.no-flush=on -blockdev driver=qcow2,node-name=hd0-overlay0,file=hd0-overlay0-file,cache.no-flush=on -device virtio-blk-device,id=hd0-device,drive=hd0-overlay0,bootindex=0,serial=hd0 -blockdev driver=file,node-name=cd0-overlay0-file,filename=/var/lib/openqa/pool/7/raid/cd0-overlay0,cache.no-flush=on -blockdev driver=qcow2,node-name=cd0-overlay0,file=cd0-overlay0-file,cache.no-flush=on -device scsi-cd,id=cd0-device,drive=cd0-overlay0,serial=cd0 -drive id=pflash-code-overlay0,if=pflash,file=/var/lib/openqa/pool/7/raid/pflash-code-overlay0,unit=0,readonly=on -drive id=pflash-vars-overlay0,if=pflash,file=/var/lib/openqa/pool/7/raid/pflash-vars-overlay0,unit=1
> 
> Running the same OS and kernel (aarch64 JeOS Tumbleweed 20211202) on RPI it's working:
> perf_event_open02.c:104: TINFO: bench_work estimated loops = 3601 in 500 ms
> perf_event_open02.c:149: TINFO: [0] value:1080601748 time_enabled:480527015 time_running:480527015
> perf_event_open02.c:149: TINFO: [1] value:1080599535 time_enabled:480540573 time_running:480540573
> perf_event_open02.c:149: TINFO: [2] value:1080592770 time_enabled:480533868 time_running:480533868
> perf_event_open02.c:149: TINFO: [3] value:1080607121 time_enabled:480571573 time_running:480571573
> perf_event_open02.c:149: TINFO: [4] value:1080598264 time_enabled:480568330 time_running:480568330
> perf_event_open02.c:149: TINFO: [5] value:1080608798 time_enabled:480600001 time_running:480600001
> perf_event_open02.c:149: TINFO: [6] value:923390393 time_enabled:480919479 time_running:410947611
> perf_event_open02.c:308: TINFO: nhw: 6, overall task clock: 4990107074
> perf_event_open02.c:309: TINFO: hw sum: 51868804135, task clock sum: 29940616417
> perf_event_open02.c:321: TINFO: ratio: 5.999995
> perf_event_open02.c:325: TPASS: test passed
> 
> Test is not supported ENOENT when running with similar setup on x86_64 and
> s390x quests:
> perf_event_open.h:31: TCONF: perf_event_open type/config not supported: ENOENT (2)
> 
> grep PERF_EVENTS config-5.15.5-1-default # x86_64
> CONFIG_HAVE_PERF_EVENTS=y
> CONFIG_PERF_EVENTS=y
> CONFIG_PERF_EVENTS_INTEL_UNCORE=y
> CONFIG_PERF_EVENTS_INTEL_RAPL=y
> CONFIG_PERF_EVENTS_INTEL_CSTATE=y
> CONFIG_PERF_EVENTS_AMD_POWER=m
> CONFIG_PERF_EVENTS_AMD_UNCORE=m
> CONFIG_HAVE_PERF_EVENTS_NMI=y
> 
> But it passes on ppc64le
> 
> perf_event_open02.c:104: TINFO: bench_work estimated loops = 4075 in 500 ms
> perf_event_open02.c:151: TINFO: [0] value:815279669 time_enabled:316461566 time_running:316461566
> perf_event_open02.c:151: TINFO: [1] value:815281799 time_enabled:316462740 time_running:316462740
> perf_event_open02.c:151: TINFO: [2] value:815280588 time_enabled:316534086 time_running:316534086
> perf_event_open02.c:151: TINFO: [3] value:815283285 time_enabled:316465672 time_running:316465672
> perf_event_open02.c:151: TINFO: [4] value:815305390 time_enabled:316492698 time_running:316492698
> perf_event_open02.c:151: TINFO: [5] value:686550649 time_enabled:316631866 time_running:266632316
> perf_event_open02.c:308: TINFO: nhw: 5, overall task clock: 2534004200
> perf_event_open02.c:309: TINFO: hw sum: 32612814180, task clock sum: 12669966232
> perf_event_open02.c:321: TINFO: ratio: 4.999978
> perf_event_open02.c:325: TPASS: test passed
> 
> grep PERF_EVENTS config # ppc64le
> CONFIG_HAVE_PERF_EVENTS=y
> CONFIG_PERF_EVENTS=y
> CONFIG_HAVE_PERF_EVENTS_NMI=y
> 
> When I tried running aarch64 quest with stable kernel 5.10.76 from kernel.org on
> my intel laptop, using simplified setup, the event was not supported (not sure
> whether that was caused unavailable -enable-kvm or something else; I also
> haven't checked kernel config):
> 
> qemu-system-aarch64 -M virt -cpu cortex-a53 -nographic -smp $SMP -kernel Image -append "rootwait root=/dev/vda console=ttyAMA0" -netdev user,id=eth0 -device virtio-net-device,netdev=eth0 -drive file=rootfs.ext4,if=none,format=raw,id=hd0 -device virtio-blk-device,drive=hd0
> ...
> perf_event_open.h:26: TINFO: perf_event_open event.type: 0, event.config: 1
> perf_event_open.h:30: TCONF: perf_event_open type/config not supported: ENOENT (2)
> 
> I also tested that stable kernel 5.10.76 on RPI but that passed (the same as openSUSE 5.15.5-1-default)
> perf_event_open02.c:104: TINFO: bench_work estimated loops = 1496 in 500 ms
> perf_event_open02.c:149: TINFO: [0] value:449725668 time_enabled:500191054 time_running:500191054
> perf_event_open02.c:149: TINFO: [1] value:449728803 time_enabled:500204795 time_running:500204795
> perf_event_open02.c:149: TINFO: [2] value:449732944 time_enabled:500210665 time_running:500210665
> perf_event_open02.c:149: TINFO: [3] value:449738099 time_enabled:500210443 time_running:500210443
> perf_event_open02.c:149: TINFO: [4] value:449745104 time_enabled:500234961 time_running:500234961
> perf_event_open02.c:149: TINFO: [5] value:449756676 time_enabled:500247647 time_running:500247647
> perf_event_open02.c:149: TINFO: [6] value:385474224 time_enabled:502975813 time_running:430976612
> perf_event_open02.c:308: TINFO: nhw: 6, overall task clock: 4031349522
> perf_event_open02.c:309: TINFO: hw sum: 21590362808, task clock sum: 24187113827
> perf_event_open02.c:321: TINFO: ratio: 5.999756
> perf_event_open02.c:325: TPASS: test passed
> 
> So is it a rounding issue on aarch64 QEMU/KVM?
> Thanks for any hint what to check / try.
> 
> Kind regards,
> Petr
> 
> [1] https://github.com/linux-test-project/ltp/tree/c2d4836c057fb9f78e7f625d71638d4f40f98659/testcases/kernel/syscalls/perf_event_open/perf_event_open02.c
>