[sched/core] 0a7f120b8b: WARNING: CPU: 0 PID: 0 at kernel/sched/sched.h:799 update_load_avg
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/peterz/queue.git sched/debug
commit 0a7f120b8b60e0ecc3e7bc19a18eac523bbec215
Author: Matt Fleming <matt(a)codeblueprint.co.uk>
AuthorDate: Wed Sep 21 14:38:13 2016 +0100
Commit: Peter Zijlstra <peterz(a)infradead.org>
CommitDate: Sun Nov 20 15:27:58 2016 +0100
sched/core: Add debug code to catch missing update_rq_clock()
There's no diagnostic checks for figuring out when we've accidentally
missed update_rq_clock() calls. Let's add some by piggybacking on the
rq_*pin_lock() wrappers.
The idea behind the diagnostic checks is that upon pining rq lock the
rq clock should be updated, via update_rq_clock(), before anybody
reads the clock with rq_clock() or rq_clock_task().
The exception to this rule is when updates have explicitly been
disabled with the rq_clock_skip_update() optimisation.
There are some functions that only unpin the rq lock in order to grab
some other lock and avoid deadlock. In that case we don't need to
update the clock again and the previous diagnostic state can be
carried over in rq_repin_lock() by saving the state in the rq_flags
context.
Since this patch adds a new clock update flag and some already exist
in rq::clock_skip_update, that field has now been renamed. An attempt
has been made to keep the flag manipulation code small and fast since
it's used in the heart of the __schedule() fast path.
For the !CONFIG_SCHED_DEBUG case the only object code change (other
than addresses) is the following change to reset RQCF_ACT_SKIP inside
of __schedule(),
- c7 83 38 09 00 00 00 movl $0x0,0x938(%rbx)
- 00 00 00
+ 83 a3 38 09 00 00 fc andl $0xfffffffc,0x938(%rbx)
Cc: Yuyang Du <yuyang.du(a)intel.com>
Cc: Ingo Molnar <mingo(a)kernel.org>
Cc: Luca Abeni <luca.abeni(a)unitn.it>
Cc: Wanpeng Li <wanpeng.li(a)hotmail.com>
Cc: Sergey Senozhatsky <sergey.senozhatsky.work(a)gmail.com>
Cc: Byungchul Park <byungchul.park(a)lge.com>
Cc: Frederic Weisbecker <fweisbec(a)gmail.com>
Cc: Thomas Gleixner <tglx(a)linutronix.de>
Cc: Jan Kara <jack(a)suse.cz>
Cc: Rik van Riel <riel(a)redhat.com>
Cc: Petr Mladek <pmladek(a)suse.com>
Cc: Mel Gorman <mgorman(a)techsingularity.net>
Cc: Mike Galbraith <umgwanakikbuti(a)gmail.com>
Suggested-by: Peter Zijlstra <peterz(a)infradead.org>
Signed-off-by: Matt Fleming <matt(a)codeblueprint.co.uk>
Signed-off-by: Peter Zijlstra (Intel) <peterz(a)infradead.org>
Link: http://lkml.kernel.org/r/20160921133813.31976-8-matt@codeblueprint.co.uk
+------------------------------------------------------+------------+------------+------------+
| | 68124eebc2 | 0a7f120b8b | ac39efd278 |
+------------------------------------------------------+------------+------------+------------+
| boot_successes | 4 | 0 | 0 |
| boot_failures | 202 | 55 | 34 |
| WARNING:at_arch/x86/mm/dump_pagetables.c:#note_page | 202 | 51 | 32 |
| calltrace:mark_rodata_ro | 202 | 51 | |
| invoked_oom-killer:gfp_mask=0x | 1 | | |
| Mem-Info | 1 | | |
| WARNING:at_kernel/sched/sched.h:#update_load_avg | 0 | 55 | 9 |
| calltrace:_do_fork | 0 | 55 | |
| WARNING:at_kernel/locking/lockdep.c:#lock_release | 0 | 0 | 9 |
| WARNING:at_kernel/sched/core.c:#update_rq_clock | 0 | 0 | 34 |
| WARNING:at_kernel/locking/lockdep.c:#lock_unpin_lock | 0 | 0 | 5 |
| WARNING:at_kernel/workqueue.c:#process_one_work | 0 | 0 | 1 |
+------------------------------------------------------+------------+------------+------------+
[ 0.444285] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[ 0.446184] Freeing SMP alternatives memory: 20K (41862000 - 41867000)
[ 0.457784] ------------[ cut here ]------------
[ 0.458458] WARNING: CPU: 0 PID: 0 at kernel/sched/sched.h:799 update_load_avg+0x8d/0xc90
[ 0.459752] rq->clock_update_flags < RQCF_ACT_SKIP
[ 0.464483] Modules linked in:
[ 0.464925] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.9.0-rc5-00291-g0a7f120 #42
[ 0.466110] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[ 0.467710] 4173be70 41201ad0 4173beb8 41689c08 4173be88 4105f59b 0000031f 5e36c594
[ 0.481208] 5e36c540 00000001 4173bea4 4105f5e8 00000009 00000000 4173be9c 41689c30
[ 0.482382] 4173beb8 4173bf0c 4108df1d 41689c08 0000031f 41689c30 00000000 00000000
[ 0.483534] Call Trace:
[ 0.483872] [<41201ad0>] dump_stack+0x8b/0xcb
[ 0.484588] [<4105f59b>] __warn+0xbb/0xe0
[ 0.485241] [<4105f5e8>] warn_slowpath_fmt+0x28/0x30
[ 0.486046] [<4108df1d>] update_load_avg+0x8d/0xc90
[ 0.486850] [<410ac386>] ? lock_acquire+0x86/0xc0
[ 0.487607] [<41083398>] ? __task_rq_lock+0x48/0xc0
[ 0.500669] [<41090630>] attach_entity_cfs_rq+0x40/0xe0
[ 0.501515] [<41090cf7>] post_init_entity_util_avg+0x127/0x150
[ 0.502439] [<410872db>] wake_up_new_task+0x14b/0x210
[ 0.503245] [<4105ed28>] _do_fork+0x488/0x4b0
[ 0.503967] [<41296ccc>] ? acpi_read_bit_register+0x1e/0x3d
[ 0.504778] [<4121538a>] ? find_next_bit+0xa/0x10
[ 0.505412] [<414bc320>] ? rest_init+0x120/0x120
[ 0.506036] [<4105ed6c>] kernel_thread+0x1c/0x30
[ 0.506661] [<414bc21a>] rest_init+0x1a/0x120
[ 0.507244] [<417a90ce>] start_kernel+0x3bc/0x3d6
[ 0.507880] [<417a830f>] i386_start_kernel+0xd3/0xe9
[ 0.508689] ---[ end trace 0000000000000000 ]---
[ 0.509593] smpboot: APIC(0) Converting physical 0 to logical package 0
git bisect start ac39efd278f89a1bbefbc6409f3fa33eb788a892 a25f0944ba9b1d8a6813fd6f1a86f1bd59ac25a6 --
git bisect bad 602c55d057cf3a64f4dde5f734c7d511382dcf46 # 01:23 2- 7 Merge 'nsekhar-davinci/master' into devel-spot-201611210414
git bisect bad 34c3adea0d0ecf462b5ddbb625a86d73a708db08 # 01:32 4- 11 Merge 'peterz-queue/irq/for-block' into devel-spot-201611210414
git bisect good a317c366cadd4c52639d6c02d87061f1c9eade0e # 01:40 51+ 51 Merge 'linux-review/sunil-kamath-intel-com/drm-i915-Use-num_scalers-instead-of-SKL_NUM_SCALERS-in-debugfs/20161121-015335' into devel-spot-201611210414
git bisect good a54725f60e4a63237f549983d5714e620afeba7d # 01:50 48+ 48 Merge 'peterz-queue/x86/idle' into devel-spot-201611210414
git bisect bad 30438e96ceeba7687ed3cb91b7738a6ea6343608 # 01:53 0- 1 Merge 'peterz-queue/sched/debug' into devel-spot-201611210414
git bisect good 9c2791f936ef5fd04a118b5c284f2c9a95f4a647 # 01:59 51+ 51 sched/fair: Fix hierarchical order in rq->leaf_cfs_rq_list
git bisect bad 0a7f120b8b60e0ecc3e7bc19a18eac523bbec215 # 02:03 0- 6 sched/core: Add debug code to catch missing update_rq_clock()
git bisect good d03266910a533d874c01ef2ca8dc73009f2925fa # 02:12 51+ 51 sched/fair: Fix task group initialization
git bisect good a41729b46459ed7937d92e4065831c6e5dc10e37 # 02:17 51+ 51 sched: Add wrappers for lockdep_(un)pin_lock()
git bisect good 68124eebc2985f3d613043c6f873483288525795 # 02:25 51+ 51 sched/fair: Push rq lock pin/unpin into idle_balance()
# first bad commit: [0a7f120b8b60e0ecc3e7bc19a18eac523bbec215] sched/core: Add debug code to catch missing update_rq_clock()
git bisect good 68124eebc2985f3d613043c6f873483288525795 # 02:33 151+ 202 sched/fair: Push rq lock pin/unpin into idle_balance()
# extra tests with CONFIG_DEBUG_INFO_REDUCED
git bisect bad 0a7f120b8b60e0ecc3e7bc19a18eac523bbec215 # 02:40 0- 23 sched/core: Add debug code to catch missing update_rq_clock()
# extra tests on HEAD of linux-devel/devel-spot-201611210414
git bisect bad ac39efd278f89a1bbefbc6409f3fa33eb788a892 # 02:40 0- 34 0day head guard for 'devel-spot-201611210414'
# extra tests on tree/branch peterz-queue/sched/debug
git bisect bad 2892d308e51d64c4f107408b4baef4c292ae4744 # 02:48 23- 33 sched: Avoid double update_rq_clock()
# extra tests on tree/branch linus/master
git bisect good 9c763584b7c8911106bb77af7e648bef09af9d80 # 02:55 151+ 266 Linux 4.9-rc6
# extra tests on tree/branch linux-next/master
git bisect good e3b16de6a58e005a1dcc6109483371c069387d76 # 03:10 141+ 143 Add linux-next specific files for 20161117
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
4 years, 2 months
- 1
- 0
[lkp] [f2fs] fff59ca2bd: fsmark.files_per_sec 38.5% improvement
by kernel test robot
Greeting,
FYI, we noticed a 38.5% improvement of fsmark.files_per_sec due to commit:
commit fff59ca2bd6b19ff8533052183865d3202d522f2 ("f2fs: remove percpu_count due to performance regression")
https://git.kernel.org/pub/scm/linux/kernel/git/jaegeuk/f2fs.git dev
in testcase: fsmark
on test machine: 48 threads Intel(R) Xeon(R) CPU E5-2697 v2 @ 2.70GHz with 64G memory
with following parameters:
iterations: 1x
nr_threads: 1t
disk: 1BRD_48G
fs: f2fs
filesize: 4M
test_size: 40G
sync_method: fsyncBeforeClose
cpufreq_governor: performance
test-description: The fsmark is a file system benchmark to test synchronous write workloads, for example, mail servers workload.
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/cpufreq_governor/disk/filesize/fs/iterations/kconfig/nr_threads/rootfs/sync_method/tbox_group/test_size/testcase:
gcc-6/performance/1BRD_48G/4M/f2fs/1x/x86_64-rhel-7.2/1t/debian-x86_64-2016-08-31.cgz/fsyncBeforeClose/ivb44/40G/fsmark
commit:
33f4764fe5 ("f2fs: make clean inodes when flushing inode page")
fff59ca2bd ("f2fs: remove percpu_count due to performance regression")
33f4764fe52849a4 fff59ca2bd6b19ff8533052183
---------------- --------------------------
%stddev %change %stddev
\ | \
162.30 ± 0% +38.5% 224.80 ± 3% fsmark.files_per_sec
63.11 ± 0% -27.7% 45.61 ± 3% fsmark.time.elapsed_time
63.11 ± 0% -27.7% 45.61 ± 3% fsmark.time.elapsed_time.max
62.72 ± 0% -27.9% 45.22 ± 3% fsmark.time.system_time
44794 ± 2% -17.5% 36941 ± 3% interrupts.CAL:Function_call_interrupts
49639 ± 4% -23.2% 38113 ± 12% meminfo.AnonHugePages
641642 ± 0% +35.8% 871649 ± 2% vmstat.io.bo
4330 ± 1% +12.5% 4871 ± 9% slabinfo.free_nid.active_objs
4330 ± 1% +12.5% 4871 ± 9% slabinfo.free_nid.num_objs
0.09 ± 81% +110.8% 0.19 ± 35% turbostat.Pkg%pc6
4.88 ± 1% +9.0% 5.33 ± 1% turbostat.RAMWatt
85244 ± 12% -18.8% 69209 ± 11% numa-meminfo.node0.SReclaimable
18949 ± 26% +34.1% 25416 ± 13% numa-meminfo.node1.Dirty
71271 ± 14% +21.0% 86264 ± 10% numa-meminfo.node1.SReclaimable
21312 ± 12% -18.8% 17306 ± 11% numa-vmstat.node0.nr_slab_reclaimable
4749 ± 25% +32.8% 6308 ± 13% numa-vmstat.node1.nr_dirty
17819 ± 14% +21.0% 21569 ± 10% numa-vmstat.node1.nr_slab_reclaimable
137024 ± 0% -25.3% 102422 ± 3% proc-vmstat.pgfault
661896 ± 44% -100.0% 0.00 ± -1% proc-vmstat.pgrefill
661896 ± 44% -100.0% 0.00 ± -1% proc-vmstat.pgskip_normal
31214 ± 3% -14.9% 26561 ± 6% cpuidle.C1-IVT.usage
725753 ± 1% -30.0% 507682 ± 5% cpuidle.C1E-IVT.time
5336 ± 3% -28.0% 3844 ± 3% cpuidle.C1E-IVT.usage
2712582 ± 7% -27.3% 1970783 ± 11% cpuidle.C3-IVT.time
10417 ± 5% -29.4% 7350 ± 7% cpuidle.C3-IVT.usage
2.904e+09 ± 0% -27.4% 2.108e+09 ± 3% cpuidle.C6-IVT.time
3479259 ± 0% -28.6% 2482785 ± 3% cpuidle.C6-IVT.usage
6.134e+10 ± 11% -47.8% 3.202e+10 ± 6% perf-stat.branch-instructions
5.476e+08 ± 4% -36.2% 3.496e+08 ± 3% perf-stat.branch-misses
59.23 ± 2% +3.5% 61.30 ± 0% perf-stat.cache-miss-rate%
2.386e+09 ± 7% -11.8% 2.105e+09 ± 5% perf-stat.cache-misses
4.024e+09 ± 5% -14.7% 3.433e+09 ± 5% perf-stat.cache-references
89488 ± 2% -27.2% 65191 ± 6% perf-stat.context-switches
5.194e+11 ± 8% -29.1% 3.683e+11 ± 9% perf-stat.cpu-cycles
2200 ± 3% -21.4% 1728 ± 5% perf-stat.cpu-migrations
3.31 ± 1% -91.1% 0.29 ± 8% perf-stat.dTLB-load-miss-rate%
2.082e+09 ± 1% -94.2% 1.213e+08 ± 6% perf-stat.dTLB-load-misses
6.086e+10 ± 1% -32.3% 4.12e+10 ± 4% perf-stat.dTLB-loads
27307653 ± 0% -26.0% 20212475 ± 3% perf-stat.dTLB-store-misses
4.807e+10 ± 17% -24.4% 3.636e+10 ± 0% perf-stat.dTLB-stores
30800489 ± 0% -27.6% 22284183 ± 3% perf-stat.iTLB-load-misses
11313078 ± 0% -22.0% 8821214 ± 2% perf-stat.iTLB-loads
3.404e+11 ± 11% -48.0% 1.768e+11 ± 5% perf-stat.instructions
11048 ± 10% -28.2% 7936 ± 4% perf-stat.instructions-per-iTLB-miss
0.65 ± 2% -26.3% 0.48 ± 4% perf-stat.ipc
126399 ± 0% -25.3% 94438 ± 2% perf-stat.minor-faults
126421 ± 0% -25.3% 94468 ± 2% perf-stat.page-faults
26.72 ± 9% -46.2% 14.37 ± 62% perf-profile.calltrace.cycles-pp.__filemap_fdatawrite_range.filemap_write_and_wait_range.f2fs_do_sync_file.f2fs_sync_file.vfs_fsync_range
9.99 ± 13% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.__percpu_counter_sum.f2fs_balance_fs.f2fs_write_data_page.f2fs_write_cache_pages.f2fs_write_data_pages
1.87 ± 9% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp._find_next_bit.__percpu_counter_sum.f2fs_balance_fs.f2fs_write_data_page.f2fs_write_cache_pages
1.31 ± 13% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp._find_next_bit.find_next_bit.__percpu_counter_sum.f2fs_balance_fs.f2fs_write_data_page
26.80 ± 9% -46.0% 14.47 ± 62% perf-profile.calltrace.cycles-pp.do_fsync.sys_fsync.entry_SYSCALL_64_fastpath
26.72 ± 9% -46.2% 14.37 ± 62% perf-profile.calltrace.cycles-pp.do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.f2fs_do_sync_file.f2fs_sync_file
11.13 ± 12% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.f2fs_balance_fs.f2fs_write_data_page.f2fs_write_cache_pages.f2fs_write_data_pages.do_writepages
26.80 ± 9% -46.0% 14.47 ± 62% perf-profile.calltrace.cycles-pp.f2fs_do_sync_file.f2fs_sync_file.vfs_fsync_range.do_fsync.sys_fsync
26.80 ± 9% -46.0% 14.47 ± 62% perf-profile.calltrace.cycles-pp.f2fs_sync_file.vfs_fsync_range.do_fsync.sys_fsync.entry_SYSCALL_64_fastpath
26.70 ± 9% -46.2% 14.36 ± 62% perf-profile.calltrace.cycles-pp.f2fs_write_cache_pages.f2fs_write_data_pages.do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range
23.24 ± 9% -52.4% 11.06 ± 61% perf-profile.calltrace.cycles-pp.f2fs_write_data_page.f2fs_write_cache_pages.f2fs_write_data_pages.do_writepages.__filemap_fdatawrite_range
26.72 ± 9% -46.2% 14.37 ± 62% perf-profile.calltrace.cycles-pp.f2fs_write_data_pages.do_writepages.__filemap_fdatawrite_range.filemap_write_and_wait_range.f2fs_do_sync_file
26.72 ± 9% -46.2% 14.38 ± 62% perf-profile.calltrace.cycles-pp.filemap_write_and_wait_range.f2fs_do_sync_file.f2fs_sync_file.vfs_fsync_range.do_fsync
1.75 ± 12% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.find_next_bit.__percpu_counter_sum.f2fs_balance_fs.f2fs_write_data_page.f2fs_write_cache_pages
26.80 ± 9% -46.0% 14.47 ± 62% perf-profile.calltrace.cycles-pp.sys_fsync.entry_SYSCALL_64_fastpath
26.80 ± 9% -46.0% 14.47 ± 62% perf-profile.calltrace.cycles-pp.vfs_fsync_range.do_fsync.sys_fsync.entry_SYSCALL_64_fastpath
26.72 ± 9% -46.2% 14.37 ± 62% perf-profile.children.cycles-pp.__filemap_fdatawrite_range
10.06 ± 13% -100.0% 0.00 ± -1% perf-profile.children.cycles-pp.__percpu_counter_sum
3.41 ± 11% -95.5% 0.15 ± 68% perf-profile.children.cycles-pp._find_next_bit
26.80 ± 9% -46.0% 14.47 ± 62% perf-profile.children.cycles-pp.do_fsync
26.72 ± 9% -46.2% 14.38 ± 62% perf-profile.children.cycles-pp.do_writepages
11.17 ± 12% -99.6% 0.05 ± 62% perf-profile.children.cycles-pp.f2fs_balance_fs
26.80 ± 9% -46.0% 14.47 ± 62% perf-profile.children.cycles-pp.f2fs_do_sync_file
26.80 ± 9% -46.0% 14.47 ± 62% perf-profile.children.cycles-pp.f2fs_sync_file
26.70 ± 9% -46.2% 14.36 ± 62% perf-profile.children.cycles-pp.f2fs_write_cache_pages
23.24 ± 9% -52.4% 11.06 ± 61% perf-profile.children.cycles-pp.f2fs_write_data_page
26.72 ± 9% -46.2% 14.37 ± 62% perf-profile.children.cycles-pp.f2fs_write_data_pages
26.72 ± 9% -46.2% 14.38 ± 62% perf-profile.children.cycles-pp.filemap_write_and_wait_range
2.87 ± 11% -93.2% 0.20 ± 59% perf-profile.children.cycles-pp.find_next_bit
26.80 ± 9% -46.0% 14.47 ± 62% perf-profile.children.cycles-pp.sys_fsync
26.80 ± 9% -46.0% 14.47 ± 62% perf-profile.children.cycles-pp.vfs_fsync_range
5.67 ± 12% -100.0% 0.00 ± -1% perf-profile.self.cycles-pp.__percpu_counter_sum
3.41 ± 11% -95.5% 0.15 ± 68% perf-profile.self.cycles-pp._find_next_bit
1.48 ± 8% -91.7% 0.12 ± 63% perf-profile.self.cycles-pp.find_next_bit
658.15 ± 0% -100.0% 0.00 ± -1% sched_debug.cfs_rq:/.exec_clock.avg
25800 ± 5% -100.0% 0.00 ± -1% sched_debug.cfs_rq:/.exec_clock.max
1.14 ± 44% -100.0% 0.00 ± -1% sched_debug.cfs_rq:/.exec_clock.min
3695 ± 4% -100.0% 0.00 ± -1% sched_debug.cfs_rq:/.exec_clock.stddev
839.72 ± 4% +91.9% 1611 ± 10% sched_debug.cfs_rq:/.load_avg.avg
1738 ± 4% +33.4% 2319 ± 13% sched_debug.cfs_rq:/.load_avg.max
754.88 ± 3% +88.3% 1421 ± 15% sched_debug.cfs_rq:/.load_avg.min
9878 ± 6% -30.2% 6892 ± 25% sched_debug.cfs_rq:/.min_vruntime.avg
125413 ± 30% -87.5% 15661 ± 11% sched_debug.cfs_rq:/.min_vruntime.max
17476 ± 31% -88.3% 2052 ± 9% sched_debug.cfs_rq:/.min_vruntime.stddev
0.16 ± 18% +77.8% 0.29 ± 15% sched_debug.cfs_rq:/.nr_running.avg
0.34 ± 5% +34.4% 0.46 ± 7% sched_debug.cfs_rq:/.nr_running.stddev
0.50 ± 0% -100.0% 0.00 ± -1% sched_debug.cfs_rq:/.nr_spread_over.avg
0.50 ± 0% -100.0% 0.00 ± -1% sched_debug.cfs_rq:/.nr_spread_over.max
0.50 ± 0% -100.0% 0.00 ± -1% sched_debug.cfs_rq:/.nr_spread_over.min
12.42 ± 4% -74.3% 3.19 ± 17% sched_debug.cfs_rq:/.runnable_load_avg.avg
536.00 ± 2% -83.4% 89.00 ± 24% sched_debug.cfs_rq:/.runnable_load_avg.max
76.95 ± 2% -83.3% 12.85 ± 23% sched_debug.cfs_rq:/.runnable_load_avg.stddev
-4922 ±-15% +69.4% -8337 ±-13% sched_debug.cfs_rq:/.spread0.avg
110636 ± 35% -99.6% 458.39 ±173% sched_debug.cfs_rq:/.spread0.max
17478 ± 31% -88.2% 2069 ± 8% sched_debug.cfs_rq:/.spread0.stddev
360.17 ± 3% +87.1% 673.99 ± 7% sched_debug.cfs_rq:/.util_avg.avg
265.00 ± 16% +111.9% 561.50 ± 12% sched_debug.cfs_rq:/.util_avg.min
105.27 ± 3% -36.8% 66.51 ± 23% sched_debug.cfs_rq:/.util_avg.stddev
821295 ± 1% -19.0% 665543 ± 7% sched_debug.cpu.avg_idle.avg
295130 ± 26% -94.1% 17416 ± 71% sched_debug.cpu.avg_idle.min
172871 ± 4% +60.8% 277965 ± 5% sched_debug.cpu.avg_idle.stddev
54997 ± 0% -51.1% 26906 ± 9% sched_debug.cpu.clock.avg
55002 ± 0% -51.1% 26909 ± 9% sched_debug.cpu.clock.max
54973 ± 0% -51.1% 26901 ± 9% sched_debug.cpu.clock.min
5.36 ± 56% -66.0% 1.82 ± 3% sched_debug.cpu.clock.stddev
54997 ± 0% -51.1% 26906 ± 9% sched_debug.cpu.clock_task.avg
55002 ± 0% -51.1% 26909 ± 9% sched_debug.cpu.clock_task.max
54973 ± 0% -51.1% 26901 ± 9% sched_debug.cpu.clock_task.min
5.36 ± 56% -66.0% 1.82 ± 3% sched_debug.cpu.clock_task.stddev
12.20 ± 4% -75.1% 3.04 ± 19% sched_debug.cpu.cpu_load[0].avg
536.00 ± 2% -83.3% 89.50 ± 23% sched_debug.cpu.cpu_load[0].max
76.96 ± 2% -83.2% 12.92 ± 23% sched_debug.cpu.cpu_load[0].stddev
15.12 ± 3% -58.6% 6.26 ± 33% sched_debug.cpu.cpu_load[1].avg
591.38 ± 4% -82.2% 105.50 ± 30% sched_debug.cpu.cpu_load[1].max
85.95 ± 3% -77.8% 19.07 ± 39% sched_debug.cpu.cpu_load[1].stddev
14.92 ± 4% -52.8% 7.05 ± 33% sched_debug.cpu.cpu_load[2].avg
582.50 ± 4% -78.8% 123.75 ± 45% sched_debug.cpu.cpu_load[2].max
84.78 ± 3% -74.6% 21.51 ± 43% sched_debug.cpu.cpu_load[2].stddev
14.84 ± 5% -51.4% 7.20 ± 29% sched_debug.cpu.cpu_load[3].avg
579.62 ± 6% -79.8% 117.00 ± 52% sched_debug.cpu.cpu_load[3].max
84.63 ± 5% -75.3% 20.87 ± 42% sched_debug.cpu.cpu_load[3].stddev
14.70 ± 5% -52.7% 6.95 ± 22% sched_debug.cpu.cpu_load[4].avg
585.88 ± 7% -79.0% 123.25 ± 39% sched_debug.cpu.cpu_load[4].max
84.99 ± 6% -76.1% 20.34 ± 33% sched_debug.cpu.cpu_load[4].stddev
196.09 ± 14% +61.0% 315.71 ± 12% sched_debug.cpu.curr->pid.avg
2003 ± 0% -38.8% 1226 ± 2% sched_debug.cpu.curr->pid.max
257003 ±158% -96.1% 10093 ±100% sched_debug.cpu.load.avg
6597 ± 1% -13.5% 5708 ± 6% sched_debug.cpu.nr_load_updates.avg
32785 ± 2% -67.6% 10619 ± 15% sched_debug.cpu.nr_load_updates.max
4283 ± 3% -71.5% 1221 ± 11% sched_debug.cpu.nr_load_updates.stddev
1848 ± 1% -49.9% 925.32 ± 5% sched_debug.cpu.nr_switches.avg
15395 ± 22% -63.2% 5672 ± 6% sched_debug.cpu.nr_switches.max
523.75 ± 8% -26.7% 384.00 ± 10% sched_debug.cpu.nr_switches.min
2439 ± 13% -61.9% 929.32 ± 11% sched_debug.cpu.nr_switches.stddev
5.03 ± 14% -27.0% 3.67 ± 21% sched_debug.cpu.nr_uninterruptible.stddev
1798 ± 10% -100.0% 0.00 ± -1% sched_debug.cpu.sched_count.avg
34909 ± 10% -100.0% 0.00 ± -1% sched_debug.cpu.sched_count.max
54.38 ± 14% -100.0% 0.00 ± -1% sched_debug.cpu.sched_count.min
5381 ± 8% -100.0% 0.00 ± -1% sched_debug.cpu.sched_count.stddev
442.41 ± 3% -100.0% 0.00 ± -1% sched_debug.cpu.sched_goidle.avg
6133 ± 28% -100.0% 0.00 ± -1% sched_debug.cpu.sched_goidle.max
21.88 ± 26% -100.0% 0.00 ± -1% sched_debug.cpu.sched_goidle.min
987.99 ± 17% -100.0% 0.00 ± -1% sched_debug.cpu.sched_goidle.stddev
449.64 ± 3% -100.0% 0.00 ± -1% sched_debug.cpu.ttwu_count.avg
5829 ± 26% -100.0% 0.00 ± -1% sched_debug.cpu.ttwu_count.max
14.88 ± 19% -100.0% 0.00 ± -1% sched_debug.cpu.ttwu_count.min
958.97 ± 16% -100.0% 0.00 ± -1% sched_debug.cpu.ttwu_count.stddev
202.36 ± 0% -100.0% 0.00 ± -1% sched_debug.cpu.ttwu_local.avg
4908 ± 35% -100.0% 0.00 ± -1% sched_debug.cpu.ttwu_local.max
10.12 ± 8% -100.0% 0.00 ± -1% sched_debug.cpu.ttwu_local.min
730.35 ± 30% -100.0% 0.00 ± -1% sched_debug.cpu.ttwu_local.stddev
54996 ± 0% -51.1% 26904 ± 9% sched_debug.cpu_clk
53880 ± 0% -52.3% 25695 ± 9% sched_debug.ktime
0.10 ± 9% +94.4% 0.19 ± 15% sched_debug.rt_rq:/.rt_time.avg
4.44 ± 4% +105.6% 9.12 ± 15% sched_debug.rt_rq:/.rt_time.max
0.64 ± 4% +104.6% 1.30 ± 15% sched_debug.rt_rq:/.rt_time.stddev
54996 ± 0% -51.1% 26904 ± 9% sched_debug.sched_clk
perf-stat.dTLB-load-misses
2.5e+09 ++----------------------------------------------------------------+
| |
| * * .*. .*..*.* |
2e+09 ++ + + .. + .*.* *.* |
| *.. .*. .* * * |
*. : * *.*.* |
1.5e+09 ++* : |
| : : |
1e+09 ++ : : |
| : : |
| : : |
5e+08 ++ : : |
| : |
O O O O O O O O O O O O O O O O O O O O O O O O O O O O O O O
0 ++--*----------------O--------------------------------------------+
perf-stat.page-faults
1.4e+06 ++-------------------*----*---------------------------------------+
| : : |
1.2e+06 ++ : : |
| : :: |
1e+06 ++ : : : : |
| : : : : |
800000 ++ : : : : |
| : : : : |
600000 ++ : : : : |
| : : : : |
400000 ++ : :: : |
| : : : |
200000 ++ : : : |
O.O.O.O..O.O.O.O.O.O O O O.O.O.O.O.O.O..O.O O O O O O O O O O O
0 ++--*----------------O--------------------------------------------+
perf-stat.minor-faults
1.4e+06 ++-------------------*----*---------------------------------------+
| : : |
1.2e+06 ++ : : |
| : :: |
1e+06 ++ : : : : |
| : : : : |
800000 ++ : : : : |
| : : : : |
600000 ++ : : : : |
| : : : : |
400000 ++ : :: : |
| : : : |
200000 ++ : : : |
O.O.O.O..O.O.O.O.O.O O O O.O.O.O.O.O.O..O.O O O O O O O O O O O
0 ++--*----------------O--------------------------------------------+
perf-stat.dTLB-load-miss-rate_
3.5 ++-------------------------------------------*------------------------+
| *.*.*.*..*.* * |
3 *+ *.*. .. |
| * : *..*.*.*.* * * |
2.5 ++: : + : : : |
| : : + : : : |
2 ++ : : * * |
| : : |
1.5 ++ : : |
| : : |
1 ++ : : |
| : : |
0.5 ++ :: O |
O O O O O O O O O O O O O O O O O O O O O O O O O O O O O O
0 ++---*-----------------O----------------------------------------------+
perf-stat.ipc
0.7 ++-------------------------------------------*------------------------+
*. .*.. .*.* .*.*.*. .*.* * |
0.6 ++* *.* *.* : * *. *. |
| : : O : : : |
0.5 O+O: O O O O O O: O O O O O O O O O O O O O O O O O O O
| : : O : : : : O O |
0.4 ++ : : : : : : |
| : : : : : : |
0.3 ++ : : : : : : |
| : : :: : |
0.2 ++ : : : : |
| : : * * |
0.1 ++ : |
| : |
0 ++---*-----------------O----------------------------------------------+
fsmark.time.system_time
70 ++---------------------------------------------------------------------+
| .*. .*.. .*.* |
60 *+* *.*. .*. .* * *.*.*. * * |
| : : *..* *. : : : |
50 ++ : : : : : O O |
O O: O O O O O O O O: O:O :O O O O O O O O O O O O O O O O O
40 ++ : : : : : : |
| : : : : : : |
30 ++ : : : : : : |
| : : : : : : |
20 ++ : : : : : : |
| : : :: :: |
10 ++ : : :: |
| : : : |
0 ++---*-----------------O---*-------------------------------------------+
fsmark.time.elapsed_time
70 ++---------------------------------------------------------------------+
| .*.*..*. .*..*.*.* |
60 *+* *.*.*.. .*.*..* * * * |
| : : * : : : |
50 ++ : : : : : O O O |
O O: O O O O O O O O: O:O :O O O O O O O O O O O O O O O O
40 ++ : : : : : : |
| : : : : : : |
30 ++ : : : : : : |
| : : : : : : |
20 ++ : : : : : : |
| : : :: :: |
10 ++ : : :: |
| : : : |
0 ++---*-----------------O---*-------------------------------------------+
fsmark.time.elapsed_time.max
70 ++---------------------------------------------------------------------+
| .*.*..*. .*..*.*.* |
60 *+* *.*.*.. .*.*..* * * * |
| : : * : : : |
50 ++ : : : : : O O O |
O O: O O O O O O O O: O:O :O O O O O O O O O O O O O O O O
40 ++ : : : : : : |
| : : : : : : |
30 ++ : : : : : : |
| : : : : : : |
20 ++ : : : : : : |
| : : :: :: |
10 ++ : : :: |
| : : : |
0 ++---*-----------------O---*-------------------------------------------+
vmstat.io.bo
1e+06 ++-----------------------------------------------------------------+
900000 ++ O
O O O O O O O O O O O O O O O O O O O O O O O O O O O O O O |
800000 ++ |
700000 *+* *..*.*.*.*.*.* |
| : : : * *.*.*..*.*.*.*.*.* |
600000 ++: : : : : |
500000 ++ : : : :: : |
400000 ++ : : : : : : |
| : : : : : : |
300000 ++ : : : : : : |
200000 ++ : : : : :: |
| : : : |
100000 ++ : * * |
0 ++--*-----------------O--------------------------------------------+
fsmark.files_per_sec
250 ++--------------------------------------------------------------------+
O O O O O O O
| O O O O O O O O O O O O O O O O O O O O O O O O |
200 ++ |
*.* *.*.*..*.*.*.* * *.. |
| : : : : : *.*.*.*..*.*.*.* |
150 ++ : : : : : |
| : : : : : : |
100 ++ : : : : : : |
| : : : : : : |
| : : : : : : |
50 ++ : : : : : : |
| :: :: : |
| : : : |
0 ++---*-----------------O---*------------------------------------------+
[*] bisect-good sample
[O] bisect-bad sample
Disclaimer:
Results have been estimated based on internal Intel analysis and are provided
for informational purposes only. Any difference in system hardware or software
design or configuration may affect actual performance.
Thanks,
Xiaolong
4 years, 2 months
- 1
- 0
[lkp] [virtio_pci] 9ddb06b188: WARNING:at_kernel/irq/manage.c:#__free_irq
by kernel test robot
FYI, we noticed the following commit:
git://git.infradead.org/users/hch/block.git virtio-affinity
commit 9ddb06b1881ae79983c9b8afe41f25cde37f647b ("virtio_pci: use shared interrupts for virtqueues")
in testcase: trinity
with following parameters:
runtime: 300s
test-description: Trinity is a linux system call fuzz tester.
on test machine: qemu-system-i386 -enable-kvm -smp 2 -m 320M
caused below changes:
+--------------------------------------------+------------+------------+
| | 425c1a1458 | 9ddb06b188 |
+--------------------------------------------+------------+------------+
| boot_successes | 11 | 4 |
| boot_failures | 1 | 8 |
| invoked_oom-killer:gfp_mask=0x | 1 | |
| Mem-Info | 1 | |
| WARNING:at_kernel/irq/manage.c:#__free_irq | 0 | 8 |
| calltrace:init | 0 | 8 |
+--------------------------------------------+------------+------------+
[ 4.965451] HP CISS Driver (v 3.6.26)
[ 4.967273] MM: desc_per_page = 128
[ 4.968957] ------------[ cut here ]------------
[ 4.970737] WARNING: CPU: 0 PID: 1 at kernel/irq/manage.c:1478 __free_irq+0x91/0x200
[ 4.975001] Trying to free already-free IRQ 11
[ 4.977251] CPU: 0 PID: 1 Comm: swapper Not tainted 4.9.0-rc4-00013-g9ddb06b #1
[ 4.980897] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[ 4.985242] d344bc4c c144eb99 d344bc7c c1043049 c1e8b95c d344bcac 00000001 c1e8b894
[ 4.990243] 000005c6 c1079f31 000005c6 0000000b d0a6fc00 0000000b d344bc98 c10430a6
[ 4.995218] 00000009 00000000 d344bc90 c1e8b95c d344bcac d344bcc4 c1079f31 c1e8b894
[ 5.000174] Call Trace:
[ 5.001876] [<c144eb99>] dump_stack+0x16/0x1d
[ 5.003930] [<c1043049>] __warn+0xc9/0xf0
[ 5.005151] [<c1079f31>] ? __free_irq+0x91/0x200
[ 5.007206] [<c10430a6>] warn_slowpath_fmt+0x36/0x40
[ 5.009491] [<c1079f31>] __free_irq+0x91/0x200
[ 5.011533] [<c107ac81>] free_irq+0x21/0x50
[ 5.013382] [<c153822c>] vp_del_vqs+0x7c/0x130
[ 5.015558] [<c1538396>] vp_find_vqs_msix+0xb6/0x380
[ 5.017919] [<c153868c>] vp_find_vqs+0x2c/0x170
[ 5.020153] [<c15373ef>] vp_modern_find_vqs+0x1f/0x80
[ 5.022539] [<c15efeea>] init_vq+0x12a/0x220
[ 5.024580] [<c15f00f3>] virtblk_probe+0xa3/0x6e0
[ 5.026701] [<c1536ba2>] ? vp_finalize_features+0x62/0x90
[ 5.028866] [<c1536d51>] ? vp_get_status+0x11/0x20
[ 5.030792] [<c153421c>] virtio_dev_probe+0x1ac/0x290
[ 5.032842] [<c15afa59>] driver_probe_device+0x1e9/0x460
[ 5.034922] [<c1164d20>] ? kernfs_create_dir_ns+0x40/0x70
[ 5.036956] [<c15afdb9>] __driver_attach+0xe9/0xf0
[ 5.038861] [<c14511d8>] ? kobject_add_internal+0x1a8/0x340
[ 5.040941] [<c15adbf0>] ? bus_uevent_store+0x40/0x40
[ 5.043013] [<c15afcd0>] ? driver_probe_device+0x460/0x460
[ 5.045180] [<c15add97>] bus_for_each_dev+0x47/0x80
[ 5.047107] [<c15afef9>] driver_attach+0x19/0x20
[ 5.048975] [<c15afcd0>] ? driver_probe_device+0x460/0x460
[ 5.051023] [<c15ae717>] bus_add_driver+0x167/0x260
[ 5.053038] [<c15b0554>] driver_register+0x54/0xe0
[ 5.055016] [<c15343c6>] register_virtio_driver+0x16/0x30
[ 5.057044] [<c2182154>] init+0x70/0xba
[ 5.058753] [<c21820e4>] ? mm_init+0x1e1/0x1e1
[ 5.060583] [<c2139266>] do_one_initcall+0xa9/0x189
[ 5.062615] [<c1059fa1>] ? parse_args+0x2b1/0x560
[ 5.064625] [<c1061b00>] ? ___might_sleep+0xf0/0x120
[ 5.066587] [<c213942b>] ? kernel_init_freeable+0xe5/0x1e5
[ 5.068642] [<c213945e>] kernel_init_freeable+0x118/0x1e5
[ 5.070689] [<c1b1c990>] ? rest_init+0x70/0x70
[ 5.072638] [<c1b1c99b>] kernel_init+0xb/0x100
[ 5.074548] [<c106046c>] ? schedule_tail+0xc/0x50
[ 5.076452] [<c1b1c990>] ? rest_init+0x70/0x70
[ 5.078281] [<c1b20ffb>] ret_from_fork+0x1b/0x30
[ 5.080151] ---[ end trace a746fb31fb7351d3 ]---
[ 5.082165] ------------[ cut here ]------------
[ 5.084179] WARNING: CPU: 0 PID: 1 at kernel/irq/manage.c:1478 __free_irq+0x91/0x200
[ 5.087949] Trying to free already-free IRQ 11
[ 5.089771] CPU: 0 PID: 1 Comm: swapper Tainted: G W 4.9.0-rc4-00013-g9ddb06b #1
[ 5.093486] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[ 5.097781] d344bc4c c144eb99 d344bc7c c1043049 c1e8b95c d344bcac 00000001 c1e8b894
[ 5.102581] 000005c6 c1079f31 000005c6 0000000b d0a6fc00 0000000b d344bc98 c10430a6
[ 5.107350] 00000009 00000000 d344bc90 c1e8b95c d344bcac d344bcc4 c1079f31 c1e8b894
[ 5.112152] Call Trace:
[ 5.113705] [<c144eb99>] dump_stack+0x16/0x1d
[ 5.115718] [<c1043049>] __warn+0xc9/0xf0
[ 5.117680] [<c1079f31>] ? __free_irq+0x91/0x200
[ 5.119765] [<c10430a6>] warn_slowpath_fmt+0x36/0x40
[ 5.121968] [<c1079f31>] __free_irq+0x91/0x200
[ 5.124050] [<c107ac81>] free_irq+0x21/0x50
[ 5.126056] [<c153822c>] vp_del_vqs+0x7c/0x130
[ 5.128123] [<c1538396>] vp_find_vqs_msix+0xb6/0x380
[ 5.130291] [<c15386c1>] vp_find_vqs+0x61/0x170
[ 5.132388] [<c15373ef>] vp_modern_find_vqs+0x1f/0x80
[ 5.134102] [<c15efeea>] init_vq+0x12a/0x220
[ 5.135292] [<c15f00f3>] virtblk_probe+0xa3/0x6e0
[ 5.136551] [<c1536ba2>] ? vp_finalize_features+0x62/0x90
[ 5.137940] [<c1536d51>] ? vp_get_status+0x11/0x20
[ 5.139230] [<c153421c>] virtio_dev_probe+0x1ac/0x290
[ 5.140549] [<c15afa59>] driver_probe_device+0x1e9/0x460
[ 5.141889] [<c1164d20>] ? kernfs_create_dir_ns+0x40/0x70
[ 5.143262] [<c15afdb9>] __driver_attach+0xe9/0xf0
[ 5.144550] [<c14511d8>] ? kobject_add_internal+0x1a8/0x340
[ 5.145931] [<c15adbf0>] ? bus_uevent_store+0x40/0x40
[ 5.147238] [<c15afcd0>] ? driver_probe_device+0x460/0x460
[ 5.148607] [<c15add97>] bus_for_each_dev+0x47/0x80
[ 5.149882] [<c15afef9>] driver_attach+0x19/0x20
[ 5.151188] [<c15afcd0>] ? driver_probe_device+0x460/0x460
[ 5.152550] [<c15ae717>] bus_add_driver+0x167/0x260
[ 5.153875] [<c15b0554>] driver_register+0x54/0xe0
[ 5.155316] [<c15343c6>] register_virtio_driver+0x16/0x30
[ 5.181812] [<c2182154>] init+0x70/0xba
[ 5.183841] [<c21820e4>] ? mm_init+0x1e1/0x1e1
[ 5.185988] [<c2139266>] do_one_initcall+0xa9/0x189
[ 5.188280] [<c1059fa1>] ? parse_args+0x2b1/0x560
[ 5.189864] [<c1061b00>] ? ___might_sleep+0xf0/0x120
[ 5.191113] [<c213942b>] ? kernel_init_freeable+0xe5/0x1e5
[ 5.192453] [<c213945e>] kernel_init_freeable+0x118/0x1e5
[ 5.193920] [<c1b1c990>] ? rest_init+0x70/0x70
[ 5.195106] [<c1b1c99b>] kernel_init+0xb/0x100
[ 5.196289] [<c106046c>] ? schedule_tail+0xc/0x50
[ 5.197657] [<c1b1c990>] ? rest_init+0x70/0x70
[ 5.198834] [<c1b20ffb>] ret_from_fork+0x1b/0x30
[ 5.200031] ---[ end trace a746fb31fb7351d4 ]---
[ 5.202151] FDC 0 is a S82078B
[ 5.204574] mtip32xx Version 1.3.1
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
4 years, 2 months
- 1
- 0
[lkp] [rcu] 83ee00c6cf: WARNING:at_kernel/softirq.c:#__local_bh_enable
by kernel test robot
FYI, we noticed the following commit:
https://github.com/0day-ci/linux Ding-Tianhong/rcu-fix-the-OOM-problem-of-huge-IP-abnormal-packet-traffic/20161118-204521
commit 83ee00c6cf5eaa85f74094d6800732edf7114ef9 ("rcu: fix the OOM problem of huge IP abnormal packet traffic")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -m 320M
caused below changes:
+------------------------------------------------+------------+------------+
| | 68ad1194cf | 83ee00c6cf |
+------------------------------------------------+------------+------------+
| boot_successes | 6 | 0 |
| boot_failures | 0 | 6 |
| WARNING:at_kernel/softirq.c:#__local_bh_enable | 0 | 6 |
| calltrace:_local_bh_enable | 0 | 6 |
+------------------------------------------------+------------+------------+
[ 0.846125] PCI: CLS 0 bytes, default 64
[ 0.847479] Unpacking initramfs...
[ 0.849690] ------------[ cut here ]------------
[ 0.850615] WARNING: CPU: 0 PID: 9 at kernel/softirq.c:140 __local_bh_enable+0x35/0x41
[ 0.852518] Modules linked in:
[ 0.853178] CPU: 0 PID: 9 Comm: rcuos/0 Not tainted 4.9.0-rc1-00041-g83ee00c #1
[ 0.854630] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[ 0.856628] ffff8800002f7c70 ffffffff81267760 0000000000000000 ffffffff81837340
[ 0.858185] ffff8800002f7cb0 ffffffff81060e07 0000008c00000009 0000000000000200
[ 0.859742] ffff8800002f7dc8 ffff88000f808bb0 0000000000000001 ffff88000f808bb0
[ 0.861293] Call Trace:
[ 0.861795] [<ffffffff81267760>] dump_stack+0x61/0x7e
[ 0.862809] [<ffffffff81060e07>] __warn+0xf5/0x110
[ 0.863870] [<ffffffff81060f85>] warn_slowpath_null+0x18/0x1a
[ 0.865020] [<ffffffff81066b09>] __local_bh_enable+0x35/0x41
[ 0.866143] [<ffffffff81066b52>] _local_bh_enable+0x3d/0x3f
[ 0.867252] [<ffffffff810dbf14>] rcu_nocb_kthread+0x69b/0x6f2
[ 0.868393] [<ffffffff811cbe81>] ? __d_free_external+0x3f/0x3f
[ 0.869554] [<ffffffff810db879>] ? note_gp_changes+0xcd/0xcd
[ 0.870679] [<ffffffff815ff413>] ? __schedule+0x5fc/0x73c
[ 0.871755] [<ffffffff810db879>] ? note_gp_changes+0xcd/0xcd
[ 0.872980] [<ffffffff810898c7>] kthread+0x191/0x1a0
[ 0.873971] [<ffffffff81089736>] ? kthread_park+0x5d/0x5d
[ 0.875059] [<ffffffff8108fd54>] ? finish_task_switch+0x1e4/0x2a0
[ 0.876262] [<ffffffff81089736>] ? kthread_park+0x5d/0x5d
[ 0.877331] [<ffffffff81089736>] ? kthread_park+0x5d/0x5d
[ 0.878401] [<ffffffff81606a45>] ret_from_fork+0x25/0x30
[ 0.879484] ---[ end trace 825c5dbf85ebfadd ]---
[ 0.899723] workqueue: round-robin CPU selection forced, expect performance impact
[ 2.115863] Freeing initrd memory: 9088K (ffff880013700000 - ffff880013fe0000)
To reproduce:
git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
Xiaolong
4 years, 2 months
- 1
- 0
[rcu] 83ee00c6cf: WARNING: CPU: 0 PID: 9 at kernel/softirq.c:140 __local_bh_enable
by kernel test robot
Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
https://github.com/0day-ci/linux Ding-Tianhong/rcu-fix-the-OOM-problem-of-huge-IP-abnormal-packet-traffic/20161118-204521
commit 83ee00c6cf5eaa85f74094d6800732edf7114ef9
Author: Ding Tianhong <dingtianhong(a)huawei.com>
AuthorDate: Fri Nov 18 20:40:09 2016 +0800
Commit: 0day robot <fengguang.wu(a)intel.com>
CommitDate: Fri Nov 18 20:45:23 2016 +0800
rcu: fix the OOM problem of huge IP abnormal packet traffic
The commit bedc196915 ("rcu: Fix soft lockup for rcu_nocb_kthread")
will introduce a new problem that when huge IP abnormal packet arrived,
it may cause OOM and break the kernel, just like this:
[ 79.441538] mlx4_en: eth5: Leaving promiscuous mode steering mode:2
[ 100.067032] ksoftirqd/0: page allocation failure: order:0, mode:0x120
[ 100.067038] CPU: 0 PID: 3 Comm: ksoftirqd/0 Tainted: G OE ----V------- 3.10.0-327.28.3.28.x86_64 #1
[ 100.067039] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.9.1-0-gb3ef39f-20161018_184732-HGH1000003483 04/01/2014
[ 100.067041] 0000000000000120 00000000b080d798 ffff8802afd5b968 ffffffff81638cb9
[ 100.067045] ffff8802afd5b9f8 ffffffff81171380 0000000000000010 0000000000000000
[ 100.067048] ffff8802befd8000 00000000ffffffff 0000000000000001 00000000b080d798
[ 100.067050] Call Trace:
[ 100.067057] [<ffffffff81638cb9>] dump_stack+0x19/0x1b
[ 100.067062] [<ffffffff81171380>] warn_alloc_failed+0x110/0x180
[ 100.067066] [<ffffffff81175b16>] __alloc_pages_nodemask+0x9b6/0xba0
[ 100.067070] [<ffffffff8151e400>] ? skb_add_rx_frag+0x90/0xb0
[ 100.067075] [<ffffffff811b6fba>] alloc_pages_current+0xaa/0x170
[ 100.067080] [<ffffffffa06b9be0>] mlx4_alloc_pages.isra.24+0x40/0x170 [mlx4_en]
[ 100.067083] [<ffffffffa06b9dec>] mlx4_en_alloc_frags+0xdc/0x220 [mlx4_en]
[ 100.067086] [<ffffffff8152eeb8>] ? __netif_receive_skb+0x18/0x60
[ 100.067088] [<ffffffff8152ef40>] ? netif_receive_skb+0x40/0xc0
[ 100.067092] [<ffffffffa06bb521>] mlx4_en_process_rx_cq+0x5f1/0xec0 [mlx4_en]
[ 100.067095] [<ffffffff8131027d>] ? list_del+0xd/0x30
[ 100.067098] [<ffffffff8152c90f>] ? __napi_complete+0x1f/0x30
[ 100.067101] [<ffffffffa06bbeef>] mlx4_en_poll_rx_cq+0x9f/0x170 [mlx4_en]
[ 100.067103] [<ffffffff8152f372>] net_rx_action+0x152/0x240
[ 100.067107] [<ffffffff81084d1f>] __do_softirq+0xef/0x280
[ 100.067109] [<ffffffff81084ee0>] run_ksoftirqd+0x30/0x50
[ 100.067114] [<ffffffff810ae93f>] smpboot_thread_fn+0xff/0x1a0
[ 100.067117] [<ffffffff8163e269>] ? schedule+0x29/0x70
[ 100.067120] [<ffffffff810ae840>] ? lg_double_unlock+0x90/0x90
[ 100.067122] [<ffffffff810a5d4f>] kthread+0xcf/0xe0
[ 100.067124] [<ffffffff810a5c80>] ? kthread_create_on_node+0x140/0x140
[ 100.067127] [<ffffffff81649198>] ret_from_fork+0x58/0x90
[ 100.067129] [<ffffffff810a5c80>] ? kthread_create_on_node+0x140/0x140
================================cut here=====================================
The reason is that the huge abnormal IP packet will be received to net stack
and be dropped finally by dst_release, and the dst_release would use the rcuos
callback-offload kthread to free the packet, but the cond_resched_rcu_qs() will
calling do_softirq() to receive more and more IP abnormal packets which will be
throw into the RCU callbacks again later, the number of received packet is much
greater than the number of packets freed, it will exhaust the memory and then OOM,
so don't try to process any pending softirqs in the rcuos callback-offload kthread
is a more effective solution.
Fix commit bedc196915 ("rcu: Fix soft lockup for rcu_nocb_kthread")
Signed-off-by: Ding Tianhong <dingtianhong(a)huawei.com>
Signed-off-by: Ding Tianhong <dingtianhong(a)huawei.com>
+--------------------------------------------------------+------------+------------+------------+
| | 68ad1194cf | 83ee00c6cf | 723010c613 |
+--------------------------------------------------------+------------+------------+------------+
| boot_successes | 86 | 0 | 0 |
| boot_failures | 4 | 26 | 13 |
| BUG:kernel_reboot-without-warning_in_test_stage | 1 | | |
| BUG:unable_to_handle_kernel | 3 | 2 | |
| Oops | 3 | 2 | |
| RIP:auxv_read | 1 | | |
| calltrace:SyS_pread64 | 1 | | |
| Kernel_panic-not_syncing:Fatal_exception | 1 | | |
| calltrace:SyS_readv | 1 | | |
| RIP:tty_wakeup | 1 | 2 | |
| calltrace:SyS_select | 1 | | |
| WARNING:at_kernel/softirq.c:#__local_bh_enable | 0 | 26 | 13 |
| calltrace:_local_bh_enable | 0 | 26 | 13 |
| WARNING:at_kernel/locking/lockdep.c:#trace_softirqs_on | 0 | 26 | 13 |
| calltrace:SyS_munmap | 0 | 1 | |
| calltrace:SyS_wait4 | 0 | 1 | |
+--------------------------------------------------------+------------+------------+------------+
[ 1.756849] PCI: CLS 0 bytes, default 64
[ 1.757887] Unpacking initramfs...
[ 1.762037] ------------[ cut here ]------------
[ 1.762768] WARNING: CPU: 0 PID: 9 at kernel/softirq.c:140 __local_bh_enable+0x35/0x59
[ 1.764216] CPU: 0 PID: 9 Comm: rcuos/0 Not tainted 4.9.0-rc1-00041-g83ee00c #1
[ 1.765305] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[ 1.766867] ffff88000015fd70 ffffffff8123f5d7 0000000000000000 0000000000000000
[ 1.768160] ffff88000015fdb0 ffffffff810a6bd9 0000008c201b88c2 0000000000000200
[ 1.769371] 0000000000000000 ffff88000015fe30 ffff88001e110f70 ffff88001e110f70
[ 1.770645] Call Trace:
[ 1.771034] [<ffffffff8123f5d7>] dump_stack+0x86/0xc0
[ 1.771830] [<ffffffff810a6bd9>] __warn+0xb3/0xce
[ 1.772578] [<ffffffff810a6ca1>] warn_slowpath_null+0x18/0x1a
[ 1.773474] [<ffffffff810aaf09>] __local_bh_enable+0x35/0x59
[ 1.774348] [<ffffffff810ab2d1>] _local_bh_enable+0x3d/0x3f
[ 1.775222] [<ffffffff810fc229>] rcu_nocb_kthread+0x41f/0x459
[ 1.776122] [<ffffffff810fbe0a>] ? note_gp_changes+0xb3/0xb3
[ 1.777009] [<ffffffff810c1fa7>] kthread+0xf4/0xfc
[ 1.777763] [<ffffffff810c1eb3>] ? __kthread_unpark+0x55/0x55
[ 1.778660] [<ffffffff8164bfaa>] ret_from_fork+0x2a/0x40
[ 1.787488] ---[ end trace 4a52d6eed34e5b2e ]---
[ 1.788226] ------------[ cut here ]------------
git bisect start 723010c6130fda3f271a02bdefcc0058debd40a3 a25f0944ba9b1d8a6813fd6f1a86f1bd59ac25a6 --
git bisect good 7b217ca5cba8eb540ce77920eda5c1285fe37bd5 # 14:34 22+ 0 Merge 'wireless-drivers-next/master' into devel-catchup-201611182101
git bisect bad 76286e9305bca13c2d2207957fd521732dc14aeb # 14:49 0- 18 Merge 'agross/for-next' into devel-catchup-201611182101
git bisect good f31a5041519e9eefe95333c19a05b2332cde5d51 # 14:57 22+ 1 Merge 'linux-review/Amitkumar-Karwar/mwifiex-parse-device-tree-node-for-PCIe/20161118-204030' into devel-catchup-201611182101
git bisect good 4cf17feaf1add4851922b1bffd13ac2623a503a0 # 15:10 22+ 0 Merge 'linux-review/Michael-Ellerman/powerpc-prom-Define-structs-for-client-architecture-vectors/20161118-203016' into devel-catchup-201611182101
git bisect good 8ee901c45149a4305dc2c5eb09434c93f01eadbd # 15:24 22+ 0 Merge 'kvmarm/master' into devel-catchup-201611182101
git bisect bad 467ee17379040908f3341625f1b305b98dfb406c # 15:32 0- 13 Merge 'linux-review/Ding-Tianhong/rcu-fix-the-OOM-problem-of-huge-IP-abnormal-packet-traffic/20161118-204521' into devel-catchup-201611182101
git bisect good f61c9b4e9640dbf60bc438a6034aa1374dd19d0d # 15:41 22+ 3 SRCU: More efficient reader counts.
git bisect good 3ec1b169d4868fa28c84c7237332ae00436a5213 # 15:52 22+ 3 torture: Add CONFIG_PROVE_RCU_REPEATEDLY=y for TINY02
git bisect good 416b6b9a878141238d34819f60d0703bd921d8da # 15:59 21+ 2 torture: Update RCU test scenario documentation
git bisect good 1d35bffd0fab0fc930d4f48e74f72af52fc02db5 # 16:07 22+ 3 rcu: Only dump stalled-tasks stacks if there was a real stall
git bisect bad 83ee00c6cf5eaa85f74094d6800732edf7114ef9 # 16:15 0- 6 rcu: fix the OOM problem of huge IP abnormal packet traffic
git bisect good 68ad1194cfc010f5f627dd9eec827e8ee94c18df # 16:23 22+ 1 rcu: Remove unneeded rcu_process_callbacks() declarations
# first bad commit: [83ee00c6cf5eaa85f74094d6800732edf7114ef9] rcu: fix the OOM problem of huge IP abnormal packet traffic
git bisect good 68ad1194cfc010f5f627dd9eec827e8ee94c18df # 16:27 66+ 4 rcu: Remove unneeded rcu_process_callbacks() declarations
# extra tests with CONFIG_DEBUG_INFO_REDUCED
git bisect bad 83ee00c6cf5eaa85f74094d6800732edf7114ef9 # 16:37 0- 11 rcu: fix the OOM problem of huge IP abnormal packet traffic
# extra tests on HEAD of linux-devel/devel-catchup-201611182101
git bisect bad 723010c6130fda3f271a02bdefcc0058debd40a3 # 16:37 0- 13 0day head guard for 'devel-catchup-201611182101'
# extra tests on tree/branch linux-review/Ding-Tianhong/rcu-fix-the-OOM-problem-of-huge-IP-abnormal-packet-traffic/20161118-204521
git bisect bad 83ee00c6cf5eaa85f74094d6800732edf7114ef9 # 16:40 0- 22 rcu: fix the OOM problem of huge IP abnormal packet traffic
# extra tests with first bad commit reverted
git bisect good 3c5482fa583d8366592586d7081143c6f4f4ebd1 # 16:51 65+ 7 Revert "rcu: fix the OOM problem of huge IP abnormal packet traffic"
# extra tests on tree/branch linus/master
git bisect good 77079b133f242d3e3710c9b89ed54458307e54ff # 17:09 62+ 0 Merge tag 'armsoc-fixes' of git://git.kernel.org/pub/scm/linux/kernel/git/arm/arm-soc
# extra tests on tree/branch linux-next/master
git bisect good e3b16de6a58e005a1dcc6109483371c069387d76 # 17:21 66+ 0 Add linux-next specific files for 20161117
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
4 years, 2 months
- 1
- 0
[lkp] [x86/copy_user] adb402cd14: will-it-scale.per_process_ops -12.7% regression
by kernel test robot
Greeting,
FYI, we noticed a -12.7% regression of will-it-scale.per_process_ops due to commit:
commit adb402cd1461eef6e1a21db4532a3b9e6a6be853 ("x86/copy_user: Unify the code by removing the 64-bit asm _copy_*_user() variants")
https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git x86/asm
in testcase: will-it-scale
on test machine: 8 threads Intel(R) Core(TM) i7 CPU 870 @ 2.93GHz with 4G memory
with following parameters:
test: poll1
cpufreq_governor: performance
Will It Scale takes a testcase and runs it from 1 through to n parallel copies to see if the testcase will scale. It builds both a process and threads based test in order to see any differences between the two.
In addition to that, the commit also has significant impact on the following tests:
+------------------+---------------------------------------------------------------------+
| testcase: change | aim7: aim7.jobs-per-min -11.6% regression |
| test machine | qemu-system-x86_64 -enable-kvm -cpu host -smp 4 -m 5G |
| test parameters | load=200 |
| | test=dir_rtns_1 |
+------------------+---------------------------------------------------------------------+
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/cpufreq_governor/kconfig/rootfs/tbox_group/test/testcase:
gcc-6/performance/x86_64-rhel-7.2/debian-x86_64-2016-08-31.cgz/xps/poll1/will-it-scale
commit:
05b93c19d5 ("Merge branch 'linus' into x86/asm, to pick up fixes")
adb402cd14 ("x86/copy_user: Unify the code by removing the 64-bit asm _copy_*_user() variants")
05b93c19d50af2bd adb402cd1461eef6e1a21db453
---------------- --------------------------
%stddev %change %stddev
\ | \
6754528 ± 0% -12.7% 5899566 ± 2% will-it-scale.per_process_ops
5574363 ± 0% -8.1% 5121156 ± 0% will-it-scale.per_thread_ops
577.71 ± 0% +1.9% 588.63 ± 0% will-it-scale.time.system_time
143.21 ± 0% -7.5% 132.53 ± 0% will-it-scale.time.user_time
2984 ± 3% +12.5% 3357 ± 7% cpuidle.C1E-NHM.usage
11.55 ± 4% +6.8% 12.34 ± 7% turbostat.CPU%c3
7.704e+11 ± 0% +3.2% 7.95e+11 ± 0% perf-stat.branch-instructions
0.20 ± 3% +16.3% 0.23 ± 3% perf-stat.branch-miss-rate%
1.527e+09 ± 2% +20.0% 1.833e+09 ± 3% perf-stat.branch-misses
4.543e+08 ± 3% +7.0% 4.862e+08 ± 3% perf-stat.cache-references
1.377e+12 ± 0% +5.6% 1.454e+12 ± 0% perf-stat.dTLB-loads
0.00 ± 2% -3.9% 0.00 ± 1% perf-stat.dTLB-store-miss-rate%
8.151e+11 ± 0% +5.4% 8.591e+11 ± 0% perf-stat.dTLB-stores
0.00 ± 11% -15.1% 0.00 ± 4% perf-stat.iTLB-load-miss-rate%
3.852e+12 ± 0% +5.6% 4.067e+12 ± 0% perf-stat.iTLB-loads
3.373e+12 ± 1% +5.0% 3.542e+12 ± 1% perf-stat.instructions
0.80 ± 0% +5.4% 0.84 ± 0% perf-stat.ipc
297784 ± 0% -1.1% 294651 ± 0% perf-stat.minor-faults
297784 ± 0% -1.1% 294651 ± 0% perf-stat.page-faults
230146 ± 5% +33.3% 306713 ± 21% sched_debug.cfs_rq:/.load.max
23374 ± 13% -22.2% 18188 ± 8% sched_debug.cpu.nr_load_updates.stddev
5268307 ± 41% -52.4% 2508626 ± 40% sched_debug.cpu.nr_switches.max
1749053 ± 40% -45.8% 947909 ± 29% sched_debug.cpu.nr_switches.stddev
14.50 ± 42% -47.4% 7.62 ± 30% sched_debug.cpu.nr_uninterruptible.max
10.42 ± 24% -42.1% 6.03 ± 15% sched_debug.cpu.nr_uninterruptible.stddev
5265639 ± 41% -52.4% 2505468 ± 40% sched_debug.cpu.sched_count.max
1748858 ± 40% -45.8% 947432 ± 29% sched_debug.cpu.sched_count.stddev
2627322 ± 41% -52.5% 1247788 ± 40% sched_debug.cpu.sched_goidle.max
2636214 ± 41% -52.5% 1251571 ± 40% sched_debug.cpu.ttwu_count.max
875433 ± 40% -45.8% 474432 ± 29% sched_debug.cpu.ttwu_count.stddev
2629058 ± 41% -52.6% 1245111 ± 40% sched_debug.cpu.ttwu_local.max
876396 ± 40% -45.8% 474742 ± 29% sched_debug.cpu.ttwu_local.stddev
0.00 ± -1% +Inf% 2.95 ± 11% perf-profile.calltrace.cycles-pp.___might_sleep.__might_sleep.__might_fault._copy_from_user.do_sys_poll
0.00 ± -1% +Inf% 4.78 ± 12% perf-profile.calltrace.cycles-pp.__might_fault._copy_from_user.do_sys_poll.sys_poll.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 4.04 ± 11% perf-profile.calltrace.cycles-pp.__might_sleep.__might_fault._copy_from_user.do_sys_poll.sys_poll
0.00 ± -1% +Inf% 8.23 ± 14% perf-profile.calltrace.cycles-pp._copy_from_user.do_sys_poll.sys_poll.entry_SYSCALL_64_fastpath
5.91 ± 21% +42.3% 8.41 ± 18% perf-profile.calltrace.cycles-pp.call_cpuidle.cpu_startup_entry.rest_init.start_kernel.x86_64_start_reservations
0.00 ± -1% +Inf% 15.23 ± 13% perf-profile.calltrace.cycles-pp.copy_user_generic_string.do_sys_poll.sys_poll.entry_SYSCALL_64_fastpath
20.07 ± 14% -100.0% 0.00 ± -1% perf-profile.calltrace.cycles-pp.copy_user_generic_string.sys_poll.entry_SYSCALL_64_fastpath
5.91 ± 21% +42.3% 8.41 ± 18% perf-profile.calltrace.cycles-pp.cpu_startup_entry.rest_init.start_kernel.x86_64_start_reservations.x86_64_start_kernel
5.91 ± 21% +42.3% 8.41 ± 18% perf-profile.calltrace.cycles-pp.cpuidle_enter.call_cpuidle.cpu_startup_entry.rest_init.start_kernel
5.91 ± 21% +42.3% 8.41 ± 18% perf-profile.calltrace.cycles-pp.cpuidle_enter_state.cpuidle_enter.call_cpuidle.cpu_startup_entry.rest_init
22.59 ± 13% +88.1% 42.49 ± 11% perf-profile.calltrace.cycles-pp.do_sys_poll.sys_poll.entry_SYSCALL_64_fastpath
7.62 ± 9% -18.9% 6.18 ± 10% perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_swapgs
5.91 ± 21% +42.3% 8.41 ± 18% perf-profile.calltrace.cycles-pp.rest_init.start_kernel.x86_64_start_reservations.x86_64_start_kernel.start_cpu
5.91 ± 21% +42.3% 8.41 ± 18% perf-profile.calltrace.cycles-pp.start_kernel.x86_64_start_reservations.x86_64_start_kernel.start_cpu
5.91 ± 21% +42.3% 8.41 ± 18% perf-profile.calltrace.cycles-pp.x86_64_start_kernel.start_cpu
5.91 ± 21% +42.3% 8.41 ± 18% perf-profile.calltrace.cycles-pp.x86_64_start_reservations.x86_64_start_kernel.start_cpu
1.81 ± 18% +174.0% 4.96 ± 12% perf-profile.children.cycles-pp.___might_sleep
3.96 ± 17% +139.4% 9.49 ± 13% perf-profile.children.cycles-pp.__might_fault
2.90 ± 15% +146.7% 7.16 ± 12% perf-profile.children.cycles-pp.__might_sleep
0.42 ± 26% +1964.5% 8.57 ± 13% perf-profile.children.cycles-pp._copy_from_user
22.75 ± 13% +87.6% 42.66 ± 11% perf-profile.children.cycles-pp.do_sys_poll
7.62 ± 9% -18.9% 6.18 ± 10% perf-profile.children.cycles-pp.entry_SYSCALL_64_after_swapgs
5.91 ± 21% +42.3% 8.41 ± 18% perf-profile.children.cycles-pp.rest_init
5.91 ± 21% +42.3% 8.41 ± 18% perf-profile.children.cycles-pp.start_kernel
5.91 ± 21% +42.3% 8.41 ± 18% perf-profile.children.cycles-pp.x86_64_start_kernel
5.91 ± 21% +42.3% 8.41 ± 18% perf-profile.children.cycles-pp.x86_64_start_reservations
1.80 ± 18% +174.2% 4.95 ± 12% perf-profile.self.cycles-pp.___might_sleep
1.08 ± 19% +129.3% 2.48 ± 15% perf-profile.self.cycles-pp.__might_fault
1.54 ± 12% +91.9% 2.96 ± 13% perf-profile.self.cycles-pp.__might_sleep
0.42 ± 26% +681.3% 3.24 ± 15% perf-profile.self.cycles-pp._copy_from_user
14.39 ± 14% -26.1% 10.64 ± 9% perf-profile.self.cycles-pp.do_sys_poll
7.62 ± 9% -18.9% 6.18 ± 10% perf-profile.self.cycles-pp.entry_SYSCALL_64_after_swapgs
will-it-scale.time.user_time
148 ++--------------------------------------------------------------------+
146 ++ .*.*.*..* .*. .*.*.*.*.. |
*.* : .*. .*. .* * * |
144 ++ : .*.* *.*..*.* *.*.*.*.*..* + .*.*.|
142 ++ *.* * *
| |
140 ++ |
138 ++ |
136 ++ |
| |
134 ++ O O O O O O |
132 O+ O O O O O O |
| |
130 ++O O O |
128 ++--O-----------------------------------------------------------------+
will-it-scale.time.system_time
594 ++--------------------------------------------------------------------+
592 ++O O O |
| |
590 O+ O O O O |
588 ++ O O O O O O O |
586 ++ O O |
584 ++ |
| |
582 ++ |
580 ++ *. |
578 ++ : *. *.*. .*. .*.*
576 *+ : *.*.*.*.*..*.*. + *.*.*..*. .*. * * |
| *.*.*.*.. : * *.* *.*.*. .. |
574 ++ * * |
572 ++--------------------------------------------------------------------+
will-it-scale.per_process_ops
7.2e+06 ++----------------------------------------------------------------+
| * |
7e+06 ++ : : |
6.8e+06 ++*.*.*. : : .*.*.*.*.*.*.*.*.*.*.*.*.*.*. .*.*. .*. .*.*. .*.*
|+ * *.*.* * * * * |
6.6e+06 *+ |
6.4e+06 ++ |
| |
6.2e+06 O+ O O O O O |
6e+06 ++ O O O O O O |
| O O |
5.8e+06 ++ |
5.6e+06 ++O O |
| O |
5.4e+06 ++----------------------------------------------------------------+
will-it-scale.per_thread_ops
5.9e+06 ++----------------------------------------------------------------+
5.8e+06 ++ * |
| + : |
5.7e+06 *+*.*.*.* : .*.*.*.*. .*.*.*.*.*.*.*.*.*.*.*.*.*. .*. |
5.6e+06 ++ *.*.* *.* * * *.*
| + + |
5.5e+06 ++ * |
5.4e+06 ++ |
5.3e+06 ++ |
| |
5.2e+06 O+ O O O O O O |
5.1e+06 ++O O O O O O O O |
| |
5e+06 ++ O |
4.9e+06 ++--O-------------------------------------------------------------+
[*] bisect-good sample
[O] bisect-bad sample
***************************************************************************************************
vm-lkp-a03: qemu-system-x86_64 -enable-kvm -cpu host -smp 4 -m 5G
=========================================================================================
compiler/kconfig/load/rootfs/tbox_group/test/testcase:
gcc-6/x86_64-rhel-7.2/200/debian-x86_64-2016-08-31.cgz/vm-lkp-a03/dir_rtns_1/aim7
commit:
05b93c19d5 ("Merge branch 'linus' into x86/asm, to pick up fixes")
adb402cd14 ("x86/copy_user: Unify the code by removing the 64-bit asm _copy_*_user() variants")
05b93c19d50af2bd adb402cd1461eef6e1a21db453
---------------- --------------------------
fail:runs %reproduction fail:runs
| | |
%stddev %change %stddev
\ | \
25422 ± 0% -11.6% 22469 ± 0% aim7.jobs-per-min
49.16 ± 1% +13.7% 55.90 ± 1% aim7.time.elapsed_time
49.16 ± 1% +13.7% 55.90 ± 1% aim7.time.elapsed_time.max
56074 ± 1% +18.2% 66257 ± 0% aim7.time.involuntary_context_switches
2544 ± 0% +0.9% 2566 ± 0% aim7.time.maximum_resident_set_size
102.58 ± 0% +22.4% 125.56 ± 0% aim7.time.system_time
109578 ± 12% -38.9% 66934 ± 46% sched_debug.cfs_rq:/.load.stddev
29520 ± 4% +15.4% 34074 ± 5% proc-vmstat.numa_hit
29495 ± 4% +15.4% 34047 ± 5% proc-vmstat.numa_local
43435 ± 4% +12.3% 48756 ± 5% proc-vmstat.pgalloc_normal
31786 ± 4% +15.3% 36656 ± 5% proc-vmstat.pgfault
35307 ± 11% +26.0% 44486 ± 10% proc-vmstat.pgfree
0.00 ± -1% +Inf% 168236 ±138% latency_stats.avg.call_rwsem_down_write_failed.copy_process._do_fork.SyS_clone.do_syscall_64.return_from_SYSCALL_64
0.00 ± -1% +Inf% 19256 ±109% latency_stats.avg.call_rwsem_down_write_failed.unlink_file_vma.free_pgtables.exit_mmap.mmput.flush_old_exec.load_elf_binary.search_binary_handler.do_execveat_common.SyS_execve.do_syscall_64.return_from_SYSCALL_64
91562 ± 74% +638.3% 675991 ±107% latency_stats.avg.max
69313 ±121% +661.5% 527827 ±150% latency_stats.avg.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_keep_errors.sync_inodes_sb.sync_inodes_one_sb.iterate_supers.sys_sync.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 175494 ±131% latency_stats.max.call_rwsem_down_write_failed.copy_process._do_fork.SyS_clone.do_syscall_64.return_from_SYSCALL_64
0.00 ± -1% +Inf% 19825 ±107% latency_stats.max.call_rwsem_down_write_failed.unlink_file_vma.free_pgtables.exit_mmap.mmput.flush_old_exec.load_elf_binary.search_binary_handler.do_execveat_common.SyS_execve.do_syscall_64.return_from_SYSCALL_64
240734 ± 29% +217.3% 763970 ± 86% latency_stats.max.max
69313 ±121% +661.5% 527827 ±150% latency_stats.max.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_keep_errors.sync_inodes_sb.sync_inodes_one_sb.iterate_supers.sys_sync.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 178824 ±127% latency_stats.sum.call_rwsem_down_write_failed.copy_process._do_fork.SyS_clone.do_syscall_64.return_from_SYSCALL_64
0.00 ± -1% +Inf% 25864 ±100% latency_stats.sum.call_rwsem_down_write_failed.unlink_file_vma.free_pgtables.exit_mmap.mmput.flush_old_exec.load_elf_binary.search_binary_handler.do_execveat_common.SyS_execve.do_syscall_64.return_from_SYSCALL_64
69313 ±121% +661.5% 527827 ±150% latency_stats.sum.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_keep_errors.sync_inodes_sb.sync_inodes_one_sb.iterate_supers.sys_sync.entry_SYSCALL_64_fastpath
Thanks,
Xiaolong
4 years, 2 months
- 3
- 8
[lkp] [kobject] 547996275a: WARNING:at_lib/kobject.c:#kobject_put
by kernel test robot
FYI, we noticed the following commit:
https://github.com/0day-ci/linux Songjun-Wu/kobject-set-state_initialized-to-0-in-kobject_cleanup/20161101-190346
commit 547996275ae678361443674078759e455659af2e ("kobject: set state_initialized to 0 in kobject_cleanup")
in testcase: trinity
with following parameters:
runtime: 300s
test-description: Trinity is a linux system call fuzz tester.
on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -m 512M
caused below changes:
+-----------------------------------------------------------+------------+------------+
| | baa8809f60 | 547996275a |
+-----------------------------------------------------------+------------+------------+
| boot_successes | 0 | 0 |
| boot_failures | 70 | 26 |
| calltrace:async_run_entry_fn | 70 | 26 |
| WARNING:at_include/linux/kref.h:#kobject_get | 70 | |
| Kernel_panic-not_syncing:Attempted_to_kill_init!exitcode= | 14 | 14 |
| kernel_BUG_at_mm/slab.c | 1 | |
| invalid_opcode:#[##]PREEMPT | 1 | |
| RIP:free_block | 1 | |
| calltrace:scsi_debug_init | 1 | |
| Kernel_panic-not_syncing:Fatal_exception | 1 | |
| WARNING:at_lib/kobject.c:#kobject_put | 0 | 26 |
+-----------------------------------------------------------+------------+------------+
[ 11.023595] ffff8bdfdb61f9d8 ffffffffaa76facb ffff8bdfdb61fa38 ffffffffaa773519
[ 11.026305] 0000000000000000 ffff8bdfdbfd0fa8 ffff8bdfdbfd17d8 ffffffffab610f50
[ 11.027128] ffff8bdfdb61fa68 ffffffffaa7734fe ffff8bdf00000020 0000000000000000
[ 11.028031] Call Trace:
[ 11.028317] [<ffffffffaa76facb>] dump_stack+0x19/0x1b
[ 11.028850] [<ffffffffaa773519>] kobject_add+0x5f/0x66
[ 11.029423] [<ffffffffaa7734fe>] ? kobject_add+0x44/0x66
[ 11.029994] [<ffffffffaa75f694>] blk_mq_register_hctx+0x58/0xb2
[ 11.030649] [<ffffffffaa75fed3>] blk_mq_register_dev+0xb1/0xe5
[ 11.031341] [<ffffffffaa753059>] blk_register_queue+0xd3/0x15c
[ 11.031959] [<ffffffffaa7632e6>] device_add_disk+0x10d/0x2ee
[ 11.034256] [<ffffffffaae7eb38>] sd_probe_async+0x114/0x1bc
[ 11.034899] [<ffffffffaa2cc434>] async_run_entry_fn+0x42/0x19b
[ 11.036268] [<ffffffffaa2c1e11>] process_one_work+0x346/0x770
[ 11.036879] [<ffffffffaa2c1d59>] ? process_one_work+0x28e/0x770
[ 11.039260] [<ffffffffaa212289>] ? sched_clock+0x9/0xd
[ 11.039809] [<ffffffffaa2e2bf6>] ? put_lock_stats+0xe/0x21
[ 11.041272] [<ffffffffaa2e3d45>] ? __lock_acquired+0x202/0x30c
[ 11.041913] [<ffffffffaa7a5c50>] ? __list_del_entry+0xfc/0x1ab
[ 11.044254] [<ffffffffaa2c34c8>] worker_thread+0x2a2/0x60f
[ 11.044884] [<ffffffffab252108>] ? preempt_schedule+0x4d/0x4f
[ 11.046264] [<ffffffffaa201066>] ? ___preempt_schedule+0x16/0x18
[ 11.046896] [<ffffffffab25234f>] ? schedule+0x4e/0xcd
[ 11.049260] [<ffffffffaa2c3226>] ? worker_leave_idle+0x147/0x147
[ 11.049897] [<ffffffffab25236a>] ? schedule+0x69/0xcd
[ 11.051297] [<ffffffffaa2c3226>] ? worker_leave_idle+0x147/0x147
[ 11.051946] [<ffffffffaa2c8c82>] kthread+0xe6/0xff
[ 11.054254] [<ffffffffaa2c8b9c>] ? kthreadd+0x20e/0x20e
[ 11.054863] [<ffffffffab259aea>] ret_from_fork+0x2a/0x40
[ 11.055449] ------------[ cut here ]------------
[ 11.055932] WARNING: CPU: 0 PID: 210 at lib/kobject.c:692 kobject_put+0x72/0x74
[ 11.059257] kobject: '0:0:0:0' (ffff8bdfd464da50): is not initialized, yet kobject_put() is being called.
[ 11.061273] CPU: 0 PID: 210 Comm: kworker/u2:2 Not tainted 4.9.0-rc3-00009-g5479962 #1
[ 11.062120] Workqueue: events_unbound async_run_entry_fn
[ 11.064303] ffff8bdfdb61f958 ffffffffaa76facb ffff8bdfdb61f9a8 ffffffffaa2a59a1
[ 11.065157] 0000000000000001 ffffffff000002b4 ffff8bdf00000000 ffff8bdfd464da50
[ 11.066790] 0000000000000001 ffff8bdfd46fa0a0 ffff8bdfd464d800 0000000000000000
[ 11.069625] Call Trace:
[ 11.069887] [<ffffffffaa76facb>] dump_stack+0x19/0x1b
[ 11.070440] [<ffffffffaa2a59a1>] __warn+0xda/0xfb
[ 11.070941] [<ffffffffaa2a5a6e>] warn_slowpath_fmt+0x49/0x4b
[ 11.074257] [<ffffffffaa773033>] kobject_put+0x72/0x74
[ 11.074861] [<ffffffffaa75fdd2>] __blk_mq_unregister_dev+0x83/0xd3
[ 11.075533] [<ffffffffaa75fee5>] blk_mq_register_dev+0xc3/0xe5
[ 11.076150] [<ffffffffaa753059>] blk_register_queue+0xd3/0x15c
[ 11.079261] [<ffffffffaa7632e6>] device_add_disk+0x10d/0x2ee
[ 11.079861] [<ffffffffaae7eb38>] sd_probe_async+0x114/0x1bc
[ 11.080469] [<ffffffffaa2cc434>] async_run_entry_fn+0x42/0x19b
[ 11.081123] [<ffffffffaa2c1e11>] process_one_work+0x346/0x770
[ 11.084255] [<ffffffffaa2c1d59>] ? process_one_work+0x28e/0x770
[ 11.084926] [<ffffffffaa212289>] ? sched_clock+0x9/0xd
[ 11.085491] [<ffffffffaa2e2bf6>] ? put_lock_stats+0xe/0x21
[ 11.086073] [<ffffffffaa2e3d45>] ? __lock_acquired+0x202/0x30c
[ 11.089260] [<ffffffffaa7a5c50>] ? __list_del_entry+0xfc/0x1ab
[ 11.089879] [<ffffffffaa2c34c8>] worker_thread+0x2a2/0x60f
[ 11.090479] [<ffffffffab252108>] ? preempt_schedule+0x4d/0x4f
[ 11.091115] [<ffffffffaa201066>] ? ___preempt_schedule+0x16/0x18
[ 11.094046] mousedev: PS/2 mouse device common for all mice
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
4 years, 2 months
- 1
- 0
[lkp] [fixup! rcu] 1157ae41a3: WARNING:at_include/linux/mm.h:#workingset_activation
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/paulmck/linux-rcu.git dev.2016.11.09a
commit 1157ae41a38d92d38c954835f5688046e2af6da9 ("fixup! rcu: Abstract the dynticks snapshot operation")
in testcase: boot
on test machine: qemu-system-i386 -enable-kvm -m 360M
caused below changes:
+----------------------------------------------------------+------------+------------+
| | ee17957e96 | 1157ae41a3 |
+----------------------------------------------------------+------------+------------+
| boot_successes | 4 | 0 |
| boot_failures | 4 | 8 |
| WARNING:at_kernel/rcu/tree.c:#rcu_dynticks_eqs_enter | 4 | 2 |
| WARNING:at_kernel/rcu/tree.c:#rcu_dynticks_eqs_exit | 4 | 2 |
| WARNING:at_arch/x86/mm/dump_pagetables.c:#note_page | 2 | |
| calltrace:mark_rodata_ro | 2 | |
| WARNING:at_include/linux/mm.h:#workingset_activation | 0 | 8 |
| calltrace:run_init_process | 0 | 8 |
| kernel_BUG_at_include/linux/memcontrol.h | 0 | 8 |
| invalid_opcode:#[##]SMP | 0 | 8 |
| EIP_is_at_page_remove_rmap | 0 | 8 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 8 |
| WARNING:at_kernel/rcu/tree.c:#rcu_momentary_dyntick_idle | 0 | 1 |
| WARNING:at_kernel/rcu/tree.c:#rcu_nmi_exit | 0 | 2 |
| calltrace:init_kprobes | 0 | 2 |
| calltrace:SyS_exit_group | 0 | 2 |
+----------------------------------------------------------+------------+------------+
[ 70.012733] Write protecting the kernel text: 6576k
[ 70.021808] Write protecting the kernel read-only data: 3928k
[ 70.030077] ------------[ cut here ]------------
[ 70.057976] WARNING: CPU: 0 PID: 1 at include/linux/mm.h:983 workingset_activation+0x84/0x148
[ 70.071977] Modules linked in:
[ 70.076703] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.9.0-rc1-00038-g1157ae4 #1
[ 70.087859] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 70.102726] 93c5dce4 87f1cabe 00000000 885809c9 000003d7 93c5dcfc 87cc0206 87e0133f
[ 70.114880] 00000001 94640b40 00000001 93c5dd10 87cc0298 00000009 00000000 00000000
[ 70.127708] 93c5dd24 87e0133f 94640b40 00000000 94640ac4 93c5dd38 87de4fbf 00000000
[ 70.141748] Call Trace:
[ 70.145240] [<87f1cabe>] dump_stack+0xc4/0x12c
[ 70.151437] [<87cc0206>] __warn+0x110/0x127
[ 70.157362] [<87e0133f>] ? workingset_activation+0x84/0x148
[ 70.166505] [<87cc0298>] warn_slowpath_null+0x16/0x1b
[ 70.175189] [<87e0133f>] workingset_activation+0x84/0x148
[ 70.183811] [<87de4fbf>] mark_page_accessed+0x242/0x2bc
[ 70.191065] [<87dca4d1>] do_read_cache_page+0x83b/0x84c
[ 70.198322] [<87e90205>] ? simple_setattr+0x77/0x77
[ 70.206362] [<87e82a06>] ? touch_atime+0xbc/0xc3
[ 70.214403] [<87e68906>] ? page_put_link+0xe7/0xe7
[ 70.221169] [<87dca4f8>] read_cache_page+0x16/0x18
[ 70.227848] [<87e68ac9>] page_get_link+0x1c3/0x265
[ 70.235751] [<87e68906>] ? page_put_link+0xe7/0xe7
[ 70.242397] [<87e6c360>] trailing_symlink+0x2bf/0x3d2
[ 70.249401] [<87e7166f>] path_openat+0x1d32/0x1f9d
[ 70.257235] [<87cad3b1>] ? update_stack_state+0x32/0x72
[ 70.265795] [<87cad42d>] ? unwind_next_frame+0x3c/0x56
[ 70.272929] [<87c8e6ec>] ? __save_stack_trace+0x11d/0x127
[ 70.280412] [<87e71923>] do_filp_open+0x49/0xe6
[ 70.288193] [<87e638be>] do_open_execat+0xb7/0x232
[ 70.296645] [<87e640b9>] do_execveat_common+0x28b/0xa4e
[ 70.304292] [<87e64895>] do_execve+0x19/0x1b
[ 70.310348] [<87c02021>] run_init_process+0x21/0x23
[ 70.318588] [<8825e0f7>] kernel_init+0x75/0x162
[ 70.325288] [<8825e082>] ? rest_init+0xaa/0xaa
[ 70.331614] [<8826972b>] ret_from_fork+0x1b/0x30
[ 70.340394] ---[ end trace 8e502acf29f2a82a ]---
[ 70.354103] ------------[ cut here ]------------
[ 70.360613] kernel BUG at include/linux/memcontrol.h:500!
[ 70.372900] invalid opcode: 0000 [#1] SMP
[ 70.378373] Modules linked in:
[ 70.383658] CPU: 0 PID: 1 Comm: init Tainted: G W 4.9.0-rc1-00038-g1157ae4 #1
[ 70.394897] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 70.406796] task: 93c4f000 task.stack: 93c5c000
[ 70.414770] EIP: 0060:[<87e1e391>] EFLAGS: 00010202 CPU: 0
[ 70.422222] EIP is at page_remove_rmap+0x2d1/0x60b
[ 70.428697] EAX: 00000001 EBX: 00000001 ECX: 00000000 EDX: 00000001
[ 70.437127] ESI: 94641cf8 EDI: 94641ce8 EBP: 93c5de28 ESP: 93c5de14
[ 70.447174] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[ 70.456053] CR0: 80050033 CR2: 55583bb0 CR3: 0c6d1280 CR4: 000006b0
[ 70.465962] Stack:
[ 70.493774] 00000001 94641c01 00000000 00000000 00000001 93c5de78 87e05956 55584000
[ 70.517400] 00000000 55583000 55584000 0893f067 55583000 0ecce001 00000001 00000000
[ 70.532117] 8c6c1e90 8c6d34e0 93c5df10 0893f067 00000000 93c46210 00000000 0ecce025
[ 70.546013] Call Trace:
[ 70.549801] [<87e05956>] wp_page_copy+0x68e/0xbdd
[ 70.558915] [<87e08701>] do_wp_page+0x110c/0x113a
[ 70.566076] [<87e0faf6>] handle_mm_fault+0x2022/0x21c3
[ 70.574046] [<87caf4f1>] __do_page_fault+0x4e4/0xa13
[ 70.581662] [<87cafbf0>] trace_do_page_fault+0x1b2/0x1ba
[ 70.590507] [<87cab625>] ? kvm_async_pf_task_wake+0x139/0x139
[ 70.598803] [<87cab64d>] do_async_page_fault+0x28/0x50
[ 70.605905] [<8826a82c>] error_code+0x6c/0x80
[ 70.612768] Code: 47 ff 8b 18 83 e3 01 83 f3 01 31 c9 89 da b8 8c 47 6c 88 e8 d9 73 f7 ff 8b 04 9d 80 46 76 88 40 85 db 89 04 9d 80 46 76 88 74 02 <0f> 0b 8b 56 20 85 d2 0f 95 c1 0f b6 d9 8b 04 9d 6c 46 76 88 40
[ 70.657260] EIP: [<87e1e391>]
[ 70.661440] page_remove_rmap+0x2d1/0x60b
[ 70.668829] SS:ESP 0068:93c5de14
[ 70.674632] ---[ end trace 8e502acf29f2a82b ]---
[ 70.682083] Kernel panic - not syncing: Fatal exception
[ 70.690809] Kernel Offset: 0x6c00000 from 0x81000000 (relocation range: 0x80000000-0x96fdffff)
Elapsed time: 150
To reproduce:
git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
Xiaolong
4 years, 2 months
- 1
- 0
[net] 2ab9fb18c4: kernel BUG at include/linux/skbuff.h:1935!
by kernel test robot
FYI, we noticed the following commit:
https://github.com/0day-ci/linux Eric-Dumazet/net-__skb_flow_dissect-must-cap-its-return-value/20161110-080839
commit 2ab9fb18c46b91b16a0f0f329336d3be9fc32deb ("net: __skb_flow_dissect() must cap its return value")
in testcase: kbuild
with following parameters:
runtime: 300s
nr_task: 50%
cpufreq_governor: performance
on test machine: 8 threads Intel(R) Atom(TM) CPU C2750 @ 2.40GHz with 16G memory
caused below changes:
+-------------------------------------------------------+------------+------------+
| | cdb26d3387 | 2ab9fb18c4 |
+-------------------------------------------------------+------------+------------+
| boot_successes | 10 | 3 |
| boot_failures | 0 | 9 |
| kernel_BUG_at_include/linux/skbuff.h | 0 | 8 |
| invalid_opcode:#[##]SMP | 0 | 8 |
| RIP:eth_type_trans | 0 | 8 |
| Kernel_panic-not_syncing:Fatal_exception_in_interrupt | 0 | 5 |
| WARNING:at_fs/sysfs/dir.c:#sysfs_warn_dup | 0 | 1 |
| calltrace:parport_pc_init | 0 | 1 |
| calltrace:SyS_finit_module | 0 | 1 |
| WARNING:at_lib/kobject.c:#kobject_add_internal | 0 | 1 |
+-------------------------------------------------------+------------+------------+
[ 20.491020] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[ 20.502988] Sending DHCP requests .
[ 20.506729] ------------[ cut here ]------------
[ 20.511369] kernel BUG at include/linux/skbuff.h:1935!
[ 20.517893] invalid opcode: 0000 [#1] SMP
[ 20.521902] Modules linked in:
[ 20.524979] CPU: 4 PID: 0 Comm: swapper/4 Not tainted 4.9.0-rc3-00286-g2ab9fb1 #1
[ 20.532463] Hardware name: Supermicro SYS-5018A-TN4/A1SAi, BIOS 1.1a 08/27/2015
[ 20.539768] task: ffff8804456c2480 task.stack: ffffc90001920000
[ 20.545684] RIP: 0010:[<ffffffff81837b48>] [<ffffffff81837b48>] eth_type_trans+0xe8/0x140
[ 20.553972] RSP: 0018:ffff88047fd03db8 EFLAGS: 00010297
[ 20.559283] RAX: 0000000000000158 RBX: ffff88047d8ae600 RCX: 0000000000001073
[ 20.566415] RDX: ffff88047bf07dc0 RSI: ffff88047d8a4000 RDI: ffff88047dac0f00
[ 20.573546] RBP: ffff88047fd03e20 R08: ffff88047d8a4000 R09: 0000000000000800
[ 20.580678] R10: ffff88047bf07ec0 R11: ffffea0011f6e400 R12: ffff88047dac0f00
[ 20.587810] R13: ffff880457413000 R14: ffffc90002129000 R15: 000000000000015e
[ 20.594946] FS: 0000000000000000(0000) GS:ffff88047fd00000(0000) knlGS:0000000000000000
[ 20.603032] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 20.608775] CR2: 00007fffadfb4ef0 CR3: 000000047ee07000 CR4: 00000000001006e0
[ 20.615906] Stack:
[ 20.617927] ffffffff816905a7 ffffea0011f6e400 ffffea0000000008 ffff88047d8ae450
[ 20.625403] ffff88047d8ae400 0000004000000166 ffffea0011f6e400 0000ffff00000000
[ 20.632873] 0000000000000040 0000000000000000 ffff88047d8ae450 ffff88047d8b1140
[ 20.640352] Call Trace:
[ 20.642805] <IRQ>
[ 20.644740] [<ffffffff816905a7>] ? igb_clean_rx_irq+0x6a7/0x7d0
[ 20.650760] [<ffffffff81690a52>] igb_poll+0x382/0x700
[ 20.655904] [<ffffffff8146edd9>] ? timerqueue_add+0x59/0xb0
[ 20.661564] [<ffffffff8180f2d7>] net_rx_action+0x217/0x360
[ 20.667137] [<ffffffff81957ef4>] __do_softirq+0x104/0x2ab
[ 20.672624] [<ffffffff81086961>] irq_exit+0xf1/0x100
[ 20.677673] [<ffffffff81957c34>] do_IRQ+0x54/0xd0
[ 20.682466] [<ffffffff81955acc>] common_interrupt+0x8c/0x8c
[ 20.688123] <EOI>
[ 20.690054] [<ffffffff817c1d12>] ? cpuidle_enter_state+0x122/0x2e0
[ 20.696333] [<ffffffff817c1f07>] cpuidle_enter+0x17/0x20
[ 20.701733] [<ffffffff810c64c3>] call_cpuidle+0x23/0x40
[ 20.707045] [<ffffffff810c66f4>] cpu_startup_entry+0x114/0x200
[ 20.712964] [<ffffffff81051c87>] start_secondary+0x107/0x130
[ 20.718708] Code: 00 04 00 00 c9 c3 48 33 86 70 03 00 00 48 c1 e0 10 48 85 c0 0f b6 87 90 00 00 00 75 28 83 e0 f8 83 c8 01 88 87 90 00 00 00 eb 82 <0f> 0b 0f b6 87 90 00 00 00 83 e0 f8 83 c8 03 88 87 90 00 00 00
[ 20.738722] RIP [<ffffffff81837b48>] eth_type_trans+0xe8/0x140
[ 20.744662] RSP <ffff88047fd03db8>
[ 20.748160] ---[ end trace 153440bf1ca2e6fc ]---
[ 20.748165] ------------[ cut here ]------------
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
4 years, 2 months
- 5
- 5
[lkp] [virtio_pci] a2d58339fa: WARNING:at_kernel/irq/manage.c:#__free_irq
by kernel test robot
FYI, we noticed the following commit:
git://git.infradead.org/users/hch/block.git virtio-affinity
commit a2d58339fac343ecaa4725d8a72f39c4cb7679c7 ("virtio_pci: clean up interrupt state in struct virtio_pci_device")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu host -smp 2 -m 2G
caused below changes:
+-------------------------------------------------+------------+------------+
| | acdf932fdb | a2d58339fa |
+-------------------------------------------------+------------+------------+
| boot_successes | 12 | 6 |
| boot_failures | 2 | 8 |
| BUG:kernel_reboot-without-warning_in_test_stage | 2 | |
| WARNING:at_kernel/irq/manage.c:#__free_irq | 0 | 8 |
| calltrace:init | 0 | 8 |
| calltrace:SyS_finit_module | 0 | 8 |
| kernel_BUG_at_drivers/pci/msi.c | 0 | 8 |
| invalid_opcode:#[##]PREEMPT_SMP | 0 | 8 |
| RIP:free_msi_irqs | 0 | 8 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 7 |
+-------------------------------------------------+------------+------------+
[ 14.103167] [TTM] Initializing DMA pool allocator
[ 14.108711] fbcon: bochsdrmfb (fb0) is primary device
[ 14.114777] ------------[ cut here ]------------
[ 14.114788] WARNING: CPU: 0 PID: 248 at kernel/irq/manage.c:1478 __free_irq+0xb9/0x2df
[ 14.114790] Trying to free already-free IRQ 25
[ 14.114841] Modules linked in: virtio_blk(+) ide_pci_generic(+) fbcon bitblit softcursor crc32_pclmul font tileblit bochs_drm(+) ttm crc32c_intel drm_kms_helper ghash_clmulni_intel drm fb_sys_fops syscopyarea sysfillrect sysimgblt cfbfillrect input_leds cfbimgblt cfbcopyarea floppy virtio_pci virtio_ring fb fbdev virtio piix evbug i2c_piix4 evdev i2c_core intel_agp ide_core intel_gtt agpgart button zbud
[ 14.114854] CPU: 0 PID: 248 Comm: systemd-udevd Not tainted 4.9.0-rc4-00018-ga2d5833 #1
[ 14.114857] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 14.114864] ffffbd47001f79c8 ffffffffb85ff6d9 ffffffffff6d6180 ffffbd47001f7a30
[ 14.114871] 0000000000000000 ffffffffb82cda4c ffffbd47001f7a08 ffffffffb827f10c
[ 14.114878] 00000009001f7aa0 ffffffffb8be5e85 ffff94afff502200 0000000000000019
[ 14.114879] Call Trace:
[ 14.114886] [<ffffffffb85ff6d9>] dump_stack+0xe0/0x132
[ 14.114891] [<ffffffffb82cda4c>] ? __free_irq+0xb9/0x2df
[ 14.114896] [<ffffffffb827f10c>] __warn+0xff/0x11f
[ 14.114902] [<ffffffffb827f191>] warn_slowpath_fmt+0x65/0x6e
[ 14.114907] [<ffffffffb82cda4c>] __free_irq+0xb9/0x2df
[ 14.114911] [<ffffffffb82cdd5c>] free_irq+0x87/0x9b
[ 14.114919] [<ffffffffc04449ac>] vp_del_vqs+0xc6/0x189 [virtio_pci]
[ 14.114925] [<ffffffffc056523a>] virtblk_remove+0x7c/0xb7 [virtio_blk]
[ 14.114932] [<ffffffffc041c1dd>] virtio_dev_remove+0x40/0x99 [virtio]
[ 14.114937] [<ffffffffc041c19d>] ? virtio_config_enable+0x48/0x48 [virtio]
[ 14.114945] [<ffffffffb876eadb>] driver_probe_device+0x1db/0x3f8
[ 14.114952] [<ffffffffb876ed9b>] __driver_attach+0xa3/0xd9
[ 14.114959] [<ffffffffb876ecf8>] ? driver_probe_device+0x3f8/0x3f8
[ 14.114965] [<ffffffffb876c7e0>] bus_for_each_dev+0xa1/0xc7
[ 14.114971] [<ffffffffb876e2ec>] driver_attach+0x22/0x25
[ 14.114977] [<ffffffffb876df21>] bus_add_driver+0x110/0x240
[ 14.114984] [<ffffffffb876f8b9>] driver_register+0xc7/0x112
[ 14.114990] [<ffffffffc041c52e>] register_virtio_driver+0x41/0x44 [virtio]
[ 14.114996] [<ffffffffc0571069>] init+0x69/0x1000 [virtio_blk]
[ 14.115000] [<ffffffffc0571000>] ? 0xffffffffc0571000
[ 14.115007] [<ffffffffb82004d6>] do_one_initcall+0xa2/0x154
[ 14.115013] [<ffffffffb83875a3>] ? cache_alloc_debugcheck_after+0x51/0x14e
[ 14.115018] [<ffffffffb838772c>] ? kmem_cache_alloc+0x8c/0xb1
[ 14.115025] [<ffffffffb833064f>] do_init_module+0x55/0x1df
[ 14.115031] [<ffffffffb82fab13>] load_module+0xfe8/0x1580
[ 14.115036] [<ffffffffb83a0404>] ? vfs_read+0xdc/0xeb
[ 14.115043] [<ffffffffb83a664f>] ? allow_write_access+0x27/0x2a
[ 14.115049] [<ffffffffb82fb249>] SYSC_finit_module+0x83/0x90
To reproduce:
git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
Xiaolong
4 years, 2 months
- 1
- 0