[lkp] [Btrfs] e5a7b11a5c: shift exponent 32 is too large for 32-bit type 'int'
by kernel test robot
FYI, we noticed the following commit:
https://github.com/0day-ci/linux Omar-Sandoval/Btrfs-fix-extent-buffer-bitmap-tests-on-big-endian-systems/20160713-074511
commit e5a7b11a5caa8d42fe3fb4ff2d75b6811aeb8eb7 ("Btrfs: fix extent buffer bitmap tests on big-endian systems")
in testcase: boot
on test machine: 2 threads qemu-system-x86_64 -enable-kvm -cpu Haswell,+smep,+smap with 1G memory
caused below changes:
+------------------------------------------------------------------+----------+------------+
| | v4.7-rc7 | e5a7b11a5c |
+------------------------------------------------------------------+----------+------------+
| boot_successes | 0 | 0 |
| boot_failures | 80 | 8 |
| invoked_oom-killer:gfp_mask=0x | 59 | 2 |
| Mem-Info | 59 | 2 |
| Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 59 | 2 |
| backtrace:btrfs_test_extent_io | 35 | 6 |
| backtrace:init_btrfs_fs | 35 | 6 |
| backtrace:kernel_init_freeable | 59 | 8 |
| BUG:kernel_test_oversize | 11 | 4 |
| backtrace:vfs_write | 24 | 2 |
| backtrace:SyS_write | 24 | 2 |
| backtrace:populate_rootfs | 24 | 2 |
| kernel_BUG_at_mm/filemap.c | 1 | |
| invalid_opcode:#[##]PREEMPT_SMP | 1 | |
| RIP:unlock_page | 1 | |
| Kernel_panic-not_syncing:Fatal_exception | 1 | |
| backtrace:kswapd | 1 | |
| BUG:kernel_boot_hang | 9 | |
| BUG:kernel_torture_test_oversize | 0 | 2 |
+------------------------------------------------------------------+----------+------------+
[ 74.703186] UBSAN: Undefined behaviour in fs/btrfs/tests/extent-io-tests.c:367:4
[ 74.703359] shift exponent 32 is too large for 32-bit type 'int'
[ 74.703359] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 4.7.0-rc7-00001-ge5a7b11 #1
[ 74.703359] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 74.703359] 00000000ffffffff 0000000000000097 0000000000000001 0000000000000001
[ 74.703359] 0000000000000000 0000000000000001 ffff880035143c48 ffffffff82046359
[ 74.703359] ffffffff813e786b 000000007a4be528 000000007a4be500 0000000000000020
[ 74.703359] Call Trace:
[ 74.703359] [<ffffffff82046359>] dump_stack+0x290/0x3f0
[ 74.703359] [<ffffffff813e786b>] ? printk+0x5d/0x65
[ 74.703359] [<ffffffff8212cbd9>] ubsan_epilogue+0x12/0x3f
[ 74.703359] [<ffffffff8212d61b>] __ubsan_handle_shift_out_of_bounds+0x19c/0x1d1
[ 74.703359] [<ffffffff81ca5a42>] ? extent_buffer_bitmap_set+0x508/0x517
[ 74.703359] [<ffffffff81e142e6>] __test_eb_bitmaps+0x5f1/0x7a7
[ 74.703359] [<ffffffff81e142e6>] ? __test_eb_bitmaps+0x5f1/0x7a7
[ 74.703359] [<ffffffff81e16479>] btrfs_test_extent_io+0x281/0x427
[ 74.703359] [<ffffffff81d2b075>] ? cleanup_write_cache_enospc+0x88/0x88
[ 74.703359] [<ffffffff8606d299>] init_btrfs_fs+0x926/0xd88
[ 74.703359] [<ffffffff8606c973>] ? trace_event_define_fields_btrfs_space_reservation+0x32f/0x32f
[ 74.703359] [<ffffffff81000884>] do_one_initcall+0x240/0x4ed
[ 74.703359] [<ffffffff85fd107c>] kernel_init_freeable+0x3b7/0x628
[ 74.703359] [<ffffffff83033b7f>] kernel_init+0x1c/0x49c
[ 74.703359] [<ffffffff830600cf>] ret_from_fork+0x1f/0x40
[ 74.703359] [<ffffffff83033b63>] ? rest_init+0x2aa/0x2aa
[ 74.703359] ================================================================================
[ 75.122581] BTRFS: selftest: Extent I/O tests finished
[ 75.123550] BTRFS: selftest: Running btrfs_get_extent tests
FYI, raw QEMU command line is:
qemu-system-x86_64 -enable-kvm -cpu Haswell,+smep,+smap -kernel /pkg/linux/x86_64-randconfig-s5-07130857/gcc-6/e5a7b11a5caa8d42fe3fb4ff2d75b6811aeb8eb7/vmlinuz-4.7.0-rc7-00001-ge5a7b11 -append 'root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-kbuild-1G-4/bisect_boot-1-debian-x86_64-2015-02-07.cgz-x86_64-randconfig-s5-07130857-e5a7b11a5caa8d42fe3fb4ff2d75b6811aeb8eb7-20160715-475-o45csx-1.yaml ARCH=x86_64 kconfig=x86_64-randconfig-s5-07130857 branch=linux-devel/devel-spot-201607130837 commit=e5a7b11a5caa8d42fe3fb4ff2d75b6811aeb8eb7 BOOT_IMAGE=/pkg/linux/x86_64-randconfig-s5-07130857/gcc-6/e5a7b11a5caa8d42fe3fb4ff2d75b6811aeb8eb7/vmlinuz-4.7.0-rc7-00001-ge5a7b11 max_uptime=600 RESULT_ROOT=/result/boot/1/vm-kbuild-1G/debian-x86_64-2015-02-07.cgz/x86_64-randconfig-s5-07130857/gcc-6/e5a7b11a5caa8d42fe3fb4ff2d75b6811aeb8eb7/0 LKP_SERVER=inn earlyprintk=ttyS0,115200 systemd.log_level=err debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 console=ttyS0,115200 console=tty0 vga=normal rw ip=::::vm-kbuild-1G-4::dhcp' -initrd /fs/sdf1/initrd-vm-kbuild-1G-4 -m 1024 -smp 2 -device e1000,netdev=net0 -netdev user,id=net0,hostfwd=tcp::23003-:22 -boot order=nc -no-reboot -watchdog i6300esb -rtc base=localtime -device virtio-scsi-pci,id=scsi0 -drive file=/fs/sdf1/disk0-vm-kbuild-1G-4,if=none,id=hd0,media=disk,aio=native,cache=none -device scsi-hd,bus=scsi0.0,drive=hd0,scsi-id=1,lun=0 -drive file=/fs/sdf1/disk1-vm-kbuild-1G-4,if=none,id=hd1,media=disk,aio=native,cache=none -device scsi-hd,bus=scsi0.0,drive=hd1,scsi-id=1,lun=1 -drive file=/fs/sdf1/disk2-vm-kbuild-1G-4,if=none,id=hd2,media=disk,aio=native,cache=none -device scsi-hd,bus=scsi0.0,drive=hd2,scsi-id=1,lun=2 -drive file=/fs/sdf1/disk3-vm-kbuild-1G-4,if=none,id=hd3,media=disk,aio=native,cache=none -device scsi-hd,bus=scsi0.0,drive=hd3,scsi-id=1,lun=3 -drive file=/fs/sdf1/disk4-vm-kbuild-1G-4,if=none,id=hd4,media=disk,aio=native,cache=none -device scsi-hd,bus=scsi0.0,drive=hd4,scsi-id=1,lun=4 -pidfile /dev/shm/kboot/pid-vm-kbuild-1G-4 -serial file:/dev/shm/kboot/serial-vm-kbuild-1G-4 -daemonize -display none -monitor null
Thanks,
Xiaolong
5 years, 3 months
[lkp] [f2fs] 3bdad3c7ee: aim7.jobs-per-min -25.3% regression
by kernel test robot
FYI, we noticed a -25.3% regression of aim7.jobs-per-min due to commit:
commit 3bdad3c7ee72a76ec87be3477eb958ed7ca304fc ("f2fs: skip to check the block address of node page")
https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git master
in testcase: aim7
on test machine: 48 threads Ivytown Ivy Bridge-EP with 64G memory
with following parameters: disk=1BRD_48G/fs=f2fs/load=3000/test=disk_cp
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.
Details are as below:
-------------------------------------------------------------------------------------------------->
To reproduce:
git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
=========================================================================================
compiler/disk/fs/kconfig/load/rootfs/tbox_group/test/testcase:
gcc-4.9/1BRD_48G/f2fs/x86_64-rhel/3000/debian-x86_64-2015-02-07.cgz/ivb44/disk_cp/aim7
commit:
2555a2d558 ("f2fs: shrink critical region in spin_lock")
3bdad3c7ee ("f2fs: skip to check the block address of node page")
2555a2d55822c9b2 3bdad3c7ee72a76ec87be3477e
---------------- --------------------------
%stddev %change %stddev
\ | \
163989 ± 1% -25.3% 122533 ± 3% aim7.jobs-per-min
110.02 ± 1% +33.9% 147.30 ± 3% aim7.time.elapsed_time
110.02 ± 1% +33.9% 147.30 ± 3% aim7.time.elapsed_time.max
140571 ± 1% +166.6% 374804 ± 5% aim7.time.involuntary_context_switches
153474 ± 1% +172.8% 418682 ± 1% aim7.time.minor_page_faults
1683 ± 2% +214.5% 5292 ± 4% aim7.time.system_time
15776849 ± 1% -95.8% 670202 ± 3% aim7.time.voluntary_context_switches
Thanks,
Xiaolong
5 years, 3 months
[lkp] [Btrfs] 957780eb27: fio.write_bw_MBps 17.9% improvement
by kernel test robot
FYI, we noticed a 17.9% improvement of fio.write_bw_MBps due to commit:
commit 957780eb2788d8c218d539e19a85653f51a96dc1 ("Btrfs: introduce ticketed enospc infrastructure")
https://github.com/kdave/btrfs-devel.git misc-4.8
in testcase: fio-basic
on test machine: Broadwell-EP with 128G memory
with following parameters: bs=4k/cpufreq_governor=performance/disk=1SSD/fs=btrfs/ioengine=sync/nr_task=8/runtime=300s/rw=randwrite/test_size=512g
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.
Details are as below:
-------------------------------------------------------------------------------------------------->
To reproduce:
git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
=========================================================================================
bs/compiler/cpufreq_governor/disk/fs/ioengine/kconfig/nr_task/rootfs/runtime/rw/tbox_group/test_size/testcase:
4k/gcc-4.9/performance/1SSD/btrfs/sync/x86_64-rhel/8/debian-x86_64-2015-02-07.cgz/300s/randwrite/lkp-bdw-ep2/512g/fio-basic
commit:
c83f8effef ("Btrfs: add tracepoint for adding block groups")
957780eb27 ("Btrfs: introduce ticketed enospc infrastructure")
c83f8effefa46c15 957780eb2788d8c218d539e19a
---------------- --------------------------
fail:runs %reproduction fail:runs
| | |
%stddev %change %stddev
\ | \
66610146 ± 1% +17.5% 78260342 ± 1% fio.time.file_system_outputs
29.50 ± 2% +55.9% 46.00 ± 2% fio.time.percent_of_cpu_this_job_got
86.04 ± 2% +44.5% 124.32 ± 2% fio.time.system_time
4.92 ± 1% +214.9% 15.50 ± 8% fio.time.user_time
38716 ± 2% +22283.4% 8665975 ± 3% fio.time.voluntary_context_switches
107.91 ± 0% +17.9% 127.21 ± 1% fio.write_bw_MBps
27624 ± 0% +17.9% 32564 ± 1% fio.write_iops
23166 ± 13% +14.3% 26487 ± 0% interrupts.CAL:Function_call_interrupts
295054 ± 3% +23.6% 364727 ± 3% softirqs.RCU
2967 ± 7% -20.3% 2364 ± 14% numa-meminfo.node0.PageTables
1972 ± 13% +30.8% 2578 ± 14% numa-meminfo.node1.PageTables
741.75 ± 7% -20.4% 590.75 ± 14% numa-vmstat.node0.nr_page_table_pages
491.50 ± 13% +31.3% 645.25 ± 14% numa-vmstat.node1.nr_page_table_pages
241.08 ± 1% +2.5% 247.02 ± 1% pmeter.Average_Active_Power
115.06 ± 1% +15.0% 132.36 ± 2% pmeter.performance_per_watt
2.549e+08 ± 8% +159.3% 6.609e+08 ± 4% cpuidle.C1E-BDW.time
3794807 ± 7% +115.0% 8158363 ± 5% cpuidle.C1E-BDW.usage
4.415e+08 ± 5% +177.4% 1.225e+09 ± 2% cpuidle.C3-BDW.time
2114487 ± 5% +233.0% 7040205 ± 2% cpuidle.C3-BDW.usage
296023 ± 1% -12.1% 260328 ± 2% vmstat.io.bo
26525360 ± 0% +11.8% 29667156 ± 2% vmstat.memory.cache
307934 ± 1% +27.1% 391257 ± 1% vmstat.system.cs
120696 ± 0% +4.5% 126072 ± 0% vmstat.system.in
6.40 ± 0% +5.7% 6.77 ± 0% turbostat.%Busy
158.75 ± 1% +6.5% 169.00 ± 0% turbostat.Avg_MHz
31.79 ± 1% +22.8% 39.05 ± 0% turbostat.CPU%c1
60.26 ± 0% -12.5% 52.74 ± 0% turbostat.CPU%c6
106.53 ± 1% +4.9% 111.77 ± 1% turbostat.PkgWatt
23664017 ± 0% +12.0% 26504182 ± 2% meminfo.Cached
644438 ± 1% +52.1% 980117 ± 3% meminfo.Dirty
18624378 ± 1% +16.1% 21615196 ± 1% meminfo.Inactive
18523220 ± 1% +16.1% 21513999 ± 1% meminfo.Inactive(file)
2627475 ± 0% +10.2% 2896746 ± 1% meminfo.SReclaimable
2780053 ± 0% +9.6% 3048260 ± 1% meminfo.Slab
22521807 ± 1% -10.9% 20062877 ± 2% proc-vmstat.nr_dirtied
161064 ± 1% +52.1% 244999 ± 3% proc-vmstat.nr_dirty
5915825 ± 0% +12.0% 6626549 ± 2% proc-vmstat.nr_file_pages
4630641 ± 1% +16.2% 5378889 ± 1% proc-vmstat.nr_inactive_file
656853 ± 0% +10.3% 724211 ± 1% proc-vmstat.nr_slab_reclaimable
22259226 ± 2% -11.7% 19658019 ± 2% proc-vmstat.nr_written
12009538 ± 1% +12.1% 13459526 ± 1% proc-vmstat.numa_hit
12009538 ± 1% +12.1% 13459526 ± 1% proc-vmstat.numa_local
2034 ± 8% +15.4% 2348 ± 4% proc-vmstat.numa_pte_updates
12489110 ± 1% +12.5% 14049624 ± 0% proc-vmstat.pgalloc_normal
89105732 ± 1% -11.7% 78661122 ± 2% proc-vmstat.pgpgout
65339 ± 3% +13.6% 74212 ± 2% slabinfo.btrfs_extent_buffer.active_objs
1157 ± 2% +12.1% 1298 ± 2% slabinfo.btrfs_extent_buffer.active_slabs
67167 ± 2% +12.1% 75297 ± 2% slabinfo.btrfs_extent_buffer.num_objs
1157 ± 2% +12.1% 1298 ± 2% slabinfo.btrfs_extent_buffer.num_slabs
8606605 ± 1% +14.7% 9874153 ± 1% slabinfo.btrfs_extent_map.active_objs
153689 ± 1% +14.7% 176323 ± 1% slabinfo.btrfs_extent_map.active_slabs
8606605 ± 1% +14.7% 9874153 ± 1% slabinfo.btrfs_extent_map.num_objs
153689 ± 1% +14.7% 176323 ± 1% slabinfo.btrfs_extent_map.num_slabs
4271597 ± 1% +15.4% 4931074 ± 1% slabinfo.btrfs_extent_state.active_objs
83829 ± 1% +15.3% 96696 ± 1% slabinfo.btrfs_extent_state.active_slabs
4275329 ± 1% +15.3% 4931525 ± 1% slabinfo.btrfs_extent_state.num_objs
83829 ± 1% +15.3% 96696 ± 1% slabinfo.btrfs_extent_state.num_slabs
16712 ± 8% +23.3% 20612 ± 8% slabinfo.kmalloc-128.active_objs
16785 ± 8% +23.5% 20727 ± 8% slabinfo.kmalloc-128.num_objs
46515 ± 2% +17.1% 54488 ± 3% slabinfo.kmalloc-64.active_objs
726.50 ± 2% +17.4% 852.75 ± 4% slabinfo.kmalloc-64.active_slabs
46526 ± 2% +17.4% 54604 ± 4% slabinfo.kmalloc-64.num_objs
726.50 ± 2% +17.4% 852.75 ± 4% slabinfo.kmalloc-64.num_slabs
13179 ± 12% -100.0% 0.00 ± -1% latency_stats.avg.btrfs_wait_ordered_roots.[btrfs].flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs].btrfs_file_write_iter.[btrfs].__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
425338 ± 8% -99.9% 254.25 ± 3% latency_stats.avg.reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs].btrfs_file_write_iter.[btrfs].__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
7083 ± 52% -100.0% 0.00 ± -1% latency_stats.avg.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_ordered_range.[btrfs].btrfs_wait_cache_io.[btrfs].btrfs_start_dirty_block_groups.[btrfs].btrfs_commit_transaction.[btrfs].flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs]
705850 ± 11% -100.0% 0.00 ± -1% latency_stats.avg.wb_wait_for_completion.__writeback_inodes_sb_nr.writeback_inodes_sb_nr.flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs].btrfs_file_write_iter.[btrfs].__vfs_write.vfs_write.SyS_write
4685 ± 8% +1.8e+05% 8634828 ± 3% latency_stats.hits.reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs].btrfs_file_write_iter.[btrfs].__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
10746 ± 78% -100.0% 0.00 ± -1% latency_stats.max.btrfs_wait_ordered_extents.[btrfs].btrfs_wait_ordered_roots.[btrfs].flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs].btrfs_file_write_iter.[btrfs].__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
35989 ± 29% -100.0% 0.00 ± -1% latency_stats.max.btrfs_wait_ordered_roots.[btrfs].flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs].btrfs_file_write_iter.[btrfs].__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
14480 ± 41% -100.0% 0.00 ± -1% latency_stats.max.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_ordered_range.[btrfs].btrfs_wait_cache_io.[btrfs].btrfs_start_dirty_block_groups.[btrfs].btrfs_commit_transaction.[btrfs].flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs]
12406 ± 59% -100.0% 0.00 ± -1% latency_stats.max.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_ordered_range.[btrfs].btrfs_wait_cache_io.[btrfs].btrfs_write_dirty_block_groups.[btrfs].commit_cowonly_roots.[btrfs].btrfs_commit_transaction.[btrfs].flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs]
4782813 ± 3% -100.0% 0.00 ± -1% latency_stats.max.wb_wait_for_completion.__writeback_inodes_sb_nr.writeback_inodes_sb_nr.flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs].btrfs_file_write_iter.[btrfs].__vfs_write.vfs_write.SyS_write
34333 ± 62% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_async_run_delayed_refs.[btrfs].__btrfs_end_transaction.[btrfs].btrfs_end_transaction.[btrfs].flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs].btrfs_file_write_iter.[btrfs].__vfs_write.vfs_write.SyS_write
8628 ± 43% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_inode.[btrfs].__btrfs_update_delayed_inode.[btrfs].__btrfs_run_delayed_items.[btrfs].btrfs_run_delayed_items_nr.[btrfs].flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs]
22474 ± 70% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_wait_ordered_extents.[btrfs].btrfs_wait_ordered_roots.[btrfs].flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs].btrfs_file_write_iter.[btrfs].__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
215183 ± 26% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_wait_ordered_roots.[btrfs].flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs].btrfs_file_write_iter.[btrfs].__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
100068 ± 12% -100.0% 0.00 ± -1% latency_stats.sum.flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs].btrfs_file_write_iter.[btrfs].__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
21624 ± 41% -100.0% 0.00 ± -1% latency_stats.sum.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_marked_extents.[btrfs].btrfs_write_and_wait_transaction.[btrfs].btrfs_commit_transaction.[btrfs].flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs].btrfs_file_write_iter.[btrfs]
39252 ± 53% -100.0% 0.00 ± -1% latency_stats.sum.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_ordered_range.[btrfs].btrfs_wait_cache_io.[btrfs].btrfs_start_dirty_block_groups.[btrfs].btrfs_commit_transaction.[btrfs].flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs]
48447 ± 73% -100.0% 0.00 ± -1% latency_stats.sum.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_ordered_range.[btrfs].btrfs_wait_cache_io.[btrfs].btrfs_write_dirty_block_groups.[btrfs].commit_cowonly_roots.[btrfs].btrfs_commit_transaction.[btrfs].flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs]
11556 ± 9% -100.0% 0.00 ± -1% latency_stats.sum.wait_on_page_bit.__migration_entry_wait.migration_entry_wait.handle_pte_fault.handle_mm_fault.__do_page_fault.do_page_fault.page_fault
2.811e+08 ± 0% -100.0% 0.00 ± -1% latency_stats.sum.wb_wait_for_completion.__writeback_inodes_sb_nr.writeback_inodes_sb_nr.flush_space.[btrfs].reserve_metadata_bytes.[btrfs].btrfs_block_rsv_add.[btrfs].btrfs_delalloc_reserve_metadata.[btrfs].__btrfs_buffered_write.[btrfs].btrfs_file_write_iter.[btrfs].__vfs_write.vfs_write.SyS_write
3.911e+10 ± 2% +20.3% 4.706e+10 ± 4% perf-stat.L1-dcache-load-misses
7.052e+11 ± 4% +14.0% 8.037e+11 ± 0% perf-stat.L1-dcache-loads
4.704e+11 ± 2% +16.1% 5.461e+11 ± 3% perf-stat.L1-dcache-stores
1.839e+10 ± 3% +14.6% 2.108e+10 ± 3% perf-stat.L1-icache-load-misses
1.359e+10 ± 4% +12.6% 1.531e+10 ± 5% perf-stat.LLC-loads
8.28e+09 ± 2% +10.2% 9.127e+09 ± 3% perf-stat.LLC-stores
4.894e+11 ± 2% +16.4% 5.695e+11 ± 5% perf-stat.branch-instructions
6.831e+09 ± 1% +12.6% 7.693e+09 ± 0% perf-stat.branch-load-misses
4.999e+11 ± 2% +24.4% 6.22e+11 ± 2% perf-stat.branch-loads
7.003e+09 ± 2% +8.6% 7.604e+09 ± 2% perf-stat.branch-misses
1.529e+11 ± 0% +6.4% 1.627e+11 ± 2% perf-stat.bus-cycles
3.257e+09 ± 3% -7.5% 3.011e+09 ± 3% perf-stat.cache-misses
5.118e+10 ± 4% +14.6% 5.867e+10 ± 3% perf-stat.cache-references
93454510 ± 1% +26.7% 1.184e+08 ± 1% perf-stat.context-switches
3.999e+12 ± 1% +8.4% 4.334e+12 ± 4% perf-stat.cpu-cycles
1.514e+09 ± 2% +21.6% 1.841e+09 ± 2% perf-stat.dTLB-load-misses
6.846e+11 ± 1% +14.4% 7.832e+11 ± 2% perf-stat.dTLB-loads
1.284e+08 ± 1% +20.3% 1.545e+08 ± 0% perf-stat.dTLB-store-misses
2.585e+08 ± 0% +122.4% 5.751e+08 ± 28% perf-stat.iTLB-load-misses
1.698e+09 ± 2% +31.0% 2.225e+09 ± 1% perf-stat.iTLB-loads
2.492e+12 ± 1% +15.9% 2.888e+12 ± 0% perf-stat.instructions
3.336e+12 ± 1% +6.7% 3.561e+12 ± 2% perf-stat.ref-cycles
5047 ± 0% +15.1% 5808 ± 1% sched_debug.cfs_rq:/.exec_clock.avg
19300 ± 21% +28.2% 24741 ± 4% sched_debug.cfs_rq:/.exec_clock.max
6832 ± 20% +34.9% 9213 ± 5% sched_debug.cfs_rq:/.exec_clock.stddev
333180 ± 5% +12.4% 374426 ± 0% sched_debug.cpu.avg_idle.stddev
85525 ± 5% -10.8% 76265 ± 2% sched_debug.cpu.load.avg
42216 ± 4% +20.2% 50737 ± 4% sched_debug.cpu.nr_load_updates.avg
59969 ± 4% +50.8% 90426 ± 3% sched_debug.cpu.nr_load_updates.max
28978 ± 8% -30.2% 20220 ± 23% sched_debug.cpu.nr_load_updates.min
9597 ± 13% +129.7% 22047 ± 9% sched_debug.cpu.nr_load_updates.stddev
0.08 ± 4% -12.1% 0.07 ± 3% sched_debug.cpu.nr_running.avg
560939 ± 1% +24.9% 700884 ± 1% sched_debug.cpu.nr_switches.avg
2055391 ± 21% +41.7% 2911486 ± 3% sched_debug.cpu.nr_switches.max
777901 ± 22% +45.3% 1130221 ± 5% sched_debug.cpu.nr_switches.stddev
561318 ± 1% +24.9% 701171 ± 1% sched_debug.cpu.sched_count.avg
2055179 ± 20% +41.6% 2909542 ± 3% sched_debug.cpu.sched_count.max
779010 ± 22% +45.1% 1130640 ± 5% sched_debug.cpu.sched_count.stddev
279837 ± 1% +25.0% 349746 ± 1% sched_debug.cpu.sched_goidle.avg
1025607 ± 21% +41.7% 1453738 ± 3% sched_debug.cpu.sched_goidle.max
388473 ± 22% +45.3% 564489 ± 5% sched_debug.cpu.sched_goidle.stddev
280785 ± 1% +25.0% 350935 ± 1% sched_debug.cpu.ttwu_count.avg
1055819 ± 22% +46.8% 1550225 ± 3% sched_debug.cpu.ttwu_count.max
388631 ± 22% +46.9% 570963 ± 5% sched_debug.cpu.ttwu_count.stddev
17135 ± 1% +14.7% 19653 ± 2% sched_debug.cpu.ttwu_local.avg
3.94 ± 14% -61.9% 1.50 ±100% perf-profile.cycles-pp.__btrfs_buffered_write.btrfs_file_write_iter.__vfs_write.vfs_write.sys_write
1.29 ± 11% -80.0% 0.26 ±173% perf-profile.cycles-pp.__btrfs_cow_block.btrfs_cow_block.push_leaf_right.split_leaf.setup_leaf_for_split
0.89 ± 25% -82.6% 0.15 ±173% perf-profile.cycles-pp.__btrfs_run_delayed_refs.btrfs_run_delayed_refs.delayed_ref_async_start.normal_work_helper.btrfs_extent_refs_helper
3.98 ± 15% -61.5% 1.53 ±100% perf-profile.cycles-pp.__vfs_write.vfs_write.sys_write.entry_SYSCALL_64_fastpath
8.94 ± 7% -57.1% 3.83 ±100% perf-profile.cycles-pp.__writeback_single_inode.writeback_sb_inodes.wb_writeback.wb_workfn.process_one_work
0.86 ± 19% -100.0% 0.00 ± -1% perf-profile.cycles-pp._raw_spin_lock.block_rsv_release_bytes.btrfs_block_rsv_release.btrfs_delalloc_reserve_metadata.__btrfs_buffered_write
0.89 ± 14% -100.0% 0.00 ± -1% perf-profile.cycles-pp._raw_spin_lock.reserve_metadata_bytes.btrfs_block_rsv_add.part.71.btrfs_delalloc_reserve_metadata.__btrfs_buffered_write
3.71 ± 3% -54.5% 1.69 ±100% perf-profile.cycles-pp.apic_timer_interrupt.cpuidle_enter.call_cpuidle.cpu_startup_entry.start_secondary
0.89 ± 19% -100.0% 0.00 ± -1% perf-profile.cycles-pp.block_rsv_release_bytes.btrfs_block_rsv_release.btrfs_delalloc_reserve_metadata.__btrfs_buffered_write.btrfs_file_write_iter
1.02 ± 19% -86.0% 0.14 ±173% perf-profile.cycles-pp.btree_write_cache_pages.btree_writepages.do_writepages.__writeback_single_inode.writeback_sb_inodes
1.03 ± 19% -85.9% 0.14 ±173% perf-profile.cycles-pp.btree_writepages.do_writepages.__writeback_single_inode.writeback_sb_inodes.wb_writeback
1.29 ± 16% -100.0% 0.00 ± -1% perf-profile.cycles-pp.btrfs_block_rsv_add.part.71.btrfs_delalloc_reserve_metadata.__btrfs_buffered_write.btrfs_file_write_iter.__vfs_write
0.94 ± 18% -100.0% 0.00 ± -1% perf-profile.cycles-pp.btrfs_block_rsv_release.btrfs_delalloc_reserve_metadata.__btrfs_buffered_write.btrfs_file_write_iter.__vfs_write
1.30 ± 11% -80.2% 0.26 ±173% perf-profile.cycles-pp.btrfs_cow_block.push_leaf_right.split_leaf.setup_leaf_for_split.btrfs_duplicate_item
2.28 ± 17% -76.6% 0.53 ±100% perf-profile.cycles-pp.btrfs_delalloc_reserve_metadata.__btrfs_buffered_write.btrfs_file_write_iter.__vfs_write.vfs_write
5.40 ± 9% -55.5% 2.40 ±100% perf-profile.cycles-pp.btrfs_duplicate_item.btrfs_mark_extent_written.btrfs_finish_ordered_io.finish_ordered_fn.normal_work_helper
0.97 ± 22% -82.4% 0.17 ±173% perf-profile.cycles-pp.btrfs_extent_refs_helper.process_one_work.worker_thread.kthread.ret_from_fork
3.96 ± 15% -61.6% 1.52 ±100% perf-profile.cycles-pp.btrfs_file_write_iter.__vfs_write.vfs_write.sys_write.entry_SYSCALL_64_fastpath
1.08 ± 11% -57.6% 0.46 ±100% perf-profile.cycles-pp.btrfs_lookup_csum.btrfs_csum_file_blocks.add_pending_csums.isra.44.btrfs_finish_ordered_io.finish_ordered_fn
0.92 ± 24% -82.6% 0.16 ±173% perf-profile.cycles-pp.btrfs_run_delayed_refs.delayed_ref_async_start.normal_work_helper.btrfs_extent_refs_helper.process_one_work
1.43 ± 8% -60.6% 0.56 ±100% perf-profile.cycles-pp.btrfs_search_slot.btrfs_insert_empty_items.btrfs_csum_file_blocks.add_pending_csums.isra.44.btrfs_finish_ordered_io
1.05 ± 11% -57.6% 0.45 ±100% perf-profile.cycles-pp.btrfs_search_slot.btrfs_lookup_csum.btrfs_csum_file_blocks.add_pending_csums.isra.44.btrfs_finish_ordered_io
0.96 ± 22% -82.3% 0.17 ±173% perf-profile.cycles-pp.delayed_ref_async_start.normal_work_helper.btrfs_extent_refs_helper.process_one_work.worker_thread
8.94 ± 7% -57.1% 3.83 ±100% perf-profile.cycles-pp.do_writepages.__writeback_single_inode.writeback_sb_inodes.wb_writeback.wb_workfn
4.09 ± 14% -60.5% 1.62 ±100% perf-profile.cycles-pp.entry_SYSCALL_64_fastpath
1.30 ± 0% -58.0% 0.54 ±100% perf-profile.cycles-pp.hrtimer_interrupt.local_apic_timer_interrupt.smp_apic_timer_interrupt.apic_timer_interrupt.cpuidle_enter
1.02 ± 6% -57.8% 0.43 ±100% perf-profile.cycles-pp.irq_exit.smp_apic_timer_interrupt.apic_timer_interrupt.cpuidle_enter.call_cpuidle
1.40 ± 1% -57.4% 0.60 ±100% perf-profile.cycles-pp.local_apic_timer_interrupt.smp_apic_timer_interrupt.apic_timer_interrupt.cpuidle_enter.call_cpuidle
0.86 ± 19% -100.0% 0.00 ± -1% perf-profile.cycles-pp.native_queued_spin_lock_slowpath._raw_spin_lock.block_rsv_release_bytes.btrfs_block_rsv_release.btrfs_delalloc_reserve_metadata
0.85 ± 14% -100.0% 0.00 ± -1% perf-profile.cycles-pp.native_queued_spin_lock_slowpath._raw_spin_lock.reserve_metadata_bytes.btrfs_block_rsv_add.part.71.btrfs_delalloc_reserve_metadata
0.96 ± 22% -82.3% 0.17 ±173% perf-profile.cycles-pp.normal_work_helper.btrfs_extent_refs_helper.process_one_work.worker_thread.kthread
1.79 ± 10% -69.5% 0.55 ±104% perf-profile.cycles-pp.push_leaf_right.split_leaf.setup_leaf_for_split.btrfs_duplicate_item.btrfs_mark_extent_written
1.22 ± 17% -100.0% 0.00 ± -1% perf-profile.cycles-pp.reserve_metadata_bytes.btrfs_block_rsv_add.part.71.btrfs_delalloc_reserve_metadata.__btrfs_buffered_write.btrfs_file_write_iter
3.74 ± 9% -58.5% 1.55 ±102% perf-profile.cycles-pp.setup_leaf_for_split.btrfs_duplicate_item.btrfs_mark_extent_written.btrfs_finish_ordered_io.finish_ordered_fn
3.53 ± 4% -54.1% 1.62 ±100% perf-profile.cycles-pp.smp_apic_timer_interrupt.apic_timer_interrupt.cpuidle_enter.call_cpuidle.cpu_startup_entry
2.04 ± 10% -66.9% 0.68 ±102% perf-profile.cycles-pp.split_leaf.setup_leaf_for_split.btrfs_duplicate_item.btrfs_mark_extent_written.btrfs_finish_ordered_io
0.93 ± 4% -54.0% 0.43 ±100% perf-profile.cycles-pp.submit_extent_page.__extent_writepage_io.__extent_writepage.extent_write_cache_pages.isra.36.constprop.50.extent_writepages
4.00 ± 14% -60.5% 1.58 ±100% perf-profile.cycles-pp.sys_write.entry_SYSCALL_64_fastpath
4.00 ± 15% -60.5% 1.58 ±100% perf-profile.cycles-pp.vfs_write.sys_write.entry_SYSCALL_64_fastpath
0.94 ± 20% -85.9% 0.13 ±173% perf-profile.cycles-pp.write_one_eb.isra.42.btree_write_cache_pages.btree_writepages.do_writepages.__writeback_single_inode
8.94 ± 7% -57.1% 3.83 ±100% perf-profile.cycles-pp.writeback_sb_inodes.wb_writeback.wb_workfn.process_one_work.worker_thread
fio.write_bw_MBps
140 ++--------------------------------------------------------------------+
| |
135 ++ O O O O O |
| O O O O O O |
130 ++ O O O O OOOOOOOOO O |
|O OO OO O O O OO OO OOO |
125 O+O O O O |
| |
120 ++ |
| |
115 ++ |
| |
110 ++ * * * * * * * * * * * *. * * * * * *. * ** |
|* ** ***.*** ** ** * ** *.* *** ** ** * ** ** * ** ** * ** ** ** **
105 *+*-------------------------------------------------------------------+
fio.write_iops
35000 ++--------------------------O---------------------------------------+
| O O O O O |
34000 ++ O O O O O |
33000 ++ O O O O OOOOOOOOO O |
| O OO O O O O O OOO |
32000 OOOO O O O O O |
| |
31000 ++ |
| |
30000 ++ |
29000 ++ |
| |
28000 ++ * * * * * * * * * * * * * * *. * * * * ** |
|* ** ****** ** *.* * ** ** *** ** ** * ** ** * ** ** * ** ** ** **
27000 *+*-----------------------------------------------------------------+
[*] bisect-good sample
[O] bisect-bad sample
Thanks,
Xiaolong
5 years, 3 months
[lkp] [mm, kasan] 7392becb25: BUG: KASAN: slab-out-of-bounds in bucket_table_alloc+0x79/0x1a0 at addr ffff88003e400000
by kernel test robot
FYI, we noticed the following commit:
https://github.com/0day-ci/linux Alexander-Potapenko/mm-kasan-switch-SLUB-to-stackdepot-enable-memory-quarantine-for-SLUB/20160708-183858
commit 7392becb255cd6c0e7bedaabd58f638b732772f2 ("mm, kasan: switch SLUB to stackdepot, enable memory quarantine for SLUB")
in testcase: boot
on test machine: 2 threads qemu-system-x86_64 -enable-kvm -cpu Haswell,+smep,+smap with 1G memory
caused below changes:
+-----------------------------------------------------------------------------------------+----------+------------+
| | v4.7-rc6 | 7392becb25 |
+-----------------------------------------------------------------------------------------+----------+------------+
| boot_successes | 0 | 0 |
| boot_failures | 61 | 36 |
| BUG:workqueue_lockup-pool | 58 | 14 |
| BUG:workqueue_lockup-pool_cpus=#cpus=#node=#node=#flags=#nice=#flags=#nice=#stuck_for#s | 58 | 14 |
| BUG:workqueue_lockup-pool_cpus=#cpus=#flags=#nice=#flags=#nice=#stuck_for#s | 12 | 1 |
| Kernel_panic-not_syncing:Attempted_to_kill_init!exitcode= | 9 | |
| BUG:KASAN:slab-out-of-bounds_in_bucket_table_alloc_at_addr | 0 | 22 |
| backtrace:threadfunc | 0 | 22 |
| BUG:KASAN:slab-out-of-bounds_in | 0 | 1 |
+-----------------------------------------------------------------------------------------+----------+------------+
[ 22.095742] Testing concurrent rhashtable access from 10 threads
[ 22.756188] ==================================================================
[ 22.756188] ==================================================================
[ 22.759097] BUG: KASAN: slab-out-of-bounds in bucket_table_alloc+0x79/0x1a0 at addr ffff88003e400000
[ 22.759097] BUG: KASAN: slab-out-of-bounds in bucket_table_alloc+0x79/0x1a0 at addr ffff88003e400000
[ 22.762225] Write of size 4 by task rhashtable_thra/165
[ 22.762225] Write of size 4 by task rhashtable_thra/165
[ 22.764303] CPU: 0 PID: 165 Comm: rhashtable_thra Not tainted 4.7.0-rc6-00001-g7392bec #1
[ 22.764303] CPU: 0 PID: 165 Comm: rhashtable_thra Not tainted 4.7.0-rc6-00001-g7392bec #1
[ 22.766875] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 22.766875] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 22.769722] 0000000000000000
[ 22.769722] 0000000000000000 ffff8800165f7be8 ffff8800165f7be8 ffffffff812cd64c ffffffff812cd64c ffff8800165f7c58 ffff8800165f7c58
[ 22.772033] ffffffff811c4b96
[ 22.772033] ffffffff811c4b96 ffffffff812ec3c8 ffffffff812ec3c8 0000000000000246 0000000000000246 ffff880000082300 ffff880000082300
[ 22.774265] 0000000002089220
[ 22.774265] 0000000002089220 0000000002089220 0000000002089220 ffff8800165f7c68 ffff8800165f7c68 ffffffff811c2379 ffffffff811c2379
[ 22.776571] Call Trace:
[ 22.776571] Call Trace:
[ 22.777355] [<ffffffff812cd64c>] dump_stack+0x19/0x1b
[ 22.777355] [<ffffffff812cd64c>] dump_stack+0x19/0x1b
[ 22.779220] [<ffffffff811c4b96>] kasan_report+0x2d7/0x4ed
[ 22.779220] [<ffffffff811c4b96>] kasan_report+0x2d7/0x4ed
[ 22.780862] [<ffffffff812ec3c8>] ? bucket_table_alloc+0x79/0x1a0
[ 22.780862] [<ffffffff812ec3c8>] ? bucket_table_alloc+0x79/0x1a0
[ 22.782668] [<ffffffff811c2379>] ? __kmalloc+0x177/0x1b0
[ 22.782668] [<ffffffff811c2379>] ? __kmalloc+0x177/0x1b0
[ 22.784273] [<ffffffff811c46b0>] __asan_store4+0x6e/0x70
[ 22.784273] [<ffffffff811c46b0>] __asan_store4+0x6e/0x70
[ 22.785885] [<ffffffff812ec3c8>] bucket_table_alloc+0x79/0x1a0
[ 22.785885] [<ffffffff812ec3c8>] bucket_table_alloc+0x79/0x1a0
[ 22.787660] [<ffffffff812ecfb7>] rhashtable_insert_rehash+0xc0/0x13f
[ 22.787660] [<ffffffff812ecfb7>] rhashtable_insert_rehash+0xc0/0x13f
[ 22.789577] [<ffffffff812f15d5>] insert_retry+0x2fa/0x5bc
[ 22.789577] [<ffffffff812f15d5>] insert_retry+0x2fa/0x5bc
[ 22.791705] [<ffffffff81101f19>] ? trace_hardirqs_on+0xd/0xf
[ 22.791705] [<ffffffff81101f19>] ? trace_hardirqs_on+0xd/0xf
[ 22.793425] [<ffffffff812f195f>] threadfunc+0xc8/0x68c
[ 22.793425] [<ffffffff812f195f>] threadfunc+0xc8/0x68c
[ 22.794987] [<ffffffff81f92dbe>] ? __schedule+0x5fe/0x73f
[ 22.794987] [<ffffffff81f92dbe>] ? __schedule+0x5fe/0x73f
[ 22.796629] [<ffffffff812f1897>] ? insert_retry+0x5bc/0x5bc
[ 22.796629] [<ffffffff812f1897>] ? insert_retry+0x5bc/0x5bc
[ 22.798810] [<ffffffff810e5c55>] kthread+0x18d/0x19c
[ 22.798810] [<ffffffff810e5c55>] kthread+0x18d/0x19c
[ 22.800319] [<ffffffff810e5ac8>] ? __kthread_parkme+0xb0/0xb0
[ 22.800319] [<ffffffff810e5ac8>] ? __kthread_parkme+0xb0/0xb0
[ 22.802048] [<ffffffff810ea54c>] ? finish_task_switch+0x1ac/0x224
[ 22.802048] [<ffffffff810ea54c>] ? finish_task_switch+0x1ac/0x224
[ 22.804976] [<ffffffff81f9986f>] ret_from_fork+0x1f/0x40
[ 22.804976] [<ffffffff81f9986f>] ret_from_fork+0x1f/0x40
[ 22.807662] [<ffffffff810e5ac8>] ? __kthread_parkme+0xb0/0xb0
[ 22.807662] [<ffffffff810e5ac8>] ? __kthread_parkme+0xb0/0xb0
[ 22.810556] Object at ffff88003e400000, in cache kmalloc-4194304
[ 22.810556] Object at ffff88003e400000, in cache kmalloc-4194304
[ 22.813231] Memory state around the buggy address:
FYI, raw QEMU command line is:
qemu-system-x86_64 -enable-kvm -cpu Haswell,+smep,+smap -kernel /pkg/linux/x86_64-randconfig-s2-07120443/gcc-6/7392becb255cd6c0e7bedaabd58f638b732772f2/vmlinuz-4.7.0-rc6-00001-g7392bec -append 'root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-kbuild-1G-5/bisect_boot-1-debian-x86_64-2015-02-07.cgz-x86_64-randconfig-s2-07120443-7392becb255cd6c0e7bedaabd58f638b732772f2-20160712-21427-xipcnl-0.yaml ARCH=x86_64 kconfig=x86_64-randconfig-s2-07120443 branch=linux-devel/devel-spot-201607120350 commit=7392becb255cd6c0e7bedaabd58f638b732772f2 BOOT_IMAGE=/pkg/linux/x86_64-randconfig-s2-07120443/gcc-6/7392becb255cd6c0e7bedaabd58f638b732772f2/vmlinuz-4.7.0-rc6-00001-g7392bec max_uptime=600 RESULT_ROOT=/result/boot/1/vm-kbuild-1G/debian-x86_64-2015-02-07.cgz/x86_64-randconfig-s2-07120443/gcc-6/7392becb255cd6c0e7bedaabd58f638b732772f2/0 LKP_SERVER=inn earlyprintk=ttyS0,115200 systemd.log_level=err debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 console=ttyS0,115200 console=tty0 vga=normal rw ip=::::vm-kbuild-1G-5::dhcp' -initrd /fs/sdg1/initrd-vm-kbuild-1G-5 -m 1024 -smp 2 -device e1000,netdev=net0 -netdev user,id=net0,hostfwd=tcp::23004-:22 -boot order=nc -no-reboot -watchdog i6300esb -rtc base=localtime -device virtio-scsi-pci,id=scsi0 -drive file=/fs/sdg1/disk0-vm-kbuild-1G-5,if=none,id=hd0,media=disk,aio=native,cache=none -device scsi-hd,bus=scsi0.0,drive=hd0,scsi-id=1,lun=0 -drive file=/fs/sdg1/disk1-vm-kbuild-1G-5,if=none,id=hd1,media=disk,aio=native,cache=none -device scsi-hd,bus=scsi0.0,drive=hd1,scsi-id=1,lun=1 -drive file=/fs/sdg1/disk2-vm-kbuild-1G-5,if=none,id=hd2,media=disk,aio=native,cache=none -device scsi-hd,bus=scsi0.0,drive=hd2,scsi-id=1,lun=2 -drive file=/fs/sdg1/disk3-vm-kbuild-1G-5,if=none,id=hd3,media=disk,aio=native,cache=none -device scsi-hd,bus=scsi0.0,drive=hd3,scsi-id=1,lun=3 -drive file=/fs/sdg1/disk4-vm-kbuild-1G-5,if=none,id=hd4,media=disk,aio=native,cache=none -device scsi-hd,bus=scsi0.0,drive=hd4,scsi-id=1,lun=4 -pidfile /dev/shm/kboot/pid-vm-kbuild-1G-5 -serial file:/dev/shm/kboot/serial-vm-kbuild-1G-5 -daemonize -display none -monitor null
Thanks,
Xiaolong
5 years, 3 months
Re: [LKP] [lkp] [usb] 9696ef14de: WARNING: CPU: 0 PID: 1 at lib/list_debug.c:36 __list_add+0x104/0x188
by Ye Xiaolong
On Wed, Jul 13, 2016 at 01:55:26AM +0000, Peter Chen wrote:
>
>
>>-----Original Message-----
>>From: lkp-request(a)eclists.intel.com [mailto:lkp-request@eclists.intel.com] On Behalf
>>Of kernel test robot
>>Sent: Wednesday, July 13, 2016 9:28 AM
>>To: Peter Chen <peter.chen(a)nxp.com>
>>Cc: 0day robot <fengguang.wu(a)intel.com>; LKML <linux-kernel(a)vger.kernel.org>;
>>lkp(a)01.org
>>Subject: [lkp] [usb] 9696ef14de: WARNING: CPU: 0 PID: 1 at lib/list_debug.c:36
>>__list_add+0x104/0x188
>>
>>
>>FYI, we noticed the following commit:
>>
>>https://github.com/0day-ci/linux Peter-Chen/usb-udc-core-fix-error-
>>handling/20160711-100832
>>commit 9696ef14ded07fb0847f8e1cdda6d98a89ecd4f2 ("usb: udc: core: fix error
>>handling")
>>
>
>Thanks, but I really can't find the relationship between my patch and dump.
>Can you reproduce it after running again or without my patch?
>
Sorry, it's a false report, the error dump also showed in parent commit,
please ignore the report and sorry for the noise.
Thanks,
Xiaolong
>Peter
>
>>in testcase: boot
>>
>>on test machine: 2 threads qemu-system-x86_64 -enable-kvm -cpu Nehalem with
>>320M memory
>>
>>caused below changes:
>>
>>[ 22.076363] WARNING: CPU: 0 PID: 1 at lib/list_debug.c:36
>>__list_add+0x104/0x188
>>[ 22.079911] list_add double add: new=ffff88000e422e10, prev=ffff88000e422e10,
>>next=ffff8800135e9168.
>>[ 22.086059] CPU: 0 PID: 1 Comm: swapper Tainted: G W 4.7.0-rc4-
>>00110-g9696ef1 #1
>>[ 22.087856] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
>>Debian-1.8.2-1 04/01/2014
>>[ 22.097535] 0000000000000000 ffff88001345fc00 ffffffff8190c8e2
>>ffff88001345fc40
>>[ 22.099469] ffffffff81175453 0000002400000009 ffff88000e422e10
>>ffff8800135e9168
>>[ 22.101220] ffff88000e422e10 0000000000000000 0000000000000001
>>ffff88001345fca8
>>[ 22.103291] Call Trace:
>>[ 22.109166] [<ffffffff8190c8e2>] dump_stack+0x19/0x1b
>>[ 22.110520] [<ffffffff81175453>] __warn+0x10a/0x125
>>[ 22.111632] [<ffffffff811754b4>] warn_slowpath_fmt+0x46/0x4e
>>[ 22.112939] [<ffffffff82860938>] ? klist_add_tail+0x29/0x62
>>[ 22.114418] [<ffffffff8194b431>] __list_add+0x104/0x188
>>[ 22.115600] [<ffffffff82860962>] klist_add_tail+0x53/0x62
>>[ 22.118742] [<ffffffff81bd24e7>] device_add+0xb03/0xcca
>>[ 22.121931] [<ffffffff81bd283e>] device_create_groups_vargs+0xfe/0x133
>>[ 22.123390] [<ffffffff81bd28e7>] device_create_with_groups+0x2b/0x2d
>>[ 22.130047] [<ffffffff82871904>] ? __mutex_unlock_slowpath+0x1cb/0x1d8
>>[ 22.131513] [<ffffffff81b909eb>] misc_register+0x1e0/0x2ec
>>[ 22.132751] [<ffffffff85292b08>] mousedev_init+0x55/0x81
>>[ 22.134198] [<ffffffff85292ab3>] ? input_leds_init+0x12/0x12
>>[ 22.135442] [<ffffffff8522b831>] do_one_initcall+0xdc/0x16a
>>[ 22.139131] [<ffffffff8522bc46>] kernel_init_freeable+0x387/0x419
>>[ 22.142059] [<ffffffff8286183b>] kernel_init+0xa/0x103
>>[ 22.144618] [<ffffffff828778bf>] ret_from_fork+0x1f/0x40
>>[ 22.148576] [<ffffffff82861831>] ? rest_init+0xb8/0xb8
>>[ 22.150009] ---[ end trace 75873bca450a4fe4 ]---
>>[ 22.151559] mousedev: PS/2 mouse device common for all mice
>>[ 22.155003] evbug: Connected device: input0 (Power Button at
>>LNXPWRBN/button/input0)
>>
>>
>>FYI, raw QEMU command line is:
>>
>> qemu-system-x86_64 -enable-kvm -cpu Nehalem -kernel /pkg/linux/x86_64-
>>randconfig-s0-07121340/gcc-
>>6/9696ef14ded07fb0847f8e1cdda6d98a89ecd4f2/vmlinuz-4.7.0-rc4-00110-g9696ef1
>>-append 'root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-intel12-yocto-x86_64-
>>3/bisect_boot-1-yocto-minimal-x86_64.cgz-x86_64-randconfig-s0-07121340-
>>9696ef14ded07fb0847f8e1cdda6d98a89ecd4f2-20160712-19858-1j3k6zi-0.yaml
>>ARCH=x86_64 kconfig=x86_64-randconfig-s0-07121340 branch=linux-devel/devel-
>>hourly-2016071211 commit=9696ef14ded07fb0847f8e1cdda6d98a89ecd4f2
>>BOOT_IMAGE=/pkg/linux/x86_64-randconfig-s0-07121340/gcc-
>>6/9696ef14ded07fb0847f8e1cdda6d98a89ecd4f2/vmlinuz-4.7.0-rc4-00110-g9696ef1
>>max_uptime=600 RESULT_ROOT=/result/boot/1/vm-intel12-yocto-x86_64/yocto-
>>minimal-x86_64.cgz/x86_64-randconfig-s0-07121340/gcc-
>>6/9696ef14ded07fb0847f8e1cdda6d98a89ecd4f2/0 LKP_SERVER=inn
>>earlyprintk=ttyS0,115200 systemd.log_level=err debug apic=debug
>>sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1
>>softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2
>>prompt_ramdisk=0 console=ttyS0,115200 console=tty0 vga=normal rw ip=::::vm-
>>intel12-yocto-x86_64-3::dhcp drbd.minor_count=8' -initrd /fs/KVM/initrd-vm-intel12-
>>yocto-x86_64-3 -m 320 -smp 2 -device e1000,netdev=net0 -netdev user,id=net0 -
>>boot order=nc -no-reboot -watchdog i6300esb -rtc base=localtime -drive
>>file=/fs/KVM/disk0-vm-intel12-yocto-x86_64-3,media=disk,if=virtio -drive
>>file=/fs/KVM/disk1-vm-intel12-yocto-x86_64-3,media=disk,if=virtio -pidfile
>>/dev/shm/kboot/pid-vm-intel12-yocto-x86_64-3 -serial file:/dev/shm/kboot/serial-vm-
>>intel12-yocto-x86_64-3 -daemonize -display none -monitor null
>>
>>
>>
>>
>>
>>Thanks,
>>Xiaolong
5 years, 3 months
[lkp] [usb] 9696ef14de: WARNING: CPU: 0 PID: 1 at lib/list_debug.c:36 __list_add+0x104/0x188
by kernel test robot
FYI, we noticed the following commit:
https://github.com/0day-ci/linux Peter-Chen/usb-udc-core-fix-error-handling/20160711-100832
commit 9696ef14ded07fb0847f8e1cdda6d98a89ecd4f2 ("usb: udc: core: fix error handling")
in testcase: boot
on test machine: 2 threads qemu-system-x86_64 -enable-kvm -cpu Nehalem with 320M memory
caused below changes:
[ 22.076363] WARNING: CPU: 0 PID: 1 at lib/list_debug.c:36 __list_add+0x104/0x188
[ 22.079911] list_add double add: new=ffff88000e422e10, prev=ffff88000e422e10, next=ffff8800135e9168.
[ 22.086059] CPU: 0 PID: 1 Comm: swapper Tainted: G W 4.7.0-rc4-00110-g9696ef1 #1
[ 22.087856] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 22.097535] 0000000000000000 ffff88001345fc00 ffffffff8190c8e2 ffff88001345fc40
[ 22.099469] ffffffff81175453 0000002400000009 ffff88000e422e10 ffff8800135e9168
[ 22.101220] ffff88000e422e10 0000000000000000 0000000000000001 ffff88001345fca8
[ 22.103291] Call Trace:
[ 22.109166] [<ffffffff8190c8e2>] dump_stack+0x19/0x1b
[ 22.110520] [<ffffffff81175453>] __warn+0x10a/0x125
[ 22.111632] [<ffffffff811754b4>] warn_slowpath_fmt+0x46/0x4e
[ 22.112939] [<ffffffff82860938>] ? klist_add_tail+0x29/0x62
[ 22.114418] [<ffffffff8194b431>] __list_add+0x104/0x188
[ 22.115600] [<ffffffff82860962>] klist_add_tail+0x53/0x62
[ 22.118742] [<ffffffff81bd24e7>] device_add+0xb03/0xcca
[ 22.121931] [<ffffffff81bd283e>] device_create_groups_vargs+0xfe/0x133
[ 22.123390] [<ffffffff81bd28e7>] device_create_with_groups+0x2b/0x2d
[ 22.130047] [<ffffffff82871904>] ? __mutex_unlock_slowpath+0x1cb/0x1d8
[ 22.131513] [<ffffffff81b909eb>] misc_register+0x1e0/0x2ec
[ 22.132751] [<ffffffff85292b08>] mousedev_init+0x55/0x81
[ 22.134198] [<ffffffff85292ab3>] ? input_leds_init+0x12/0x12
[ 22.135442] [<ffffffff8522b831>] do_one_initcall+0xdc/0x16a
[ 22.139131] [<ffffffff8522bc46>] kernel_init_freeable+0x387/0x419
[ 22.142059] [<ffffffff8286183b>] kernel_init+0xa/0x103
[ 22.144618] [<ffffffff828778bf>] ret_from_fork+0x1f/0x40
[ 22.148576] [<ffffffff82861831>] ? rest_init+0xb8/0xb8
[ 22.150009] ---[ end trace 75873bca450a4fe4 ]---
[ 22.151559] mousedev: PS/2 mouse device common for all mice
[ 22.155003] evbug: Connected device: input0 (Power Button at LNXPWRBN/button/input0)
FYI, raw QEMU command line is:
qemu-system-x86_64 -enable-kvm -cpu Nehalem -kernel /pkg/linux/x86_64-randconfig-s0-07121340/gcc-6/9696ef14ded07fb0847f8e1cdda6d98a89ecd4f2/vmlinuz-4.7.0-rc4-00110-g9696ef1 -append 'root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-intel12-yocto-x86_64-3/bisect_boot-1-yocto-minimal-x86_64.cgz-x86_64-randconfig-s0-07121340-9696ef14ded07fb0847f8e1cdda6d98a89ecd4f2-20160712-19858-1j3k6zi-0.yaml ARCH=x86_64 kconfig=x86_64-randconfig-s0-07121340 branch=linux-devel/devel-hourly-2016071211 commit=9696ef14ded07fb0847f8e1cdda6d98a89ecd4f2 BOOT_IMAGE=/pkg/linux/x86_64-randconfig-s0-07121340/gcc-6/9696ef14ded07fb0847f8e1cdda6d98a89ecd4f2/vmlinuz-4.7.0-rc4-00110-g9696ef1 max_uptime=600 RESULT_ROOT=/result/boot/1/vm-intel12-yocto-x86_64/yocto-minimal-x86_64.cgz/x86_64-randconfig-s0-07121340/gcc-6/9696ef14ded07fb0847f8e1cdda6d98a89ecd4f2/0 LKP_SERVER=inn earlyprintk=ttyS0,115200 systemd.log_level=err debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 console=ttyS0,115200 console=tty0 vga=normal rw ip=::::vm-intel12-yocto-x86_64-3::dhcp drbd.minor_count=8' -initrd /fs/KVM/initrd-vm-intel12-yocto-x86_64-3 -m 320 -smp 2 -device e1000,netdev=net0 -netdev user,id=net0 -boot order=nc -no-reboot -watchdog i6300esb -rtc base=localtime -drive file=/fs/KVM/disk0-vm-intel12-yocto-x86_64-3,media=disk,if=virtio -drive file=/fs/KVM/disk1-vm-intel12-yocto-x86_64-3,media=disk,if=virtio -pidfile /dev/shm/kboot/pid-vm-intel12-yocto-x86_64-3 -serial file:/dev/shm/kboot/serial-vm-intel12-yocto-x86_64-3 -daemonize -display none -monitor null
Thanks,
Xiaolong
5 years, 3 months
[lkp] [timers] 500462a9de: netperf.Throughput_Mbps -3.8% regression
by kernel test robot
FYI, we noticed a -3.8% regression of netperf.Throughput_Mbps due to commit:
commit 500462a9de657f86edaa102f8ab6bff7f7e43fc2 ("timers: Switch to a non-cascading wheel")
https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git master
in testcase: netperf
on test machine: 16 threads Broadwell-DE with 8G memory
with following parameters: cluster=cs-localhost/cpufreq_governor=performance/ip=ipv4/nr_threads=200%/runtime=300s/test=SCTP_STREAM
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.
Details are as below:
-------------------------------------------------------------------------------------------------->
To reproduce:
git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
=========================================================================================
cluster/compiler/cpufreq_governor/ip/kconfig/nr_threads/rootfs/runtime/tbox_group/test/testcase:
cs-localhost/gcc-4.9/performance/ipv4/x86_64-rhel/200%/debian-x86_64-2015-02-07.cgz/300s/lkp-bdw-de1/SCTP_STREAM/netperf
commit:
b0d6e2dcb2 ("timers: Reduce the CPU index space to 256k")
500462a9de ("timers: Switch to a non-cascading wheel")
b0d6e2dcb284f1f4 500462a9de657f86edaa102f8a
---------------- --------------------------
fail:runs %reproduction fail:runs
| | |
%stddev %change %stddev
\ | \
4.25 ± 0% -3.8% 4.09 ± 0% netperf.Throughput_Mbps
24354 ± 0% -3.9% 23406 ± 0% netperf.time.voluntary_context_switches
442966 ± 15% -18.7% 359983 ± 3% cpuidle.C1-BDW.time
8781285 ± 58% -48.3% 4544291 ± 82% cpuidle.POLL.time
0.06 ± 9% -21.2% 0.04 ± 10% turbostat.CPU%c3
0.20 ± 7% -55.0% 0.09 ± 18% turbostat.Pkg%pc3
1.782e+09 ± 1% -6.4% 1.668e+09 ± 0% perf-stat.L1-dcache-load-misses
7.241e+08 ± 4% +28.2% 9.282e+08 ± 0% perf-stat.LLC-stores
6.285e+08 ± 0% +10.4% 6.937e+08 ± 0% perf-stat.branch-load-misses
5.831e+08 ± 2% +12.2% 6.542e+08 ± 0% perf-stat.branch-misses
4.192e+09 ± 0% +2.5% 4.299e+09 ± 0% perf-stat.cache-references
340227 ± 0% -1.7% 334278 ± 0% perf-stat.context-switches
60151 ± 0% -1.9% 59012 ± 0% perf-stat.cpu-migrations
4.863e+11 ± 1% +3.3% 5.022e+11 ± 1% perf-stat.ref-cycles
15.21 ± 14% +38.9% 21.13 ± 18% sched_debug.cfs_rq:/.runnable_load_avg.avg
-4768 ±-21% +27.5% -6078 ±-22% sched_debug.cfs_rq:/.spread0.avg
104776 ± 3% -12.8% 91330 ± 13% sched_debug.cpu.avg_idle.stddev
195.24 ± 4% -19.7% 156.75 ± 16% sched_debug.cpu.clock.stddev
195.24 ± 4% -19.7% 156.75 ± 16% sched_debug.cpu.clock_task.stddev
12.54 ± 17% +26.0% 15.80 ± 4% sched_debug.cpu.cpu_load[0].avg
3.67 ± 51% +116.7% 7.94 ± 24% sched_debug.cpu.cpu_load[1].min
6.04 ± 16% +56.3% 9.44 ± 5% sched_debug.cpu.cpu_load[2].min
5.33 ± 20% +44.8% 7.72 ± 11% sched_debug.cpu.cpu_load[3].min
1765 ± 8% +14.2% 2016 ± 3% sched_debug.cpu.nr_load_updates.min
2247 ± 8% +20.2% 2701 ± 8% sched_debug.cpu.nr_switches.min
9.71 ± 20% +160.9% 25.33 ± 47% sched_debug.cpu.nr_uninterruptible.max
-13.92 ±-24% +77.6% -24.72 ± -8% sched_debug.cpu.nr_uninterruptible.min
5.98 ± 14% +112.0% 12.68 ± 33% sched_debug.cpu.nr_uninterruptible.stddev
2.97 ± 12% -31.4% 2.04 ± 32% perf-profile.cycles-pp.__const_udelay.wait_for_xmitr.serial8250_console_putchar.uart_console_write.serial8250_console_write
1.63 ± 21% -29.3% 1.15 ± 31% perf-profile.cycles-pp.__netif_receive_skb.process_backlog.net_rx_action.__do_softirq.irq_exit
1.63 ± 21% -29.3% 1.15 ± 31% perf-profile.cycles-pp.__netif_receive_skb_core.__netif_receive_skb.process_backlog.net_rx_action.__do_softirq
7.85 ± 10% -38.9% 4.80 ± 24% perf-profile.cycles-pp.call_console_drivers.constprop.23.console_unlock.vprintk_emit.vprintk_default.printk
7.85 ± 10% -38.9% 4.80 ± 24% perf-profile.cycles-pp.console_unlock.vprintk_emit.vprintk_default.printk.perf_duration_warn
2.97 ± 12% -31.4% 2.04 ± 32% perf-profile.cycles-pp.delay_tsc.__const_udelay.wait_for_xmitr.serial8250_console_putchar.uart_console_write
0.00 ± -1% +Inf% 1.28 ± 32% perf-profile.cycles-pp.get_next_timer_interrupt.tick_nohz_stop_sched_tick.__tick_nohz_idle_enter.tick_nohz_irq_exit.irq_exit
4.46 ± 11% -46.9% 2.37 ± 15% perf-profile.cycles-pp.io_serial_in.wait_for_xmitr.serial8250_console_putchar.uart_console_write.serial8250_console_write
1.61 ± 20% -29.7% 1.13 ± 29% perf-profile.cycles-pp.ip_local_deliver.ip_rcv_finish.ip_rcv.__netif_receive_skb_core.__netif_receive_skb
1.61 ± 20% -29.7% 1.13 ± 29% perf-profile.cycles-pp.ip_local_deliver_finish.ip_local_deliver.ip_rcv_finish.ip_rcv.__netif_receive_skb_core
1.61 ± 20% -28.5% 1.15 ± 31% perf-profile.cycles-pp.ip_rcv.__netif_receive_skb_core.__netif_receive_skb.process_backlog.net_rx_action
1.61 ± 20% -29.7% 1.13 ± 29% perf-profile.cycles-pp.ip_rcv_finish.ip_rcv.__netif_receive_skb_core.__netif_receive_skb.process_backlog
1.63 ± 21% -29.3% 1.15 ± 31% perf-profile.cycles-pp.net_rx_action.__do_softirq.irq_exit.smp_apic_timer_interrupt.apic_timer_interrupt
7.85 ± 10% -38.9% 4.80 ± 24% perf-profile.cycles-pp.perf_duration_warn.irq_work_run_list.irq_work_run.smp_irq_work_interrupt.irq_work_interrupt
1.56 ± 14% -23.2% 1.20 ± 15% perf-profile.cycles-pp.perf_mux_hrtimer_handler.__hrtimer_run_queues.hrtimer_interrupt.local_apic_timer_interrupt.smp_apic_timer_interrupt
7.85 ± 10% -38.9% 4.80 ± 24% perf-profile.cycles-pp.printk.perf_duration_warn.irq_work_run_list.irq_work_run.smp_irq_work_interrupt
1.63 ± 21% -29.3% 1.15 ± 31% perf-profile.cycles-pp.process_backlog.net_rx_action.__do_softirq.irq_exit.smp_apic_timer_interrupt
1.54 ± 19% -26.9% 1.13 ± 29% perf-profile.cycles-pp.sctp_rcv.ip_local_deliver_finish.ip_local_deliver.ip_rcv_finish.ip_rcv
7.57 ± 10% -39.0% 4.62 ± 24% perf-profile.cycles-pp.serial8250_console_putchar.uart_console_write.serial8250_console_write.univ8250_console_write.call_console_drivers.constprop.23
7.85 ± 10% -38.9% 4.80 ± 24% perf-profile.cycles-pp.serial8250_console_write.univ8250_console_write.call_console_drivers.constprop.23.console_unlock.vprintk_emit
7.57 ± 10% -39.0% 4.62 ± 24% perf-profile.cycles-pp.uart_console_write.serial8250_console_write.univ8250_console_write.call_console_drivers.constprop.23.console_unlock
7.85 ± 10% -38.9% 4.80 ± 24% perf-profile.cycles-pp.univ8250_console_write.call_console_drivers.constprop.23.console_unlock.vprintk_emit.vprintk_default
7.85 ± 10% -38.9% 4.80 ± 24% perf-profile.cycles-pp.vprintk_default.printk.perf_duration_warn.irq_work_run_list.irq_work_run
7.85 ± 10% -38.9% 4.80 ± 24% perf-profile.cycles-pp.vprintk_emit.vprintk_default.printk.perf_duration_warn.irq_work_run_list
7.51 ± 9% -39.4% 4.55 ± 23% perf-profile.cycles-pp.wait_for_xmitr.serial8250_console_putchar.uart_console_write.serial8250_console_write.univ8250_console_write
netperf.Throughput_Mbps
4.5 ++--------------------------------------------------------------------+
O.O.O.*.OO *.O.* O O.*.O.O*.O.O.O.O.O.O.O.O.OO.*.O.O.O.*.*.*.**.*.*.*.*
4 ++ : : : : |
3.5 ++ : : : : |
| : : : : |
3 ++ : : : : |
2.5 ++ : : : : |
| : : : : |
2 ++ :: : : |
1.5 ++ :: : : |
| :: : : |
1 ++ : : |
0.5 ++ : : |
| : : |
0 ++----O--*-O---O-*---O----O--------------------O----------------------+
netperf.time.voluntary_context_switches
25000 *+*-*-**-*-*-*-*-**-*-*-*-*-**-*-*-*-*-**-*-*-*-*-**-*-*-*-*-**-*-*-*
O O O OO O O O O OO O O O O OO O O O O OO O O O OO |
| |
20000 ++ |
| |
| |
15000 ++ |
| |
10000 ++ |
| |
| |
5000 ++ |
| |
| |
0 ++--------------------------------------------O---------------------+
[*] bisect-good sample
[O] bisect-bad sample
Thanks,
Xiaolong
5 years, 3 months
[perf/x86] 8de4a00661: WARNING: CPU: 0 PID: 1 at kernel/locking/mutex-debug.c:80 debug_mutex_unlock+0x20c/0x2b3
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git tmp.smp/hotplug
commit 8de4a0066106bc827bdf4240beaf79110fe9e151 ("perf/x86: Convert the core to the hotplug state machine")
in testcase: boot
on test machine: 2 threads qemu-system-x86_64 -enable-kvm -cpu host with 2G memory
caused below changes:
+-------------------------------------------------------------+------------+------------+
| | fb6329aace | 8de4a00661 |
+-------------------------------------------------------------+------------+------------+
| boot_successes | 8 | 4 |
| boot_failures | 0 | 4 |
| WARNING:at_kernel/locking/mutex-debug.c:#debug_mutex_unlock | 0 | 4 |
| general_protection_fault:#[##]PREEMPT | 0 | 4 |
| RIP:wake_q_add | 0 | 4 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 4 |
| backtrace:__cpuhp_setup_state | 0 | 4 |
| backtrace:init_hw_perf_events | 0 | 4 |
| backtrace:kernel_init_freeable | 0 | 4 |
+-------------------------------------------------------------+------------+------------+
[ 1.859689] ... event mask: 000000070000000f
[ 1.861773] ------------[ cut here ]------------
[ 1.861773] ------------[ cut here ]------------
[ 1.863354] WARNING: CPU: 0 PID: 1 at kernel/locking/mutex-debug.c:80 debug_mutex_unlock+0x20c/0x2b3
[ 1.863354] WARNING: CPU: 0 PID: 1 at kernel/locking/mutex-debug.c:80 debug_mutex_unlock+0x20c/0x2b3
[ 1.877193] DEBUG_LOCKS_WARN_ON(lock->owner != current)
[ 1.877193] DEBUG_LOCKS_WARN_ON(lock->owner != current)
[ 1.889674] Modules linked in:
[ 1.889674] Modules linked in:
[ 1.898784] CPU: 0 PID: 1 Comm: swapper Not tainted 4.7.0-rc7-00174-g8de4a00 #2
[ 1.898784] CPU: 0 PID: 1 Comm: swapper Not tainted 4.7.0-rc7-00174-g8de4a00 #2
[ 1.903343] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 1.903343] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 1.906548] 0000000000000000
[ 1.906548] 0000000000000000 ffff88000028bcb8 ffff88000028bcb8 ffffffff812352f7 ffffffff812352f7 ffff88000028bcf8 ffff88000028bcf8
[ 1.908804] ffffffff8105a23e
[ 1.908804] ffffffff8105a23e 000000090028bd70 000000090028bd70 ffffffff81e30380 ffffffff81e30380 0000000000000001 0000000000000001
[ 1.918985] 0000000000000001
[ 1.918985] 0000000000000001 0000000000000000 0000000000000000 ffffffff81b8eb03 ffffffff81b8eb03 ffff88000028bd60 ffff88000028bd60
[ 1.941118] Call Trace:
[ 1.941118] Call Trace:
[ 1.945277] [<ffffffff812352f7>] dump_stack+0x19/0x1b
[ 1.945277] [<ffffffff812352f7>] dump_stack+0x19/0x1b
[ 1.947870] [<ffffffff8105a23e>] __warn+0x109/0x124
[ 1.947870] [<ffffffff8105a23e>] __warn+0x109/0x124
[ 1.949870] [<ffffffff8105a29f>] warn_slowpath_fmt+0x46/0x4e
[ 1.949870] [<ffffffff8105a29f>] warn_slowpath_fmt+0x46/0x4e
[ 1.951847] [<ffffffff810953f7>] debug_mutex_unlock+0x20c/0x2b3
[ 1.951847] [<ffffffff810953f7>] debug_mutex_unlock+0x20c/0x2b3
[ 1.953663] [<ffffffff81674fbd>] __mutex_unlock_slowpath+0x171/0x237
[ 1.953663] [<ffffffff81674fbd>] __mutex_unlock_slowpath+0x171/0x237
[ 1.955460] [<ffffffff810039b7>] ? x86_pmu_starting_cpu+0x2d/0x2d
[ 1.955460] [<ffffffff810039b7>] ? x86_pmu_starting_cpu+0x2d/0x2d
[ 1.966529] [<ffffffff810039e4>] ? x86_pmu_dead_cpu+0x2d/0x2d
[ 1.966529] [<ffffffff810039e4>] ? x86_pmu_dead_cpu+0x2d/0x2d
[ 1.979431] [<ffffffff8167508c>] mutex_unlock+0x9/0xb
[ 1.979431] [<ffffffff8167508c>] mutex_unlock+0x9/0xb
[ 1.990691] [<ffffffff8105a67f>] cpuhp_store_callbacks+0x5a/0x63
[ 1.990691] [<ffffffff8105a67f>] cpuhp_store_callbacks+0x5a/0x63
[ 1.994403] [<ffffffff810039e4>] ? x86_pmu_dead_cpu+0x2d/0x2d
[ 1.994403] [<ffffffff810039e4>] ? x86_pmu_dead_cpu+0x2d/0x2d
[ 1.997149] [<ffffffff810039b7>] ? x86_pmu_starting_cpu+0x2d/0x2d
[ 1.997149] [<ffffffff810039b7>] ? x86_pmu_starting_cpu+0x2d/0x2d
[ 2.003874] [<ffffffff8105aafc>] __cpuhp_setup_state+0x156/0x20e
[ 2.003874] [<ffffffff8105aafc>] __cpuhp_setup_state+0x156/0x20e
[ 2.021370] [<ffffffff82298961>] init_hw_perf_events+0x603/0x713
[ 2.021370] [<ffffffff82298961>] init_hw_perf_events+0x603/0x713
[ 2.034708] [<ffffffff8229835e>] ? merge_attr+0xa0/0xa0
[ 2.034708] [<ffffffff8229835e>] ? merge_attr+0xa0/0xa0
[ 2.037776] [<ffffffff810004aa>] do_one_initcall+0xad/0x1b5
[ 2.037776] [<ffffffff810004aa>] do_one_initcall+0xad/0x1b5
[ 2.040623] [<ffffffff8229635e>] kernel_init_freeable+0x71/0x1e0
[ 2.040623] [<ffffffff8229635e>] kernel_init_freeable+0x71/0x1e0
[ 2.042924] [<ffffffff8166ea54>] kernel_init+0x9/0x160
[ 2.042924] [<ffffffff8166ea54>] kernel_init+0x9/0x160
[ 2.051975] [<ffffffff8167768f>] ret_from_fork+0x1f/0x40
[ 2.051975] [<ffffffff8167768f>] ret_from_fork+0x1f/0x40
[ 2.061758] [<ffffffff8166ea4b>] ? rest_init+0x152/0x152
[ 2.061758] [<ffffffff8166ea4b>] ? rest_init+0x152/0x152
[ 2.071686] ---[ end trace ef459b19889747da ]---
[ 2.071686] ---[ end trace ef459b19889747da ]---
FYI, raw QEMU command line is:
qemu-system-x86_64 -enable-kvm -cpu host -kernel /pkg/linux/x86_64-randconfig-s4-07121850/gcc-6/8de4a0066106bc827bdf4240beaf79110fe9e151/vmlinuz-4.7.0-rc7-00174-g8de4a00 -append 'root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-lkp-wsx03-2G-9/bisect_boot-1-debian-x86_64-2015-02-07.cgz-x86_64-randconfig-s4-07121850-8de4a0066106bc827bdf4240beaf79110fe9e151-20160713-90794-4vvvnk-0.yaml ARCH=x86_64 kconfig=x86_64-randconfig-s4-07121850 branch=linux-devel/devel-catchup-201607121907 commit=8de4a0066106bc827bdf4240beaf79110fe9e151 BOOT_IMAGE=/pkg/linux/x86_64-randconfig-s4-07121850/gcc-6/8de4a0066106bc827bdf4240beaf79110fe9e151/vmlinuz-4.7.0-rc7-00174-g8de4a00 max_uptime=600 RESULT_ROOT=/result/boot/1/vm-lkp-wsx03-2G/debian-x86_64-2015-02-07.cgz/x86_64-randconfig-s4-07121850/gcc-6/8de4a0066106bc827bdf4240beaf79110fe9e151/0 LKP_SERVER=inn earlyprintk=ttyS0,115200 systemd.log_level=err debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 console=ttyS0,115200 console=tty0 vga=normal rw ip=::::vm-lkp-wsx03-2G-9::dhcp' -initrd /fs/sdc1/initrd-vm-lkp-wsx03-2G-9 -m 2048 -smp 2 -device e1000,netdev=net0 -netdev user,id=net0,hostfwd=tcp::23628-:22 -boot order=nc -no-reboot -watchdog i6300esb -rtc base=localtime -drive file=/fs/sdc1/disk0-vm-lkp-wsx03-2G-9,media=disk,if=virtio -drive file=/fs/sdc1/disk1-vm-lkp-wsx03-2G-9,media=disk,if=virtio -pidfile /dev/shm/kboot/pid-vm-lkp-wsx03-2G-9 -serial file:/dev/shm/kboot/serial-vm-lkp-wsx03-2G-9 -daemonize -display none -monitor null
Thanks,
Kernel Test Robot
5 years, 3 months
[lkp] [drm/i915/vlv] ff6eee6113: WARNING: CPU: 0 PID: 194 at drivers/gpu/drm/i915/intel_uncore.c:803 __unclaimed_reg_debug+0x6d/0x80 [i915]
by kernel test robot
FYI, we noticed the following commit:
https://github.com/0day-ci/linux Chi-Ding/drm-i915-Remove-unused-parameters-from-intel_plane_wm_parameters/20160623-210225
commit ff6eee61132377c1fcf44fec29ecc7560a2a9df0 ("drm/i915/vlv: Add intermediate field in intel_crtc_wm_state and handlers for two-level watermark")
in testcase: autotest
with following parameters: test=cyclictest
on test machine: 2 threads Minnowboard Max with 2G memory
caused below changes:
<4>[ 44.549007] ------------[ cut here ]------------
<4>[ 44.549234] WARNING: CPU: 0 PID: 194 at drivers/gpu/drm/i915/intel_uncore.c:803 __unclaimed_reg_debug+0x6d/0x80 [i915]
<4>[ 44.549241] Unclaimed register detected after reading register 0x1f0030
<4>[ 44.549313] Modules linked in: sd_mod coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel i915 aesni_intel snd_hda_intel lrw gf128mul glue_helper ablk_helper cryptd video snd_hda_codec drm_kms_helper syscopyarea snd_hda_core s
ysfillrect pcspkr usb_storage snd_hwdep sysimgblt fb_sys_fops snd_pcm snd_timer snd shpchp soundcore drm
<4>[ 44.549323] CPU: 0 PID: 194 Comm: kworker/u2:2 Not tainted 4.7.0-rc2-00666-gff6eee6 #1
<4>[ 44.549340] Workqueue: events_unbound async_run_entry_fn
<4>[ 44.549354] 0000000000000000 ffff8800774f35b8 ffffffff81432c4a ffff8800774f3608
<4>[ 44.549364] 0000000000000000 ffff8800774f35f8 ffffffff8107d681 00000323a01f4c2b
<4>[ 44.549374] 00000000001f0030 0000000000000000 0000000000000001 ffff880077a30000
<4>[ 44.549376] Call Trace:
<4>[ 44.549392] [<ffffffff81432c4a>] dump_stack+0x63/0x89
<4>[ 44.549401] [<ffffffff8107d681>] __warn+0xd1/0xf0
<4>[ 44.549410] [<ffffffff8107d6ef>] warn_slowpath_fmt+0x4f/0x60
<4>[ 44.549423] [<ffffffff810b3996>] ? update_curr+0x66/0x180
<4>[ 44.549433] [<ffffffff810b3996>] ? update_curr+0x66/0x180
<4>[ 44.549634] [<ffffffffa01f4c7d>] __unclaimed_reg_debug+0x6d/0x80 [i915]
<4>[ 44.549830] [<ffffffffa01f5e24>] vlv_read32+0x284/0x2c0 [i915]
<4>[ 44.550010] [<ffffffffa01aad44>] vlv_pipe_set_fifo_size+0xa4/0x2b0 [i915]
<4>[ 44.550190] [<ffffffffa01b0ac4>] vlv_update_wm+0x614/0x6e0 [i915]
<4>[ 44.550201] [<ffffffff810b53a5>] ? put_prev_entity+0x35/0x840
<4>[ 44.550213] [<ffffffff8102c74b>] ? __switch_to+0x29b/0x5b0
<4>[ 44.550395] [<ffffffffa01b0cbd>] vlv_initial_watermarks+0x8d/0xa0 [i915]
<4>[ 44.550594] [<ffffffffa021c30a>] intel_pre_plane_update+0x11a/0x1b0 [i915]
<4>[ 44.550795] [<ffffffffa021cb3b>] intel_atomic_commit_tail+0x2cb/0x1110 [i915]
<4>[ 44.550806] [<ffffffff810c2022>] ? complete_all+0x42/0x50
<4>[ 44.550818] [<ffffffff810a38f9>] ? __might_sleep+0x49/0x80
<4>[ 44.551018] [<ffffffffa021dd24>] intel_atomic_commit+0x3a4/0x530 [i915]
<4>[ 44.551117] [<ffffffffa001f800>] ? drm_atomic_check_only+0xd0/0x640 [drm]
<4>[ 44.551207] [<ffffffffa0020277>] ? drm_atomic_add_affected_connectors+0x27/0xf0 [drm]
<4>[ 44.551297] [<ffffffffa001fda7>] drm_atomic_commit+0x37/0x60 [drm]
<4>[ 44.551345] [<ffffffffa013924c>] restore_fbdev_mode+0x14c/0x270 [drm_kms_helper]
<4>[ 44.551389] [<ffffffffa013abf3>] drm_fb_helper_restore_fbdev_mode_unlocked+0x33/0x80 [drm_kms_helper]
<4>[ 44.551432] [<ffffffffa013ac6d>] drm_fb_helper_set_par+0x2d/0x50 [drm_kms_helper]
<4>[ 44.551475] [<ffffffffa013ab78>] drm_fb_helper_hotplug_event+0xa8/0xf0 [drm_kms_helper]
<4>[ 44.551518] [<ffffffffa013ac16>] drm_fb_helper_restore_fbdev_mode_unlocked+0x56/0x80 [drm_kms_helper]
<4>[ 44.551561] [<ffffffffa013ac6d>] drm_fb_helper_set_par+0x2d/0x50 [drm_kms_helper]
<4>[ 44.551766] [<ffffffffa0236afa>] intel_fbdev_set_par+0x1a/0x60 [i915]
<4>[ 44.551778] [<ffffffff814a6413>] fbcon_init+0x533/0x5a0
<4>[ 44.551790] [<ffffffff8153e84a>] visual_init+0xca/0x130
<4>[ 44.551800] [<ffffffff81540cc7>] do_bind_con_driver+0x167/0x3a0
<4>[ 44.551812] [<ffffffff8154122f>] do_take_over_console+0x12f/0x1a0
<4>[ 44.551822] [<ffffffff814a16e7>] do_fbcon_takeover+0x57/0xb0
<4>[ 44.551831] [<ffffffff814a6e8d>] fbcon_event_notify+0x64d/0x750
<4>[ 44.551844] [<ffffffff8109ddda>] notifier_call_chain+0x4a/0x70
<4>[ 44.551855] [<ffffffff8109e127>] __blocking_notifier_call_chain+0x47/0x60
<4>[ 44.551866] [<ffffffff8109e156>] blocking_notifier_call_chain+0x16/0x20
<4>[ 44.551876] [<ffffffff814ac6db>] fb_notifier_call_chain+0x1b/0x20
<4>[ 44.551887] [<ffffffff814ae8bb>] register_framebuffer+0x24b/0x330
<4>[ 44.551932] [<ffffffffa013aec8>] drm_fb_helper_initial_config+0x238/0x3c0 [drm_kms_helper]
<4>[ 44.552130] [<ffffffffa0237d68>] intel_fbdev_initial_config+0x18/0x30 [i915]
<4>[ 44.552140] [<ffffffff8109f87a>] async_run_entry_fn+0x4a/0x140
<4>[ 44.552149] [<ffffffff810969b8>] process_one_work+0x158/0x460
<4>[ 44.552158] [<ffffffff8109761e>] worker_thread+0x4e/0x4c0
<4>[ 44.552167] [<ffffffff810975d0>] ? rescuer_thread+0x350/0x350
<4>[ 44.552175] [<ffffffff810975d0>] ? rescuer_thread+0x350/0x350
<4>[ 44.552185] [<ffffffff8109cbc4>] kthread+0xd4/0xf0
<4>[ 44.552199] [<ffffffff819177ff>] ret_from_fork+0x1f/0x40
<4>[ 44.552209] [<ffffffff8109caf0>] ? kthread_park+0x60/0x60
<4>[ 44.552216] ---[ end trace 1395d82281f53585 ]---
To reproduce:
git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
Thanks,
Xiaolong
5 years, 3 months
Re: [LKP] [lkp] [ACPI / APEI] a3e2acc5e3: kmsg.BERT:Can't_request_iomem_region<#-#>
by Ye Xiaolong
On Sun, Jul 10, 2016 at 08:28:37PM -0700, Tony Luck wrote:
>I'm very surprised that there was a BERT table on an Atom machine. More details about the machine please. Also BIOS version.
Hi, ying
Could you tell me what's BERT table? and how to check the BIOS version?
Thanks,
Xiaolong
>
>Sent from my iPhone
>
>> On Jul 10, 2016, at 18:43, kernel test robot <xiaolong.ye(a)intel.com> wrote:
>>
>>
>> FYI, we noticed the following commit:
>>
>> https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git master
>> commit a3e2acc5e37b22b6808a0b8e46887c3577de9c9e ("ACPI / APEI: Add Boot Error Record Table (BERT) support")
>>
>> in testcase: locktorture
>> with following parameters: runtime=300s
>>
>> on test machine: Atom with 8G memory
>>
>> caused below changes:
>>
>>
>> [ 12.317148] BERT: Can't request iomem region <00000000bfccfc18-00000000bfccfc2b>.
>>
>>
>>
>> To reproduce:
>>
>> git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git
>> cd lkp-tests
>> bin/lkp install job.yaml # job file is attached in this email
>> bin/lkp run job.yaml
>>
>>
>>
>> Thanks,
>> Xiaolong
>> <config-4.7.0-rc4-00003-ga3e2acc>
>> <kmsg.xz>
>> <job.yaml>
5 years, 3 months