[lkp] [rhashtable] 9e9089e5a2: rhashtable test failed for test 01
by kernel test robot
FYI, we noticed the below changes on
https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git master
commit 9e9089e5a2d788db417d4d1f836eecc2fc44e9ff ("rhashtable-test: retry insert operations")
With the commit, the rhashtable test will fail for test 01
[ 26.692179] Running rhashtable test nelem=8, max_size=65536, shrinking=0
[ 26.693565] Test 00:
[ 26.697076] Adding 50000 keys
[ 27.017234] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[ 27.276248] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[ 27.278414] Deleting 50000 keys
[ 27.441366] Duration of test: 743500784 ns
[ 27.442701] Test 01:
[ 27.459301] Adding 50000 keys
[ 27.651878] Test failed: return code -12
But the parent commit passed test 01, failed for OOM when "Testing
concurrent rhashtable access" as below.
[ 19.973157] Running rhashtable test nelem=8, max_size=65536, shrinking=0
[ 19.974656] Test 00:
[ 19.978130] Adding 50000 keys
[ 20.168275] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[ 20.286450] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[ 20.288413] Deleting 50000 keys
[ 20.364808] Duration of test: 385834085 ns
[ 20.366042] Test 01:
[ 20.369412] Adding 50000 keys
[ 20.616114] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[ 20.791810] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[ 20.793689] Deleting 50000 keys
[ 20.933709] Duration of test: 563474738 ns
[ 20.934889] Test 02:
[ 20.938063] Adding 50000 keys
[ 21.265367] 2818 insertions failed due to memory pressure
[ 21.275442] Traversal complete: counted=47182, nelems=47182, entries=50000, table-jumps=0
[ 21.290552] Test failed: Total count mismatch ^^^
[ 21.407579] Traversal complete: counted=47182, nelems=47182, entries=50000, table-jumps=0
[ 21.409984] Test failed: Total count mismatch ^^^
[ 21.410886] Deleting 50000 keys
[ 21.549253] Duration of test: 610400037 ns
[ 21.550601] Test 03:
[ 21.553993] Adding 50000 keys
[ 21.732273] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[ 21.861057] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[ 21.863964] Deleting 50000 keys
[ 22.033796] Duration of test: 478844962 ns
[ 22.035185] Average test time: 509638455
[ 22.036198] Testing concurrent rhashtable access from 10 threads
[ 22.039738] swapper/0 invoked oom-killer: gfp_mask=0x24082c2, order=0, oom_score_adj=0
[ 22.054770] swapper/0 cpuset=/ mems_allowed=0
[ 22.056167] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.4.0-rc1-00169-gcd5b318 #2
[ 22.058034] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 22.060107] 0000000000000000 ffff88000ed8f878 ffffffff81a4dfda ffff88000ed8fb80
[ 22.062408] ffff88000ed8f8e0 ffffffff813ae1ad ffff88000ed80000 0000000200000001
[ 22.064687] ffff88000ed8fb80 ffff8800003dda00 0000000000004e75 ffffffff813143bd
[ 22.066937] Call Trace:
[ 22.071200] [<ffffffff81a4dfda>] dump_stack+0x7c/0xb2
[ 22.072430] [<ffffffff813ae1ad>] dump_header+0x9b/0x3ec
[ 22.073773] [<ffffffff813143bd>] ? out_of_memory+0x6cd/0xa90
[ 22.075111] [<ffffffff8131443e>] out_of_memory+0x74e/0xa90
[ 22.076410] [<ffffffff81314194>] ? out_of_memory+0x4a4/0xa90
[ 22.077732] [<ffffffff81313cf0>] ? unregister_oom_notifier+0x30/0x30
[ 22.079199] [<ffffffff81320310>] __alloc_pages_nodemask+0x15d0/0x1600
[ 22.080665] [<ffffffff8131ed40>] ? __alloc_pages_direct_compact+0x1d0/0x1d0
[ 22.082233] [<ffffffff811fbe07>] ? set_next_entity+0x127/0x1060
[ 22.096681] [<ffffffff811f75d7>] ? put_prev_entity+0x47/0xf00
[ 22.098049] [<ffffffff81222ad4>] ? __lock_acquire+0x7e4/0x1a00
[ 22.099522] [<ffffffff811de325>] ? finish_task_switch+0x165/0x590
[ 22.100911] [<ffffffff812296fe>] ? do_raw_spin_unlock+0xae/0x1c0
[ 22.102336] [<ffffffff81a77e3f>] ? _find_next_bit+0x4f/0x110
[ 22.103659] [<ffffffff81a77f7f>] ? find_first_bit+0x2f/0xb0
[ 22.105005] [<ffffffff8138bc44>] alloc_page_interleave+0x64/0x100
[ 22.106404] [<ffffffff8138f72f>] alloc_pages_current+0x22f/0x320
[ 22.107783] [<ffffffff81379741>] __vmalloc_node_range+0x371/0x520
[ 22.109218] [<ffffffff890087c9>] ? test_rht_init+0x25c/0x4f1
[ 22.123631] [<ffffffff81379a1f>] vzalloc+0x5f/0x70
[ 22.124835] [<ffffffff890087c9>] ? test_rht_init+0x25c/0x4f1
[ 22.138896] [<ffffffff890087c9>] test_rht_init+0x25c/0x4f1
[ 22.140206] [<ffffffff8139bc0e>] ? kfree+0x1de/0x210
[ 22.141433] [<ffffffff8900856d>] ? test_rhashtable+0xc82/0xc82
[ 22.142964] [<ffffffff88fb5a6c>] do_one_initcall+0x213/0x322
[ 22.144283] [<ffffffff88fb5859>] ? start_kernel+0x824/0x824
[ 22.145621] [<ffffffff811d21ed>] ? parameq+0x3d/0xc0
[ 22.146822] [<ffffffff811d2662>] ? parse_args+0x3f2/0x770
[ 22.148126] [<ffffffff88fb5ee7>] kernel_init_freeable+0x36c/0x474
[ 22.149532] [<ffffffff843a0bd0>] ? rest_init+0x140/0x140
[ 22.150794] [<ffffffff843a0be6>] kernel_init+0x16/0x1b0
[ 22.165118] [<ffffffff843a0bd0>] ? rest_init+0x140/0x140
[ 22.166402] [<ffffffff843ae74f>] ret_from_fork+0x3f/0x70
[ 22.167661] [<ffffffff843a0bd0>] ? rest_init+0x140/0x140
Thanks,
Ying Huang
5 years, 9 months
[lkp] [f2fs] 957efb0c21: No primary result change, -15.1% fsmark.time.voluntary_context_switches
by kernel test robot
FYI, we noticed the below changes on
https://git.kernel.org/pub/scm/linux/kernel/git/jaegeuk/f2fs dev-test
commit 957efb0c2144cc5ff1795f43bf2d2ca430eaa227 ("Revert "f2fs: check the node block address of newly allocated nid"")
=========================================================================================
compiler/cpufreq_governor/disk/filesize/fs/iterations/kconfig/nr_directories/nr_files_per_directory/nr_threads/rootfs/sync_method/tbox_group/test_size/testcase:
gcc-4.9/performance/1HDD/9B/f2fs/1x/x86_64-rhel/16d/256fpd/32t/debian-x86_64-2015-02-07.cgz/fsyncBeforeClose/lkp-ne04/400M/fsmark
commit:
a51311938e14c17f5a94d30baac9d7bec71f5858
957efb0c2144cc5ff1795f43bf2d2ca430eaa227
a51311938e14c17f 957efb0c2144cc5ff1795f43bf
---------------- --------------------------
%stddev %change %stddev
\ | \
5699822 ± 2% -23.2% 4375176 ± 5% fsmark.app_overhead
1853986 ± 0% +1.0% 1872422 ± 0% fsmark.time.file_system_outputs
60.75 ± 0% -21.4% 47.75 ± 0% fsmark.time.percent_of_cpu_this_job_got
47.56 ± 0% -21.8% 37.18 ± 1% fsmark.time.system_time
1021602 ± 0% -15.1% 867006 ± 0% fsmark.time.voluntary_context_switches
5171 ± 0% +17.5% 6076 ± 1% proc-vmstat.numa_pte_updates
31334 ± 2% -9.1% 28485 ± 3% softirqs.RCU
60.75 ± 0% -21.4% 47.75 ± 0% time.percent_of_cpu_this_job_got
47.56 ± 0% -21.8% 37.18 ± 1% time.system_time
1021602 ± 0% -15.1% 867006 ± 0% time.voluntary_context_switches
6278 ± 0% +1.8% 6390 ± 0% vmstat.io.bo
25379 ± 1% -13.9% 21840 ± 0% vmstat.system.cs
1735 ± 0% -3.6% 1672 ± 0% vmstat.system.in
2341 ±151% +263.3% 8505 ± 0% numa-meminfo.node0.Inactive(anon)
6544 ± 25% +43.9% 9414 ± 0% numa-meminfo.node0.Mapped
2516 ±141% +246.0% 8705 ± 1% numa-meminfo.node0.Shmem
80851 ± 8% -11.5% 71514 ± 1% numa-meminfo.node0.Slab
584.50 ±151% +263.7% 2125 ± 0% numa-vmstat.node0.nr_inactive_anon
1635 ± 25% +43.8% 2352 ± 0% numa-vmstat.node0.nr_mapped
628.25 ±141% +246.3% 2175 ± 1% numa-vmstat.node0.nr_shmem
2080 ± 11% -21.5% 1634 ± 21% numa-vmstat.node0.numa_other
1.173e+08 ± 4% +22.9% 1.441e+08 ± 3% cpuidle.C1-NHM.time
36242421 ± 3% +13.6% 41189247 ± 1% cpuidle.C1E-NHM.time
4.531e+08 ± 2% -22.3% 3.522e+08 ± 2% cpuidle.C3-NHM.time
447937 ± 0% -27.5% 324877 ± 1% cpuidle.C3-NHM.usage
6.434e+08 ± 1% +12.2% 7.221e+08 ± 1% cpuidle.C6-NHM.time
139.75 ± 5% -19.3% 112.75 ± 5% cpuidle.POLL.usage
3.96 ± 0% -18.7% 3.21 ± 1% turbostat.%Busy
88.25 ± 1% -13.6% 76.25 ± 1% turbostat.Avg_MHz
24.30 ± 2% +9.5% 26.61 ± 2% turbostat.CPU%c1
39.26 ± 3% -23.4% 30.08 ± 2% turbostat.CPU%c3
32.49 ± 2% +23.4% 40.10 ± 1% turbostat.CPU%c6
12.66 ± 5% -17.4% 10.46 ± 5% turbostat.Pkg%pc3
58968 ± 0% -100.0% 0.00 ± -1% latency_stats.hits.call_rwsem_down_read_failed.get_node_info.[f2fs].alloc_nid.[f2fs].f2fs_new_inode.[f2fs].f2fs_create.[f2fs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
78507 ± 0% -100.0% 0.00 ± -1% latency_stats.hits.call_rwsem_down_write_failed.get_node_info.[f2fs].alloc_nid.[f2fs].f2fs_new_inode.[f2fs].f2fs_create.[f2fs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 77032 ± 0% latency_stats.hits.call_rwsem_down_write_failed.get_node_info.[f2fs].new_node_page.[f2fs].new_inode_page.[f2fs].init_inode_metadata.[f2fs].__f2fs_add_link.[f2fs].f2fs_create.[f2fs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open
62300 ± 37% -85.0% 9341 ± 28% latency_stats.sum.call_rwsem_down_read_failed.f2fs_mkdir.[f2fs].vfs_mkdir.SyS_mkdir.entry_SYSCALL_64_fastpath
24001862 ± 1% -100.0% 0.00 ± -1% latency_stats.sum.call_rwsem_down_read_failed.get_node_info.[f2fs].alloc_nid.[f2fs].f2fs_new_inode.[f2fs].f2fs_create.[f2fs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
80814 ± 5% -100.0% 0.00 ± -1% latency_stats.sum.call_rwsem_down_read_failed.get_node_info.[f2fs].alloc_nid.[f2fs].f2fs_new_inode.[f2fs].f2fs_mkdir.[f2fs].vfs_mkdir.SyS_mkdir.entry_SYSCALL_64_fastpath
251.50 ± 87% +5565.6% 14249 ± 34% latency_stats.sum.call_rwsem_down_write_failed.f2fs_init_extent_tree.[f2fs].f2fs_new_inode.[f2fs].f2fs_create.[f2fs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
35549488 ± 1% -100.0% 0.00 ± -1% latency_stats.sum.call_rwsem_down_write_failed.get_node_info.[f2fs].alloc_nid.[f2fs].f2fs_new_inode.[f2fs].f2fs_create.[f2fs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath
116197 ± 3% -100.0% 0.00 ± -1% latency_stats.sum.call_rwsem_down_write_failed.get_node_info.[f2fs].alloc_nid.[f2fs].f2fs_new_inode.[f2fs].f2fs_mkdir.[f2fs].vfs_mkdir.SyS_mkdir.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 25888690 ± 1% latency_stats.sum.call_rwsem_down_write_failed.get_node_info.[f2fs].new_node_page.[f2fs].new_inode_page.[f2fs].init_inode_metadata.[f2fs].__f2fs_add_link.[f2fs].f2fs_create.[f2fs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open
0.00 ± -1% +Inf% 93688 ± 8% latency_stats.sum.call_rwsem_down_write_failed.get_node_info.[f2fs].new_node_page.[f2fs].new_inode_page.[f2fs].init_inode_metadata.[f2fs].__f2fs_add_link.[f2fs].f2fs_mkdir.[f2fs].vfs_mkdir.SyS_mkdir.entry_SYSCALL_64_fastpath
4443 ± 20% -39.4% 2691 ± 2% sched_debug.cfs_rq:/.exec_clock.0
1232 ± 12% -24.1% 935.06 ± 5% sched_debug.cfs_rq:/.exec_clock.11
1114 ± 4% -19.8% 894.19 ± 8% sched_debug.cfs_rq:/.exec_clock.13
2510 ± 15% -20.5% 1996 ± 12% sched_debug.cfs_rq:/.exec_clock.4
2238 ± 0% -10.9% 1994 ± 0% sched_debug.cfs_rq:/.exec_clock.avg
1043 ± 1% -17.5% 861.26 ± 6% sched_debug.cfs_rq:/.exec_clock.min
8895 ± 13% -30.2% 6209 ± 1% sched_debug.cfs_rq:/.min_vruntime.0
4162 ± 9% -38.2% 2571 ± 6% sched_debug.cfs_rq:/.min_vruntime.11
3832 ± 4% -28.4% 2742 ± 11% sched_debug.cfs_rq:/.min_vruntime.13
7383 ± 8% -32.7% 4965 ± 25% sched_debug.cfs_rq:/.min_vruntime.3
8619 ± 36% -40.6% 5122 ± 3% sched_debug.cfs_rq:/.min_vruntime.4
11149 ± 40% -56.2% 4887 ± 8% sched_debug.cfs_rq:/.min_vruntime.7
4394 ± 6% -30.0% 3074 ± 7% sched_debug.cfs_rq:/.min_vruntime.8
4383 ± 21% -31.8% 2991 ± 13% sched_debug.cfs_rq:/.min_vruntime.9
6282 ± 1% -21.0% 4963 ± 0% sched_debug.cfs_rq:/.min_vruntime.avg
3475 ± 1% -30.5% 2416 ± 4% sched_debug.cfs_rq:/.min_vruntime.min
16.50 ±131% -92.4% 1.25 ±173% sched_debug.cfs_rq:/.runnable_load_avg.5
-5301 ±-20% -51.4% -2577 ±-23% sched_debug.cfs_rq:/.spread0.12
-5063 ±-22% -39.0% -3089 ±-20% sched_debug.cfs_rq:/.spread0.15
-2654 ±-32% -90.8% -243.56 ±-336% sched_debug.cfs_rq:/.spread0.6
-4501 ±-22% -30.4% -3134 ±-10% sched_debug.cfs_rq:/.spread0.8
15693 ± 8% -11.6% 13871 ± 9% sched_debug.cpu.nr_load_updates.0
10558 ± 3% -13.3% 9151 ± 2% sched_debug.cpu.nr_load_updates.10
10664 ± 1% -14.9% 9070 ± 2% sched_debug.cpu.nr_load_updates.11
10412 ± 1% -12.2% 9140 ± 1% sched_debug.cpu.nr_load_updates.12
10568 ± 0% -13.5% 9144 ± 1% sched_debug.cpu.nr_load_updates.13
10602 ± 0% -14.5% 9068 ± 2% sched_debug.cpu.nr_load_updates.15
14807 ± 9% -21.5% 11625 ± 9% sched_debug.cpu.nr_load_updates.3
14728 ± 9% -16.2% 12336 ± 3% sched_debug.cpu.nr_load_updates.4
13550 ± 9% -16.9% 11264 ± 10% sched_debug.cpu.nr_load_updates.5
10461 ± 1% -11.5% 9259 ± 2% sched_debug.cpu.nr_load_updates.8
10854 ± 1% -15.0% 9222 ± 1% sched_debug.cpu.nr_load_updates.9
12483 ± 0% -11.9% 11002 ± 0% sched_debug.cpu.nr_load_updates.avg
10206 ± 1% -17.0% 8471 ± 2% sched_debug.cpu.nr_load_updates.min
70384 ± 1% -10.9% 62687 ± 4% sched_debug.cpu.nr_switches.0
37725 ± 1% -19.1% 30535 ± 2% sched_debug.cpu.nr_switches.11
40729 ± 4% -9.3% 36933 ± 2% sched_debug.cpu.nr_switches.12
38235 ± 2% -20.2% 30507 ± 1% sched_debug.cpu.nr_switches.13
38149 ± 0% -21.6% 29911 ± 2% sched_debug.cpu.nr_switches.15
62122 ± 6% -20.8% 49171 ± 5% sched_debug.cpu.nr_switches.3
67546 ± 5% -15.2% 57293 ± 4% sched_debug.cpu.nr_switches.4
63223 ± 7% -18.4% 51620 ± 4% sched_debug.cpu.nr_switches.5
39171 ± 3% -23.5% 29966 ± 1% sched_debug.cpu.nr_switches.9
52157 ± 1% -13.3% 45227 ± 1% sched_debug.cpu.nr_switches.avg
73302 ± 2% -8.5% 67039 ± 1% sched_debug.cpu.nr_switches.max
37405 ± 1% -20.7% 29653 ± 1% sched_debug.cpu.nr_switches.min
-11351 ± -6% -41.6% -6624 ± -5% sched_debug.cpu.nr_uninterruptible.0
2139 ± 7% -25.9% 1584 ± 8% sched_debug.cpu.nr_uninterruptible.10
2171 ± 7% -41.3% 1274 ± 9% sched_debug.cpu.nr_uninterruptible.11
2160 ± 9% -14.2% 1854 ± 2% sched_debug.cpu.nr_uninterruptible.12
2336 ± 9% -40.1% 1400 ± 5% sched_debug.cpu.nr_uninterruptible.13
2344 ± 9% -19.5% 1886 ± 4% sched_debug.cpu.nr_uninterruptible.14
2254 ± 5% -37.5% 1408 ± 5% sched_debug.cpu.nr_uninterruptible.15
-1447 ± -5% -18.8% -1174 ±-13% sched_debug.cpu.nr_uninterruptible.3
-187.00 ±-92% +111.1% -394.75 ±-18% sched_debug.cpu.nr_uninterruptible.4
-1690 ± -4% -30.0% -1182 ±-10% sched_debug.cpu.nr_uninterruptible.5
-1455 ± -9% -18.4% -1187 ± -7% sched_debug.cpu.nr_uninterruptible.7
1982 ± 2% -33.2% 1323 ± 12% sched_debug.cpu.nr_uninterruptible.8
2342 ± 5% -38.6% 1438 ± 2% sched_debug.cpu.nr_uninterruptible.9
2513 ± 8% -23.1% 1934 ± 2% sched_debug.cpu.nr_uninterruptible.max
-11352 ± -6% -41.6% -6625 ± -5% sched_debug.cpu.nr_uninterruptible.min
3333 ± 5% -37.8% 2074 ± 3% sched_debug.cpu.nr_uninterruptible.stddev
64594 ± 4% -13.4% 55961 ± 9% sched_debug.cpu.sched_count.1
37747 ± 1% -19.1% 30556 ± 2% sched_debug.cpu.sched_count.11
40752 ± 4% -9.3% 36955 ± 2% sched_debug.cpu.sched_count.12
38258 ± 2% -19.7% 30739 ± 0% sched_debug.cpu.sched_count.13
38303 ± 1% -21.9% 29929 ± 2% sched_debug.cpu.sched_count.15
65140 ± 8% -21.6% 51079 ± 6% sched_debug.cpu.sched_count.3
83422 ± 34% -29.9% 58520 ± 3% sched_debug.cpu.sched_count.4
95088 ± 36% -41.7% 55482 ± 13% sched_debug.cpu.sched_count.7
39933 ± 6% -24.9% 29988 ± 1% sched_debug.cpu.sched_count.9
37427 ± 1% -20.7% 29673 ± 1% sched_debug.cpu.sched_count.min
30342 ± 1% -10.4% 27183 ± 4% sched_debug.cpu.sched_goidle.0
16587 ± 13% -15.6% 14005 ± 4% sched_debug.cpu.sched_goidle.10
15173 ± 1% -19.2% 12260 ± 2% sched_debug.cpu.sched_goidle.11
15803 ± 4% -10.5% 14137 ± 1% sched_debug.cpu.sched_goidle.12
15371 ± 2% -20.6% 12208 ± 1% sched_debug.cpu.sched_goidle.13
15353 ± 1% -22.9% 11829 ± 2% sched_debug.cpu.sched_goidle.15
27813 ± 6% -22.0% 21689 ± 5% sched_debug.cpu.sched_goidle.3
29571 ± 6% -17.0% 24532 ± 4% sched_debug.cpu.sched_goidle.4
28495 ± 8% -19.8% 22843 ± 5% sched_debug.cpu.sched_goidle.5
15828 ± 3% -24.9% 11887 ± 2% sched_debug.cpu.sched_goidle.9
22047 ± 1% -14.3% 18903 ± 0% sched_debug.cpu.sched_goidle.avg
32479 ± 3% -8.7% 29652 ± 3% sched_debug.cpu.sched_goidle.max
14845 ± 1% -20.9% 11738 ± 1% sched_debug.cpu.sched_goidle.min
34654 ± 7% -21.2% 27307 ± 7% sched_debug.cpu.ttwu_count.1
18674 ± 8% -18.4% 15244 ± 2% sched_debug.cpu.ttwu_count.10
16391 ± 3% -15.9% 13784 ± 3% sched_debug.cpu.ttwu_count.11
18849 ± 6% -15.1% 16000 ± 4% sched_debug.cpu.ttwu_count.12
19348 ± 18% -25.2% 14469 ± 10% sched_debug.cpu.ttwu_count.13
34534 ± 4% -24.5% 26061 ± 2% sched_debug.cpu.ttwu_count.3
34388 ± 3% -20.8% 27222 ± 8% sched_debug.cpu.ttwu_count.5
33995 ± 2% -18.2% 27821 ± 6% sched_debug.cpu.ttwu_count.7
17553 ± 7% -9.8% 15835 ± 1% sched_debug.cpu.ttwu_count.8
17278 ± 3% -15.5% 14604 ± 7% sched_debug.cpu.ttwu_count.9
29489 ± 1% -12.9% 25686 ± 1% sched_debug.cpu.ttwu_count.avg
16005 ± 1% -18.1% 13115 ± 1% sched_debug.cpu.ttwu_count.min
28738 ± 1% -21.6% 22523 ± 7% sched_debug.cpu.ttwu_local.0
4013 ± 2% -9.8% 3620 ± 1% sched_debug.cpu.ttwu_local.13
4091 ± 0% -10.2% 3674 ± 3% sched_debug.cpu.ttwu_local.15
8228 ± 16% -26.4% 6054 ± 6% sched_debug.cpu.ttwu_local.3
4115 ± 5% -13.8% 3547 ± 3% sched_debug.cpu.ttwu_local.9
7392 ± 1% -10.8% 6593 ± 1% sched_debug.cpu.ttwu_local.avg
29446 ± 2% -19.4% 23729 ± 4% sched_debug.cpu.ttwu_local.max
3903 ± 0% -13.4% 3382 ± 3% sched_debug.cpu.ttwu_local.min
6008 ± 2% -21.6% 4709 ± 6% sched_debug.cpu.ttwu_local.stddev
lkp-ne04: Nehalem-EP
Memory: 12G
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
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,
Ying Huang
5 years, 9 months
[lkp] [drm/i915] 396e33ae20: [drm:intel_set_cpu_fifo_underrun_reporting [i915]] *ERROR* uncleared fifo underrun on pipe B
by kernel test robot
FYI, we noticed the below changes on
git://anongit.freedesktop.org/drm-intel drm-intel-next-queued
commit 396e33ae204f52abebec9e578f44c749305500f4 ("drm/i915: Add two-stage ILK-style watermark programming (v10)")
+--------------------------------------------------+------------+------------+
| | 2dfb0b816d | 396e33ae20 |
+--------------------------------------------------+------------+------------+
| boot_successes | 8 | 19 |
| boot_failures | 0 | 4 |
| drm:intel_set_cpu_fifo_underrun_reporting[i915]] | 0 | 4 |
| drm:intel_cpu_fifo_underrun_irq_handler[i915]] | 0 | 4 |
| drm:intel_set_pch_fifo_underrun_reporting[i915]] | 0 | 4 |
| drm:intel_pch_fifo_underrun_irq_handler[i915]] | 0 | 4 |
+--------------------------------------------------+------------+------------+
[ 36.077826] NFS: Registering the id_resolver key type
[ 36.078178] Key type id_resolver registered
[ 36.078444] Key type id_legacy registered
[ 60.884026] [drm:intel_set_cpu_fifo_underrun_reporting [i915]] *ERROR* uncleared fifo underrun on pipe B
[ 60.884659] [drm:intel_cpu_fifo_underrun_irq_handler [i915]] *ERROR* CPU pipe B FIFO underrun
[ 60.885221] [drm:intel_set_pch_fifo_underrun_reporting [i915]] *ERROR* uncleared pch fifo underrun on pch transcoder B
[ 60.885887] [drm:intel_pch_fifo_underrun_irq_handler [i915]] *ERROR* PCH transcoder B FIFO underrun
[ 61.180651] random: nonblocking pool is initialized
[ 81.430503] [drm:intel_set_cpu_fifo_underrun_reporting [i915]] *ERROR* uncleared fifo underrun on pipe C
[ 81.431193] [drm:intel_cpu_fifo_underrun_irq_handler [i915]] *ERROR* CPU pipe C FIFO underrun
[ 81.431782] [drm:intel_set_pch_fifo_underrun_reporting [i915]] *ERROR* uncleared pch fifo underrun on pch transcoder C
[ 81.432474] [drm:intel_pch_fifo_underrun_irq_handler [i915]] *ERROR* PCH transcoder C FIFO underrun
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,
Kernel Test Robot
5 years, 9 months
[x86/mm] c4125ff633: WARNING: CPU: 0 PID: 0 at arch/x86/kernel/cpu/common.c:1520 warn_pre_alternatives()
by kernel test robot
Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
https://git.kernel.org/pub/scm/linux/kernel/git/luto/linux.git x86/pcid
commit c4125ff6333c97d3ce00e5886b809b7c20594585
Author: Andy Lutomirski <luto(a)kernel.org>
AuthorDate: Sat Dec 19 22:20:32 2015 -0800
Commit: Andy Lutomirski <luto(a)kernel.org>
CommitDate: Fri Jan 8 15:11:27 2016 -0800
x86/mm: Try to preserve old TLB entries using PCID
PCID is a "process context ID" -- it's what other architectures call
an address space ID. Every non-global TLB entry is tagged with a
PCID, only TLB entries that match the currently selected PCID are
used, and we can switch PGDs without flushing the TLB. x86's
PCID is 12 bits.
This is an unorthodox approach to using PCID. x86's PCID is far too
short to uniquely identify a process, and we can't even really
uniquely identify a running process because there are monster
systems with over 4096 CPUs. To make matters worse, past attempts
to use all 12 PCID bits have resulted in slowdowns instead of
speedups.
This patch uses PCID differently. We use a PCID to identify a
recently-used mm on a per-cpu basis. An mm has no fixed PCID
binding at all; instead, we give it a fresh PCID each time it's
loaded except in cases where we want to preserve the TLB, in which
case we reuse a recent value.
In particular, we use PCIDs 1-7 for recently-used mms and we reserve
PCID 0 for swapper_pg_dir and for PCID-unaware CR3 users (e.g. EFI).
Nothing ever switches to PCID 0 without flushing PCID 0 non-global
pages, so PCID 0 conflicts won't cause problems.
This also leaves the door open for UDEREF-style address space
switching: the kernel will use PCID 0, and exits could simply switch
back. (As a practical matter, an in-tree implementation of that
feature would probably forego the full syscall fast path and just
invoke some or all of switch_mm in prepare_exit_to_usermode.)
This seems to save about 100ns on context switches between mms.
Signed-off-by: Andy Lutomirski <luto(a)kernel.org>
+------------------------------------------------------------------+------------+------------+------------+
| | df4b08184f | c4125ff633 | 7246a44772 |
+------------------------------------------------------------------+------------+------------+------------+
| boot_successes | 6 | 0 | 0 |
| boot_failures | 92 | 10 | 13 |
| WARNING:at_arch/x86/mm/dump_pagetables.c:#note_page() | 92 | 4 | 13 |
| backtrace:mark_rodata_ro | 92 | 4 | 13 |
| IP-Config:Auto-configuration_of_network_failed | 4 | 4 | |
| WARNING:at_arch/x86/kernel/cpu/common.c:#warn_pre_alternatives() | 0 | 10 | 13 |
| backtrace:zap_old_pcids | 0 | 10 | 13 |
| backtrace:kernel_physical_mapping_init | 0 | 10 | 13 |
| backtrace:init_memory_mapping | 0 | 10 | 13 |
| backtrace:init_mem_mapping | 0 | 10 | 13 |
| backtrace:init_range_memory_mapping | 0 | 10 | 13 |
| backtrace:page_table_range_init | 0 | 10 | 13 |
| backtrace:early_ioremap_page_table_range_init | 0 | 10 | 13 |
| backtrace:paging_init | 0 | 10 | 13 |
| backtrace:native_pagetable_init | 0 | 10 | 13 |
+------------------------------------------------------------------+------------+------------+------------+
early console in setup code
[ 0.000000] Linux version 4.4.0-rc5-00013-gc4125ff (kbuild@lkp-ib04) (gcc version 5.2.1 20150911 (Debian 5.2.1-17) ) #1 SMP Sat Jan 9 08:38:41 CST 2016
[ 0.000000] ------------[ cut here ]------------
[ 0.000000] WARNING: CPU: 0 PID: 0 at arch/x86/kernel/cpu/common.c:1520 warn_pre_alternatives+0x17/0x1c()
[ 0.000000] You're using static_cpu_has before alternatives have run!
[ 0.000000] Modules linked in:
[ 0.000000] CPU: 0 PID: 0 Comm: swapper Not tainted 4.4.0-rc5-00013-gc4125ff #1
[ 0.000000] 00000000 00000000 41625f34 41231c0a 41625f5c 41625f4c 41033c67 4100d0e4
[ 0.000000] 00000000 41627020 416f4020 41625f64 41033ca4 00000009 41625f5c 4155e269
[ 0.000000] 41625f78 41625f78 4100d0e4 4155e2a4 000005f0 4155e269 41625f84 410279fd
[ 0.000000] Call Trace:
[ 0.000000] [<41231c0a>] dump_stack+0x48/0x60
[ 0.000000] [<41033c67>] warn_slowpath_common+0x79/0x90
[ 0.000000] [<4100d0e4>] ? warn_pre_alternatives+0x17/0x1c
[ 0.000000] [<41033ca4>] warn_slowpath_fmt+0x26/0x2a
[ 0.000000] [<4100d0e4>] warn_pre_alternatives+0x17/0x1c
[ 0.000000] [<410279fd>] zap_old_pcids+0x1d/0x40
[ 0.000000] [<4168e2a3>] setup_arch+0xe3/0xb5f
[ 0.000000] [<410750cc>] ? vprintk_emit+0x469/0x49d
[ 0.000000] [<4168b7f7>] start_kernel+0x88/0x3bd
[ 0.000000] [<4168b2c7>] i386_start_kernel+0x91/0x95
[ 0.000000] ---[ end trace cb88537fdc8fa200 ]---
[ 0.000000] KERNEL supported cpus:
git bisect start 7246a4477267b8a2347212b8c046a68a41d2debc 168309855a7d1e16db751e9c647119fe2d2dc878 --
git bisect bad 3125083f93ee9606c4da71d32e7268ead3cb8b61 # 08:07 0- 11 Merge 'bluetooth-next/master' into devel-catchup-201601090719
git bisect good 09333fb3345b47a55fef29c9648c6ef541757dbb # 08:12 22+ 24 Merge 'linux-review/Douglas-Anderson/dma-mapping-Patches-for-speeding-up-allocation/20160109-071110' into devel-catchup-201601090719
git bisect good 04b969a74033f896596aed80fa700082551ea3c7 # 08:19 22+ 24 Merge 'mkp-scsi/4.5/scsi-queue' into devel-catchup-201601090719
git bisect bad 13e75c84fd26cecfc47f349de90295d174d29a77 # 08:22 0- 24 Merge 'luto/x86/pcid' into devel-catchup-201601090719
git bisect good 7752daf506becd3b36e768bd2561f562f64d9d16 # 08:31 22+ 22 x86/mm: Add nopcid to turn off PCID
git bisect good 357b13bf9d6d04e585894ff5dcf40fa14ea1d3a7 # 08:36 22+ 22 x86/mm: Factor out remote TLB flushing
git bisect good df4b08184f61f5b87deb065ab87e56699009253d # 08:47 21+ 21 x86/mm: Uninline switch_mm
git bisect bad c4125ff6333c97d3ce00e5886b809b7c20594585 # 08:47 0- 6 x86/mm: Try to preserve old TLB entries using PCID
# first bad commit: [c4125ff6333c97d3ce00e5886b809b7c20594585] x86/mm: Try to preserve old TLB entries using PCID
git bisect good df4b08184f61f5b87deb065ab87e56699009253d # 08:49 67+ 90 x86/mm: Uninline switch_mm
# extra tests with DEBUG_INFO
git bisect bad c4125ff6333c97d3ce00e5886b809b7c20594585 # 09:28 0- 2 x86/mm: Try to preserve old TLB entries using PCID
# extra tests on HEAD of linux-devel/devel-catchup-201601090719
git bisect bad 7246a4477267b8a2347212b8c046a68a41d2debc # 09:28 0- 13 0day head guard for 'devel-catchup-201601090719'
# extra tests on tree/branch luto/x86/pcid
git bisect bad c4125ff6333c97d3ce00e5886b809b7c20594585 # 09:31 0- 6 x86/mm: Try to preserve old TLB entries using PCID
# extra tests with first bad commit reverted
git bisect good ac3fc3ed7b4484e5b18135a8a1d904b063fe5ad5 # 09:50 60+ 65 Revert "x86/mm: Try to preserve old TLB entries using PCID"
# extra tests on tree/branch linus/master
git bisect good 44d8a7d5c1b4f9e99c5601217ce03a48412f9aac # 09:53 66+ 68 Merge tag 'fixes-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/arm/arm-soc
# extra tests on tree/branch linux-next/master
git bisect good e04c94f10a05003e5b6f2978efcc37b282483c2f # 09:57 66+ 72 Add linux-next specific files for 20160108
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
5 years, 9 months
[lkp] [x86] ee30ee7d85: No primary change, +1.3e+05% latency_stats.max.call_rwsem_down_read_failed.__do_page_fault.do_page_fault.page_fault
by kernel test robot
FYI, we noticed the below changes on
https://git.kernel.org/pub/scm/linux/kernel/git/mst/vhost.git vhost
commit ee30ee7d85844d6bcbe9c415aa0fd4f45965f9ae ("x86: faster smp_store_mb")
=========================================================================================
compiler/cpufreq_governor/kconfig/rootfs/tbox_group/test/testcase:
gcc-4.9/performance/x86_64-rhel/debian-x86_64-2015-02-07.cgz/lkp-sbx04/malloc1/will-it-scale
commit:
534610d30de2dbeadd95e7114b3359706d00f310
ee30ee7d85844d6bcbe9c415aa0fd4f45965f9ae
534610d30de2dbea ee30ee7d85844d6bcbe9c415aa
---------------- --------------------------
%stddev %change %stddev
\ | \
7744024 ± 2% -12.7% 6762131 ± 3% will-it-scale.time.minor_page_faults
65.90 ± 1% -62.4% 24.80 ± 14% will-it-scale.time.percent_of_cpu_this_job_got
197.31 ± 0% -61.1% 76.69 ± 13% will-it-scale.time.system_time
4023331 ± 10% -58.3% 1677070 ± 44% will-it-scale.time.voluntary_context_switches
40233 ± 3% -11.3% 35694 ± 2% meminfo.AnonPages
1.11 ± 2% -27.0% 0.81 ± 3% perf-profile.cycles.___might_sleep.unmap_page_range.unmap_single_vma.unmap_vmas.unmap_region
266441 ± 0% -17.5% 219888 ± 1% softirqs.SCHED
28363 ± 9% -54.9% 12790 ± 36% vmstat.system.cs
75089004 ± 12% -23.3% 57610269 ± 15% cpuidle.C1E-SNB.time
84309738 ± 21% -65.2% 29302414 ± 33% cpuidle.C3-SNB.time
240817 ± 18% -55.5% 107182 ± 34% cpuidle.C3-SNB.usage
3396236 ± 5% -68.6% 1066497 ± 11% cpuidle.C7-SNB.usage
7744024 ± 2% -12.7% 6762131 ± 3% time.minor_page_faults
65.90 ± 1% -62.4% 24.80 ± 14% time.percent_of_cpu_this_job_got
197.31 ± 0% -61.1% 76.69 ± 13% time.system_time
7.91 ± 2% -43.8% 4.45 ± 8% time.user_time
4023331 ± 10% -58.3% 1677070 ± 44% time.voluntary_context_switches
878.20 ± 6% +3034.3% 27525 ±115% latency_stats.avg.call_rwsem_down_write_failed.SyS_mprotect.entry_SYSCALL_64_fastpath
7476 ± 24% +1.3e+05% 9630396 ± 1% latency_stats.max.call_rwsem_down_read_failed.__do_page_fault.do_page_fault.page_fault
3808 ± 14% +88926.7% 3390761 ±106% latency_stats.max.call_rwsem_down_write_failed.SyS_mprotect.entry_SYSCALL_64_fastpath
7433 ± 24% +1.3e+05% 9588467 ± 1% latency_stats.max.call_rwsem_down_write_failed.vm_mmap_pgoff.SyS_mmap_pgoff.SyS_mmap.entry_SYSCALL_64_fastpath
7711 ± 22% +1.2e+05% 9630556 ± 1% latency_stats.max.call_rwsem_down_write_failed.vm_munmap.SyS_munmap.entry_SYSCALL_64_fastpath
158345 ± 9% +3082.3% 5039099 ±115% latency_stats.sum.call_rwsem_down_write_failed.SyS_mprotect.entry_SYSCALL_64_fastpath
10065 ± 4% -11.3% 8926 ± 2% proc-vmstat.nr_anon_pages
47481532 ± 1% -16.7% 39531036 ± 4% proc-vmstat.pgalloc_dma32
2.235e+08 ± 0% -13.0% 1.944e+08 ± 1% proc-vmstat.pgalloc_normal
2.71e+08 ± 0% -13.7% 2.339e+08 ± 1% proc-vmstat.pgfree
109024 ± 3% -67.5% 35400 ± 23% proc-vmstat.thp_fault_alloc
109006 ± 3% -67.5% 35384 ± 23% proc-vmstat.thp_split
22.48 ± 0% -6.4% 21.04 ± 2% turbostat.%Busy
647.70 ± 0% -6.0% 608.90 ± 2% turbostat.Avg_MHz
27.39 ± 7% -48.9% 14.00 ± 4% turbostat.CPU%c1
0.83 ± 35% -64.9% 0.29 ± 33% turbostat.CPU%c3
49.30 ± 4% +31.2% 64.67 ± 1% turbostat.CPU%c7
121.44 ± 0% -18.0% 99.63 ± 2% turbostat.CorWatt
0.12 ± 18% +14674.2% 17.73 ± 8% turbostat.Pkg%pc6
176.28 ± 0% -14.9% 149.97 ± 2% turbostat.PkgWatt
lkp-sbx04: Sandy Bridge-EX
Memory: 64G
latency_stats.max.call_rwsem_down_read_failed.__do_page_fault.do_page_fault.page_fault
2.5e+07 ++----------------------------------------------------------------+
| |
| O |
2e+07 ++ |
| O |
| |
1.5e+07 ++ |
| O O |
1e+07 ++ |
OOOOOOOOOOOOOOOOOOOOOOO OOO OOOOOOOO OOOOOOOOOOOOOOOOO |
| |
5e+06 ++ |
| |
| |
0 *******************************************************************
softirqs.SCHED
280000 ++-----------------------------------------------------------------+
| * |
270000 ++* :: *** *** * * ** ** * ******* ********* * * * *********** *
260000 ** * *** ** * ** * * * * * * ** * * * **|
| |
250000 ++ |
| |
240000 ++ |
| |
230000 ++ O O |
220000 +OO O OO O O O OO O OO O OO OOOO |
| O O OOOOO O O O O OO OO OO OO OOO O OO |
210000 O+ O OOOO O O OO O O O |
| |
200000 ++-----------------------------------------------------------------+
cpuidle.C7-SNB.usage
4e+06 ++----------------------------------------------------------------+
| * * * |
3.5e+06 +* * :*: * * * ** * ** * * * * * ** *: * *
* * * ****** **** *** * * ** ** **** ** * ********* * *** ** *|
3e+06 ++ |
| |
2.5e+06 ++ |
| |
2e+06 ++ |
| |
1.5e+06 ++ |
| OO O OO O O O O O O O O O O |
1e+06 OO OO OOOOOO OO O O OOOO OO OO OOOO OO OOOO O OO |
| O O O O O O |
500000 ++----------------------------------------------------------------+
turbostat.CPU_c1
34 ++---------------------------------------------------------------------+
32 ++ * * ** * |
| : : :: * * * ** : * |
30 ++ ::: : ** : :: ** :: ** :: :: : : : |
28 +* : :* : : : * * * * : : :: * *:* : * *: * * ** : * :: :*
26 *+** * ** ** ** ** * *** * * * * * * * **** ****** *** ** *|
24 ++ |
| |
22 ++ |
20 ++ |
18 ++ |
16 ++ O |
| OO OOOOO OOO O O O O O O O O OO O O O |
14 OO O OO O OOOO OO OOOOOO OO OO OO OO OO O OO O OO |
12 ++---------------------------------O--------O--------------------------+
turbostat.CPU_c7
70 ++---------------------------------------------------------------------+
| |
65 OO OO O OO O OOOO OOOOO O OOO OO O O O OO |
| OOOOOOOO OO OO O OOO OO O OO O O OO O O |
| OO O O O |
60 ++ |
| |
55 ++ |
| |
50 *+** * ** ** ** **** * * * * * * * * * **** ****** *** ** *|
|* ::* : : : * * * *: :::: * *:* : * * :* * ** : * : ::*
| * : ** :: * ** * ** * ** : * |
45 ++ * ** * |
| |
40 ++---------------------------------------------------------------------+
turbostat.Pkg_pc6
25 ++---------------------------------------------------------------------+
| |
| O OO O O O O |
20 ++ O O OOO OO O O |
OO O O O O O OOO OO O O O O O OO |
| O OOO O O O O O OO O OOO |
15 ++OO O OO O O O O |
| O |
10 ++ |
| |
| |
5 ++ |
| |
| |
0 ************************************************************************
turbostat.PkgWatt
180 ++--------------------------------------------------------------------+
********* ********** ************** ******** **** ************* *** * *
175 ++ * * * * * * * * *|
170 ++ |
| |
165 ++ |
| |
160 ++ |
| |
155 ++O O OOO O O O O O O |
150 ++ OO OOO O O O OOO OO O OO O O O |
O O O OO OO OO O OO |
145 +O O O OO O O O O O O O O O O |
| O O |
140 ++--------------------------------------------------------------------+
turbostat.CorWatt
125 ++--------------------------------------------------------------------+
|* ***** ** ** ** * *** ** ***** * * **** * * * ** ***** * *** * *
120 *+* ** * * * * * * * * * * * * *** *** * * * *|
| |
115 ++ |
| |
110 ++ |
| |
105 ++ O O |
| OOO OOOO O O O O O O OO OOO |
100 O+ O OOO O OOO O O OOO |
|O O O O OO O OO OOO O OOO O O |
95 ++ O O O O O O O |
| |
90 ++--------------------------------------------------------------------+
will-it-scale.time.system_time
220 ++--------------------------------------------------------------------+
| * * ** ** * * * ** * * * * ** |
200 **** *** **************** ** * * * * * * * ***** ******* **********
180 ++ |
| |
160 ++ |
140 ++ |
| |
120 ++ |
100 ++ |
| OO O O O OO OO O O |
80 +O OO O O O O OO O O O O O O O O O OO |
60 O+ OO O OOO O OO O O O O O OO O O O O O OO |
| O O O O |
40 ++--------------------------------------------------------------------+
will-it-scale.time.percent_of_cpu_this_job_got
70 ++--*---------------------**--**---*--**---*-------*--------*----------+
**** ********************* ** *** ** *** ******* ******** ***********
60 ++ |
| |
| |
50 ++ |
| |
40 ++ |
| |
30 ++ O O O O O O |
| O O OO O O O O OO O O O O O OOOO |
OO OOO OO OO O OO O OOO O O O O O O O |
20 ++ O OO O O O OO O O O O |
| |
10 ++---------------------------------------------------------------------+
time.user_time
9 ++----------------------------------------------------------------------+
| * * ** * ** * * |
8 ++ **** * * :* * **** * *** :* : ** :* : ** :: * * ** * : * *** *
*** * *** * * * * * * : ** : ** *** * * ** ** * ***|
| * * |
7 ++ |
| |
6 ++ |
| O O O O O |
5 O+ O O O |
| O O O O O O O O O OOO |
|O O O O O OO O O O O O OO O O OOOO OO |
4 ++ O OO OO O O O O O O O O O O |
| O O |
3 ++----------------------------------------------------------------------+
time.system_time
220 ++--------------------------------------------------------------------+
| * * ** ** * * * ** * * * * ** |
200 **** *** **************** ** * * * * * * * ***** ******* **********
180 ++ |
| |
160 ++ |
140 ++ |
| |
120 ++ |
100 ++ |
| OO O O O OO OO O O |
80 +O OO O O O O OO O O O O O O O O O OO |
60 O+ OO O OOO O OO O O O O O OO O O O O O OO |
| O O O O |
40 ++--------------------------------------------------------------------+
time.percent_of_cpu_this_job_got
70 ++--*---------------------**--**---*--**---*-------*--------*----------+
**** ********************* ** *** ** *** ******* ******** ***********
60 ++ |
| |
| |
50 ++ |
| |
40 ++ |
| |
30 ++ O O O O O O |
| O O OO O O O O OO O O O O O OOOO |
OO OOO OO OO O OO O OOO O O O O O O O |
20 ++ O OO O O O OO O O O O |
| |
10 ++---------------------------------------------------------------------+
[*] bisect-good sample
[O] bisect-bad sample
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
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,
Ying Huang
5 years, 9 months
[lkp] [blk] bf5c2e3e82: BUG kmalloc-512 (Not tainted): Poison overwritten
by kernel test robot
FYI, we noticed the below changes on
git://git.infradead.org/users/kbusch/linux-nvme master
commit bf5c2e3e82b9dd957c4aedb6fa4dabf3e7bec8a3 ("blk-mq: dynamic h/w context count")
+-----------------------------------------------+------------+------------+
| | 1fe4f3f9b7 | bf5c2e3e82 |
+-----------------------------------------------+------------+------------+
| boot_successes | 8 | 0 |
| boot_failures | 0 | 6 |
| BUG_kmalloc-#(Not_tainted):Poison_overwritten | 0 | 6 |
| INFO:#-#.First_byte#instead_of | 0 | 6 |
| INFO:Slab#objects=#used=#fp=0x(null)flags= | 0 | 6 |
| INFO:Object#@offset=#fp= | 0 | 6 |
| backtrace:init | 0 | 6 |
| backtrace:kernel_init_freeable | 0 | 6 |
+-----------------------------------------------+------------+------------+
[ 5.397219] brd: module loaded
[ 5.428701] loop: module loaded
[ 7.750179] =============================================================================
[ 7.751886] BUG kmalloc-512 (Not tainted): Poison overwritten
[ 7.752927] -----------------------------------------------------------------------------
[ 7.752927]
[ 7.755116] Disabling lock debugging due to kernel taint
[ 7.756105] INFO: 0xffff88000d0e6760-0xffff88000d0e694f. First byte 0x0 instead of 0x6b
[ 7.757747] INFO: Slab 0xffffea0000343900 objects=19 used=19 fp=0x (null) flags=0x100000000004080
[ 7.759558] INFO: Object 0xffff88000d0e6760 @offset=10080 fp=0xffff88000d0e6418
[ 7.759558]
[ 7.761653] Bytes b4 ffff88000d0e6750: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.763451] Object ffff88000d0e6760: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.765235] Object ffff88000d0e6770: 21 43 65 87 00 00 00 00 00 00 00 00 00 00 00 00 !Ce.............
[ 7.767018] Object ffff88000d0e6780: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.768797] Object ffff88000d0e6790: 00 00 00 00 00 00 00 00 21 43 65 87 00 00 00 00 ........!Ce.....
[ 7.770578] Object ffff88000d0e67a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.772366] Object ffff88000d0e67b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.774154] Object ffff88000d0e67c0: 21 43 65 87 00 00 00 00 00 00 00 00 00 00 00 00 !Ce.............
[ 7.775927] Object ffff88000d0e67d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.777709] Object ffff88000d0e67e0: 00 00 00 00 00 00 00 00 21 43 65 87 00 00 00 00 ........!Ce.....
[ 7.779492] Object ffff88000d0e67f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.781271] Object ffff88000d0e6800: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.783055] Object ffff88000d0e6810: 21 43 65 87 00 00 00 00 00 00 00 00 00 00 00 00 !Ce.............
[ 7.784834] Object ffff88000d0e6820: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.786623] Object ffff88000d0e6830: 00 00 00 00 00 00 00 00 21 43 65 87 00 00 00 00 ........!Ce.....
[ 7.788405] Object ffff88000d0e6840: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.790187] Object ffff88000d0e6850: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.791963] Object ffff88000d0e6860: 21 43 65 87 00 00 00 00 00 00 00 00 00 00 00 00 !Ce.............
[ 7.793736] Object ffff88000d0e6870: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.795518] Object ffff88000d0e6880: 00 00 00 00 00 00 00 00 21 43 65 87 00 00 00 00 ........!Ce.....
[ 7.797312] Object ffff88000d0e6890: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.799092] Object ffff88000d0e68a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.800859] Object ffff88000d0e68b0: 21 43 65 87 00 00 00 00 00 00 00 00 00 00 00 00 !Ce.............
[ 7.803045] Object ffff88000d0e68c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.804885] Object ffff88000d0e68d0: 00 00 00 00 00 00 00 00 21 43 65 87 00 00 00 00 ........!Ce.....
[ 7.806673] Object ffff88000d0e68e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.808462] Object ffff88000d0e68f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.810247] Object ffff88000d0e6900: 21 43 65 87 00 00 00 00 00 00 00 00 00 00 00 00 !Ce.............
[ 7.812024] Object ffff88000d0e6910: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.813802] Object ffff88000d0e6920: 00 00 00 00 00 00 00 00 21 43 65 87 00 00 00 00 ........!Ce.....
[ 7.815581] Object ffff88000d0e6930: 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.817361] Object ffff88000d0e6940: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ................
[ 7.819156] Object ffff88000d0e6950: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b a5 kkkkkkkkkkkkkkk.
[ 7.820933] Redzone ffff88000d0e6960: bb bb bb bb bb bb bb bb ........
[ 7.822646] Padding ffff88000d0e6aa0: 5a 5a 5a 5a 5a 5a 5a 5a ZZZZZZZZ
[ 7.824368] CPU: 0 PID: 1 Comm: swapper/0 Tainted: G B 4.4.0-rc8-00134-gbf5c2e3 #1
[ 7.826099] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 7.827832] 0000000000000000 ffff88001209f7f0 ffffffff8150590a ffff880012802b40
[ 7.829658] ffff88001209f820 ffffffff811c0f5f ffff88000d0e6760 000000000000006b
[ 7.831483] ffff880012802b40 ffff88000d0e694f ffff88001209f878 ffffffff811c100a
[ 7.833306] Call Trace:
[ 7.833997] [<ffffffff8150590a>] dump_stack+0x4b/0x63
[ 7.834968] [<ffffffff811c0f5f>] print_trailer+0x127/0x130
[ 7.835986] [<ffffffff811c100a>] check_bytes_and_report+0xa2/0xea
[ 7.837066] [<ffffffff811c1346>] check_object+0x10a/0x1f7
[ 7.838073] [<ffffffff814f3219>] ? efi_partition+0xd0/0x523
[ 7.839092] [<ffffffff811c246b>] alloc_debug_processing+0xdc/0x14b
[ 7.840179] [<ffffffff811c295f>] ___slab_alloc+0x485/0x612
[ 7.841193] [<ffffffff814f3219>] ? efi_partition+0xd0/0x523
[ 7.842225] [<ffffffff810d7381>] ? __lock_is_held+0x3c/0x57
[ 7.843244] [<ffffffff810d7381>] ? __lock_is_held+0x3c/0x57
[ 7.844267] [<ffffffff814f3219>] ? efi_partition+0xd0/0x523
[ 7.845289] [<ffffffff811c2b3b>] __slab_alloc+0x4f/0x83
[ 7.846277] [<ffffffff811c2b3b>] ? __slab_alloc+0x4f/0x83
[ 7.847279] [<ffffffff814f3219>] ? efi_partition+0xd0/0x523
[ 7.848302] [<ffffffff814f3219>] ? efi_partition+0xd0/0x523
[ 7.849324] [<ffffffff811c2e0a>] kmem_cache_alloc_trace+0x88/0x209
[ 7.850414] [<ffffffff814f3219>] efi_partition+0xd0/0x523
[ 7.851422] [<ffffffff8150f86b>] ? vsnprintf+0x89/0x3af
[ 7.852406] [<ffffffff8150fc3e>] ? snprintf+0x36/0x3e
[ 7.853377] [<ffffffff814f243c>] check_partition+0x11c/0x1b2
[ 7.854411] [<ffffffff814f243c>] ? check_partition+0x11c/0x1b2
[ 7.855467] [<ffffffff814f16c8>] rescan_partitions+0x7c/0x252
[ 7.856513] [<ffffffff81c414ca>] ? mutex_unlock+0xe/0x10
[ 7.857509] [<ffffffff81203d3b>] __blkdev_get+0x1c4/0x3dc
[ 7.858513] [<ffffffff81204119>] blkdev_get+0x1c6/0x2fd
[ 7.859501] [<ffffffff814ef24f>] add_disk+0x42d/0x456
[ 7.860470] [<ffffffff812032d8>] ? revalidate_disk+0x78/0x84
[ 7.861503] [<ffffffff815c8acf>] ? vp_get+0x57/0x67
[ 7.862454] [<ffffffff816fd5fb>] virtblk_probe+0x560/0x641
[ 7.863472] [<ffffffff815c57ff>] virtio_dev_probe+0x111/0x187
[ 7.864512] [<ffffffff816d47d6>] driver_probe_device+0xf7/0x250
[ 7.865582] [<ffffffff816d4990>] __driver_attach+0x61/0x83
[ 7.866599] [<ffffffff816d492f>] ? driver_probe_device+0x250/0x250
[ 7.867686] [<ffffffff816d2d77>] bus_for_each_dev+0x6f/0x87
[ 7.868711] [<ffffffff816d4381>] driver_attach+0x1e/0x20
[ 7.869710] [<ffffffff816d3f6e>] bus_add_driver+0xf2/0x1e4
[ 7.880475] [<ffffffff8261c3a8>] ? init_cryptoloop+0x28/0x28
[ 7.881509] [<ffffffff816d54b4>] driver_register+0x8a/0xc6
[ 7.882530] [<ffffffff8261c3a8>] ? init_cryptoloop+0x28/0x28
[ 7.883560] [<ffffffff815c568b>] register_virtio_driver+0x2b/0x2d
[ 7.884637] [<ffffffff8261c402>] init+0x5a/0x87
[ 7.885552] [<ffffffff81000402>] do_one_initcall+0xe7/0x177
[ 7.886580] [<ffffffff825cf0ec>] kernel_init_freeable+0x1c2/0x24a
[ 7.887663] [<ffffffff81c35e49>] ? rest_init+0x140/0x140
[ 7.888658] [<ffffffff81c35e57>] kernel_init+0xe/0xd4
[ 7.889630] [<ffffffff81c4415f>] ret_from_fork+0x3f/0x70
[ 7.890631] [<ffffffff81c35e49>] ? rest_init+0x140/0x140
[ 7.891635] FIX kmalloc-512: Restoring 0xffff88000d0e6760-0xffff88000d0e694f=0x6b
[ 7.891635]
[ 7.893751] FIX kmalloc-512: Marking all objects used
Thanks,
Kernel Test Robot
5 years, 9 months
[lkp] [rcu] b8084f70e0: No primary result change, 1414.7% unixbench.time.involuntary_context_switches
by kernel test robot
FYI, we noticed the below changes on
https://git.kernel.org/pub/scm/linux/kernel/git/rt/linux-rt-devel.git for-kbuild-bot/current-stable
commit b8084f70e028697b342d6388b244d6171717fc54 ("rcu: Eliminate softirq processing from rcutree")
=========================================================================================
compiler/cpufreq_governor/kconfig/nr_task/rootfs/tbox_group/test/testcase:
gcc-4.9/performance/x86_64-rhel/1/debian-x86_64-2015-02-07.cgz/lkp-ivb-d02/fsbuffer/unixbench
commit:
ee644236a506642e20637f954d286f49a76ed83a
b8084f70e028697b342d6388b244d6171717fc54
ee644236a506642e b8084f70e028697b342d6388b2
---------------- --------------------------
%stddev %change %stddev
\ | \
257.25 ± 18% +1414.7% 3896 ± 13% unixbench.time.involuntary_context_switches
4425148 ± 22% -61.9% 1684712 ± 29% cpuidle.C1E-IVB.time
83.75 ± 48% +91.6% 160.50 ± 31% cpuidle.POLL.usage
1902 ± 7% -12.0% 1674 ± 1% slabinfo.anon_vma.active_objs
1902 ± 7% -12.0% 1674 ± 1% slabinfo.anon_vma.num_objs
257.25 ± 18% +1414.7% 3896 ± 13% time.involuntary_context_switches
8.15 ± 6% -14.1% 7.00 ± 1% time.user_time
34345 ± 14% -33.3% 22908 ± 33% sched_debug.cfs_rq:/.exec_clock.2
34987 ± 13% -19.7% 28093 ± 15% sched_debug.cfs_rq:/.exec_clock.max
642.75 ± 5% +59.6% 1025 ± 55% sched_debug.cfs_rq:/.exec_clock.min
14639 ± 13% -21.8% 11443 ± 16% sched_debug.cfs_rq:/.exec_clock.stddev
127.75 ± 16% -26.2% 94.25 ± 25% sched_debug.cfs_rq:/.load_avg.3
38865 ± 12% -36.0% 24885 ± 34% sched_debug.cfs_rq:/.min_vruntime.2
39385 ± 12% -22.8% 30395 ± 16% sched_debug.cfs_rq:/.min_vruntime.max
1090 ± 11% +45.3% 1584 ± 32% sched_debug.cfs_rq:/.min_vruntime.min
16286 ± 13% -25.1% 12200 ± 18% sched_debug.cfs_rq:/.min_vruntime.stddev
2.00 ± 0% -50.0% 1.00 ± 0% sched_debug.cfs_rq:/.nr_spread_over.0
2.00 ± 0% -50.0% 1.00 ± 0% sched_debug.cfs_rq:/.nr_spread_over.max
0.87 ± 0% -42.3% 0.50 ± 0% sched_debug.cfs_rq:/.nr_spread_over.stddev
28.50 ± 62% +338.6% 125.00 ±114% sched_debug.cfs_rq:/.runnable_load_avg.1
16286 ± 13% -25.1% 12200 ± 18% sched_debug.cfs_rq:/.spread0.stddev
127.75 ± 16% -26.0% 94.50 ± 25% sched_debug.cfs_rq:/.tg_load_avg_contrib.3
626662 ± 5% -13.2% 544121 ± 9% sched_debug.cpu.avg_idle.0
20.25 ± 28% +419.8% 105.25 ±132% sched_debug.cpu.cpu_load[3].1
692.40 ± 7% -15.2% 586.96 ± 9% sched_debug.cpu.curr->pid.avg
36187 ± 12% -31.5% 24793 ± 29% sched_debug.cpu.nr_load_updates.2
15625 ± 11% +61.6% 25245 ± 23% sched_debug.cpu.nr_switches.0
20008 ± 4% +14.1% 22828 ± 4% sched_debug.cpu.nr_switches.avg
23333 ± 8% +40.9% 32872 ± 18% sched_debug.cpu.sched_count.0
21974 ± 4% +12.7% 24771 ± 4% sched_debug.cpu.sched_count.avg
31771 ± 9% +22.6% 38942 ± 5% sched_debug.cpu.sched_count.max
9514 ± 28% +75.8% 16728 ± 7% sched_debug.cpu.ttwu_count.0
4323 ± 10% +40.6% 6080 ± 30% sched_debug.cpu.ttwu_count.2
10068 ± 4% +15.6% 11639 ± 4% sched_debug.cpu.ttwu_count.avg
4101 ± 10% +21.7% 4990 ± 8% sched_debug.cpu.ttwu_count.min
3676 ± 21% +102.5% 7443 ± 8% sched_debug.cpu.ttwu_local.0
2014 ± 15% +43.2% 2884 ± 10% sched_debug.cpu.ttwu_local.2
3508 ± 1% +24.8% 4377 ± 4% sched_debug.cpu.ttwu_local.avg
5554 ± 19% +34.0% 7444 ± 8% sched_debug.cpu.ttwu_local.max
1846 ± 16% +40.2% 2588 ± 6% sched_debug.cpu.ttwu_local.min
=========================================================================================
compiler/cpufreq_governor/kconfig/nr_task/rootfs/tbox_group/test/testcase:
gcc-4.9/performance/x86_64-rhel/1/debian-x86_64-2015-02-07.cgz/lkp-ivb-d02/fsdisk/unixbench
commit:
ee644236a506642e20637f954d286f49a76ed83a
b8084f70e028697b342d6388b244d6171717fc54
ee644236a506642e b8084f70e028697b342d6388b2
---------------- --------------------------
fail:runs %reproduction fail:runs
| | |
:4 25% 1:4 kmsg.DHCP/BOOTP:Reply_not_for_us,op[#]xid[#]
%stddev %change %stddev
\ | \
265.75 ± 18% +1313.4% 3756 ± 9% unixbench.time.involuntary_context_switches
659.50 ± 6% +16.5% 768.00 ± 7% slabinfo.kmalloc-512.num_objs
265.75 ± 18% +1313.4% 3756 ± 9% time.involuntary_context_switches
5911312 ± 13% -55.9% 2606719 ± 10% cpuidle.C1E-IVB.time
95195 ±172% +815.7% 871684 ±140% cpuidle.POLL.time
51.75 ± 10% -30.9% 35.75 ± 24% cpuidle.POLL.usage
13361 ± 22% -27.0% 9754 ± 4% sched_debug.cfs_rq:/.exec_clock.stddev
14632 ± 24% -28.1% 10524 ± 5% sched_debug.cfs_rq:/.min_vruntime.stddev
14632 ± 24% -28.1% 10524 ± 5% sched_debug.cfs_rq:/.spread0.stddev
197.25 ± 14% +52.9% 301.50 ± 41% sched_debug.cfs_rq:/.util_avg.0
552666 ± 8% -7.7% 510200 ± 7% sched_debug.cpu.avg_idle.1
13610 ± 30% +59.7% 21734 ± 7% sched_debug.cpu.nr_switches.0
21145 ± 1% +12.3% 23752 ± 7% sched_debug.cpu.nr_switches.avg
10105 ± 21% +62.1% 16380 ± 7% sched_debug.cpu.nr_switches.min
11293 ± 28% -44.4% 6276 ± 16% sched_debug.cpu.nr_switches.stddev
21314 ± 19% +38.1% 29437 ± 5% sched_debug.cpu.sched_count.0
11261 ± 22% +57.2% 17703 ± 9% sched_debug.cpu.sched_count.min
11158 ± 27% -36.7% 7068 ± 12% sched_debug.cpu.sched_count.stddev
5854 ± 35% +57.0% 9194 ± 8% sched_debug.cpu.sched_goidle.0
3713 ± 27% +68.4% 6253 ± 11% sched_debug.cpu.sched_goidle.min
5638 ± 29% -44.5% 3131 ± 18% sched_debug.cpu.sched_goidle.stddev
8286 ± 32% +85.0% 15333 ± 15% sched_debug.cpu.ttwu_count.0
10697 ± 1% +13.2% 12107 ± 7% sched_debug.cpu.ttwu_count.avg
4845 ± 5% +17.8% 5707 ± 8% sched_debug.cpu.ttwu_count.min
2886 ± 47% +105.5% 5931 ± 16% sched_debug.cpu.ttwu_local.0
3667 ± 3% +17.0% 4291 ± 1% sched_debug.cpu.ttwu_local.avg
2127 ± 17% +29.2% 2748 ± 7% sched_debug.cpu.ttwu_local.min
lkp-ivb-d02: Ivy Bridge
Memory: 8G
unixbench.time.involuntary_context_switches
5000 ++-------------------------------------------------------------------+
4500 O+ |
| O O O O O
4000 ++ O O O |
3500 ++O O O O O O O O O O O |
| O O O |
3000 ++ O O |
2500 ++ |
2000 ++ |
| |
1500 ++ |
1000 ++ |
|.*.. .*.. .*. .*.*.. .*.. |
500 *+ * *.*..*.*. *. .*.. .*.*..* *.*..*.* |
0 ++----------O---------O-------*----*------O----O---------------------+
[*] bisect-good sample
[O] bisect-bad sample
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
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,
Ying Huang
5 years, 9 months
[DEBUG] 76af8859bd: WARNING: CPU: 0 PID: 0 at init/main.c:685 start_kernel()
by kernel test robot
Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
https://git.kernel.org/pub/scm/linux/kernel/git/kees/linux.git kaslr/weak
commit 76af8859bd7cf8a0eba20c3ebb5b738eca33907d
Author: Kees Cook <keescook(a)chromium.org>
AuthorDate: Thu Jan 15 16:47:03 2015 -0800
Commit: Kees Cook <keescook(a)chromium.org>
CommitDate: Tue Jan 5 14:05:29 2016 -0800
DEBUG: testing weak symbols during relocation
This is to report weak symbol locations after relocation.
Signed-off-by: Kees Cook <keescook(a)chromium.org>
+-------------------------------------------------------+------------+------------+------------+
| | ee9a7d2cb0 | 76af8859bd | 2bd4d8e3f4 |
+-------------------------------------------------------+------------+------------+------------+
| boot_successes | 138 | 0 | 0 |
| boot_failures | 2 | 17 | 41 |
| IP-Config:Auto-configuration_of_network_failed | 2 | 2 | 2 |
| WARNING:at_init/main.c:#start_kernel() | 0 | 17 | 41 |
| BUG:unable_to_handle_kernel | 0 | 0 | 4 |
| Oops | 0 | 0 | 4 |
| EIP_is_at_perf_prepare_sample | 0 | 0 | 4 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 0 | 1 |
| Kernel_panic-not_syncing:Fatal_exception_in_interrupt | 0 | 0 | 3 |
| backtrace:vfs_fstatat | 0 | 0 | 2 |
| backtrace:SyS_fstatat64 | 0 | 0 | 2 |
+-------------------------------------------------------+------------+------------+------------+
[ 0.388437] Freeing SMP alternatives memory: 12K (7b308000 - 7b30b000)
[ 0.392437] nosuchfn = 01a00000
[ 0.392878] ------------[ cut here ]------------
[ 0.396367] WARNING: CPU: 0 PID: 0 at init/main.c:685 start_kernel+0x3b3/0x3bd()
[ 0.398604] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.4.0-rc8-00006-g76af885 #1
[ 0.404649] 00000000 00000000 7b0b1fb0 7ab8284e 00000000 7b0b1fc8 7aa3b547 7b166aef
[ 0.405902] 7b1a33a0 00020800 7b30f800 7b0b1fd8 7aa3b5e4 00000009 00000000 7b0b1fe8
[ 0.407139] 7b166aef 7b1a33a0 00000800 7b0b1ff8 7b1662c3 00000800 7b30f800 047c5003
[ 0.408316] Call Trace:
[ 0.408642] [<7ab8284e>] dump_stack+0x48/0x69
[ 0.410272] [<7aa3b547>] warn_slowpath_common+0x74/0x8b
[ 0.411000] [<7b166aef>] ? start_kernel+0x3b3/0x3bd
[ 0.412742] [<7aa3b5e4>] warn_slowpath_null+0xf/0x13
[ 0.414397] [<7b166aef>] start_kernel+0x3b3/0x3bd
[ 0.415005] [<7b1662c3>] i386_start_kernel+0x91/0x95
[ 0.416745] ---[ end trace cb88537fdc8fa200 ]---
[ 0.418785] Enabling APIC mode: Flat. Using 1 I/O APICs
git bisect start 2bd4d8e3f4269ce704f98b699cb2318997c192d2 168309855a7d1e16db751e9c647119fe2d2dc878 --
git bisect bad 025a0ad03e0e2b830eb29bdfece2d5aa0ecb1fb0 # 12:54 0- 2 Merge 'tip/x86/mm' into devel-spot-201601060621
git bisect bad 655f7c0dc78d7b77006e17bfa541afff2bb9cfe2 # 12:54 0- 6 Merge 'asoc/for-next' into devel-spot-201601060621
git bisect good 332369c1028ba45c39e85c433c46b8e2c3d92604 # 13:00 21+ 0 Merge 'kees/kspp/lkdtm-atomics' into devel-spot-201601060621
git bisect bad bf68b34e3402d8c390e6558fe23f1fa4e70b304f # 13:01 0- 28 Merge 'linux-review/Craig-Gallek/soreuseport-pass-skb-to-secondary-UDP-socket-lookup/20160106-041145' into devel-spot-201601060621
git bisect bad ff20e1a9e8341310c9a47bac8813ed9f88acc08d # 13:01 0- 6 Merge 'kees/getsockname' into devel-spot-201601060621
git bisect good 05eabb541e9ea232ab4c1c0a84051350c780fd9f # 13:07 21+ 2 Merge 'kees/kspp/arm-rodata' into devel-spot-201601060621
git bisect bad 58ea632845ead13aa582cc087a3406158cefdbc7 # 13:07 0- 8 Merge 'kees/kaslr/weak' into devel-spot-201601060621
git bisect bad 76af8859bd7cf8a0eba20c3ebb5b738eca33907d # 13:08 0- 17 DEBUG: testing weak symbols during relocation
# first bad commit: [76af8859bd7cf8a0eba20c3ebb5b738eca33907d] DEBUG: testing weak symbols during relocation
git bisect good ee9a7d2cb0cf1a1498478bc923d911f3d9c910ac # 13:11 66+ 2 Merge tag 'trace-v4.4-rc4-3' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace
# extra tests with DEBUG_INFO
git bisect bad 76af8859bd7cf8a0eba20c3ebb5b738eca33907d # 13:11 0- 4 DEBUG: testing weak symbols during relocation
# extra tests on HEAD of linux-devel/devel-spot-201601060621
git bisect bad 2bd4d8e3f4269ce704f98b699cb2318997c192d2 # 13:11 0- 41 0day head guard for 'devel-spot-201601060621'
# extra tests on tree/branch kees/kaslr/weak
git bisect bad 76af8859bd7cf8a0eba20c3ebb5b738eca33907d # 13:12 0- 17 DEBUG: testing weak symbols during relocation
# extra tests with first bad commit reverted
git bisect good 44ce2ae44d528c4ddbdc1237e796edae70ec4a5a # 13:20 61+ 0 Revert "DEBUG: testing weak symbols during relocation"
# extra tests on tree/branch linus/master
git bisect good ee9a7d2cb0cf1a1498478bc923d911f3d9c910ac # 13:22 66+ 2 Merge tag 'trace-v4.4-rc4-3' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace
# extra tests on tree/branch linux-next/master
git bisect good 8ef79cd05e6894c01ab9b41aa918a402fa8022a7 # 13:25 65+ 0 Add linux-next specific files for 20160105
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
5 years, 9 months
[lkp] [i2c] 3489746df0: WARNING: CPU: 0 PID: 1 at drivers/base/devres.c:888 devm_kfree+0x61/0x76()
by kernel test robot
FYI, we noticed the below changes on
https://github.com/0day-ci/linux Peter-Rosin/i2c-mux-cleanup-and-locking-update/20160106-000205
commit 3489746df00f2f18b1a6dc2ba4de263e980cfbb0 ("i2c-mux: move the slave side adapter management to i2c_mux_core")
+------------------------------------------------------------------+------------+------------+
| | f3ce0531d6 | 3489746df0 |
+------------------------------------------------------------------+------------+------------+
| boot_successes | 16 | 0 |
| boot_failures | 76 | 22 |
| Out_of_memory:Kill_process | 46 | |
| Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 2 | |
| Kernel_panic-not_syncing:Attempted_to_kill_init!exitcode= | 30 | 21 |
| WARNING:at_drivers/base/devres.c:#devm_kfree() | 0 | 22 |
| backtrace:of_unittest | 0 | 22 |
| backtrace:kernel_init_freeable | 0 | 22 |
+------------------------------------------------------------------+------------+------------+
[ 17.661085] overlay_removal_is_ok: overlay #5 is not topmost
[ 17.662994] of_overlay_destroy: removal check failed for overlay #5
[ 17.668348] ------------[ cut here ]------------
[ 17.683131] WARNING: CPU: 0 PID: 1 at drivers/base/devres.c:888 devm_kfree+0x61/0x76()
[ 17.686302] CPU: 0 PID: 1 Comm: swapper Not tainted 4.4.0-rc3-00086-g3489746 #1
[ 17.688867] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 17.692001] 0000000000000000 ffff880013e43b60 ffffffff8177aefa ffff880013e43b98
[ 17.708372] ffffffff81119965 ffffffff81d0a80c 0000000000000001 00000000fffffffe
[ 17.711702] ffff88000de285d8 ffff88000c73d820 ffff880013e43ba8 ffffffff81119a50
[ 17.714839] Call Trace:
[ 17.716069] [<ffffffff8177aefa>] dump_stack+0x19/0x1b
[ 17.718206] [<ffffffff81119965>] warn_slowpath_common+0xb6/0xcf
[ 17.720721] [<ffffffff81d0a80c>] ? devm_kfree+0x61/0x76
[ 17.735171] [<ffffffff81119a50>] warn_slowpath_null+0x1a/0x1c
[ 17.746025] [<ffffffff81d0a80c>] devm_kfree+0x61/0x76
[ 17.747733] [<ffffffff8252ad4c>] i2c_mux_reserve_adapters+0xae/0xbf
[ 17.749751] [<ffffffff82842105>] unittest_i2c_mux_probe+0x1af/0x234
[ 17.751739] [<ffffffff82841f56>] ? unittest_i2c_mux_remove+0x90/0x90
[ 17.753753] [<ffffffff82526726>] i2c_device_probe+0x370/0x3b9
[ 17.755599] [<ffffffff81d05602>] driver_probe_device+0x2c5/0x6db
[ 17.774860] [<ffffffff81d05ab7>] __driver_attach+0x9f/0xd5
[ 17.776761] [<ffffffff81d05a18>] ? driver_probe_device+0x6db/0x6db
[ 17.778805] [<ffffffff81d02f3a>] bus_for_each_dev+0x91/0xa9
[ 17.780696] [<ffffffff81d05dc4>] driver_attach+0x1e/0x20
[ 17.782548] [<ffffffff81d03bd7>] bus_add_driver+0x1f7/0x36d
[ 17.796930] [<ffffffff81d06a93>] driver_register+0x10d/0x17f
[ 17.798748] [<ffffffff82528714>] i2c_register_driver+0xb1/0x147
[ 17.800803] [<ffffffff84f32561>] of_unittest_overlay+0xf05/0x1304
[ 17.802967] [<ffffffff84f339e8>] of_unittest+0x1088/0x10b6
[ 17.804937] [<ffffffff817b1043>] ? debug_check_no_obj_freed+0x26/0x28
[ 17.807212] [<ffffffff8125a594>] ? kfree+0x2c7/0x307
[ 17.809013] [<ffffffff84e87520>] ? do_one_initcall+0xf8/0x26c
[ 17.823489] [<ffffffff84f32960>] ? of_unittest_overlay+0x1304/0x1304
[ 17.825596] [<ffffffff84e875a1>] do_one_initcall+0x179/0x26c
[ 17.827551] [<ffffffff84e877f7>] kernel_init_freeable+0x163/0x22b
[ 17.829642] [<ffffffff82e3cc03>] ? rest_init+0x7a/0x7a
[ 17.831424] [<ffffffff82e3cc11>] kernel_init+0xe/0x13f
[ 17.833228] [<ffffffff82e4bfcf>] ret_from_fork+0x3f/0x70
[ 17.835066] [<ffffffff82e3cc03>] ? rest_init+0x7a/0x7a
[ 17.836853] ---[ end trace 9266670885044a94 ]---
[ 17.851608] i2c i2c-0: Added multiplexed i2c bus 1
Thanks,
Kernel Test Robot
5 years, 9 months