[KVM] 323d73a8ec: kernel_selftests.kvm.vmx_set_nested_state_test.fail
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: 323d73a8ecad22bf3284f11112a7cce576ade6af ("KVM: nVMX: Change KVM_STATE_NESTED_EVMCS to signal vmcs12 is copied from eVMCS")
https://kernel.googlesource.com/pub/scm/linux/kernel/git/torvalds/linux.git master
in testcase: kernel_selftests
with following parameters:
group: kselftests-01
test-description: The kernel contains a set of "self tests" under the tools/testing/selftests/ directory. These are intended to be small unit tests to exercise individual code paths in the kernel.
test-url: https://www.kernel.org/doc/Documentation/kselftest.txt
on test machine: 8 threads Intel(R) Core(TM) i7-6700 CPU @ 3.40GHz with 16G memory
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <rong.a.chen(a)intel.com>
# selftests: kvm: vmx_set_nested_state_test
# ==== Test Assertion Failure ====
# lib/kvm_util.c:1277: ret == 0
# pid=12810 tid=12810 - Invalid argument
# 1 0x0000000000403624: vcpu_nested_state_set at kvm_util.c:1275
# 2 0x0000000000401197: test_nested_state at vmx_set_nested_state_test.c:32
# 3 0x0000000000401562: test_vmx_nested_state at vmx_set_nested_state_test.c:151
# 4 0x000000000040100f: main at vmx_set_nested_state_test.c:283
# 5 0x00007efdc57f409a: ?? ??:0
# 6 0x0000000000401099: _start at ??:?
# KVM_SET_NESTED_STATE failed, ret: -1 errno: 22
not ok 12 selftests: kvm: vmx_set_nested_state_test
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
Thanks,
Rong Chen
9 months, 2 weeks
- 2
- 1
[printk] 6d74d467b2: BUG:sleeping_function_called_from_invalid_context_at_kernel/printk/printk.c
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: 6d74d467b29ceae9bc6cb6625b38029b53dc4fe2 ("printk: redirect emit/store to new ringbuffer")
https://kernel.googlesource.com/pub/scm/linux/kernel/git/bigeasy/staging.git next-RT
in testcase: rcutorture
with following parameters:
runtime: 300s
test: cpuhotplug
torture_type: srcud
test-description: rcutorture is rcutorture kernel module load/unload test.
test-url: https://www.kernel.org/doc/Documentation/RCU/torture.txt
on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 4G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-----------------------------------------------------------------------------+------------+------------+
| | 706ce957bb | 6d74d467b2 |
+-----------------------------------------------------------------------------+------------+------------+
| boot_successes | 14 | 0 |
| boot_failures | 0 | 16 |
| BUG:sleeping_function_called_from_invalid_context_at_kernel/printk/printk.c | 0 | 16 |
+-----------------------------------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <lkp(a)intel.com>
[ 10.034125] BUG: sleeping function called from invalid context at kernel/printk/printk.c:2312
[ 10.034128] in_atomic(): 1, irqs_disabled(): 0, pid: 176, name: printk
[ 10.034131] CPU: 1 PID: 176 Comm: printk Tainted: G E 5.3.0-rc4-next-20190814-00010-g6d74d467b29ce #1
[ 10.034134] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 10.034135] Call Trace:
[ 10.034187] dump_stack+0x5c/0x7b
[ 10.034198] ___might_sleep+0xf1/0x110
[ 10.034205] console_conditional_schedule+0x24/0x30
[ 10.034210] fbcon_redraw+0x96/0x1c0
[ 10.034216] ? fbcon_cursor+0x100/0x190
[ 10.034219] fbcon_scroll+0x556/0xd70
[ 10.034221] con_scroll+0x147/0x1e0
[ 10.034225] lf+0x9e/0xb0
[ 10.034228] vt_console_print+0x253/0x3d0
[ 10.034231] printk_kthread_func+0x1d5/0x3b0
[ 10.034239] ? register_console+0x370/0x370
[ 10.034241] kthread+0x11e/0x140
[ 10.034252] ? kthread_park+0xa0/0xa0
[ 10.034255] ret_from_fork+0x35/0x40
[ 10.034410] srcud-torture: Creating rcu_torture_fakewriter task
[ 10.034448] srcud-torture: rcu_torture_fakewriter task started
[ 10.034462] srcud-torture: Creating rcu_torture_fakewriter task
[ 10.034486] srcud-torture: rcu_torture_fakewriter task started
[ 10.034499] srcud-torture: Creating rcu_torture_reader task
[ 10.034524] srcud-torture: rcu_torture_fakewriter task started
[ 10.034535] srcud-torture: Creating rcu_torture_stats task
[ 10.034559] srcud-torture: rcu_torture_reader task started
[ 10.035276] srcud-torture: Creating torture_shuffle task
[ 10.035305] srcud-torture: rcu_torture_stats task started
[ 10.035317] srcud-torture: Creating torture_stutter task
[ 10.035343] srcud-torture: torture_shuffle task started
[ 10.035354] srcud-torture: Creating torture_onoff task
[ 10.035375] srcud-torture: torture_stutter task started
[ 10.035746] srcud-torture: torture_onoff task started
[ 10.035748] srcud-torture: torture_onoff begin holdoff
[ 10.580020] 2019-08-17 14:30:20 modprobe rcutorture onoff_interval=3 onoff_holdoff=30 torture_type=srcud
[ 10.580020] 2019-08-17 14:30:20 sleep 300
Linux version 5.3.0-rc4-next-20190814-00010-g6d74d467b29ce #1
Command line: ip=::::vm-snb-4G-b8323c36aad9::dhcp root=/dev/ram0 user=lkp job=/lkp/jobs/scheduled/vm-snb-4G-b8323c36aad9/rcutorture-300s-cpuhotplug-srcud-yocto-minimal-i386-2019-05-20.cgz-6-20190817-3200-1ve3ns3-1.yaml ARCH=x86_64 kconfig=x86_64-fedora-25 branch=bigeasy-staging/next-RT commit=6d74d467b29ceae9bc6cb6625b38029b53dc4fe2 BOOT_IMAGE=/pkg/linux/x86_64-fedora-25/gcc-7/6d74d467b29ceae9bc6cb6625b38029b53dc4fe2/vmlinuz-5.3.0-rc4-next-20190814-00010-g6d74d467b29ce rcutorture.fwd_progress=0 max_uptime=1500 RESULT_ROOT=/result/rcutorture/300s-cpuhotplug-srcud/vm-snb-4G/yocto-minimal-i386-2019-05-20.cgz/x86_64-fedora-25/gcc-7/6d74d467b29ceae9bc6cb6625b38029b53dc4fe2/3 LKP_SERVER=inn debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel console=tty0 earlyprintk=ttyS0,115200 console=ttyS0,115200 vga=normal rw rcuperf.shutdown=0
Elapsed time: 20
qemu-img create -f qcow2 disk-vm-snb-4G-b8323c36aad9-0 256G
qemu-img create -f qcow2 disk-vm-snb-4G-b8323c36aad9-1 256G
qemu-img create -f qcow2 disk-vm-snb-4G-b8323c36aad9-2 256G
qemu-img create -f qcow2 disk-vm-snb-4G-b8323c36aad9-3 256G
qemu-img create -f qcow2 disk-vm-snb-4G-b8323c36aad9-4 256G
qemu-img create -f qcow2 disk-vm-snb-4G-b8323c36aad9-5 256G
qemu-img create -f qcow2 disk-vm-snb-4G-b8323c36aad9-6 256G
kvm=(
qemu-system-x86_64
-enable-kvm
-cpu SandyBridge
-kernel $kernel
-initrd initrd-vm-snb-4G-b8323c36aad9
-m 4096
-smp 2
-device e1000,netdev=net0
-netdev user,id=net0,hostfwd=tcp::32032-:22
-boot order=nc
-no-reboot
-watchdog i6300esb
-watchdog-action debug
-rtc base=localtime
-drive file=disk-vm-snb-4G-b8323c36aad9-0,media=disk,if=virtio
-drive file=disk-vm-snb-4G-b8323c36aad9-1,media=disk,if=virtio
-drive file=disk-vm-snb-4G-b8323c36aad9-2,media=disk,if=virtio
-drive file=disk-vm-snb-4G-b8323c36aad9-3,media=disk,if=virtio
-drive file=disk-vm-snb-4G-b8323c36aad9-4,media=disk,if=virtio
-drive file=disk-vm-snb-4G-b8323c36aad9-5,media=disk,if=virtio
-drive file=disk-vm-snb-4G-b8323c36aad9-6,media=disk,if=virtio
-serial stdio
-display none
-monitor null
)
append=(
ip=::::vm-snb-4G-b8323c36aad9::dhcp
root=/dev/ram0
user=lkp
job=/job-script
ARCH=x86_64
kconfig=x86_64-fedora-25
branch=bigeasy-staging/next-RT
commit=6d74d467b29ceae9bc6cb6625b38029b53dc4fe2
BOOT_IMAGE=/pkg/linux/x86_64-fedora-25/gcc-7/6d74d467b29ceae9bc6cb6625b38029b53dc4fe2/vmlinuz-5.3.0-rc4-next-20190814-00010-g6d74d467b29ce
rcutorture.fwd_progress=0
max_uptime=1500
RESULT_ROOT=/result/rcutorture/300s-cpuhotplug-srcud/vm-snb-4G/yocto-minimal-i386-2019-05-20.cgz/x86_64-fedora-25/gcc-7/6d74d467b29ceae9bc6cb6625b38029b53dc4fe2/3
result_service=tmpfs
debug
apic=debug
sysrq_always_enabled
rcupdate.rcu_cpu_stall_timeout=100
net.ifnames=0
printk.devkmsg=on
panic=-1
softlockup_panic=1
nmi_watchdog=panic
oops=panic
To reproduce:
# build kernel
cd linux
cp config-5.3.0-rc4-next-20190814-00010-g6d74d467b29ce .config
make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
lkp
9 months, 2 weeks
- 1
- 0
[x86/speculation] a17888154c: will-it-scale.per_thread_ops 26.3% improvement
by kernel test robot
Greeting,
FYI, we noticed a 26.3% improvement of will-it-scale.per_thread_ops due to commit:
commit: a17888154cf202ccf05d2efb71ed0f632f2d8897 ("x86/speculation: Prepare for conditional IBPB in switch_mm()")
https://kernel.googlesource.com/pub/scm/linux/kernel/git/stable/linux-sta... linux-4.19.y
in testcase: will-it-scale
on test machine: 288 threads Intel(R) Xeon Phi(TM) CPU 7295 @ 1.50GHz with 80G memory
with following parameters:
nr_task: 100%
mode: thread
test: lock1
cpufreq_governor: performance
test-description: Will It Scale takes a testcase and runs it from 1 through to n parallel copies to see if the testcase will scale. It builds both a process and threads based test in order to see any differences between the two.
test-url: https://github.com/antonblanchard/will-it-scale
Details are as below:
-------------------------------------------------------------------------------------------------->
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
=========================================================================================
compiler/cpufreq_governor/kconfig/mode/nr_task/rootfs/tbox_group/test/testcase:
gcc-7/performance/x86_64-rhel-7.6/thread/100%/debian-x86_64-2019-05-14.cgz/lkp-knm01/lock1/will-it-scale
commit:
dd73e15ea2 ("x86/speculation: Avoid __switch_to_xtra() calls")
a17888154c ("x86/speculation: Prepare for conditional IBPB in switch_mm()")
dd73e15ea21307f5 a17888154cf202ccf05d2efb71e
---------------- ---------------------------
%stddev %change %stddev
\ | \
4087 ± 2% +26.3% 5163 will-it-scale.per_thread_ops
473.30 ± 8% +43.5% 679.18 ± 5% will-it-scale.time.user_time
1177292 ± 2% +26.3% 1487098 will-it-scale.workload
286106 ± 30% +45.8% 417095 ± 8% cpuidle.C6.usage
0.00 ± 22% +0.0 0.00 ± 7% mpstat.cpu.all.soft%
0.65 ± 8% +0.2 0.89 ± 5% mpstat.cpu.all.usr%
129743 ± 57% +119.2% 284405 ± 9% turbostat.C6
1.90 ± 2% +29.7% 2.46 turbostat.RAMWatt
53407 ± 49% -35.2% 34627 ± 36% sched_debug.cfs_rq:/.MIN_vruntime.avg
15380679 ± 49% -47.9% 8016795 ± 3% sched_debug.cfs_rq:/.MIN_vruntime.max
904763 ± 49% -42.9% 516186 ± 18% sched_debug.cfs_rq:/.MIN_vruntime.stddev
1480 ± 10% -30.2% 1033 ± 6% sched_debug.cfs_rq:/.exec_clock.stddev
53407 ± 49% -35.2% 34627 ± 36% sched_debug.cfs_rq:/.max_vruntime.avg
15380679 ± 49% -47.9% 8016795 ± 3% sched_debug.cfs_rq:/.max_vruntime.max
904763 ± 49% -42.9% 516186 ± 18% sched_debug.cfs_rq:/.max_vruntime.stddev
790547 ± 2% -19.2% 638979 ± 4% sched_debug.cfs_rq:/.min_vruntime.stddev
317232 ± 19% +83.0% 580571 ± 39% sched_debug.cfs_rq:/.spread0.avg
614655 ± 8% +42.9% 878296 ± 26% sched_debug.cfs_rq:/.spread0.max
972.20 ± 9% -16.5% 811.40 ± 12% sched_debug.cfs_rq:/.util_est_enqueued.max
1300 ± 11% -38.9% 794.23 ± 2% sched_debug.cpu.clock.stddev
1300 ± 11% -38.9% 794.23 ± 2% sched_debug.cpu.clock_task.stddev
415370 ± 19% -28.5% 296908 ± 24% sched_debug.cpu.load.max
0.00 ± 11% -39.0% 0.00 ± 2% sched_debug.cpu.next_balance.stddev
87.20 ± 3% -9.7% 78.75 sched_debug.cpu.sched_count.min
0.96 ± 2% +0.1 1.08 perf-stat.i.branch-miss-rate%
81540515 ± 3% +16.3% 94797570 perf-stat.i.branch-misses
38822692 +4.9% 40736129 perf-stat.i.cache-misses
1.735e+08 ± 2% +6.8% 1.853e+08 perf-stat.i.cache-references
11306 -4.6% 10789 perf-stat.i.cycles-between-cache-misses
0.20 ± 5% +0.0 0.22 perf-stat.i.iTLB-load-miss-rate%
68601028 ± 6% +15.2% 79001841 perf-stat.i.iTLB-load-misses
510.28 ± 5% -10.9% 454.52 perf-stat.i.instructions-per-iTLB-miss
0.96 ± 2% +0.1 1.08 perf-stat.overall.branch-miss-rate%
11294 -4.5% 10782 perf-stat.overall.cycles-between-cache-misses
0.20 ± 5% +0.0 0.22 perf-stat.overall.iTLB-load-miss-rate%
510.16 ± 5% -10.9% 454.48 perf-stat.overall.instructions-per-iTLB-miss
8926043 ± 2% -18.4% 7286569 perf-stat.overall.path-length
81245950 ± 3% +16.3% 94455444 perf-stat.ps.branch-misses
38684989 +4.9% 40592042 perf-stat.ps.cache-misses
1.729e+08 ± 2% +6.8% 1.847e+08 perf-stat.ps.cache-references
68352742 ± 6% +15.2% 78716460 perf-stat.ps.iTLB-load-misses
135356 ± 10% -18.5% 110367 ± 9% softirqs.CPU103.TIMER
131702 ± 10% -15.2% 111681 ± 8% softirqs.CPU113.TIMER
131026 ± 14% -14.4% 112100 ± 7% softirqs.CPU116.TIMER
123745 ± 10% -10.9% 110198 ± 6% softirqs.CPU121.TIMER
133939 ± 14% -14.1% 115090 ± 7% softirqs.CPU124.TIMER
134228 ± 9% -12.2% 117851 ± 4% softirqs.CPU130.TIMER
129713 ± 12% -15.4% 109742 ± 10% softirqs.CPU139.TIMER
130778 ± 11% -14.6% 111633 ± 8% softirqs.CPU142.TIMER
137792 ± 7% -13.3% 119519 ± 12% softirqs.CPU145.TIMER
141170 ± 14% -23.2% 108480 ± 6% softirqs.CPU146.TIMER
127476 ± 16% -17.7% 104892 ± 4% softirqs.CPU148.TIMER
137275 ± 12% -14.4% 117489 ± 8% softirqs.CPU151.TIMER
129712 ± 12% -14.4% 111075 ± 9% softirqs.CPU155.TIMER
132127 ± 9% -11.7% 116693 ± 8% softirqs.CPU158.TIMER
134777 ± 12% -14.3% 115516 ± 8% softirqs.CPU164.TIMER
132913 ± 11% -14.2% 114070 ± 9% softirqs.CPU165.TIMER
131646 ± 8% -15.6% 111099 ± 10% softirqs.CPU171.TIMER
136165 ± 9% -13.9% 117217 ± 8% softirqs.CPU174.TIMER
147401 ± 13% -20.9% 116578 ± 5% softirqs.CPU178.TIMER
123830 ± 12% -11.4% 109655 ± 8% softirqs.CPU187.TIMER
133199 ± 7% -10.7% 118914 ± 5% softirqs.CPU192.TIMER
124858 ± 6% -7.7% 115234 ± 4% softirqs.CPU195.TIMER
129571 ± 8% -12.3% 113597 ± 6% softirqs.CPU200.TIMER
133620 ± 7% -11.7% 117993 ± 7% softirqs.CPU218.TIMER
136197 ± 10% -13.6% 117731 ± 9% softirqs.CPU219.TIMER
136701 ± 9% -14.3% 117127 ± 4% softirqs.CPU220.TIMER
133887 ± 8% -15.7% 112900 ± 6% softirqs.CPU222.TIMER
129124 ± 7% -14.5% 110385 ± 4% softirqs.CPU235.TIMER
136383 ± 8% -16.5% 113834 ± 8% softirqs.CPU242.TIMER
132180 ± 9% -12.5% 115706 ± 5% softirqs.CPU243.TIMER
130946 ± 12% -14.4% 112121 ± 7% softirqs.CPU246.TIMER
130677 ± 9% -13.3% 113233 ± 9% softirqs.CPU251.TIMER
129249 ± 10% -11.7% 114064 ± 8% softirqs.CPU257.TIMER
132340 ± 8% -13.3% 114727 ± 6% softirqs.CPU264.TIMER
138405 ± 9% -17.9% 113609 ± 9% softirqs.CPU268.TIMER
136635 ± 9% -14.6% 116621 ± 9% softirqs.CPU270.TIMER
128757 ± 17% -24.1% 97715 ± 2% softirqs.CPU30.TIMER
127524 ± 10% -11.2% 113182 ± 8% softirqs.CPU82.TIMER
133218 ± 10% -11.7% 117674 ± 8% softirqs.CPU89.TIMER
130174 ± 11% -15.1% 110526 ± 7% softirqs.CPU91.TIMER
139469 ± 11% -17.4% 115196 ± 10% softirqs.CPU93.TIMER
95.69 -1.0 94.69 perf-profile.calltrace.cycles-pp._raw_spin_lock.fcntl_setlk.do_fcntl.__x64_sys_fcntl.do_syscall_64
95.80 -1.0 94.84 perf-profile.calltrace.cycles-pp.native_queued_spin_lock_slowpath._raw_spin_lock.fcntl_setlk.do_fcntl.__x64_sys_fcntl
97.76 -0.4 97.37 perf-profile.calltrace.cycles-pp.fcntl_setlk.do_fcntl.__x64_sys_fcntl.do_syscall_64.entry_SYSCALL_64_after_hwframe
98.02 -0.3 97.70 perf-profile.calltrace.cycles-pp.do_fcntl.__x64_sys_fcntl.do_syscall_64.entry_SYSCALL_64_after_hwframe.do_fcntl
0.80 ± 2% +0.2 1.00 perf-profile.calltrace.cycles-pp.posix_lock_inode.do_lock_file_wait.fcntl_setlk.do_fcntl.__x64_sys_fcntl
0.96 ± 2% +0.2 1.19 perf-profile.calltrace.cycles-pp.do_lock_file_wait.fcntl_setlk.do_fcntl.__x64_sys_fcntl.do_syscall_64
96.04 -0.9 95.12 perf-profile.children.cycles-pp.native_queued_spin_lock_slowpath
96.16 -0.9 95.29 perf-profile.children.cycles-pp._raw_spin_lock
97.83 -0.4 97.47 perf-profile.children.cycles-pp.fcntl_setlk
99.03 -0.1 98.91 perf-profile.children.cycles-pp.do_syscall_64
99.09 -0.1 98.98 perf-profile.children.cycles-pp.entry_SYSCALL_64_after_hwframe
0.11 +0.0 0.12 perf-profile.children.cycles-pp.security_file_lock
0.13 ± 3% +0.0 0.14 perf-profile.children.cycles-pp.memset_erms
0.11 ± 8% +0.0 0.12 ± 6% perf-profile.children.cycles-pp.___might_sleep
0.24 +0.0 0.26 ± 3% perf-profile.children.cycles-pp.syscall_return_via_sysret
0.07 ± 17% +0.0 0.09 ± 11% perf-profile.children.cycles-pp.account_system_index_time
0.07 ± 6% +0.0 0.11 ± 4% perf-profile.children.cycles-pp.__might_fault
0.07 ± 5% +0.0 0.12 ± 3% perf-profile.children.cycles-pp._cond_resched
0.15 ± 5% +0.0 0.19 ± 2% perf-profile.children.cycles-pp._copy_from_user
0.00 +0.1 0.05 perf-profile.children.cycles-pp.locks_release_private
0.00 +0.1 0.05 perf-profile.children.cycles-pp.inode_has_perm
0.00 +0.1 0.05 ± 8% perf-profile.children.cycles-pp.__pthread_disable_asynccancel
0.04 ± 60% +0.1 0.10 ± 11% perf-profile.children.cycles-pp._raw_spin_unlock_irqrestore
0.20 ± 7% +0.1 0.27 perf-profile.children.cycles-pp.locks_free_lock
0.00 +0.1 0.08 perf-profile.children.cycles-pp.rcu_all_qs
0.46 ± 3% +0.1 0.57 perf-profile.children.cycles-pp.kmem_cache_alloc
0.56 ± 2% +0.1 0.67 perf-profile.children.cycles-pp.locks_alloc_lock
0.11 ± 6% +0.1 0.22 ± 3% perf-profile.children.cycles-pp.avc_has_perm
0.31 ± 3% +0.1 0.43 perf-profile.children.cycles-pp.file_has_perm
0.29 ± 5% +0.1 0.41 perf-profile.children.cycles-pp.security_file_fcntl
0.16 ± 2% +0.1 0.28 ± 2% perf-profile.children.cycles-pp.kmem_cache_free
0.38 ± 9% +0.2 0.56 ± 17% perf-profile.children.cycles-pp.rcu_check_callbacks
0.81 ± 2% +0.2 1.02 perf-profile.children.cycles-pp.posix_lock_inode
0.97 ± 2% +0.2 1.19 perf-profile.children.cycles-pp.do_lock_file_wait
89.30 -1.6 87.70 perf-profile.self.cycles-pp.native_queued_spin_lock_slowpath
0.11 +0.0 0.12 ± 4% perf-profile.self.cycles-pp.memset_erms
0.24 +0.0 0.26 ± 2% perf-profile.self.cycles-pp.syscall_return_via_sysret
0.09 ± 7% +0.0 0.11 perf-profile.self.cycles-pp.locks_free_lock
0.17 ± 4% +0.0 0.20 ± 2% perf-profile.self.cycles-pp.kmem_cache_alloc
0.04 ± 60% +0.0 0.08 ± 14% perf-profile.self.cycles-pp.account_system_index_time
0.11 ± 4% +0.0 0.15 ± 5% perf-profile.self.cycles-pp.do_syscall_64
0.00 +0.1 0.05 perf-profile.self.cycles-pp.__pthread_disable_asynccancel
0.00 +0.1 0.05 ± 8% perf-profile.self.cycles-pp.__might_fault
0.04 ± 60% +0.1 0.10 ± 11% perf-profile.self.cycles-pp._raw_spin_unlock_irqrestore
0.04 ± 63% +0.1 0.10 ± 7% perf-profile.self.cycles-pp.scheduler_tick
0.00 +0.1 0.06 ± 15% perf-profile.self.cycles-pp.testcase
0.00 +0.1 0.07 perf-profile.self.cycles-pp.rcu_all_qs
0.12 +0.1 0.21 ± 5% perf-profile.self.cycles-pp.posix_lock_inode
0.10 ± 7% +0.1 0.20 ± 4% perf-profile.self.cycles-pp.avc_has_perm
0.15 ± 2% +0.1 0.26 perf-profile.self.cycles-pp.kmem_cache_free
0.32 ± 2% +0.1 0.44 ± 10% perf-profile.self.cycles-pp.fcntl_setlk
0.27 ± 10% +0.2 0.44 ± 18% perf-profile.self.cycles-pp.rcu_check_callbacks
2299970 ± 5% +11.6% 2566488 ± 6% interrupts.CAL:Function_call_interrupts
8020 ± 5% +11.1% 8914 ± 6% interrupts.CPU0.CAL:Function_call_interrupts
8069 ± 6% +12.1% 9049 ± 5% interrupts.CPU1.CAL:Function_call_interrupts
7975 ± 5% +11.2% 8871 ± 5% interrupts.CPU10.CAL:Function_call_interrupts
451.25 ± 41% -50.7% 222.25 ± 17% interrupts.CPU10.RES:Rescheduling_interrupts
8029 ± 6% +11.6% 8962 ± 6% interrupts.CPU100.CAL:Function_call_interrupts
8025 ± 5% +11.6% 8957 ± 6% interrupts.CPU101.CAL:Function_call_interrupts
7975 ± 5% +12.6% 8980 ± 6% interrupts.CPU102.CAL:Function_call_interrupts
8010 ± 6% +12.0% 8974 ± 6% interrupts.CPU104.CAL:Function_call_interrupts
7943 ± 6% +12.5% 8939 ± 6% interrupts.CPU105.CAL:Function_call_interrupts
8015 ± 6% +12.2% 8993 ± 6% interrupts.CPU106.CAL:Function_call_interrupts
8048 ± 6% +11.4% 8968 ± 6% interrupts.CPU107.CAL:Function_call_interrupts
7996 ± 5% +11.4% 8910 ± 6% interrupts.CPU11.CAL:Function_call_interrupts
7993 ± 6% +12.5% 8989 ± 6% interrupts.CPU110.CAL:Function_call_interrupts
8026 ± 6% +11.6% 8960 ± 6% interrupts.CPU111.CAL:Function_call_interrupts
8072 ± 5% +11.5% 9003 ± 6% interrupts.CPU117.CAL:Function_call_interrupts
8041 ± 5% +11.7% 8981 ± 6% interrupts.CPU118.CAL:Function_call_interrupts
8058 ± 5% +11.6% 8996 ± 6% interrupts.CPU119.CAL:Function_call_interrupts
7985 ± 5% +11.2% 8883 ± 5% interrupts.CPU12.CAL:Function_call_interrupts
7992 ± 5% +12.5% 8988 ± 6% interrupts.CPU120.CAL:Function_call_interrupts
7885 ± 6% +13.9% 8981 ± 6% interrupts.CPU121.CAL:Function_call_interrupts
7917 ± 5% +13.3% 8971 ± 6% interrupts.CPU122.CAL:Function_call_interrupts
8008 ± 5% +11.9% 8965 ± 6% interrupts.CPU123.CAL:Function_call_interrupts
8046 ± 5% +11.5% 8973 ± 6% interrupts.CPU124.CAL:Function_call_interrupts
8001 ± 6% +12.3% 8985 ± 6% interrupts.CPU125.CAL:Function_call_interrupts
8031 ± 5% +11.9% 8985 ± 6% interrupts.CPU127.CAL:Function_call_interrupts
8042 ± 5% +11.9% 9001 ± 6% interrupts.CPU128.CAL:Function_call_interrupts
7889 ± 5% +12.8% 8899 ± 5% interrupts.CPU13.CAL:Function_call_interrupts
8050 ± 6% +11.3% 8958 ± 6% interrupts.CPU131.CAL:Function_call_interrupts
8041 ± 6% +10.4% 8876 ± 5% interrupts.CPU132.CAL:Function_call_interrupts
19.00 ± 35% +261.8% 68.75 ± 67% interrupts.CPU132.RES:Rescheduling_interrupts
7995 ± 6% +12.2% 8969 ± 6% interrupts.CPU134.CAL:Function_call_interrupts
3612 ± 2% +50.6% 5439 ± 31% interrupts.CPU134.NMI:Non-maskable_interrupts
3612 ± 2% +50.6% 5439 ± 31% interrupts.CPU134.PMI:Performance_monitoring_interrupts
7999 ± 6% +12.1% 8966 ± 6% interrupts.CPU135.CAL:Function_call_interrupts
8028 ± 7% +11.5% 8954 ± 6% interrupts.CPU136.CAL:Function_call_interrupts
7993 ± 7% +12.3% 8975 ± 6% interrupts.CPU138.CAL:Function_call_interrupts
444.50 ± 40% -52.7% 210.25 ± 15% interrupts.CPU14.RES:Rescheduling_interrupts
7961 ± 6% +12.5% 8953 ± 6% interrupts.CPU142.CAL:Function_call_interrupts
8004 ± 6% +11.5% 8926 ± 5% interrupts.CPU145.CAL:Function_call_interrupts
7874 ± 6% +13.5% 8940 ± 5% interrupts.CPU146.CAL:Function_call_interrupts
7949 ± 6% +11.9% 8899 ± 6% interrupts.CPU147.CAL:Function_call_interrupts
7959 ± 7% +12.0% 8917 ± 6% interrupts.CPU148.CAL:Function_call_interrupts
7906 ± 8% +12.3% 8883 ± 5% interrupts.CPU149.CAL:Function_call_interrupts
8017 ± 6% +10.8% 8884 ± 5% interrupts.CPU152.CAL:Function_call_interrupts
8073 ± 7% +10.5% 8922 ± 6% interrupts.CPU153.CAL:Function_call_interrupts
8017 ± 7% +11.2% 8915 ± 5% interrupts.CPU154.CAL:Function_call_interrupts
8006 ± 6% +11.5% 8923 ± 6% interrupts.CPU155.CAL:Function_call_interrupts
8002 ± 6% +11.4% 8915 ± 6% interrupts.CPU156.CAL:Function_call_interrupts
8023 ± 5% +11.2% 8918 ± 5% interrupts.CPU157.CAL:Function_call_interrupts
7935 ± 5% +12.3% 8908 ± 6% interrupts.CPU16.CAL:Function_call_interrupts
8051 ± 5% +11.3% 8964 ± 6% interrupts.CPU160.CAL:Function_call_interrupts
8039 ± 6% +11.6% 8971 ± 6% interrupts.CPU161.CAL:Function_call_interrupts
8005 ± 6% +11.8% 8949 ± 6% interrupts.CPU162.CAL:Function_call_interrupts
8064 ± 5% +11.2% 8968 ± 6% interrupts.CPU163.CAL:Function_call_interrupts
8075 ± 5% +10.5% 8924 ± 6% interrupts.CPU165.CAL:Function_call_interrupts
8061 ± 5% +10.6% 8914 ± 6% interrupts.CPU166.CAL:Function_call_interrupts
8078 ± 5% +10.2% 8905 ± 5% interrupts.CPU167.CAL:Function_call_interrupts
7967 ± 6% +11.1% 8855 ± 5% interrupts.CPU170.CAL:Function_call_interrupts
8019 ± 6% +11.1% 8907 ± 5% interrupts.CPU173.CAL:Function_call_interrupts
7961 ± 6% +11.9% 8907 ± 5% interrupts.CPU174.CAL:Function_call_interrupts
7917 ± 6% +12.8% 8930 ± 5% interrupts.CPU175.CAL:Function_call_interrupts
7970 ± 6% +12.1% 8936 ± 5% interrupts.CPU176.CAL:Function_call_interrupts
7881 ± 6% +13.3% 8927 ± 5% interrupts.CPU177.CAL:Function_call_interrupts
7962 ± 6% +12.2% 8938 ± 5% interrupts.CPU178.CAL:Function_call_interrupts
8009 ± 5% +11.2% 8904 ± 6% interrupts.CPU18.CAL:Function_call_interrupts
6369 ± 22% -28.5% 4555 ± 34% interrupts.CPU180.NMI:Non-maskable_interrupts
6369 ± 22% -28.5% 4555 ± 34% interrupts.CPU180.PMI:Performance_monitoring_interrupts
8023 ± 6% +11.5% 8943 ± 5% interrupts.CPU181.CAL:Function_call_interrupts
8057 ± 5% +11.4% 8972 ± 6% interrupts.CPU182.CAL:Function_call_interrupts
8042 ± 6% +11.2% 8945 ± 5% interrupts.CPU183.CAL:Function_call_interrupts
8058 ± 5% +11.0% 8946 ± 6% interrupts.CPU184.CAL:Function_call_interrupts
8002 ± 6% +11.8% 8946 ± 5% interrupts.CPU185.CAL:Function_call_interrupts
7994 ± 5% +11.8% 8935 ± 5% interrupts.CPU187.CAL:Function_call_interrupts
8018 ± 5% +11.9% 8969 ± 6% interrupts.CPU188.CAL:Function_call_interrupts
7982 ± 5% +11.9% 8928 ± 7% interrupts.CPU189.CAL:Function_call_interrupts
7982 ± 5% +12.0% 8942 ± 6% interrupts.CPU190.CAL:Function_call_interrupts
7965 ± 5% +12.1% 8925 ± 5% interrupts.CPU191.CAL:Function_call_interrupts
7935 ± 5% +12.3% 8915 ± 6% interrupts.CPU192.CAL:Function_call_interrupts
7990 ± 5% +11.7% 8921 ± 5% interrupts.CPU193.CAL:Function_call_interrupts
7881 ± 5% +12.9% 8901 ± 6% interrupts.CPU194.CAL:Function_call_interrupts
7976 ± 5% +11.5% 8893 ± 5% interrupts.CPU195.CAL:Function_call_interrupts
7965 ± 5% +11.9% 8916 ± 6% interrupts.CPU196.CAL:Function_call_interrupts
7946 ± 4% +12.2% 8918 ± 5% interrupts.CPU197.CAL:Function_call_interrupts
7931 ± 4% +12.2% 8901 ± 5% interrupts.CPU198.CAL:Function_call_interrupts
6408 ± 23% -28.8% 4563 ± 32% interrupts.CPU198.NMI:Non-maskable_interrupts
6408 ± 23% -28.8% 4563 ± 32% interrupts.CPU198.PMI:Performance_monitoring_interrupts
7745 ± 8% +15.8% 8965 ± 6% interrupts.CPU199.CAL:Function_call_interrupts
6338 ± 23% -29.1% 4491 ± 30% interrupts.CPU199.NMI:Non-maskable_interrupts
6338 ± 23% -29.1% 4491 ± 30% interrupts.CPU199.PMI:Performance_monitoring_interrupts
7950 ± 5% +12.7% 8959 ± 6% interrupts.CPU2.CAL:Function_call_interrupts
7893 ± 5% +13.2% 8931 ± 5% interrupts.CPU200.CAL:Function_call_interrupts
7910 ± 4% +13.6% 8982 ± 6% interrupts.CPU201.CAL:Function_call_interrupts
8008 ± 5% +11.8% 8955 ± 6% interrupts.CPU202.CAL:Function_call_interrupts
8024 ± 5% +11.6% 8952 ± 6% interrupts.CPU203.CAL:Function_call_interrupts
8002 ± 5% +10.9% 8877 ± 6% interrupts.CPU204.CAL:Function_call_interrupts
7994 ± 5% +12.2% 8967 ± 5% interrupts.CPU209.CAL:Function_call_interrupts
5391 ± 30% -32.5% 3639 ± 2% interrupts.CPU209.NMI:Non-maskable_interrupts
5391 ± 30% -32.5% 3639 ± 2% interrupts.CPU209.PMI:Performance_monitoring_interrupts
8015 ± 5% +12.1% 8984 ± 6% interrupts.CPU210.CAL:Function_call_interrupts
7804 ± 9% +15.0% 8973 ± 6% interrupts.CPU211.CAL:Function_call_interrupts
8035 ± 6% +11.2% 8933 ± 6% interrupts.CPU213.CAL:Function_call_interrupts
7934 ± 4% +12.3% 8911 ± 6% interrupts.CPU214.CAL:Function_call_interrupts
7988 ± 5% +11.8% 8927 ± 6% interrupts.CPU215.CAL:Function_call_interrupts
8001 ± 5% +12.1% 8968 ± 6% interrupts.CPU216.CAL:Function_call_interrupts
8007 ± 5% +11.5% 8924 ± 6% interrupts.CPU217.CAL:Function_call_interrupts
7844 ± 5% +13.6% 8912 ± 6% interrupts.CPU218.CAL:Function_call_interrupts
7737 ± 8% +15.1% 8905 ± 6% interrupts.CPU219.CAL:Function_call_interrupts
7996 ± 6% +11.5% 8916 ± 6% interrupts.CPU22.CAL:Function_call_interrupts
7933 ± 6% +11.9% 8880 ± 6% interrupts.CPU220.CAL:Function_call_interrupts
7870 ± 6% +12.8% 8880 ± 6% interrupts.CPU221.CAL:Function_call_interrupts
6511 ± 24% -30.9% 4502 ± 31% interrupts.CPU222.NMI:Non-maskable_interrupts
6511 ± 24% -30.9% 4502 ± 31% interrupts.CPU222.PMI:Performance_monitoring_interrupts
7776 ± 6% +14.6% 8911 ± 6% interrupts.CPU224.CAL:Function_call_interrupts
6538 ± 23% -30.8% 4525 ± 32% interrupts.CPU224.NMI:Non-maskable_interrupts
6538 ± 23% -30.8% 4525 ± 32% interrupts.CPU224.PMI:Performance_monitoring_interrupts
7964 ± 5% +12.1% 8928 ± 6% interrupts.CPU225.CAL:Function_call_interrupts
5541 ± 31% -32.8% 3723 interrupts.CPU225.NMI:Non-maskable_interrupts
5541 ± 31% -32.8% 3723 interrupts.CPU225.PMI:Performance_monitoring_interrupts
7953 ± 5% +11.0% 8830 ± 6% interrupts.CPU226.CAL:Function_call_interrupts
7974 ± 5% +11.0% 8852 ± 7% interrupts.CPU228.CAL:Function_call_interrupts
7952 ± 5% +11.7% 8879 ± 7% interrupts.CPU229.CAL:Function_call_interrupts
7951 ± 5% +12.1% 8917 ± 6% interrupts.CPU23.CAL:Function_call_interrupts
7978 ± 5% +12.2% 8955 ± 6% interrupts.CPU232.CAL:Function_call_interrupts
7981 ± 5% +12.0% 8943 ± 6% interrupts.CPU233.CAL:Function_call_interrupts
7974 ± 5% +12.4% 8964 ± 6% interrupts.CPU234.CAL:Function_call_interrupts
7971 ± 5% +12.9% 8998 ± 6% interrupts.CPU235.CAL:Function_call_interrupts
7968 ± 5% +12.6% 8974 ± 6% interrupts.CPU236.CAL:Function_call_interrupts
8020 ± 5% +11.9% 8971 ± 6% interrupts.CPU237.CAL:Function_call_interrupts
8016 ± 5% +12.0% 8979 ± 6% interrupts.CPU238.CAL:Function_call_interrupts
8036 ± 5% +12.0% 9003 ± 6% interrupts.CPU239.CAL:Function_call_interrupts
6388 ± 22% -28.5% 4567 ± 33% interrupts.CPU243.NMI:Non-maskable_interrupts
6388 ± 22% -28.5% 4567 ± 33% interrupts.CPU243.PMI:Performance_monitoring_interrupts
10.50 ± 38% +292.9% 41.25 ±109% interrupts.CPU244.RES:Rescheduling_interrupts
6268 ± 22% -27.8% 4526 ± 32% interrupts.CPU245.NMI:Non-maskable_interrupts
6268 ± 22% -27.8% 4526 ± 32% interrupts.CPU245.PMI:Performance_monitoring_interrupts
6366 ± 23% -28.7% 4537 ± 33% interrupts.CPU246.NMI:Non-maskable_interrupts
6366 ± 23% -28.7% 4537 ± 33% interrupts.CPU246.PMI:Performance_monitoring_interrupts
5596 ± 32% -18.7% 4548 ± 33% interrupts.CPU248.NMI:Non-maskable_interrupts
5596 ± 32% -18.7% 4548 ± 33% interrupts.CPU248.PMI:Performance_monitoring_interrupts
5564 ± 30% -33.8% 3681 ± 2% interrupts.CPU252.NMI:Non-maskable_interrupts
5564 ± 30% -33.8% 3681 ± 2% interrupts.CPU252.PMI:Performance_monitoring_interrupts
7987 ± 5% +12.1% 8953 ± 7% interrupts.CPU260.CAL:Function_call_interrupts
5387 ± 29% -32.3% 3648 ± 2% interrupts.CPU260.NMI:Non-maskable_interrupts
5387 ± 29% -32.3% 3648 ± 2% interrupts.CPU260.PMI:Performance_monitoring_interrupts
8007 ± 5% +11.7% 8942 ± 6% interrupts.CPU261.CAL:Function_call_interrupts
8014 ± 5% +12.1% 8986 ± 6% interrupts.CPU262.CAL:Function_call_interrupts
8039 ± 6% +11.6% 8975 ± 6% interrupts.CPU263.CAL:Function_call_interrupts
3632 +50.4% 5464 ± 31% interrupts.CPU263.NMI:Non-maskable_interrupts
3632 +50.4% 5464 ± 31% interrupts.CPU263.PMI:Performance_monitoring_interrupts
7885 ± 5% +14.0% 8987 ± 6% interrupts.CPU264.CAL:Function_call_interrupts
8016 ± 6% +12.5% 9018 ± 6% interrupts.CPU265.CAL:Function_call_interrupts
7945 ± 5% +13.2% 8991 ± 6% interrupts.CPU266.CAL:Function_call_interrupts
7966 ± 5% +13.0% 9000 ± 6% interrupts.CPU267.CAL:Function_call_interrupts
8050 ± 6% +12.0% 9012 ± 6% interrupts.CPU269.CAL:Function_call_interrupts
8050 ± 6% +11.5% 8976 ± 6% interrupts.CPU270.CAL:Function_call_interrupts
8048 ± 6% +11.7% 8986 ± 6% interrupts.CPU271.CAL:Function_call_interrupts
8033 ± 6% +12.0% 8994 ± 6% interrupts.CPU272.CAL:Function_call_interrupts
8061 ± 6% +11.8% 9008 ± 6% interrupts.CPU273.CAL:Function_call_interrupts
8028 ± 6% +10.9% 8904 ± 5% interrupts.CPU276.CAL:Function_call_interrupts
8053 ± 6% +10.8% 8925 ± 6% interrupts.CPU277.CAL:Function_call_interrupts
8007 ± 6% +12.3% 8990 ± 6% interrupts.CPU278.CAL:Function_call_interrupts
8027 ± 6% +12.2% 9005 ± 6% interrupts.CPU279.CAL:Function_call_interrupts
7969 ± 5% +11.4% 8875 ± 5% interrupts.CPU28.CAL:Function_call_interrupts
8019 ± 6% +12.6% 9028 ± 6% interrupts.CPU280.CAL:Function_call_interrupts
8027 ± 7% +12.1% 9001 ± 6% interrupts.CPU281.CAL:Function_call_interrupts
8016 ± 6% +12.3% 9005 ± 7% interrupts.CPU282.CAL:Function_call_interrupts
8006 ± 7% +12.0% 8963 ± 6% interrupts.CPU283.CAL:Function_call_interrupts
8025 ± 5% +12.1% 8997 ± 6% interrupts.CPU286.CAL:Function_call_interrupts
8062 ± 5% +11.6% 8999 ± 6% interrupts.CPU287.CAL:Function_call_interrupts
7827 ± 5% +14.0% 8922 ± 6% interrupts.CPU29.CAL:Function_call_interrupts
7963 ± 5% +12.0% 8919 ± 5% interrupts.CPU3.CAL:Function_call_interrupts
7896 ± 5% +12.8% 8910 ± 6% interrupts.CPU30.CAL:Function_call_interrupts
7871 ± 5% +13.9% 8964 ± 6% interrupts.CPU31.CAL:Function_call_interrupts
7895 ± 5% +13.5% 8964 ± 6% interrupts.CPU32.CAL:Function_call_interrupts
7834 ± 4% +14.3% 8952 ± 6% interrupts.CPU33.CAL:Function_call_interrupts
7888 ± 5% +13.1% 8919 ± 7% interrupts.CPU34.CAL:Function_call_interrupts
7942 ± 5% +12.9% 8964 ± 6% interrupts.CPU35.CAL:Function_call_interrupts
7950 ± 5% +11.6% 8875 ± 6% interrupts.CPU36.CAL:Function_call_interrupts
7902 ± 5% +13.1% 8940 ± 6% interrupts.CPU37.CAL:Function_call_interrupts
7957 ± 5% +12.3% 8940 ± 6% interrupts.CPU38.CAL:Function_call_interrupts
105.75 ± 14% +91.0% 202.00 ± 18% interrupts.CPU39.RES:Rescheduling_interrupts
7910 ± 8% +13.6% 8988 ± 5% interrupts.CPU4.CAL:Function_call_interrupts
7927 ± 5% +12.1% 8887 ± 5% interrupts.CPU40.CAL:Function_call_interrupts
7940 ± 5% +11.9% 8884 ± 6% interrupts.CPU41.CAL:Function_call_interrupts
7957 ± 5% +11.7% 8886 ± 6% interrupts.CPU42.CAL:Function_call_interrupts
7990 ± 5% +11.3% 8894 ± 5% interrupts.CPU43.CAL:Function_call_interrupts
7929 ± 4% +12.2% 8896 ± 6% interrupts.CPU44.CAL:Function_call_interrupts
230.75 ± 11% +38.4% 319.25 ± 11% interrupts.CPU44.RES:Rescheduling_interrupts
7998 ± 5% +11.7% 8933 ± 6% interrupts.CPU46.CAL:Function_call_interrupts
192.50 ± 13% +55.3% 299.00 ± 27% interrupts.CPU46.RES:Rescheduling_interrupts
7955 ± 5% +12.0% 8910 ± 6% interrupts.CPU47.CAL:Function_call_interrupts
7788 ± 5% +14.2% 8893 ± 6% interrupts.CPU48.CAL:Function_call_interrupts
7836 ± 5% +13.7% 8910 ± 6% interrupts.CPU49.CAL:Function_call_interrupts
7776 ± 5% +14.8% 8925 ± 6% interrupts.CPU50.CAL:Function_call_interrupts
7862 ± 5% +14.0% 8963 ± 6% interrupts.CPU51.CAL:Function_call_interrupts
7984 ± 5% +12.1% 8951 ± 6% interrupts.CPU52.CAL:Function_call_interrupts
7992 ± 5% +12.0% 8953 ± 6% interrupts.CPU53.CAL:Function_call_interrupts
7986 ± 5% +11.0% 8867 ± 5% interrupts.CPU54.CAL:Function_call_interrupts
8012 ± 5% +11.7% 8951 ± 6% interrupts.CPU55.CAL:Function_call_interrupts
8021 ± 5% +11.0% 8902 ± 5% interrupts.CPU56.CAL:Function_call_interrupts
7995 ± 5% +11.3% 8901 ± 5% interrupts.CPU57.CAL:Function_call_interrupts
7982 ± 5% +11.4% 8895 ± 5% interrupts.CPU58.CAL:Function_call_interrupts
7967 ± 5% +12.6% 8971 ± 6% interrupts.CPU59.CAL:Function_call_interrupts
7953 ± 5% +11.1% 8832 ± 5% interrupts.CPU61.CAL:Function_call_interrupts
7853 ± 5% +13.7% 8929 ± 6% interrupts.CPU62.CAL:Function_call_interrupts
7940 ± 5% +12.3% 8913 ± 6% interrupts.CPU63.CAL:Function_call_interrupts
7931 ± 5% +12.2% 8896 ± 6% interrupts.CPU64.CAL:Function_call_interrupts
7893 ± 5% +13.1% 8923 ± 6% interrupts.CPU65.CAL:Function_call_interrupts
7872 ± 5% +12.9% 8886 ± 6% interrupts.CPU66.CAL:Function_call_interrupts
7877 ± 7% +12.3% 8844 ± 6% interrupts.CPU67.CAL:Function_call_interrupts
7970 ± 5% +11.9% 8919 ± 6% interrupts.CPU72.CAL:Function_call_interrupts
7964 ± 5% +11.8% 8901 ± 7% interrupts.CPU73.CAL:Function_call_interrupts
7891 ± 5% +12.7% 8896 ± 5% interrupts.CPU8.CAL:Function_call_interrupts
7973 ± 5% +11.6% 8896 ± 6% interrupts.CPU9.CAL:Function_call_interrupts
8029 ± 5% +11.4% 8946 ± 6% interrupts.CPU93.CAL:Function_call_interrupts
8005 ± 5% +11.7% 8945 ± 6% interrupts.CPU94.CAL:Function_call_interrupts
will-it-scale.per_thread_ops
5400 +-+------------------------------------------------------------------+
| O O
5200 +-+ O O O O O O O O O O O O O |
5000 +-+ O O O |
O O |
4800 +-+O O O |
| |
4600 +-+ |
| |
4400 +-+ ..+.. |
4200 +-+ .+. +.. |
| +..+. +..+..+.. .+..+... .. +.. |
4000 +-+ +. + + |
| |
3800 +-+------------------------------------------------------------------+
[*] bisect-good sample
[O] bisect-bad sample
Disclaimer:
Results have been estimated based on internal Intel analysis and are provided
for informational purposes only. Any difference in system hardware or software
design or configuration may affect actual performance.
Thanks,
Rong Chen
9 months, 3 weeks
- 1
- 0
780a16e323: WARNING:at_lib/vsprintf.c:#format_decode
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: 780a16e323917b78004645d94400296a5e0826f3 ("Patch to do key type autoloading v2")
https://kernel.googlesource.com/pub/scm/linux/kernel/git/mbroz/linux.git dm-cryptsetup
in testcase: trinity
with following parameters:
runtime: 300s
test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/
on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 4G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+----------------------------------------------------+----------+------------+
| | v5.3-rc4 | 780a16e323 |
+----------------------------------------------------+----------+------------+
| boot_successes | 3374 | 13 |
| boot_failures | 50 | 18 |
| invoked_oom-killer:gfp_mask=0x | 26 | 1 |
| Mem-Info | 26 | 1 |
| RIP:copy_user_generic_string | 5 | |
| kernel_BUG_at_security/keys/keyring.c | 12 | |
| invalid_opcode:#[##] | 12 | |
| RIP:__key_link_begin | 12 | |
| Kernel_panic-not_syncing:Fatal_exception | 12 | 1 |
| BUG:soft_lockup-CPU##stuck_for#s | 2 | |
| RIP:clear_page_rep | 1 | |
| Kernel_panic-not_syncing:softlockup:hung_tasks | 2 | |
| BUG:kernel_hang_in_boot_stage | 8 | |
| RIP:__memcpy | 1 | |
| BUG:kernel_hang_in_boot-around-mounting-root_stage | 1 | |
| BUG:kernel_reboot-without-warning_in_test_stage | 1 | |
| WARNING:at_lib/vsprintf.c:#format_decode | 0 | 16 |
| RIP:format_decode | 0 | 16 |
| general_protection_fault:#[##] | 0 | 1 |
| RIP:string_nocheck | 0 | 1 |
+----------------------------------------------------+----------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <rong.a.chen(a)intel.com>
[ 96.204959] WARNING: CPU: 1 PID: 2265 at lib/vsprintf.c:2359 format_decode+0x3dd/0x3f0
[ 96.214488] Modules linked in: ieee802154_socket ieee802154 bridge stp llc sr_mod cdrom intel_rapl_msr sg ppdev af_key hidp cmtp kernelcapi bnep rfcomm bluetooth ecdh_generic ecc rfkill can_bcm can_raw can pptp gre l2tp_ppp l2tp_netlink l2tp_core ip6_udp_tunnel udp_tunnel pppoe pppox ppp_generic slhc intel_rapl_common crct10dif_pclmul crypto_user crc32_pclmul nfnetlink ghash_clmulni_intel scsi_transport_iscsi dccp_ipv6 atm aesni_intel sctp libcrc32c crypto_simd crc32c_intel dccp_ipv4 cryptd dccp glue_helper joydev pcspkr serio_raw bochs_drm parport_pc drm_vram_helper ttm parport drm_kms_helper floppy syscopyarea sysfillrect sysimgblt fb_sys_fops ata_generic pata_acpi drm i2c_piix4 ata_piix libata ip_tables
[ 96.279994] CPU: 1 PID: 2265 Comm: trinity-c2 Not tainted 5.3.0-rc4-00001-g780a16e323917 #1
[ 96.294201] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 96.305126] RIP: 0010:format_decode+0x3dd/0x3f0
[ 96.312620] Code: ff ff 48 8d 42 02 b9 4c 00 00 00 48 89 04 24 e9 db fc ff ff 0f be f2 48 c7 c7 80 15 fc b3 c6 05 1b b5 d9 00 01 e8 63 e8 63 ff <0f> 0b 48 8b 04 24 e9 04 ff ff ff 0f 1f 84 00 00 00 00 00 89 f0 c1
[ 96.331681] RSP: 0018:ffffbe4b0058fd48 EFLAGS: 00010282
[ 96.337426] RAX: 0000000000000000 RBX: ffffbe4b0058fd78 RCX: 0000000000000000
[ 96.343707] RDX: ffff9a49ffd27200 RSI: ffff9a49ffd17778 RDI: ffff9a49ffd17778
[ 96.349607] RBP: ffff9a493aaa142c R08: 0000000000000322 R09: 0000000000aaaaaa
[ 96.355159] R10: ffffbe4b0058fec0 R11: ffff9a4950ae2070 R12: ffffbe4b0058fe48
[ 96.361237] R13: 0000000000000038 R14: ffffbe4b0058fdf8 R15: ffff9a493aaa142c
[ 96.367489] FS: 00007fc509049740(0000) GS:ffff9a49ffd00000(0000) knlGS:0000000000000000
[ 96.373905] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 96.378953] CR2: 0000000000000000 CR3: 000000007a442000 CR4: 00000000000406e0
[ 96.384394] Call Trace:
[ 96.388238] vsnprintf+0x65/0x4d0
[ 96.392840] __request_module+0xb7/0x450
[ 96.396968] ? kasprintf+0x49/0x70
[ 96.400972] key_type_lookup+0xba/0x110
[ 96.406382] __x64_sys_request_key+0xcf/0x190
[ 96.411046] do_syscall_64+0x5b/0x1f0
[ 96.415363] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 96.419802] RIP: 0033:0x7fc5089561c9
[ 96.424822] Code: 01 00 48 81 c4 80 00 00 00 e9 f1 fe ff ff 0f 1f 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 97 dc 2c 00 f7 d8 64 89 01 48
[ 96.439124] RSP: 002b:00007fffc6696be8 EFLAGS: 00000246 ORIG_RAX: 00000000000000f9
[ 96.453973] RAX: ffffffffffffffda RBX: 00000000000000f9 RCX: 00007fc5089561c9
[ 96.464762] RDX: 00007fc506b5700c RSI: 00007fc506b57004 RDI: 00007fc506b57000
[ 96.477464] RBP: 00007fc509034000 R08: 0000000004000000 R09: 0000000000000000
[ 96.491136] R10: fffffffffffffffd R11: 0000000000000246 R12: 00007fc509034058
[ 96.504153] R13: 00007fc5090496b0 R14: 0000000000000000 R15: 00007fc509034000
[ 96.509849] ---[ end trace 79467a168956abee ]---
To reproduce:
# build kernel
cd linux
cp config-5.3.0-rc4-00001-g780a16e323917 .config
make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
Rong Chen
9 months, 3 weeks
- 1
- 0
[sched/fair] 6b8fd01b21: INFO:rcu_sched_detected_stalls_on_CPUs/tasks
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: 6b8fd01b21f5f2701b407a7118f236ba4c41226d ("sched/fair: Use rq_lock/unlock in online_fair_sched_group")
https://kernel.googlesource.com/pub/scm/linux/kernel/git/peterz/queue.git sched/core
in testcase: trinity
with following parameters:
runtime: 300s
test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/
on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 4G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+----------------------------------------------------+------------+------------+
| | 5c3ceef9ad | 6b8fd01b21 |
+----------------------------------------------------+------------+------------+
| boot_successes | 39 | 391 |
| boot_failures | 0 | 87 |
| BUG:kernel_hang_in_test_stage | 0 | 68 |
| BUG:kernel_hang_in_boot-around-mounting-root_stage | 0 | 7 |
| BUG:soft_lockup-CPU##stuck_for#s | 0 | 12 |
| RIP:smp_call_function_single | 0 | 8 |
| Kernel_panic-not_syncing:softlockup:hung_tasks | 0 | 12 |
| RIP:native_queued_spin_lock_slowpath | 0 | 6 |
| INFO:rcu_sched_detected_stalls_on_CPUs/tasks | 0 | 5 |
| RIP:propagate_entity_cfs_rq | 0 | 2 |
| RIP:native_safe_halt | 0 | 3 |
| RIP:console_unlock | 0 | 1 |
+----------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <lkp(a)intel.com>
[ 343.745182] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[ 343.753425] rcu: 0-...!: (0 ticks this GP) idle=a8a/1/0x4000000000000002 softirq=192259/192259 fqs=0
[ 343.757282] (detected by 1, t=100002 jiffies, g=378081, q=193)
[ 343.759684] Sending NMI from CPU 1 to CPUs 0:
[ 343.762288] NMI backtrace for cpu 0
[ 343.762289] CPU: 0 PID: 15242 Comm: trinity-c0 Not tainted 5.3.0-rc1-00092-g6b8fd01b21f5f #5
[ 343.762290] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 343.762290] RIP: 0010:native_queued_spin_lock_slowpath+0x21/0x1e0
[ 343.762291] Code: c5 ff ff ff 5e 5a c3 66 90 66 66 66 66 90 66 66 66 66 90 ba 01 00 00 00 8b 07 85 c0 75 0a f0 0f b1 17 85 c0 75 f2 f3 c3 f3 90 <eb> ec 81 fe 00 01 00 00 0f 84 ab 00 00 00 81 e6 00 ff ff ff 75 44
[ 343.762291] RSP: 0018:ffffc90000003f90 EFLAGS: 00000002
[ 343.762292] RAX: 0000000000000001 RBX: 0000000000000086 RCX: 0000000000000002
[ 343.762293] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffff88813fc2b180
[ 343.762293] RBP: ffffc90000003fd0 R08: 0000000000000000 R09: 0000000000000000
[ 343.762294] R10: 0000000000000000 R11: 0000000000000000 R12: ffff88813fc2b180
[ 343.762294] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 343.762294] FS: 0000000000000000(0000) GS:ffff88813fc00000(0063) knlGS:00000000f7e28900
[ 343.762295] CS: 0010 DS: 002b ES: 002b CR0: 0000000080050033
[ 343.762295] CR2: 00000000c0100220 CR3: 000000007f114000 CR4: 00000000000406f0
[ 343.762296] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 343.762296] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 343.762296] Call Trace:
[ 343.762297] <IRQ>
[ 343.762297] _raw_spin_lock_irqsave+0x37/0x40
[ 343.762297] sched_ttwu_pending+0x45/0xe0
[ 343.762298] scheduler_ipi+0xa9/0x130
[ 343.762298] reschedule_interrupt+0xf/0x20
[ 343.762298] </IRQ>
[ 343.762299] RIP: 0010:propagate_entity_cfs_rq+0x5cb/0x5f0
[ 343.762300] Code: c1 ea 0a 48 85 d2 74 0f 48 8b 81 88 00 00 00 48 63 f2 48 99 48 f7 fe 48 8b b5 88 01 00 00 48 39 c6 48 0f 46 c6 e9 4c fb ff ff <f3> c3 80 3d b7 6c 73 01 00 75 8b 48 89 3c 24 e8 21 bd ff ff 48 8b
[ 343.762300] RSP: 0018:ffffc900007efe98 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff02
[ 343.762301] RAX: ffff88813fc17810 RBX: ffff88813fc2b180 RCX: 0000000000000400
[ 343.762301] RDX: 0000000000000000 RSI: ffffffff82f8ff00 RDI: 0000000000000000
[ 343.762302] RBP: 0000000000000000 R08: 00000000000001c1 R09: ffff88812ec03500
[ 343.762302] R10: ffffc900007efe48 R11: 0000000000000000 R12: ffff88807fbaa400
[ 343.762303] R13: 000000000002b180 R14: 0000000000000000 R15: ffff88807ec44c00
[ 343.762303] online_fair_sched_group+0x5e/0x110
[ 343.762303] sched_autogroup_create_attach+0xbb/0x170
[ 343.762304] ksys_setsid+0xf2/0x110
[ 343.762304] __ia32_sys_setsid+0xa/0x10
[ 343.762304] do_fast_syscall_32+0xa9/0x340
[ 343.762305] entry_SYSENTER_compat+0x7f/0x91
[ 343.762314] rcu: rcu_sched kthread starved for 100002 jiffies! g378081 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=0
[ 343.831714] rcu: RCU grace-period kthread stack dump:
[ 343.833255] rcu_sched I 0 10 2 0x90004000
[ 343.834788] Call Trace:
[ 343.835652] ? __schedule+0x252/0x6b0
[ 343.836792] schedule+0x34/0xb0
[ 343.837807] schedule_timeout+0x16b/0x310
[ 343.839021] ? __next_timer_interrupt+0xc0/0xc0
[ 343.840353] rcu_gp_kthread+0x643/0xac0
[ 343.841524] ? rcu_accelerate_cbs_unlocked+0x70/0x70
[ 343.842946] kthread+0x11e/0x140
[ 343.843980] ? kthread_park+0xa0/0xa0
[ 343.845118] ret_from_fork+0x35/0x40
[ 643.750180] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[ 643.756145] rcu: 0-...!: (0 ticks this GP) idle=a8a/1/0x4000000000000002 softirq=192259/192259 fqs=0
[ 643.759476] (detected by 1, t=400007 jiffies, g=378081, q=204)
[ 643.761127] Sending NMI from CPU 1 to CPUs 0:
[ 643.763438] NMI backtrace for cpu 0
[ 643.763439] CPU: 0 PID: 15242 Comm: trinity-c0 Not tainted 5.3.0-rc1-00092-g6b8fd01b21f5f #5
[ 643.763440] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 643.763440] RIP: 0010:native_queued_spin_lock_slowpath+0x21/0x1e0
[ 643.763441] Code: c5 ff ff ff 5e 5a c3 66 90 66 66 66 66 90 66 66 66 66 90 ba 01 00 00 00 8b 07 85 c0 75 0a f0 0f b1 17 85 c0 75 f2 f3 c3 f3 90 <eb> ec 81 fe 00 01 00 00 0f 84 ab 00 00 00 81 e6 00 ff ff ff 75 44
[ 643.763441] RSP: 0018:ffffc90000003f90 EFLAGS: 00000002
[ 643.763442] RAX: 0000000000000001 RBX: 0000000000000086 RCX: 0000000000000002
[ 643.763443] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffff88813fc2b180
[ 643.763443] RBP: ffffc90000003fd0 R08: 0000000000000000 R09: 0000000000000000
[ 643.763444] R10: 0000000000000000 R11: 0000000000000000 R12: ffff88813fc2b180
[ 643.763444] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 643.763445] FS: 0000000000000000(0000) GS:ffff88813fc00000(0063) knlGS:00000000f7e28900
[ 643.763445] CS: 0010 DS: 002b ES: 002b CR0: 0000000080050033
[ 643.763445] CR2: 00000000c0100220 CR3: 000000007f114000 CR4: 00000000000406f0
[ 643.763446] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 643.763446] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 643.763447] Call Trace:
[ 643.763447] <IRQ>
[ 643.763447] _raw_spin_lock_irqsave+0x37/0x40
[ 643.763448] sched_ttwu_pending+0x45/0xe0
[ 643.763448] scheduler_ipi+0xa9/0x130
[ 643.763448] reschedule_interrupt+0xf/0x20
[ 643.763449] </IRQ>
[ 643.763449] RIP: 0010:propagate_entity_cfs_rq+0x5cb/0x5f0
[ 643.763450] Code: c1 ea 0a 48 85 d2 74 0f 48 8b 81 88 00 00 00 48 63 f2 48 99 48 f7 fe 48 8b b5 88 01 00 00 48 39 c6 48 0f 46 c6 e9 4c fb ff ff <f3> c3 80 3d b7 6c 73 01 00 75 8b 48 89 3c 24 e8 21 bd ff ff 48 8b
[ 643.763450] RSP: 0018:ffffc900007efe98 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff02
[ 643.763451] RAX: ffff88813fc17810 RBX: ffff88813fc2b180 RCX: 0000000000000400
[ 643.763451] RDX: 0000000000000000 RSI: ffffffff82f8ff00 RDI: 0000000000000000
[ 643.763452] RBP: 0000000000000000 R08: 00000000000001c1 R09: ffff88812ec03500
[ 643.763452] R10: ffffc900007efe48 R11: 0000000000000000 R12: ffff88807fbaa400
[ 643.763453] R13: 000000000002b180 R14: 0000000000000000 R15: ffff88807ec44c00
[ 643.763453] online_fair_sched_group+0x5e/0x110
[ 643.763453] sched_autogroup_create_attach+0xbb/0x170
[ 643.763454] ksys_setsid+0xf2/0x110
[ 643.763454] __ia32_sys_setsid+0xa/0x10
[ 643.763454] do_fast_syscall_32+0xa9/0x340
[ 643.763455] entry_SYSENTER_compat+0x7f/0x91
[ 643.763457] rcu: rcu_sched kthread starved for 400007 jiffies! g378081 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 ->cpu=0
[ 643.833220] rcu: RCU grace-period kthread stack dump:
[ 643.834689] rcu_sched R 0 10 2 0x90004000
[ 643.836245] Call Trace:
[ 643.837118] ? __schedule+0x252/0x6b0
[ 643.838275] schedule+0x34/0xb0
[ 643.839300] schedule_timeout+0x16b/0x310
[ 643.840525] ? __next_timer_interrupt+0xc0/0xc0
[ 643.841872] rcu_gp_kthread+0x643/0xac0
[ 643.843066] ? rcu_accelerate_cbs_unlocked+0x70/0x70
[ 643.844502] kthread+0x11e/0x140
[ 643.845556] ? kthread_park+0xa0/0xa0
[ 643.846704] ret_from_fork+0x35/0x40
[ 943.755175] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[ 943.764934] rcu: 0-...!: (0 ticks this GP) idle=a8a/1/0x4000000000000002 softirq=192259/192259 fqs=0
[ 943.768354] (detected by 1, t=700012 jiffies, g=378081, q=204)
[ 943.770485] Sending NMI from CPU 1 to CPUs 0:
[ 943.772976] NMI backtrace for cpu 0
[ 943.772977] CPU: 0 PID: 15242 Comm: trinity-c0 Not tainted 5.3.0-rc1-00092-g6b8fd01b21f5f #5
[ 943.772977] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 943.772978] RIP: 0010:native_queued_spin_lock_slowpath+0x21/0x1e0
[ 943.772978] Code: c5 ff ff ff 5e 5a c3 66 90 66 66 66 66 90 66 66 66 66 90 ba 01 00 00 00 8b 07 85 c0 75 0a f0 0f b1 17 85 c0 75 f2 f3 c3 f3 90 <eb> ec 81 fe 00 01 00 00 0f 84 ab 00 00 00 81 e6 00 ff ff ff 75 44
[ 943.772979] RSP: 0018:ffffc90000003f90 EFLAGS: 00000002
[ 943.772980] RAX: 0000000000000001 RBX: 0000000000000086 RCX: 0000000000000002
[ 943.772980] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffff88813fc2b180
[ 943.772981] RBP: ffffc90000003fd0 R08: 0000000000000000 R09: 0000000000000000
[ 943.772981] R10: 0000000000000000 R11: 0000000000000000 R12: ffff88813fc2b180
[ 943.772982] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 943.772982] FS: 0000000000000000(0000) GS:ffff88813fc00000(0063) knlGS:00000000f7e28900
[ 943.772982] CS: 0010 DS: 002b ES: 002b CR0: 0000000080050033
[ 943.772983] CR2: 00000000c0100220 CR3: 000000007f114000 CR4: 00000000000406f0
[ 943.772983] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 943.772984] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 943.772984] Call Trace:
[ 943.772984] <IRQ>
[ 943.772985] _raw_spin_lock_irqsave+0x37/0x40
[ 943.772985] sched_ttwu_pending+0x45/0xe0
[ 943.772985] scheduler_ipi+0xa9/0x130
[ 943.772986] reschedule_interrupt+0xf/0x20
[ 943.772986] </IRQ>
[ 943.772986] RIP: 0010:propagate_entity_cfs_rq+0x5cb/0x5f0
[ 943.772987] Code: c1 ea 0a 48 85 d2 74 0f 48 8b 81 88 00 00 00 48 63 f2 48 99 48 f7 fe 48 8b b5 88 01 00 00 48 39 c6 48 0f 46 c6 e9 4c fb ff ff <f3> c3 80 3d b7 6c 73 01 00 75 8b 48 89 3c 24 e8 21 bd ff ff 48 8b
[ 943.772988] RSP: 0018:ffffc900007efe98 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff02
[ 943.772988] RAX: ffff88813fc17810 RBX: ffff88813fc2b180 RCX: 0000000000000400
[ 943.772989] RDX: 0000000000000000 RSI: ffffffff82f8ff00 RDI: 0000000000000000
[ 943.772989] RBP: 0000000000000000 R08: 00000000000001c1 R09: ffff88812ec03500
[ 943.772990] R10: ffffc900007efe48 R11: 0000000000000000 R12: ffff88807fbaa400
[ 943.772990] R13: 000000000002b180 R14: 0000000000000000 R15: ffff88807ec44c00
[ 943.772990] online_fair_sched_group+0x5e/0x110
[ 943.772991] sched_autogroup_create_attach+0xbb/0x170
[ 943.772991] ksys_setsid+0xf2/0x110
[ 943.772991] __ia32_sys_setsid+0xa/0x10
[ 943.772992] do_fast_syscall_32+0xa9/0x340
[ 943.772992] entry_SYSENTER_compat+0x7f/0x91
[ 943.772995] rcu: rcu_sched kthread starved for 700012 jiffies! g378081 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 ->cpu=0
[ 943.845807] rcu: RCU grace-period kthread stack dump:
[ 943.847283] rcu_sched R 0 10 2 0x90004000
[ 943.848843] Call Trace:
[ 943.849720] ? __schedule+0x252/0x6b0
[ 943.850873] schedule+0x34/0xb0
[ 943.851923] schedule_timeout+0x16b/0x310
[ 943.853149] ? __next_timer_interrupt+0xc0/0xc0
[ 943.854489] rcu_gp_kthread+0x643/0xac0
[ 943.855711] ? rcu_accelerate_cbs_unlocked+0x70/0x70
[ 943.857152] kthread+0x11e/0x140
[ 943.858228] ? kthread_park+0xa0/0xa0
[ 943.859415] ret_from_fork+0x35/0x40
[ 1243.760147] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[ 1243.765939] rcu: 0-...!: (0 ticks this GP) idle=a8a/1/0x4000000000000002 softirq=192259/192259 fqs=0
[ 1243.769537] (detected by 1, t=1000017 jiffies, g=378081, q=204)
[ 1243.771822] Sending NMI from CPU 1 to CPUs 0:
[ 1243.774628] NMI backtrace for cpu 0
[ 1243.774630] CPU: 0 PID: 15242 Comm: trinity-c0 Not tainted 5.3.0-rc1-00092-g6b8fd01b21f5f #5
[ 1243.774630] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 1243.774631] RIP: 0010:native_queued_spin_lock_slowpath+0x21/0x1e0
[ 1243.774632] Code: c5 ff ff ff 5e 5a c3 66 90 66 66 66 66 90 66 66 66 66 90 ba 01 00 00 00 8b 07 85 c0 75 0a f0 0f b1 17 85 c0 75 f2 f3 c3 f3 90 <eb> ec 81 fe 00 01 00 00 0f 84 ab 00 00 00 81 e6 00 ff ff ff 75 44
[ 1243.774632] RSP: 0018:ffffc90000003f90 EFLAGS: 00000002
[ 1243.774634] RAX: 0000000000000001 RBX: 0000000000000086 RCX: 0000000000000002
[ 1243.774634] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffff88813fc2b180
[ 1243.774635] RBP: ffffc90000003fd0 R08: 0000000000000000 R09: 0000000000000000
[ 1243.774635] R10: 0000000000000000 R11: 0000000000000000 R12: ffff88813fc2b180
[ 1243.774636] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 1243.774637] FS: 0000000000000000(0000) GS:ffff88813fc00000(0063) knlGS:00000000f7e28900
[ 1243.774637] CS: 0010 DS: 002b ES: 002b CR0: 0000000080050033
[ 1243.774638] CR2: 00000000c0100220 CR3: 000000007f114000 CR4: 00000000000406f0
[ 1243.774638] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 1243.774639] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 1243.774639] Call Trace:
[ 1243.774640] <IRQ>
[ 1243.774640] _raw_spin_lock_irqsave+0x37/0x40
[ 1243.774641] sched_ttwu_pending+0x45/0xe0
[ 1243.774641] scheduler_ipi+0xa9/0x130
[ 1243.774642] reschedule_interrupt+0xf/0x20
[ 1243.774642] </IRQ>
[ 1243.774642] RIP: 0010:propagate_entity_cfs_rq+0x5cb/0x5f0
[ 1243.774644] Code: c1 ea 0a 48 85 d2 74 0f 48 8b 81 88 00 00 00 48 63 f2 48 99 48 f7 fe 48 8b b5 88 01 00 00 48 39 c6 48 0f 46 c6 e9 4c fb ff ff <f3> c3 80 3d b7 6c 73 01 00 75 8b 48 89 3c 24 e8 21 bd ff ff 48 8b
[ 1243.774644] RSP: 0018:ffffc900007efe98 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff02
[ 1243.774645] RAX: ffff88813fc17810 RBX: ffff88813fc2b180 RCX: 0000000000000400
[ 1243.774646] RDX: 0000000000000000 RSI: ffffffff82f8ff00 RDI: 0000000000000000
[ 1243.774646] RBP: 0000000000000000 R08: 00000000000001c1 R09: ffff88812ec03500
[ 1243.774647] R10: ffffc900007efe48 R11: 0000000000000000 R12: ffff88807fbaa400
[ 1243.774647] R13: 000000000002b180 R14: 0000000000000000 R15: ffff88807ec44c00
[ 1243.774648] online_fair_sched_group+0x5e/0x110
[ 1243.774648] sched_autogroup_create_attach+0xbb/0x170
[ 1243.774649] ksys_setsid+0xf2/0x110
[ 1243.774649] __ia32_sys_setsid+0xa/0x10
[ 1243.774650] do_fast_syscall_32+0xa9/0x340
[ 1243.774650] entry_SYSENTER_compat+0x7f/0x91
[ 1243.774654] rcu: rcu_sched kthread starved for 1000017 jiffies! g378081 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 ->cpu=0
[ 1243.844719] rcu: RCU grace-period kthread stack dump:
[ 1243.846166] rcu_sched R 0 10 2 0x90004000
[ 1243.847732] Call Trace:
[ 1243.848614] ? __schedule+0x252/0x6b0
[ 1243.849778] schedule+0x34/0xb0
[ 1243.850798] schedule_timeout+0x16b/0x310
[ 1243.852053] ? __next_timer_interrupt+0xc0/0xc0
[ 1243.853400] rcu_gp_kthread+0x643/0xac0
[ 1243.854568] ? rcu_accelerate_cbs_unlocked+0x70/0x70
[ 1243.856000] kthread+0x11e/0x140
[ 1243.857063] ? kthread_park+0xa0/0xa0
[ 1243.858194] ret_from_fork+0x35/0x40
[ 1543.765186] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[ 1543.774595] rcu: 0-...!: (0 ticks this GP) idle=a8a/1/0x4000000000000002 softirq=192259/192259 fqs=0
[ 1543.778676] (detected by 1, t=1300022 jiffies, g=378081, q=204)
[ 1543.780360] Sending NMI from CPU 1 to CPUs 0:
[ 1543.782720] NMI backtrace for cpu 0
[ 1543.782721] CPU: 0 PID: 15242 Comm: trinity-c0 Not tainted 5.3.0-rc1-00092-g6b8fd01b21f5f #5
[ 1543.782721] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 1543.782722] RIP: 0010:native_queued_spin_lock_slowpath+0x21/0x1e0
[ 1543.782722] Code: c5 ff ff ff 5e 5a c3 66 90 66 66 66 66 90 66 66 66 66 90 ba 01 00 00 00 8b 07 85 c0 75 0a f0 0f b1 17 85 c0 75 f2 f3 c3 f3 90 <eb> ec 81 fe 00 01 00 00 0f 84 ab 00 00 00 81 e6 00 ff ff ff 75 44
[ 1543.782723] RSP: 0018:ffffc90000003f90 EFLAGS: 00000002
[ 1543.782724] RAX: 0000000000000001 RBX: 0000000000000086 RCX: 0000000000000002
[ 1543.782724] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffff88813fc2b180
[ 1543.782725] RBP: ffffc90000003fd0 R08: 0000000000000000 R09: 0000000000000000
[ 1543.782725] R10: 0000000000000000 R11: 0000000000000000 R12: ffff88813fc2b180
[ 1543.782725] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 1543.782726] FS: 0000000000000000(0000) GS:ffff88813fc00000(0063) knlGS:00000000f7e28900
[ 1543.782726] CS: 0010 DS: 002b ES: 002b CR0: 0000000080050033
[ 1543.782727] CR2: 00000000c0100220 CR3: 000000007f114000 CR4: 00000000000406f0
[ 1543.782727] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 1543.782728] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 1543.782728] Call Trace:
[ 1543.782728] <IRQ>
[ 1543.782728] _raw_spin_lock_irqsave+0x37/0x40
[ 1543.782729] sched_ttwu_pending+0x45/0xe0
[ 1543.782729] scheduler_ipi+0xa9/0x130
[ 1543.782729] reschedule_interrupt+0xf/0x20
[ 1543.782730] </IRQ>
[ 1543.782730] RIP: 0010:propagate_entity_cfs_rq+0x5cb/0x5f0
[ 1543.782731] Code: c1 ea 0a 48 85 d2 74 0f 48 8b 81 88 00 00 00 48 63 f2 48 99 48 f7 fe 48 8b b5 88 01 00 00 48 39 c6 48 0f 46 c6 e9 4c fb ff ff <f3> c3 80 3d b7 6c 73 01 00 75 8b 48 89 3c 24 e8 21 bd ff ff 48 8b
[ 1543.782731] RSP: 0018:ffffc900007efe98 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff02
[ 1543.782732] RAX: ffff88813fc17810 RBX: ffff88813fc2b180 RCX: 0000000000000400
[ 1543.782733] RDX: 0000000000000000 RSI: ffffffff82f8ff00 RDI: 0000000000000000
[ 1543.782733] RBP: 0000000000000000 R08: 00000000000001c1 R09: ffff88812ec03500
[ 1543.782734] R10: ffffc900007efe48 R11: 0000000000000000 R12: ffff88807fbaa400
[ 1543.782734] R13: 000000000002b180 R14: 0000000000000000 R15: ffff88807ec44c00
[ 1543.782735] online_fair_sched_group+0x5e/0x110
[ 1543.782735] sched_autogroup_create_attach+0xbb/0x170
[ 1543.782735] ksys_setsid+0xf2/0x110
[ 1543.782736] __ia32_sys_setsid+0xa/0x10
[ 1543.782736] do_fast_syscall_32+0xa9/0x340
[ 1543.782736] entry_SYSENTER_compat+0x7f/0x91
[ 1543.782739] rcu: rcu_sched kthread starved for 1300022 jiffies! g378081 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 ->cpu=0
[ 1543.853291] rcu: RCU grace-period kthread stack dump:
[ 1543.854765] rcu_sched R 0 10 2 0x90004000
[ 1543.856316] Call Trace:
[ 1543.857191] ? __schedule+0x252/0x6b0
[ 1543.858386] schedule+0x34/0xb0
[ 1543.859409] schedule_timeout+0x16b/0x310
[ 1543.860658] ? __next_timer_interrupt+0xc0/0xc0
[ 1543.862018] rcu_gp_kthread+0x643/0xac0
[ 1543.863209] ? rcu_accelerate_cbs_unlocked+0x70/0x70
[ 1543.864647] kthread+0x11e/0x140
[ 1543.865702] ? kthread_park+0xa0/0xa0
[ 1543.866859] ret_from_fork+0x35/0x40
[ 1843.770181] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[ 1843.777403] rcu: 0-...!: (0 ticks this GP) idle=a8a/1/0x4000000000000002 softirq=192259/192259 fqs=0
[ 1843.780727] (detected by 1, t=1600027 jiffies, g=378081, q=204)
[ 1843.782434] Sending NMI from CPU 1 to CPUs 0:
[ 1843.784771] NMI backtrace for cpu 0
[ 1843.784772] CPU: 0 PID: 15242 Comm: trinity-c0 Not tainted 5.3.0-rc1-00092-g6b8fd01b21f5f #5
[ 1843.784772] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 1843.784773] RIP: 0010:native_queued_spin_lock_slowpath+0x21/0x1e0
[ 1843.784773] Code: c5 ff ff ff 5e 5a c3 66 90 66 66 66 66 90 66 66 66 66 90 ba 01 00 00 00 8b 07 85 c0 75 0a f0 0f b1 17 85 c0 75 f2 f3 c3 f3 90 <eb> ec 81 fe 00 01 00 00 0f 84 ab 00 00 00 81 e6 00 ff ff ff 75 44
[ 1843.784774] RSP: 0018:ffffc90000003f90 EFLAGS: 00000002
[ 1843.784775] RAX: 0000000000000001 RBX: 0000000000000086 RCX: 0000000000000002
[ 1843.784775] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffff88813fc2b180
[ 1843.784776] RBP: ffffc90000003fd0 R08: 0000000000000000 R09: 0000000000000000
[ 1843.784776] R10: 0000000000000000 R11: 0000000000000000 R12: ffff88813fc2b180
[ 1843.784777] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 1843.784777] FS: 0000000000000000(0000) GS:ffff88813fc00000(0063) knlGS:00000000f7e28900
[ 1843.784777] CS: 0010 DS: 002b ES: 002b CR0: 0000000080050033
[ 1843.784778] CR2: 00000000c0100220 CR3: 000000007f114000 CR4: 00000000000406f0
[ 1843.784778] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 1843.784779] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 1843.784779] Call Trace:
[ 1843.784779] <IRQ>
[ 1843.784780] _raw_spin_lock_irqsave+0x37/0x40
[ 1843.784780] sched_ttwu_pending+0x45/0xe0
[ 1843.784780] scheduler_ipi+0xa9/0x130
[ 1843.784781] reschedule_interrupt+0xf/0x20
[ 1843.784781] </IRQ>
[ 1843.784781] RIP: 0010:propagate_entity_cfs_rq+0x5cb/0x5f0
[ 1843.784782] Code: c1 ea 0a 48 85 d2 74 0f 48 8b 81 88 00 00 00 48 63 f2 48 99 48 f7 fe 48 8b b5 88 01 00 00 48 39 c6 48 0f 46 c6 e9 4c fb ff ff <f3> c3 80 3d b7 6c 73 01 00 75 8b 48 89 3c 24 e8 21 bd ff ff 48 8b
[ 1843.784782] RSP: 0018:ffffc900007efe98 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff02
[ 1843.784783] RAX: ffff88813fc17810 RBX: ffff88813fc2b180 RCX: 0000000000000400
[ 1843.784784] RDX: 0000000000000000 RSI: ffffffff82f8ff00 RDI: 0000000000000000
[ 1843.784784] RBP: 0000000000000000 R08: 00000000000001c1 R09: ffff88812ec03500
[ 1843.784796] R10: ffffc900007efe48 R11: 0000000000000000 R12: ffff88807fbaa400
[ 1843.784796] R13: 000000000002b180 R14: 0000000000000000 R15: ffff88807ec44c00
[ 1843.784796] online_fair_sched_group+0x5e/0x110
[ 1843.784797] sched_autogroup_create_attach+0xbb/0x170
[ 1843.784797] ksys_setsid+0xf2/0x110
[ 1843.784798] __ia32_sys_setsid+0xa/0x10
[ 1843.784798] do_fast_syscall_32+0xa9/0x340
[ 1843.784798] entry_SYSENTER_compat+0x7f/0x91
[ 1843.784801] rcu: rcu_sched kthread starved for 1600027 jiffies! g378081 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 ->cpu=0
[ 1843.858031] rcu: RCU grace-period kthread stack dump:
[ 1843.859519] rcu_sched R 0 10 2 0x90004000
[ 1843.861094] Call Trace:
[ 1843.861972] ? __schedule+0x252/0x6b0
[ 1843.863151] schedule+0x34/0xb0
[ 1843.864205] schedule_timeout+0x16b/0x310
[ 1843.865464] ? __next_timer_interrupt+0xc0/0xc0
[ 1843.866860] rcu_gp_kthread+0x643/0xac0
[ 1843.868048] ? rcu_accelerate_cbs_unlocked+0x70/0x70
[ 1843.869506] kthread+0x11e/0x140
[ 1843.870561] ? kthread_park+0xa0/0xa0
[ 1843.871745] ret_from_fork+0x35/0x40
BUG: kernel hang in test stage
Elapsed time: 2130
qemu-img create -f qcow2 disk-vm-snb-4G-9bcbf29744f9-0 256G
qemu-img create -f qcow2 disk-vm-snb-4G-9bcbf29744f9-1 256G
qemu-img create -f qcow2 disk-vm-snb-4G-9bcbf29744f9-2 256G
qemu-img create -f qcow2 disk-vm-snb-4G-9bcbf29744f9-3 256G
qemu-img create -f qcow2 disk-vm-snb-4G-9bcbf29744f9-4 256G
qemu-img create -f qcow2 disk-vm-snb-4G-9bcbf29744f9-5 256G
qemu-img create -f qcow2 disk-vm-snb-4G-9bcbf29744f9-6 256G
kvm=(
qemu-system-x86_64
-enable-kvm
-cpu SandyBridge
-kernel $kernel
-initrd initrd-vm-snb-4G-9bcbf29744f9
-m 4096
-smp 2
-device e1000,netdev=net0
-netdev user,id=net0,hostfwd=tcp::32032-:22
-boot order=nc
-no-reboot
-watchdog i6300esb
-watchdog-action debug
-rtc base=localtime
-drive file=disk-vm-snb-4G-9bcbf29744f9-0,media=disk,if=virtio
-drive file=disk-vm-snb-4G-9bcbf29744f9-1,media=disk,if=virtio
-drive file=disk-vm-snb-4G-9bcbf29744f9-2,media=disk,if=virtio
-drive file=disk-vm-snb-4G-9bcbf29744f9-3,media=disk,if=virtio
-drive file=disk-vm-snb-4G-9bcbf29744f9-4,media=disk,if=virtio
-drive file=disk-vm-snb-4G-9bcbf29744f9-5,media=disk,if=virtio
-drive file=disk-vm-snb-4G-9bcbf29744f9-6,media=disk,if=virtio
-serial stdio
-display none
-monitor null
)
append=(
ip=::::vm-snb-4G-9bcbf29744f9::dhcp
root=/dev/ram0
user=lkp
job=/job-script
ARCH=x86_64
kconfig=x86_64-rhel
branch=linux-devel/devel-hourly-2019080920
To reproduce:
# build kernel
cd linux
cp config-5.3.0-rc1-00092-g6b8fd01b21f5f .config
make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
lkp
9 months, 3 weeks
- 2
- 1
[x86/boot] 5b51ae969e: kexec boot failed
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: 5b51ae969e3d8ab0134ee3c98a769ad6d2cc2e24 ("x86/boot: Call get_rsdp_addr() after console_init()")
https://kernel.googlesource.com/pub/scm/linux/kernel/git/torvalds/linux.git master
in testcase: boot
on test machine: Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz with 4G memory
The commit broke kexec boot on physical machines, We have to set "nokaslr" to kernel cmdline to avoid the issue.
Best Regards,
Rong Chen
9 months, 3 weeks
- 5
- 15
[keys] f771fde820: kernel_BUG_at_security/keys/keyring.c
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: f771fde82051976a6fc0fd570f8b86de4a92124b ("keys: Simplify key description management")
https://kernel.googlesource.com/pub/scm/linux/kernel/git/torvalds/linux.git master
in testcase: trinity
with following parameters:
runtime: 300s
test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/
on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 4G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-------------------------------------------------+------------+------------+
| | 3b8c4a08a4 | f771fde820 |
+-------------------------------------------------+------------+------------+
| boot_successes | 705 | 703 |
| boot_failures | 43 | 32 |
| BUG:kernel_reboot-without-warning_in_test_stage | 12 | |
| invoked_oom-killer:gfp_mask=0x | 20 | 15 |
| Mem-Info | 20 | 15 |
| BUG:kernel_hang_in_boot_stage | 10 | 5 |
| RIP:__clear_user | 2 | |
| RIP:copy_user_generic_string | 3 | 3 |
| RIP:__get_user_8 | 1 | |
| WARNING:at_kernel/rcu/tree.c:#rcu_irq_exit | 1 | |
| RIP:rcu_irq_exit | 1 | |
| RIP:native_safe_halt | 1 | |
| WARNING:at_kernel/rcu/tree.c:#rcu_irq_enter | 1 | |
| RIP:rcu_irq_enter | 1 | |
| WARNING:at_kernel/rcu/tree.c:#rcu_nmi_enter | 1 | |
| RIP:rcu_nmi_enter | 1 | |
| WARNING:at_kernel/rcu/tree.c:#rcu_nmi_exit | 1 | |
| RIP:rcu_nmi_exit | 1 | |
| WARNING:at_kernel/rcu/tree.c:#rcu_eqs_exit | 1 | |
| RIP:rcu_eqs_exit | 1 | |
| BUG:scheduling_while_atomic | 1 | |
| kernel_BUG_at_security/keys/keyring.c | 0 | 12 |
| invalid_opcode:#[##] | 0 | 12 |
| RIP:__key_link_begin | 0 | 12 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 12 |
+-------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <rong.a.chen(a)intel.com>
[ 34.431436] kernel BUG at security/keys/keyring.c:1245!
[ 34.432866] invalid opcode: 0000 [#1] SMP PTI
[ 34.433774] CPU: 1 PID: 2592 Comm: trinity-c7 Not tainted 5.2.0-rc1-00017-gf771fde820519 #1
[ 34.435431] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 34.437099] RIP: 0010:__key_link_begin+0x88/0xa0
[ 34.438538] Code: 5d 41 5c c3 0f b7 43 76 48 89 df 48 8d 70 04 e8 de dd ff ff 85 c0 79 dd 48 89 ef 89 44 24 04 e8 be f3 0b 00 8b 44 24 04 eb d1 <0f> 0b 0f 0b b8 80 ff ff ff eb c6 66 66 2e 0f 1f 84 00 00 00 00 00
[ 34.445962] RSP: 0018:ffffa91140d0fde8 EFLAGS: 00010246
[ 34.447932] RAX: 0000000000000000 RBX: ffff99787dd0f401 RCX: ffffa91140d0fe31
[ 34.450598] RDX: ffffa91140d0fe28 RSI: ffffa91140d0fe30 RDI: ffff99787dd0f400
[ 34.453125] RBP: ffff997895e78a40 R08: 0000000000000000 R09: ffff997907c03980
[ 34.455524] R10: ffff99787dd0f400 R11: 00000000d0f9514f R12: 00000000ffffffff
[ 34.458190] R13: ffff99793fde86c0 R14: ffffffffffffffec R15: 0000000000000008
[ 34.460708] FS: 00007f06eb481740(0000) GS:ffff99793fd00000(0000) knlGS:0000000000000000
[ 34.463433] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 34.465468] CR2: 00007f06e97613cc CR3: 000000007a9fe000 CR4: 00000000000406e0
[ 34.467888] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 34.470335] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 34.472748] Call Trace:
[ 34.473852] key_create_or_update+0x211/0x4b0
[ 34.475269] __x64_sys_add_key+0x101/0x200
[ 34.476740] do_syscall_64+0x5b/0x1e0
[ 34.477975] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 34.479678] RIP: 0033:0x7f06ead8e1c9
[ 34.482108] Code: 01 00 48 81 c4 80 00 00 00 e9 f1 fe ff ff 0f 1f 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 97 dc 2c 00 f7 d8 64 89 01 48
[ 34.490151] RSP: 002b:00007ffd0cc33628 EFLAGS: 00000246 ORIG_RAX: 00000000000000f8
[ 34.493640] RAX: ffffffffffffffda RBX: 00000000000000f8 RCX: 00007f06ead8e1c9
[ 34.497038] RDX: 00007f06eb342000 RSI: 0000000000400000 RDI: 000000000043c5ae
[ 34.500296] RBP: 00007f06eb449000 R08: ffffffffffffffff R09: fffffffffffffffb
[ 34.503601] R10: 0000000000000008 R11: 0000000000000246 R12: 00007f06eb449058
[ 34.506005] R13: 00007f06eb4816b0 R14: 0000000000000000 R15: 00007f06eb449000
[ 34.508374] Modules linked in: af_key mpls_router ip_tunnel vmw_vsock_vmci_transport vsock vmw_vmci ieee802154_socket ieee802154 hidp cmtp kernelcapi bnep rfcomm bluetooth ecdh_generic ecc rfkill can_bcm can_raw can pptp gre l2tp_ppp l2tp_netlink l2tp_core ip6_udp_tunnel udp_tunnel pppoe pppox ppp_generic slhc crypto_user nfnetlink scsi_transport_iscsi dccp_ipv6 atm sctp libcrc32c dccp_ipv4 dccp sr_mod cdrom sg ppdev crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel aesni_intel crypto_simd cryptd glue_helper joydev ata_generic pata_acpi serio_raw pcspkr parport_pc parport floppy bochs_drm ttm drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops drm ata_piix libata i2c_piix4 ip_tables
[ 34.526027] ---[ end trace cfce0f246614c04a ]---
To reproduce:
# build kernel
cd linux
cp config-5.2.0-rc1-00017-gf771fde820519 .config
make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
Rong Chen
9 months, 3 weeks
- 1
- 0
21871a99b3 ("of/platform: Pause/resume sync state during init .."): WARNING: CPU: 0 PID: 1 at drivers/base/core.c:691 device_links_supplier_sync_state_resume
by kernel test robot
Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
https://kernel.googlesource.com/pub/scm/linux/kernel/git/gregkh/driver-co... driver-core-testing
commit 21871a99b34c65c56a24193c277a4981529c306f
Author: Saravana Kannan <saravanak(a)google.com>
AuthorDate: Wed Jul 31 15:17:18 2019 -0700
Commit: Greg Kroah-Hartman <gregkh(a)linuxfoundation.org>
CommitDate: Thu Aug 1 16:04:14 2019 +0200
of/platform: Pause/resume sync state during init and of_platform_populate()
When all the top level devices are populated from DT during kernel
init, the supplier devices could be added and probed before the
consumer devices are added and linked to the suppliers. To avoid the
sync_state() callback from being called prematurely, pause the
sync_state() callbacks before populating the devices and resume them
at late_initcall_sync().
Similarly, when children devices are populated after kernel init using
of_platform_populate(), there could be supplier-consumer dependencies
between the children devices that are populated. To avoid the same
problem with sync_state() being called prematurely, pause and resume
sync_state() callbacks across of_platform_populate().
Signed-off-by: Saravana Kannan <saravanak(a)google.com>
Link: https://lore.kernel.org/r/20190731221721.187713-6-saravanak@google.com
Signed-off-by: Greg Kroah-Hartman <gregkh(a)linuxfoundation.org>
8f8184d6bf driver core: Add sync_state driver/bus callback
21871a99b3 of/platform: Pause/resume sync state during init and of_platform_populate()
5adf578101 of/platform: Fix device_links_supplier_sync_state_resume() warning
3880be629e Add linux-next specific files for 20190807
+-------------------------------------------------------------------------+------------+------------+------------+---------------+
| | 8f8184d6bf | 21871a99b3 | 5adf578101 | next-20190807 |
+-------------------------------------------------------------------------+------------+------------+------------+---------------+
| boot_successes | 27 | 0 | 0 | 0 |
| boot_failures | 2 | 11 | 11 | 11 |
| WARNING:at_mm/usercopy.c:#usercopy_warn | 1 | | | |
| RIP:usercopy_warn | 1 | | | |
| invoked_oom-killer:gfp_mask=0x | 1 | | | |
| Mem-Info | 1 | | | |
| WARNING:at_drivers/base/core.c:#device_links_supplier_sync_state_resume | 0 | 11 | 11 | 11 |
| RIP:device_links_supplier_sync_state_resume | 0 | 11 | 11 | 11 |
+-------------------------------------------------------------------------+------------+------------+------------+---------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <lkp(a)intel.com>
[ 26.905004] i2c i2c-1: Added multiplexed i2c bus 3
[ 26.917068] ### dt-test ### FAIL of_unittest_overlay_high_level():2380 overlay_base_root not initialized
[ 26.920311] ### dt-test ### end of unittest - 219 passed, 1 failed
[ 26.922504] ------------[ cut here ]------------
[ 26.924102] Unmatched sync_state pause/resume!
[ 26.924192] WARNING: CPU: 0 PID: 1 at drivers/base/core.c:691 device_links_supplier_sync_state_resume+0x140/0x160
[ 26.929493] Modules linked in:
[ 26.930681] CPU: 0 PID: 1 Comm: swapper Tainted: G T 5.3.0-rc1-00025-g21871a99b34c6 #1
[ 26.933665] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 26.936451] RIP: 0010:device_links_supplier_sync_state_resume+0x140/0x160
[ 26.938611] Code: 84 c0 49 8d 84 24 c8 00 00 00 0f 85 48 ff ff ff 49 8d 94 24 d0 00 00 00 48 89 55 d0 eb 86 48 c7 c7 c0 30 be 83 e8 10 c0 e5 fe <0f> 0b 48 c7 c7 80 33 c4 84 e8 12 19 d0 00 48 83 c4 10 5b 41 5c 41
[ 26.944420] RSP: 0018:ffff88801a397da8 EFLAGS: 00010286
[ 26.946213] RAX: 0000000000000022 RBX: b05332a62e1f2e76 RCX: 0000000000000000
[ 26.948487] RDX: 0000000000000022 RSI: ffffffff81276c83 RDI: 0000000000000246
[ 26.950858] RBP: ffff88801a397de0 R08: fffffbfff0aa192d R09: fffffbfff0aa192d
[ 26.953192] R10: ffff88801a397df0 R11: 0000000000000001 R12: 0000000000000000
[ 26.955411] R13: 00000000ffffffff R14: 1ffff11003472fc3 R15: ffff88801a397eb8
[ 26.957678] FS: 0000000000000000(0000) GS:ffffffff846b3000(0000) knlGS:0000000000000000
[ 26.960398] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 26.962374] CR2: 00007fb42acb9480 CR3: 000000000462a006 CR4: 00000000001606f0
[ 26.964683] Call Trace:
[ 26.965713] of_platform_sync_state_init+0x17/0x3a
[ 26.967381] ? of_core_init+0x16a/0x16a
[ 26.968769] do_one_initcall+0x103/0x295
[ 26.970179] ? trace_event_raw_event_initcall_finish+0x150/0x150
[ 26.972130] ? down_write+0xbe/0x100
[ 26.973467] ? __down_killable+0x260/0x260
[ 26.974933] ? __kasan_check_write+0x1f/0x30
[ 26.976433] kernel_init_freeable+0x232/0x349
[ 26.978003] ? rest_init+0xd0/0xd0
[ 26.979274] kernel_init+0xe/0x120
[ 26.980580] ? rest_init+0xd0/0xd0
[ 26.981870] ret_from_fork+0x24/0x30
[ 26.983168] ---[ end trace fa753e8363323d3d ]---
[ 26.991111] Freeing unused decrypted memory: 2040K
# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start b1645c0cbd486ccebf76e0c3d4d2439f846316b0 609488bc979f99f805f34e9a32c1e3b71179d10b --
git bisect good 41f15b7fcd6a55ce02d7e4a353031a96f1df61b2 # 06:37 G 10 0 1 1 Merge remote-tracking branch 'mips/mips-next'
git bisect good 10cf4ad21d712fe3f90b187503661a5fa7163280 # 07:04 G 10 0 1 1 Merge remote-tracking branch 'input/next'
git bisect bad d6c8a0a14a98ea15fe01c46a04d458d86655f489 # 07:52 B 0 2 18 0 Merge remote-tracking branch 'soundwire/next'
git bisect good ddcfc1ce636ad25269b027f2df88d171e96b4d91 # 09:07 G 11 0 1 1 Merge remote-tracking branch 'tip/auto-latest'
git bisect good 625cf0c4b86f06bd96e270862251fb2f3bd7a8bd # 10:24 G 10 0 1 1 Merge remote-tracking branch 'leds/for-next'
git bisect bad 093afe985f8ffd11b7b63289a70281c9fa66ce58 # 01:15 B 0 1 17 0 Merge remote-tracking branch 'usb/usb-next'
git bisect good dd0937eff2a7dc19716b1829cfac132049c51e46 # 19:38 G 10 0 2 2 Merge remote-tracking branch 'ipmi/for-next'
git bisect bad 90bb1c44123da5b5d43335bc2f7c26407042c14a # 20:22 B 0 3 19 0 Merge remote-tracking branch 'driver-core/driver-core-next'
git bisect good 134b23eec9e3a3c795a6ceb0efe2fa63e87983b2 # 22:50 G 11 0 3 3 driver core: Add edit_links() callback for drivers
git bisect bad 97e2551de3f91add297c1dc4c9dc95297eaadf12 # 12:54 B 0 1 17 0 Merge tag 'dev_groups_all_drivers' into driver-core-next
git bisect bad 21871a99b34c65c56a24193c277a4981529c306f # 13:41 B 0 1 17 0 of/platform: Pause/resume sync state during init and of_platform_populate()
git bisect good 8f8184d6bf676a8680d6f441e40317d166b46f73 # 14:10 G 10 0 4 4 driver core: Add sync_state driver/bus callback
# first bad commit: [21871a99b34c65c56a24193c277a4981529c306f] of/platform: Pause/resume sync state during init and of_platform_populate()
git bisect good 8f8184d6bf676a8680d6f441e40317d166b46f73 # 14:22 G 30 0 5 9 driver core: Add sync_state driver/bus callback
# extra tests on HEAD of linux-next/master
git bisect bad b1645c0cbd486ccebf76e0c3d4d2439f846316b0 # 14:22 B 1 368 0 0 Add linux-next specific files for 20190805
# extra tests on tree/branch driver-core/driver-core-testing
git bisect bad 5adf5781019dd21233d6d13ab0d78bf03a13d4f1 # 14:48 B 0 3 19 0 of/platform: Fix device_links_supplier_sync_state_resume() warning
# extra tests on tree/branch linux-next/master
git bisect bad 3880be629e26f6c407593602398c6651860d5fae # 15:20 B 0 2 18 0 Add linux-next specific files for 20190807
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
9 months, 4 weeks
- 2
- 1
[btrfs] 06297d8cef: fio hangs
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: 06297d8cefcaa2029c4cb71b79285d2bfff06d4d ("btrfs: switch
extent_buffer blocking_writers from atomic to int")
https://kernel.googlesource.com/pub/scm/linux/kernel/git/torvalds/linux.git
master
in testcase: fio-basic
on test machine: Intel(R) Xeon(R) CPU @ 2.30GHz with 128G memory
with following parameters:
rw: randwrite
bs: 4k
ioengine: sync
caused below changes (please refer to attached dmesg/kmsg for entire
log/backtrace):
[ 34.311829] 2019-08-07 11:58:01 echo '[global]
[ 34.311830]
[ 34.318517] bs=4k
[ 34.318517]
[ 34.322805] ioengine=sync
[ 34.322805]
[ 34.327737] iodepth=32
[ 34.327738]
[ 34.332492] size=1431655765
[ 34.332493]
[ 34.337560] direct=0
[ 34.337561]
[ 34.342045] runtime=300
[ 34.342046]
[ 34.346783] invalidate=1
[ 34.346784]
[ 34.351665] fallocate=posix
[ 34.351666]
[ 34.356790] group_reporting
[ 34.356791]
[ 34.361662]
[ 34.363592] [task_0]
[ 34.363593]
[ 34.368050] rw=randwrite
[ 34.368051]
[ 34.372937] directory=/fs/sdd1
[ 34.372938]
[ 34.378767] numjobs=96' | fio --output-format=json -
[ 34.378768]
[ 187.562008] perf: interrupt took too long (2520 > 2500), lowering
kernel.perf_event_max_sample_rate to 79000
[ 188.486146] perf: interrupt took too long (3163 > 3150), lowering
kernel.perf_event_max_sample_rate to 63000
[ 189.763008] perf: interrupt took too long (3956 > 3953), lowering
kernel.perf_event_max_sample_rate to 50000
[ 194.385019] perf: interrupt took too long (4946 > 4945), lowering
kernel.perf_event_max_sample_rate to 40000
[ 194.688010] WARNING: can't dereference registers at 0000000021c3c486
for ip interrupt_entry+0xc4/0x100
Starting Update UTMP about System Runlevel Changes...
Starting watchdog daemon...
[ 1542.201214] Wed Aug 7 12:23:11 CST 2019 detected soft_timeout
[ 1542.201216]
[ 1542.225285] kill 2409 /usr/bin/time -v -o /tmp/lkp/fio.time
/lkp/lkp/src/tests/fio
[ 1542.225287]
[ 1542.287150] /usr/bin/wget -q --timeout=1800 --tries=1
--local-encoding=UTF-8
http://inn:80/~lkp/cgi-bin/lkp-jobfile-append-var?job_file=/lkp/jobs/sche...
-O /dev/null
[ 1542.287152]
[ 1542.613409] Wed Aug 7 12:23:11 CST 2019 wait_job_finished --timeout 60
[ 1542.613411]
[ 1542.803940] Terminated
[ 1542.803942]
[ 1543.616604] kill 1975 vmstat --timestamp -n 10
[ 1543.616606]
[ 1543.623224] kill 1971 iostat -tkx 1 /dev/sdd
[ 1543.623225]
[ 1543.629617] kill 1966 dmesg --follow --decode
[ 1543.629618]
[ 1543.636123] kill 1980 vmstat --timestamp -n 1
[ 1543.636124]
[ 1544.329205] wait for background processes: 2023 2138 2055 1989 2029
2155 1984 1994 2007 2089 2015 2073 2000 2118 2165 2049 2106 2129 2150
slabinfo mpstat softirqs numa-vmstat interrupts uptime numa-numastat
numa-meminfo proc-stat cpuidle meminfo diskstats proc-vmstat sched_debug
oom-killer latency_stats turbostat perf-stat perf-profile
[ 1544.329207]
[ 1546.577996] umount: /fs/sdd1: target is busy
[ 1546.577998]
[ 1547.476297] (In some cases useful info about processes that
[ 1547.476298]
[ 1547.560117] use the device is found by lsof(8) or fuser(1).)
[ 1547.560118]
[ 1550.398285] /usr/bin/wget -q --timeout=1800 --tries=1
--local-encoding=UTF-8
http://inn:80/~lkp/cgi-bin/lkp-jobfile-append-var?job_file=/lkp/jobs/sche...
-O /dev/null
[ 1550.398287]
[ 1550.441061] /usr/bin/wget -q --timeout=1800 --tries=1
--local-encoding=UTF-8
http://inn:80/~lkp/cgi-bin/lkp-jobfile-append-var?job_file=/lkp/jobs/sche...
-O /dev/null
[ 1550.441062]
[ 1602.613268] Wed Aug 7 12:24:11 CST 2019 sleep 141
[ 1602.613270]
[ 1743.615203] Wed Aug 7 12:26:32 CST 2019 try to force reboot
[ 1743.615204]
Stopping watchdog daemon...
Unmounting RPC Pipe File System...
Stopping NFS status monitor for NFSv2/3 locking....
Stopping OpenBSD Secure Shell server...
Stopping System Logging Service...
Stopping LSB: Start and stop bmc-watchdog...
Stopping Login Service...
Stopping D-Bus System Message Bus...
Stopping Regular background program processing daemon...
Stopping Getty on tty1...
Stopping LSB: Load kernel image with kexec...
Stopping Permit User Sessions...
Unmounting /inn/result...
Stopping LSB: Execute the kexec -e command to reboot system...
Stopping Load/Save Random Seed...
Stopping Network Time Synchronization...
Stopping Update UTMP about System Boot/Shutdown...
Stopping Raise network interfaces...
Unmounting /tmp...
Unmounting /opt/rootfs...
Unmounting /fs/sdd1...
[ 1834.925026] systemd-journald[778]: Failed to send WATCHDOG=1
notification message: Connection refused
[ 1888.266366] sysrq: Show Blocked State
[ 1888.270063] task PC stack pid father
[ 1888.276016] systemd D 0 1 0 0x80004000
[ 1888.281540] Call Trace:
[ 1888.284014] ? __schedule+0x255/0x670
[ 1888.287702] ? flush_old_exec+0xaf/0x760
[ 1888.291643] schedule+0x34/0xb0
[ 1888.294803] flush_old_exec+0xe4/0x760
[ 1888.298577] load_elf_binary+0x32d/0x1180
[ 1888.302606] ? _cond_resched+0x19/0x30
[ 1888.306374] search_binary_handler+0x91/0x1e0
[ 1888.310752] __do_execve_file+0x761/0x940
[ 1888.315473] __x64_sys_execve+0x34/0x40
[ 1888.319330] do_syscall_64+0x5b/0x1e0
[ 1888.323011] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 1888.328085] RIP: 0033:0x7f25fd43a647
[ 1888.331680] Code: Bad RIP value.
[ 1888.334925] RSP: 002b:00007ffc13c11e18 EFLAGS: 00000202 ORIG_RAX:
000000000000003b
[ 1888.342508] RAX: ffffffffffffffda RBX: 0000000000000007 RCX:
00007f25fd43a647
[ 1888.349658] RDX: 0000561320ceaf30 RSI: 00007ffc13c11fe0 RDI:
00005613206fc4d0
[ 1888.356805] RBP: 00007ffc13c120a0 R08: 0000561320ceb000 R09:
0000561320cfa700
[ 1888.363954] R10: 00007f25fee92500 R11: 0000000000000202 R12:
0000000000000001
[ 1888.371106] R13: 00005613207661e0 R14: 00007ffc13c11fe0 R15:
0000000000000000
[ 1888.378261] systemd D 0 40005 0 0x00000004
[ 1888.383762] Call Trace:
[ 1888.386231] ? __schedule+0x255/0x670
[ 1888.389907] schedule+0x34/0xb0
[ 1888.393066] ? rwsem_down_write_failed+0x1b5/0x410
[ 1888.397873] rwsem_down_write_failed+0x1ba/0x410
[ 1888.402507] ? _cond_resched+0x19/0x30
[ 1888.406280] ? default_file_splice_write+0x20/0x20
[ 1888.411089] ? down_write+0x4c/0x50
[ 1888.414595] down_write+0x4c/0x50
[ 1888.417921] sync_inodes_sb+0xbe/0x310
[ 1888.421690] ? free_one_page+0x169/0x4c0
[ 1888.425631] ? default_file_splice_write+0x20/0x20
[ 1888.430447] iterate_supers+0x9f/0x110
[ 1888.434218] ksys_sync+0x40/0xb0
[ 1888.437465] __ia32_sys_sync+0xa/0x10
[ 1888.441139] do_syscall_64+0x5b/0x1e0
[ 1888.444818] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 1888.449888] RIP: 0033:0x7f25fd4637f7
[ 1888.453485] Code: Bad RIP value.
[ 1888.456728] RSP: 002b:00007f25fb714d08 EFLAGS: 00000202 ORIG_RAX:
00000000000000a2
[ 1888.464313] RAX: ffffffffffffffda RBX: 0000000000000000 RCX:
00007f25fd4637f7
[ 1888.471464] RDX: 48d62f35817dccf0 RSI: 0000000000000000 RDI:
0000000000000000
[ 1888.478611] RBP: 0000000000000000 R08: 00007f25fb715700 R09:
00007f25fb715700
[ 1888.486143] R10: 00000000000003de R11: 0000000000000202 R12:
00007ffc13c1176e
[ 1888.493618] R13: 00007ffc13c1176f R14: 00007f25faf15000 R15:
0000000000000003
[ 1888.501411] kworker/u194:0 D 0 135 2 0x80004000
[ 1888.507269] Workqueue: btrfs-endio-write btrfs_endio_write_helper [btrfs]
[ 1888.514401] Call Trace:
[ 1888.517197] ? __schedule+0x255/0x670
[ 1888.521222] ? _raw_spin_lock_irqsave+0x37/0x40
[ 1888.526104] schedule+0x34/0xb0
[ 1888.529617] btrfs_tree_lock+0x100/0x1d0 [btrfs]
[ 1888.534591] ? finish_wait+0x80/0x80
[ 1888.538527] btrfs_lock_root_node+0x2f/0x40 [btrfs]
[ 1888.543769] btrfs_search_slot+0x54e/0x9a0 [btrfs]
[ 1888.548918] ? _cond_resched+0x19/0x30
[ 1888.553036] btrfs_mark_extent_written+0xb9/0xc60 [btrfs]
[ 1888.558804] ? merge_state+0x3f/0x160 [btrfs]
[ 1888.564219] ? _cond_resched+0x19/0x30
[ 1888.568330] ? join_transaction+0x24/0x440 [btrfs]
[ 1888.573491] btrfs_finish_ordered_io+0x5a0/0x860 [btrfs]
[ 1888.579156] ? syscall_return_via_sysret+0x10/0x7f
[ 1888.584298] ? syscall_return_via_sysret+0xf/0x7f
[ 1888.589356] normal_work_helper+0x83/0x340 [btrfs]
[ 1888.594494] ? move_linked_works+0x6e/0xa0
[ 1888.598937] process_one_work+0x19c/0x3c0
[ 1888.603287] worker_thread+0x3c/0x3b0
[ 1888.607284] ? process_one_work+0x3c0/0x3c0
[ 1888.611807] kthread+0x11e/0x140
[ 1888.615368] ? kthread_park+0x90/0x90
[ 1888.619365] ret_from_fork+0x1f/0x40
[ 1888.624531] kworker/u194:1 D 0 1068 2 0x80004000
To reproduce:
git clonehttps://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
Thanks,
Rong Chen
10 months
- 2
- 1
[mm] 755d6edc1a: will-it-scale.per_process_ops -4.1% regression
by kernel test robot
Greeting,
FYI, we noticed a -4.1% regression of will-it-scale.per_process_ops due to commit:
commit: 755d6edc1aee4489c90975ec093d724d5492cecd ("[PATCH] mm: release the spinlock on zap_pte_range")
url: https://github.com/0day-ci/linux/commits/Minchan-Kim/mm-release-the-spinl...
in testcase: will-it-scale
on test machine: 8 threads Intel(R) Core(TM) i7-3770K CPU @ 3.50GHz with 16G memory
with following parameters:
nr_task: 100%
mode: process
test: malloc1
cpufreq_governor: performance
ucode: 0x21
test-description: Will It Scale takes a testcase and runs it from 1 through to n parallel copies to see if the testcase will scale. It builds both a process and threads based test in order to see any differences between the two.
test-url: https://github.com/antonblanchard/will-it-scale
Details are as below:
-------------------------------------------------------------------------------------------------->
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
=========================================================================================
compiler/cpufreq_governor/kconfig/mode/nr_task/rootfs/tbox_group/test/testcase/ucode:
gcc-7/performance/x86_64-rhel-7.6/process/100%/debian-x86_64-2019-05-14.cgz/lkp-ivb-d01/malloc1/will-it-scale/0x21
commit:
v5.3-rc2
755d6edc1a ("mm: release the spinlock on zap_pte_range")
v5.3-rc2 755d6edc1aee4489c90975ec093
---------------- ---------------------------
fail:runs %reproduction fail:runs
| | |
1:5 -20% :4 dmesg.RIP:__d_lookup_rcu
1:5 -20% :4 dmesg.RIP:mnt_drop_write
:5 20% 1:4 kmsg.ab33a8>]usb_hcd_irq
:5 20% 1:4 kmsg.b445f28>]usb_hcd_irq
:5 20% 1:4 kmsg.cdf63ef>]usb_hcd_irq
1:5 -20% :4 kmsg.d4af11>]usb_hcd_irq
1:5 -20% :4 kmsg.d9>]usb_hcd_irq
:5 20% 1:4 kmsg.f805d78>]usb_hcd_irq
5:5 -7% 4:4 perf-profile.calltrace.cycles-pp.error_entry
7:5 -39% 5:4 perf-profile.children.cycles-pp.error_entry
0:5 -1% 0:4 perf-profile.children.cycles-pp.error_exit
5:5 -30% 4:4 perf-profile.self.cycles-pp.error_entry
%stddev %change %stddev
\ | \
119757 -4.1% 114839 will-it-scale.per_process_ops
958059 -4.1% 918718 will-it-scale.workload
2429 ± 16% -34.5% 1591 ± 32% cpuidle.C1.usage
0.97 ± 88% -0.7 0.26 mpstat.cpu.all.idle%
78.40 +2.0% 80.00 vmstat.cpu.sy
45.42 +2.1% 46.38 turbostat.CorWatt
50.46 +2.0% 51.45 turbostat.PkgWatt
6641 ± 4% +8.6% 7215 ± 8% slabinfo.anon_vma_chain.num_objs
1327 ± 3% +23.0% 1632 ± 5% slabinfo.kmalloc-96.active_objs
1327 ± 3% +23.0% 1632 ± 5% slabinfo.kmalloc-96.num_objs
1235 ± 30% +37.7% 1700 ± 18% interrupts.29:PCI-MSI.409600-edge.eth0
4361 ± 81% +149.4% 10876 ± 32% interrupts.CPU0.NMI:Non-maskable_interrupts
4361 ± 81% +149.4% 10876 ± 32% interrupts.CPU0.PMI:Performance_monitoring_interrupts
1235 ± 30% +37.7% 1700 ± 18% interrupts.CPU7.29:PCI-MSI.409600-edge.eth0
93196 +9.1% 101723 ± 6% sched_debug.cfs_rq:/.load.min
15.37 ± 11% +13.6% 17.46 ± 3% sched_debug.cfs_rq:/.nr_spread_over.max
5.01 ± 11% +14.5% 5.74 ± 4% sched_debug.cfs_rq:/.nr_spread_over.stddev
53.80 ± 15% +41.6% 76.21 ± 7% sched_debug.cfs_rq:/.util_avg.stddev
60098 +1.6% 61056 proc-vmstat.nr_active_anon
6867 -1.2% 6781 proc-vmstat.nr_slab_unreclaimable
60098 +1.6% 61056 proc-vmstat.nr_zone_active_anon
5.757e+08 -4.2% 5.517e+08 proc-vmstat.numa_hit
5.757e+08 -4.2% 5.517e+08 proc-vmstat.numa_local
5.758e+08 -4.1% 5.52e+08 proc-vmstat.pgalloc_normal
2.881e+08 -4.1% 2.762e+08 proc-vmstat.pgfault
5.758e+08 -4.1% 5.52e+08 proc-vmstat.pgfree
2.861e+09 ± 41% +41.1% 4.038e+09 perf-stat.i.branch-instructions
41921318 ± 38% +34.9% 56552695 ± 2% perf-stat.i.cache-references
2.173e+10 ± 41% +34.9% 2.931e+10 perf-stat.i.cpu-cycles
2.26e+09 ± 41% +41.3% 3.194e+09 perf-stat.i.dTLB-stores
57813 ± 26% +66.7% 96370 ± 6% perf-stat.i.iTLB-loads
1.365e+10 ± 41% +37.9% 1.882e+10 perf-stat.i.instructions
661.20 ± 40% +45.4% 961.52 perf-stat.i.instructions-per-iTLB-miss
0.47 ± 41% +37.3% 0.64 perf-stat.i.ipc
948620 -3.5% 915067 perf-stat.i.minor-faults
948620 -3.5% 915067 perf-stat.i.page-faults
0.51 ± 7% -0.1 0.45 perf-stat.overall.branch-miss-rate%
1.59 -2.4% 1.56 perf-stat.overall.cpi
0.38 -0.0 0.35 ± 2% perf-stat.overall.dTLB-store-miss-rate%
875.11 +8.7% 950.89 perf-stat.overall.instructions-per-iTLB-miss
0.63 +2.4% 0.64 perf-stat.overall.ipc
4337585 ± 41% +42.3% 6173557 perf-stat.overall.path-length
2.855e+09 ± 41% +41.0% 4.028e+09 perf-stat.ps.branch-instructions
41833739 ± 38% +34.8% 56408902 ± 2% perf-stat.ps.cache-references
2.255e+09 ± 41% +41.2% 3.186e+09 perf-stat.ps.dTLB-stores
57677 ± 26% +66.7% 96124 ± 6% perf-stat.ps.iTLB-loads
1.362e+10 ± 41% +37.8% 1.877e+10 perf-stat.ps.instructions
946368 -3.6% 912714 perf-stat.ps.minor-faults
946368 -3.6% 912714 perf-stat.ps.page-faults
4.155e+12 ± 41% +36.5% 5.672e+12 perf-stat.total.instructions
20.10 -0.7 19.42 perf-profile.calltrace.cycles-pp.__do_page_fault.do_page_fault.page_fault
17.83 -0.7 17.17 perf-profile.calltrace.cycles-pp.handle_mm_fault.__do_page_fault.do_page_fault.page_fault
5.47 ± 2% -0.5 4.92 ± 4% perf-profile.calltrace.cycles-pp.pagevec_lru_move_fn.lru_add_drain_cpu.lru_add_drain.unmap_region.__do_munmap
5.75 ± 2% -0.5 5.20 ± 4% perf-profile.calltrace.cycles-pp.lru_add_drain.unmap_region.__do_munmap.__vm_munmap.__x64_sys_munmap
5.69 ± 2% -0.5 5.17 ± 4% perf-profile.calltrace.cycles-pp.lru_add_drain_cpu.lru_add_drain.unmap_region.__do_munmap.__vm_munmap
2.61 -0.5 2.16 ± 12% perf-profile.calltrace.cycles-pp._raw_spin_lock_irqsave.pagevec_lru_move_fn.lru_add_drain_cpu.lru_add_drain.unmap_region
2.09 ± 2% -0.4 1.67 ± 15% perf-profile.calltrace.cycles-pp.native_queued_spin_lock_slowpath._raw_spin_lock_irqsave.pagevec_lru_move_fn.lru_add_drain_cpu.lru_add_drain
2.81 ± 2% -0.2 2.56 ± 2% perf-profile.calltrace.cycles-pp.__anon_vma_prepare.do_anonymous_page.__handle_mm_fault.handle_mm_fault.__do_page_fault
2.62 ± 2% -0.2 2.45 ± 2% perf-profile.calltrace.cycles-pp.flush_tlb_func_common.flush_tlb_mm_range.tlb_flush_mmu.tlb_finish_mmu.unmap_region
1.89 ± 2% -0.2 1.73 perf-profile.calltrace.cycles-pp.unlink_anon_vmas.free_pgtables.unmap_region.__do_munmap.__vm_munmap
3.05 ± 2% -0.1 2.91 perf-profile.calltrace.cycles-pp.flush_tlb_mm_range.tlb_flush_mmu.tlb_finish_mmu.unmap_region.__do_munmap
1.07 ± 3% -0.1 0.95 ± 2% perf-profile.calltrace.cycles-pp.percpu_counter_add_batch.__do_munmap.__vm_munmap.__x64_sys_munmap.do_syscall_64
0.91 ± 3% -0.1 0.84 ± 4% perf-profile.calltrace.cycles-pp.native_flush_tlb.flush_tlb_func_common.flush_tlb_mm_range.tlb_flush_mmu.tlb_finish_mmu
1.94 ± 3% +0.1 2.06 perf-profile.calltrace.cycles-pp.get_unmapped_area.do_mmap.vm_mmap_pgoff.ksys_mmap_pgoff.do_syscall_64
1.31 ± 8% +0.1 1.45 perf-profile.calltrace.cycles-pp.arch_get_unmapped_area_topdown.get_unmapped_area.do_mmap.vm_mmap_pgoff.ksys_mmap_pgoff
0.31 ± 81% +0.2 0.54 ± 3% perf-profile.calltrace.cycles-pp.mem_cgroup_commit_charge.do_anonymous_page.__handle_mm_fault.handle_mm_fault.__do_page_fault
2.27 ± 50% +0.7 2.97 ± 3% perf-profile.calltrace.cycles-pp.syscall_return_via_sysret
43.67 +2.4 46.10 perf-profile.calltrace.cycles-pp.__do_munmap.__vm_munmap.__x64_sys_munmap.do_syscall_64.entry_SYSCALL_64_after_hwframe
39.41 ± 2% +2.7 42.07 perf-profile.calltrace.cycles-pp.unmap_region.__do_munmap.__vm_munmap.__x64_sys_munmap.do_syscall_64
18.28 ± 2% +3.7 21.95 perf-profile.calltrace.cycles-pp.unmap_vmas.unmap_region.__do_munmap.__vm_munmap.__x64_sys_munmap
17.43 ± 2% +3.7 21.12 perf-profile.calltrace.cycles-pp.unmap_page_range.unmap_vmas.unmap_region.__do_munmap.__vm_munmap
35.89 ± 50% +11.0 46.92 perf-profile.calltrace.cycles-pp.__vm_munmap.__x64_sys_munmap.do_syscall_64.entry_SYSCALL_64_after_hwframe
36.13 ± 50% +11.1 47.22 perf-profile.calltrace.cycles-pp.__x64_sys_munmap.do_syscall_64.entry_SYSCALL_64_after_hwframe
51.68 ± 50% +14.5 66.17 perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe
51.90 ± 50% +14.5 66.42 perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe
17.89 -0.7 17.20 perf-profile.children.cycles-pp.handle_mm_fault
20.13 -0.7 19.45 perf-profile.children.cycles-pp.__do_page_fault
5.25 ± 2% -0.6 4.62 ± 8% perf-profile.children.cycles-pp._raw_spin_lock_irqsave
5.50 ± 2% -0.6 4.95 ± 4% perf-profile.children.cycles-pp.pagevec_lru_move_fn
5.93 ± 2% -0.5 5.39 ± 4% perf-profile.children.cycles-pp.lru_add_drain
5.86 ± 2% -0.5 5.33 ± 4% perf-profile.children.cycles-pp.lru_add_drain_cpu
2.80 ± 2% -0.3 2.55 ± 3% perf-profile.children.cycles-pp.entry_SYSCALL_64
2.86 ± 2% -0.3 2.60 ± 2% perf-profile.children.cycles-pp.__anon_vma_prepare
1.92 ± 3% -0.2 1.75 perf-profile.children.cycles-pp.unlink_anon_vmas
1.88 ± 4% -0.2 1.72 ± 2% perf-profile.children.cycles-pp.percpu_counter_add_batch
2.03 ± 3% -0.2 1.88 perf-profile.children.cycles-pp.free_pgtables
3.06 ± 2% -0.1 2.92 perf-profile.children.cycles-pp.flush_tlb_mm_range
0.89 ± 5% -0.1 0.76 ± 6% perf-profile.children.cycles-pp.__might_sleep
1.58 ± 2% -0.1 1.45 perf-profile.children.cycles-pp.native_flush_tlb
1.97 -0.1 1.85 ± 2% perf-profile.children.cycles-pp.flush_tlb_func_common
0.41 ± 8% -0.1 0.32 ± 8% perf-profile.children.cycles-pp.___pte_free_tlb
0.10 ± 14% -0.1 0.03 ±100% perf-profile.children.cycles-pp.should_fail_alloc_page
0.55 ± 3% -0.1 0.49 ± 4% perf-profile.children.cycles-pp.down_write
0.10 ± 19% -0.1 0.05 ± 58% perf-profile.children.cycles-pp.should_failslab
0.28 ± 10% -0.0 0.23 perf-profile.children.cycles-pp.anon_vma_interval_tree_remove
0.11 ± 19% -0.0 0.07 ± 7% perf-profile.children.cycles-pp.policy_nodemask
0.10 ± 11% -0.0 0.06 ± 14% perf-profile.children.cycles-pp.__vma_link_file
0.11 ± 9% -0.0 0.08 ± 6% perf-profile.children.cycles-pp.anon_vma_chain_link
0.13 ± 8% -0.0 0.11 ± 4% perf-profile.children.cycles-pp.try_charge
0.18 ± 6% -0.0 0.16 ± 5% perf-profile.children.cycles-pp.inc_zone_page_state
0.14 ± 2% -0.0 0.12 ± 3% perf-profile.children.cycles-pp.anon_vma_interval_tree_insert
0.10 ± 17% +0.0 0.14 ± 7% perf-profile.children.cycles-pp.strlen
0.52 ± 2% +0.0 0.56 ± 3% perf-profile.children.cycles-pp.mem_cgroup_commit_charge
0.17 ± 16% +0.0 0.21 ± 6% perf-profile.children.cycles-pp.uncharge_page
0.08 ± 16% +0.0 0.13 ± 7% perf-profile.children.cycles-pp.__vma_link_list
0.26 ± 6% +0.1 0.31 ± 6% perf-profile.children.cycles-pp.mem_cgroup_charge_statistics
0.00 +0.1 0.06 ± 22% perf-profile.children.cycles-pp.__get_vma_policy
0.13 ± 9% +0.1 0.19 ± 9% perf-profile.children.cycles-pp.vma_merge
0.02 ±122% +0.1 0.09 ± 11% perf-profile.children.cycles-pp.kthread_blkcg
0.25 ± 11% +0.1 0.33 ± 6% perf-profile.children.cycles-pp.get_task_policy
0.00 +0.1 0.08 ± 5% perf-profile.children.cycles-pp.memcpy
0.25 ± 9% +0.1 0.35 ± 2% perf-profile.children.cycles-pp.memcpy_erms
1.97 ± 2% +0.1 2.09 perf-profile.children.cycles-pp.get_unmapped_area
1.34 ± 7% +0.1 1.47 ± 2% perf-profile.children.cycles-pp.arch_get_unmapped_area_topdown
0.38 ± 5% +0.1 0.52 ± 5% perf-profile.children.cycles-pp.alloc_pages_current
3.08 ± 2% +0.2 3.24 ± 2% perf-profile.children.cycles-pp.syscall_return_via_sysret
64.46 +2.0 66.45 perf-profile.children.cycles-pp.entry_SYSCALL_64_after_hwframe
64.19 +2.0 66.19 perf-profile.children.cycles-pp.do_syscall_64
43.77 +2.4 46.18 perf-profile.children.cycles-pp.__do_munmap
44.49 +2.5 46.95 perf-profile.children.cycles-pp.__vm_munmap
44.77 +2.5 47.24 perf-profile.children.cycles-pp.__x64_sys_munmap
39.43 ± 2% +2.7 42.10 perf-profile.children.cycles-pp.unmap_region
18.07 ± 2% +3.7 21.73 perf-profile.children.cycles-pp.unmap_page_range
18.29 ± 2% +3.7 21.97 perf-profile.children.cycles-pp.unmap_vmas
6.02 ± 3% -0.5 5.57 ± 3% perf-profile.self.cycles-pp.do_syscall_64
1.73 -0.1 1.59 perf-profile.self.cycles-pp._raw_spin_lock_irqsave
1.56 ± 2% -0.1 1.44 perf-profile.self.cycles-pp.native_flush_tlb
0.34 ± 11% -0.1 0.24 ± 7% perf-profile.self.cycles-pp.strlcpy
0.57 ± 5% -0.1 0.49 ± 6% perf-profile.self.cycles-pp.unlink_anon_vmas
0.68 ± 4% -0.1 0.60 ± 8% perf-profile.self.cycles-pp._raw_spin_lock
0.37 ± 5% -0.1 0.31 ± 6% perf-profile.self.cycles-pp.cpumask_any_but
0.42 ± 7% -0.1 0.36 ± 6% perf-profile.self.cycles-pp.handle_mm_fault
0.23 ± 7% -0.1 0.18 ± 4% perf-profile.self.cycles-pp.__perf_sw_event
0.10 ± 23% -0.0 0.06 ± 9% perf-profile.self.cycles-pp.policy_nodemask
0.09 ± 11% -0.0 0.04 ± 59% perf-profile.self.cycles-pp.__vma_link_file
0.13 ± 6% -0.0 0.10 ± 8% perf-profile.self.cycles-pp.try_charge
0.14 ± 2% -0.0 0.12 ± 3% perf-profile.self.cycles-pp.anon_vma_interval_tree_insert
0.10 ± 15% +0.0 0.11 ± 4% perf-profile.self.cycles-pp.strlen
0.09 ± 17% +0.0 0.12 ± 5% perf-profile.self.cycles-pp.memcg_check_events
0.07 ± 19% +0.0 0.10 ± 7% perf-profile.self.cycles-pp.__vma_link_list
0.16 ± 16% +0.0 0.20 ± 5% perf-profile.self.cycles-pp.uncharge_page
0.24 ± 7% +0.0 0.28 ± 2% perf-profile.self.cycles-pp.memcpy_erms
0.04 ± 53% +0.0 0.09 ± 8% perf-profile.self.cycles-pp.do_page_fault
0.42 ± 9% +0.1 0.48 ± 7% perf-profile.self.cycles-pp.find_next_bit
0.13 ± 10% +0.1 0.19 ± 8% perf-profile.self.cycles-pp.vma_merge
0.02 ±122% +0.1 0.09 ± 11% perf-profile.self.cycles-pp.kthread_blkcg
0.25 ± 10% +0.1 0.32 ± 7% perf-profile.self.cycles-pp.get_task_policy
0.00 +0.1 0.08 ± 6% perf-profile.self.cycles-pp.memcpy
0.14 ± 5% +0.1 0.25 ± 15% perf-profile.self.cycles-pp.alloc_pages_current
3.08 ± 2% +0.2 3.23 ± 2% perf-profile.self.cycles-pp.syscall_return_via_sysret
0.43 ± 10% +0.2 0.58 ± 6% perf-profile.self.cycles-pp.arch_get_unmapped_area_topdown
11.00 ± 2% +3.6 14.56 perf-profile.self.cycles-pp.unmap_page_range
will-it-scale.per_process_ops
120000 +-+----------------------------------------------------------------+
| +. +. +.. .. + +. +. + |
119000 +-+ +.+..+..+ |
118000 +-+ |
| |
117000 +-+ |
| O |
116000 O-+O O O O |
| O O O O O |
115000 +-+ O O O O O O O O
114000 +-+ |
| O O O O O |
113000 +-+ O |
| |
112000 +-+----------------------------------------------------------------+
[*] bisect-good sample
[O] bisect-bad sample
Disclaimer:
Results have been estimated based on internal Intel analysis and are provided
for informational purposes only. Any difference in system hardware or software
design or configuration may affect actual performance.
Thanks,
Oliver Sang
10 months
- 3
- 3