Re: [LKP] [rcu] kernel BUG at include/linux/pagemap.h:149!
by Frederic Weisbecker
On Fri, Sep 11, 2015 at 10:19:47AM +0800, Boqun Feng wrote:
> Subject: [PATCH 01/27] rcu: Don't disable preemption for Tiny and Tree RCU
> readers
>
> Because preempt_disable() maps to barrier() for non-debug builds,
> it forces the compiler to spill and reload registers. Because Tree
> RCU and Tiny RCU now only appear in CONFIG_PREEMPT=n builds, these
> barrier() instances generate needless extra code for each instance of
> rcu_read_lock() and rcu_read_unlock(). This extra code slows down Tree
> RCU and bloats Tiny RCU.
>
> This commit therefore removes the preempt_disable() and preempt_enable()
> from the non-preemptible implementations of __rcu_read_lock() and
> __rcu_read_unlock(), respectively.
>
> For debug purposes, preempt_disable() and preempt_enable() are still
> kept if CONFIG_PREEMPT_COUNT=y, which makes the detection of sleeping
> inside atomic sections still work in non-preemptible kernels.
>
> Signed-off-by: Boqun Feng <boqun.feng(a)gmail.com>
> Signed-off-by: Paul E. McKenney <paulmck(a)linux.vnet.ibm.com>
> ---
> include/linux/rcupdate.h | 6 ++++--
> include/linux/rcutiny.h | 1 +
> kernel/rcu/tree.c | 9 +++++++++
> 3 files changed, 14 insertions(+), 2 deletions(-)
>
> diff --git a/include/linux/rcupdate.h b/include/linux/rcupdate.h
> index d63bb77..6c3cece 100644
> --- a/include/linux/rcupdate.h
> +++ b/include/linux/rcupdate.h
> @@ -297,12 +297,14 @@ void synchronize_rcu(void);
>
> static inline void __rcu_read_lock(void)
> {
> - preempt_disable();
> + if (IS_ENABLED(CONFIG_PREEMPT_COUNT))
> + preempt_disable();
preempt_disable() is a no-op when !CONFIG_PREEMPT_COUNT, right?
Or rather it's a barrier(), which is anyway implied by rcu_read_lock().
So perhaps we can get rid of the IS_ENABLED() check?
1 year, 10 months
Re: [LKP] [lkp] [f2fs] ec795418c4: fsmark.files_per_sec -36.3% regression
by Jaegeuk Kim
On Wed, Aug 24, 2016 at 09:51:11AM -0700, huang ying wrote:
> Hi, Jaegeuk,
>
> On Thu, Aug 11, 2016 at 6:22 PM, Jaegeuk Kim <jaegeuk(a)kernel.org> wrote:
> > On Thu, Aug 11, 2016 at 03:49:41PM -0700, Huang, Ying wrote:
> >> Hi, Kim,
> >>
> >> "Huang, Ying" <ying.huang(a)intel.com> writes:
> >> >>
> >> >> [lkp] [f2fs] 3bdad3c7ee: aim7.jobs-per-min -25.3% regression
> >> >> [lkp] [f2fs] b93f771286: aim7.jobs-per-min -81.2% regression
> >> >>
> >> >> In terms of the above regression, I could check that _reproduce_ procedure
> >> >> includes mounting filesystem only. Is that correct?
> >> >
> >> > Sorry, our test system failed to generate reproduce steps for aim7. We
> >> > will implement it.
> >> >
> >> > - [lkp] [f2fs] 3bdad3c7ee: aim7.jobs-per-min -25.3% regression
> >> >
> >> > The disk is one 48G ram disk. The steps for aim7 is,
> >> >
> >> > cat > workfile <<EOF
> >> > FILESIZE: 1M
> >> > POOLSIZE: 10M
> >> > 10 disk_cp
> >> > EOF
> >> >
> >> > (
> >> > echo $HOSTNAME
> >> > echo disk_cp
> >> >
> >> > echo 1
> >> > echo 3000
> >> > echo 2
> >> > echo 3000
> >> > echo 1
> >> > ) | ./multitask -t &
> >> >
> >> >
> >> > - [lkp] [f2fs] b93f771286: aim7.jobs-per-min -81.2% regression
> >> >
> >> > The disk is 4 12G ram disk, and setup RAID0 on them via mdadm. The
> >> > steps for aim7 is,
> >> >
> >> > cat > workfile <<EOF
> >> > FILESIZE: 1M
> >> > POOLSIZE: 10M
> >> > 10 sync_disk_rw
> >> > EOF
> >> >
> >> > (
> >> > echo $HOSTNAME
> >> > echo sync_disk_rw
> >> >
> >> > echo 1
> >> > echo 600
> >> > echo 2
> >> > echo 600
> >> > echo 1
> >> > ) | ./multitask -t &
> >>
> >> Any update on these 2 regressions? Is the information is enough for you
> >> to reproduce?
> >
> > Sorry, I've had no time to dig this due to business travel now.
> > I'll check that when back to US.
>
> Any update?
Sorry, how can I get multitask binary?
Thanks,
>
> Best Regards,
> Huang, Ying
4 years, 5 months
[lkp] [sctp] a6c2f79287: netperf.Throughput_Mbps -37.2% regression
by kernel test robot
FYI, we noticed a -37.2% regression of netperf.Throughput_Mbps due to commit:
commit a6c2f792873aff332a4689717c3cd6104f46684c ("sctp: implement prsctp TTL policy")
https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git master
in testcase: netperf
on test machine: 4 threads Ivy Bridge with 8G memory
with following parameters:
ip: ipv4
runtime: 300s
nr_threads: 200%
cluster: cs-localhost
send_size: 10K
test: SCTP_STREAM_MANY
cpufreq_governor: performance
Disclaimer:
Results have been estimated based on internal Intel analysis and are provided
for informational purposes only. Any difference in system hardware or software
design or configuration may affect actual performance.
Details are as below:
-------------------------------------------------------------------------------------------------->
To reproduce:
git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
=========================================================================================
cluster/compiler/cpufreq_governor/ip/kconfig/nr_threads/rootfs/runtime/send_size/tbox_group/test/testcase:
cs-localhost/gcc-6/performance/ipv4/x86_64-rhel-7.2/200%/debian-x86_64-2015-02-07.cgz/300s/10K/lkp-ivb-d02/SCTP_STREAM_MANY/netperf
commit:
826d253d57 ("sctp: add SCTP_PR_ASSOC_STATUS on sctp sockopt")
a6c2f79287 ("sctp: implement prsctp TTL policy")
826d253d57b11f69 a6c2f792873aff332a4689717c
---------------- --------------------------
%stddev %change %stddev
\ | \
3923 ± 0% -37.2% 2462 ± 0% netperf.Throughput_Mbps
11701 ± 14% -21.9% 9139 ± 11% meminfo.AnonHugePages
642.75 ± 7% +15.8% 744.00 ± 6% slabinfo.kmalloc-512.active_objs
4993 ± 2% +14.6% 5724 ± 2% slabinfo.kmalloc-64.active_objs
4993 ± 2% +14.6% 5724 ± 2% slabinfo.kmalloc-64.num_objs
9.00 ± 0% -77.8% 2.00 ± 0% vmstat.procs.r
112616 ± 1% +19.0% 133959 ± 0% vmstat.system.cs
4053 ± 0% +6.3% 4309 ± 0% vmstat.system.in
16466114 ± 0% -37.4% 10307354 ± 0% softirqs.NET_RX
72067 ± 10% -63.5% 26326 ± 4% softirqs.RCU
8598 ± 4% +954.6% 90677 ± 1% softirqs.SCHED
605899 ± 0% -45.7% 329111 ± 0% softirqs.TIMER
2529 ± 4% -15.1% 2147 ± 1% proc-vmstat.nr_alloc_batch
1.48e+08 ± 0% -37.1% 93059843 ± 0% proc-vmstat.numa_hit
1.48e+08 ± 0% -37.1% 93059842 ± 0% proc-vmstat.numa_local
3.742e+08 ± 1% -36.9% 2.362e+08 ± 0% proc-vmstat.pgalloc_dma32
4.733e+08 ± 0% -36.6% 3e+08 ± 0% proc-vmstat.pgalloc_normal
8.476e+08 ± 0% -36.7% 5.362e+08 ± 0% proc-vmstat.pgfree
99.31 ± 0% -44.6% 55.03 ± 0% turbostat.%Busy
3269 ± 0% -44.8% 1804 ± 1% turbostat.Avg_MHz
0.05 ± 17% +51942.1% 24.72 ± 1% turbostat.CPU%c1
0.64 ± 0% +3067.3% 20.11 ± 3% turbostat.CPU%c6
20.20 ± 0% -24.7% 15.21 ± 0% turbostat.CorWatt
0.12 ± 39% +1906.4% 2.36 ± 3% turbostat.Pkg%pc2
0.46 ± 10% +1696.7% 8.27 ± 6% turbostat.Pkg%pc6
37.54 ± 0% -14.5% 32.11 ± 0% turbostat.PkgWatt
76510 ± 46% +2.6e+05% 1.954e+08 ± 1% cpuidle.C1-IVB.time
6742 ± 76% +2.9e+05% 19860856 ± 1% cpuidle.C1-IVB.usage
19769 ± 17% +5414.4% 1090172 ± 3% cpuidle.C1E-IVB.time
151.00 ± 11% +4024.8% 6228 ± 3% cpuidle.C1E-IVB.usage
33074 ± 14% +5086.6% 1715442 ± 2% cpuidle.C3-IVB.time
114.50 ± 14% +6075.1% 7070 ± 3% cpuidle.C3-IVB.usage
8006184 ± 0% +4066.3% 3.336e+08 ± 2% cpuidle.C6-IVB.time
8874 ± 0% +4197.0% 381350 ± 2% cpuidle.C6-IVB.usage
476.75 ± 92% +77822.9% 371497 ± 12% cpuidle.POLL.time
46.25 ±144% +30824.3% 14302 ± 3% cpuidle.POLL.usage
1.758e+11 ± 2% -38.4% 1.083e+11 ± 1% perf-stat.L1-dcache-load-misses
6.405e+11 ± 0% -29.7% 4.5e+11 ± 0% perf-stat.L1-dcache-loads
6.28e+09 ± 3% -30.0% 4.398e+09 ± 0% perf-stat.L1-dcache-prefetch-misses
8.142e+10 ± 1% -39.3% 4.941e+10 ± 0% perf-stat.L1-dcache-store-misses
5.32e+11 ± 0% -33.6% 3.533e+11 ± 1% perf-stat.L1-dcache-stores
5.59e+10 ± 1% -19.3% 4.512e+10 ± 1% perf-stat.L1-icache-load-misses
5.199e+10 ± 0% -42.1% 3.01e+10 ± 1% perf-stat.LLC-loads
3.066e+10 ± 1% -42.4% 1.765e+10 ± 1% perf-stat.LLC-prefetches
5.282e+10 ± 0% -40.0% 3.168e+10 ± 1% perf-stat.LLC-stores
2.776e+11 ± 0% -27.9% 2.002e+11 ± 0% perf-stat.branch-instructions
3.861e+09 ± 1% -50.8% 1.9e+09 ± 0% perf-stat.branch-load-misses
2.772e+11 ± 0% -27.8% 2e+11 ± 0% perf-stat.branch-loads
3.864e+09 ± 1% -50.8% 1.9e+09 ± 0% perf-stat.branch-misses
1.179e+11 ± 0% -43.9% 6.61e+10 ± 0% perf-stat.bus-cycles
7.126e+09 ± 16% -96.8% 2.272e+08 ± 4% perf-stat.cache-misses
1.173e+11 ± 0% -38.0% 7.278e+10 ± 0% perf-stat.cache-references
34232822 ± 1% +19.1% 40787311 ± 0% perf-stat.context-switches
3.897e+12 ± 0% -44.2% 2.174e+12 ± 1% perf-stat.cpu-cycles
12019 ± 35% +306.6% 48867 ± 1% perf-stat.cpu-migrations
4.069e+09 ± 20% -58.4% 1.694e+09 ± 46% perf-stat.dTLB-load-misses
6.421e+11 ± 0% -30.3% 4.476e+11 ± 1% perf-stat.dTLB-loads
5.285e+08 ± 22% -71.0% 1.531e+08 ± 17% perf-stat.dTLB-store-misses
5.32e+11 ± 0% -33.4% 3.544e+11 ± 1% perf-stat.dTLB-stores
3.735e+08 ± 5% -48.5% 1.923e+08 ± 3% perf-stat.iTLB-load-misses
1.803e+08 ± 52% +662.4% 1.374e+09 ± 2% perf-stat.iTLB-loads
1.505e+12 ± 0% -29.3% 1.064e+12 ± 0% perf-stat.instructions
339045 ± 0% +4.4% 354068 ± 0% perf-stat.minor-faults
339041 ± 0% +4.4% 354062 ± 0% perf-stat.page-faults
3.892e+12 ± 0% -43.9% 2.182e+12 ± 0% perf-stat.ref-cycles
3.052e+12 ± 0% -25.9% 2.261e+12 ± 0% perf-stat.stalled-cycles-frontend
34082 ± 16% -65.5% 11746 ± 83% sched_debug.cfs_rq:/.MIN_vruntime.avg
75047 ± 3% -58.2% 31366 ± 63% sched_debug.cfs_rq:/.MIN_vruntime.max
34069 ± 3% -59.9% 13660 ± 61% sched_debug.cfs_rq:/.MIN_vruntime.stddev
1403286 ± 4% -34.9% 913870 ± 14% sched_debug.cfs_rq:/.load.avg
1874082 ± 7% -27.9% 1352098 ± 19% sched_debug.cfs_rq:/.load.max
1041057 ± 0% -66.8% 345620 ± 35% sched_debug.cfs_rq:/.load.min
1063 ± 0% -54.6% 482.93 ± 15% sched_debug.cfs_rq:/.load_avg.avg
1204 ± 3% -20.6% 956.50 ± 4% sched_debug.cfs_rq:/.load_avg.max
939.38 ± 0% -86.4% 127.33 ± 31% sched_debug.cfs_rq:/.load_avg.min
104.33 ± 19% +238.6% 353.26 ± 6% sched_debug.cfs_rq:/.load_avg.stddev
34082 ± 16% -65.5% 11746 ± 83% sched_debug.cfs_rq:/.max_vruntime.avg
75047 ± 3% -58.2% 31366 ± 63% sched_debug.cfs_rq:/.max_vruntime.max
34069 ± 3% -59.9% 13660 ± 61% sched_debug.cfs_rq:/.max_vruntime.stddev
74820 ± 0% -10.4% 67031 ± 1% sched_debug.cfs_rq:/.min_vruntime.min
1091 ± 7% +378.3% 5221 ± 13% sched_debug.cfs_rq:/.min_vruntime.stddev
1.35 ± 3% -35.4% 0.88 ± 14% sched_debug.cfs_rq:/.nr_running.avg
1.83 ± 6% -29.5% 1.29 ± 19% sched_debug.cfs_rq:/.nr_running.max
1.00 ± 0% -66.7% 0.33 ± 35% sched_debug.cfs_rq:/.nr_running.min
943.28 ± 0% -61.0% 367.80 ± 20% sched_debug.cfs_rq:/.runnable_load_avg.avg
991.42 ± 1% -21.2% 781.00 ± 14% sched_debug.cfs_rq:/.runnable_load_avg.max
894.88 ± 1% -90.9% 81.46 ± 20% sched_debug.cfs_rq:/.runnable_load_avg.min
39.07 ± 31% +667.7% 299.97 ± 16% sched_debug.cfs_rq:/.runnable_load_avg.stddev
-794.96 ±-98% +505.2% -4810 ±-18% sched_debug.cfs_rq:/.spread0.avg
-1935 ±-42% +442.8% -10508 ±-13% sched_debug.cfs_rq:/.spread0.min
1092 ± 7% +378.0% 5221 ± 13% sched_debug.cfs_rq:/.spread0.stddev
949.60 ± 0% -41.6% 554.85 ± 12% sched_debug.cfs_rq:/.util_avg.avg
976.08 ± 1% -9.9% 879.71 ± 1% sched_debug.cfs_rq:/.util_avg.max
925.83 ± 0% -67.0% 305.25 ± 20% sched_debug.cfs_rq:/.util_avg.min
18.71 ± 30% +1151.4% 234.18 ± 6% sched_debug.cfs_rq:/.util_avg.stddev
2.60 ± 9% -66.3% 0.88 ± 62% sched_debug.cpu.clock.stddev
2.60 ± 9% -66.3% 0.88 ± 62% sched_debug.cpu.clock_task.stddev
941.57 ± 1% -65.8% 322.38 ± 25% sched_debug.cpu.cpu_load[0].avg
992.46 ± 1% -29.5% 700.08 ± 25% sched_debug.cpu.cpu_load[0].max
880.67 ± 4% -93.3% 58.58 ± 64% sched_debug.cpu.cpu_load[0].min
44.14 ± 46% +526.2% 276.40 ± 28% sched_debug.cpu.cpu_load[0].stddev
944.76 ± 0% -59.6% 381.23 ± 17% sched_debug.cpu.cpu_load[1].avg
980.25 ± 1% -17.5% 808.25 ± 5% sched_debug.cpu.cpu_load[1].max
900.79 ± 1% -89.8% 91.67 ± 28% sched_debug.cpu.cpu_load[1].min
30.83 ± 30% +904.7% 309.72 ± 7% sched_debug.cpu.cpu_load[1].stddev
941.95 ± 0% -61.6% 361.83 ± 18% sched_debug.cpu.cpu_load[2].avg
974.08 ± 1% -18.0% 798.29 ± 5% sched_debug.cpu.cpu_load[2].max
899.00 ± 1% -90.8% 82.42 ± 24% sched_debug.cpu.cpu_load[2].min
29.59 ± 30% +946.9% 309.73 ± 6% sched_debug.cpu.cpu_load[2].stddev
935.02 ± 0% -63.1% 344.78 ± 19% sched_debug.cpu.cpu_load[3].avg
965.83 ± 1% -18.7% 785.50 ± 5% sched_debug.cpu.cpu_load[3].max
893.04 ± 1% -91.8% 73.21 ± 26% sched_debug.cpu.cpu_load[3].min
28.77 ± 29% +976.4% 309.70 ± 6% sched_debug.cpu.cpu_load[3].stddev
922.55 ± 0% -64.2% 330.33 ± 19% sched_debug.cpu.cpu_load[4].avg
951.75 ± 1% -20.0% 761.71 ± 6% sched_debug.cpu.cpu_load[4].max
880.96 ± 0% -92.8% 63.08 ± 31% sched_debug.cpu.cpu_load[4].min
27.92 ± 26% +988.8% 304.04 ± 6% sched_debug.cpu.cpu_load[4].stddev
1302 ± 1% -15.7% 1097 ± 7% sched_debug.cpu.curr->pid.avg
798.04 ± 5% -70.5% 235.67 ± 39% sched_debug.cpu.curr->pid.min
812.92 ± 1% +22.9% 999.29 ± 4% sched_debug.cpu.curr->pid.stddev
1359793 ± 6% -34.4% 892053 ± 17% sched_debug.cpu.load.avg
1830834 ± 4% -28.5% 1308664 ± 19% sched_debug.cpu.load.max
1041241 ± 0% -62.6% 389138 ± 37% sched_debug.cpu.load.min
0.00 ± 21% +77.1% 0.00 ± 7% sched_debug.cpu.next_balance.stddev
150630 ± 0% -24.2% 114118 ± 0% sched_debug.cpu.nr_load_updates.avg
151833 ± 0% -21.6% 119037 ± 0% sched_debug.cpu.nr_load_updates.max
149812 ± 0% -27.3% 108953 ± 1% sched_debug.cpu.nr_load_updates.min
745.51 ± 1% +502.7% 4492 ± 14% sched_debug.cpu.nr_load_updates.stddev
2.60 ± 1% -52.8% 1.23 ± 17% sched_debug.cpu.nr_running.avg
3.79 ± 3% -39.6% 2.29 ± 39% sched_debug.cpu.nr_running.max
1.62 ± 8% -74.4% 0.42 ± 34% sched_debug.cpu.nr_running.min
4242583 ± 1% +20.1% 5094187 ± 0% sched_debug.cpu.nr_switches.avg
3880089 ± 1% +24.6% 4835277 ± 1% sched_debug.cpu.nr_switches.min
487080 ± 18% -61.6% 186796 ± 37% sched_debug.cpu.nr_switches.stddev
netperf.Throughput_Mbps
4000 ++-----------------------------------*--*-----*--*--*--*--*-*--*-----+
| .*.. .*..*..* *. |
3500 *+.*..* *.*..*..*. *. |
3000 ++ : : |
| : O |
2500 O+ O O: O : O O O O O O O O O O O O O O
| : : O O O O O |
2000 ++ : : |
| : : |
1500 ++ : : |
1000 ++ : : |
| : : |
500 ++ :: |
| : |
0 ++-------*------------------------------------O----------------------+
[*] bisect-good sample
[O] bisect-bad sample
Thanks,
Xiaolong
4 years, 6 months
[lkp] [xfs] 68a9f5e700: aim7.jobs-per-min -13.6% regression
by kernel test robot
FYI, we noticed a -13.6% regression of aim7.jobs-per-min due to commit:
commit 68a9f5e7007c1afa2cf6830b690a90d0187c0684 ("xfs: implement iomap based buffered write path")
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
in testcase: aim7
on test machine: 48 threads Ivytown Ivy Bridge-EP with 64G memory
with following parameters:
disk: 1BRD_48G
fs: xfs
test: disk_wrt
load: 3000
cpufreq_governor: performance
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/disk/fs/kconfig/load/rootfs/tbox_group/test/testcase:
gcc-6/performance/1BRD_48G/xfs/x86_64-rhel/3000/debian-x86_64-2015-02-07.cgz/ivb44/disk_wrt/aim7
commit:
f0c6bcba74 ("xfs: reorder zeroing and flushing sequence in truncate")
68a9f5e700 ("xfs: implement iomap based buffered write path")
f0c6bcba74ac51cb 68a9f5e7007c1afa2cf6830b69
---------------- --------------------------
%stddev %change %stddev
\ | \
486586 ± 0% -13.6% 420342 ± 0% aim7.jobs-per-min
37.23 ± 0% +15.6% 43.04 ± 0% aim7.time.elapsed_time
37.23 ± 0% +15.6% 43.04 ± 0% aim7.time.elapsed_time.max
6424 ± 1% +31.3% 8432 ± 1% aim7.time.involuntary_context_switches
151288 ± 0% +2.8% 155579 ± 0% aim7.time.minor_page_faults
376.31 ± 0% +28.5% 483.48 ± 0% aim7.time.system_time
429058 ± 0% -20.0% 343371 ± 0% aim7.time.voluntary_context_switches
16014 ± 0% +28.8% 20628 ± 1% meminfo.Active(file)
127154 ± 9% -14.4% 108893 ± 11% softirqs.SCHED
14084 ± 18% -33.1% 9421 ± 17% numa-numastat.node1.numa_foreign
15461 ± 17% -31.4% 10598 ± 13% numa-numastat.node1.numa_miss
24561 ± 0% -27.2% 17873 ± 1% vmstat.system.cs
47289 ± 0% +1.2% 47866 ± 0% vmstat.system.in
7868 ± 1% +27.3% 10013 ± 6% numa-meminfo.node0.Active(file)
8148 ± 1% +29.5% 10554 ± 7% numa-meminfo.node1.Active(file)
81041 ± 3% +30.0% 105374 ± 24% numa-meminfo.node1.Slab
1966 ± 1% +30.1% 2558 ± 4% numa-vmstat.node0.nr_active_file
4204 ± 3% +17.1% 4921 ± 8% numa-vmstat.node0.nr_alloc_batch
2037 ± 1% +26.6% 2579 ± 5% numa-vmstat.node1.nr_active_file
4003 ± 0% +28.1% 5129 ± 1% proc-vmstat.nr_active_file
979.25 ± 0% +63.7% 1602 ± 1% proc-vmstat.pgactivate
4699 ± 3% +162.6% 12340 ± 73% proc-vmstat.pgpgout
50.23 ± 19% -27.3% 36.50 ± 17% sched_debug.cpu.cpu_load[1].avg
466.50 ± 29% -51.8% 225.00 ± 73% sched_debug.cpu.cpu_load[1].max
77.78 ± 33% -50.6% 38.40 ± 57% sched_debug.cpu.cpu_load[1].stddev
300.50 ± 33% -52.9% 141.50 ± 48% sched_debug.cpu.cpu_load[2].max
1836 ± 10% +65.5% 3039 ± 8% slabinfo.scsi_data_buffer.active_objs
1836 ± 10% +65.5% 3039 ± 8% slabinfo.scsi_data_buffer.num_objs
431.75 ± 10% +65.6% 715.00 ± 8% slabinfo.xfs_efd_item.active_objs
431.75 ± 10% +65.6% 715.00 ± 8% slabinfo.xfs_efd_item.num_objs
24.26 ± 0% +8.7% 26.36 ± 0% turbostat.%Busy
686.75 ± 0% +9.1% 749.25 ± 0% turbostat.Avg_MHz
0.29 ± 1% -24.3% 0.22 ± 1% turbostat.CPU%c3
91.39 ± 2% +3.6% 94.71 ± 0% turbostat.CorWatt
121.88 ± 1% +2.8% 125.23 ± 0% turbostat.PkgWatt
53643508 ± 0% -19.6% 43119128 ± 2% cpuidle.C1-IVT.time
318952 ± 0% -25.7% 237018 ± 0% cpuidle.C1-IVT.usage
3471235 ± 2% -16.9% 2886121 ± 2% cpuidle.C1E-IVT.time
46642 ± 1% -22.4% 36214 ± 0% cpuidle.C1E-IVT.usage
12601665 ± 1% -21.8% 9854467 ± 1% cpuidle.C3-IVT.time
79872 ± 1% -19.6% 64244 ± 1% cpuidle.C3-IVT.usage
1.292e+09 ± 0% +13.7% 1.47e+09 ± 0% cpuidle.C6-IVT.time
5131 ±121% -100.0% 0.00 ± -1% latency_stats.avg.nfs_wait_on_request.nfs_updatepage.nfs_write_end.generic_perform_write.__generic_file_write_iter.generic_file_write_iter.nfs_file_write.__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
5131 ±121% -100.0% 0.00 ± -1% latency_stats.max.nfs_wait_on_request.nfs_updatepage.nfs_write_end.generic_perform_write.__generic_file_write_iter.generic_file_write_iter.nfs_file_write.__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
9739 ± 99% -99.0% 95.50 ± 10% latency_stats.max.submit_bio_wait.blkdev_issue_flush.ext4_sync_fs.sync_fs_one_sb.iterate_supers.sys_sync.entry_SYSCALL_64_fastpath
7739 ± 81% -72.1% 2162 ± 52% 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
5131 ±121% -100.0% 0.00 ± -1% latency_stats.sum.nfs_wait_on_request.nfs_updatepage.nfs_write_end.generic_perform_write.__generic_file_write_iter.generic_file_write_iter.nfs_file_write.__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
10459 ± 97% -97.5% 262.75 ± 5% latency_stats.sum.submit_bio_wait.blkdev_issue_flush.ext4_sync_fs.sync_fs_one_sb.iterate_supers.sys_sync.entry_SYSCALL_64_fastpath
9097 ± 81% -72.5% 2505 ± 45% 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
2.59e+11 ± 6% +24.1% 3.213e+11 ± 4% perf-stat.branch-instructions
0.41 ± 2% -9.5% 0.38 ± 1% perf-stat.branch-miss-rate
1.072e+09 ± 4% +12.5% 1.206e+09 ± 3% perf-stat.branch-misses
972882 ± 0% -17.4% 803990 ± 0% perf-stat.context-switches
1.472e+12 ± 6% +22.4% 1.801e+12 ± 5% perf-stat.cpu-cycles
100350 ± 1% -5.1% 95219 ± 1% perf-stat.cpu-migrations
7.315e+08 ± 24% +60.4% 1.174e+09 ± 37% perf-stat.dTLB-load-misses
3.225e+11 ± 5% +36.4% 4.398e+11 ± 2% perf-stat.dTLB-loads
2.176e+11 ± 9% +44.6% 3.147e+11 ± 6% perf-stat.dTLB-stores
1.452e+12 ± 6% +29.5% 1.879e+12 ± 4% perf-stat.instructions
42168 ± 16% +27.5% 53751 ± 6% perf-stat.instructions-per-iTLB-miss
0.99 ± 0% +5.7% 1.04 ± 0% perf-stat.ipc
252401 ± 0% +6.6% 269148 ± 0% perf-stat.minor-faults
10.16 ± 3% +13.0% 11.48 ± 3% perf-stat.node-store-miss-rate
24842185 ± 2% +11.9% 27804764 ± 1% perf-stat.node-store-misses
252321 ± 0% +6.6% 268999 ± 0% perf-stat.page-faults
aim7.jobs-per-min
540000 ++-----------------------------------------------------------------+
520000 **.* *.**. .**.* |
| *.**.**.* ** *.**.**.**.**.* |
500000 ++ : |
480000 ++ *.**.**.**.**.**.**.**.**.*|
| |
460000 ++ |
440000 ++ |
420000 ++ O OO OO OO OO OO OO
|O O O OO O O O O O |
400000 O+ OO O OO O O O OO OO OO O O OO |
380000 ++ |
| |
360000 ++ O OO O |
340000 ++-----------------------------------------------------------------+
[*] bisect-good sample
[O] bisect-bad sample
Thanks,
Xiaolong
4 years, 6 months
Re: [LKP] [lkp] [xfs] 68a9f5e700: aim7.jobs-per-min -13.6% regression
by Linus Torvalds
On Aug 14, 2016 10:00 PM, "Dave Chinner" <david(a)fromorbit.com> wrote:
>
> > What does it say if you annotate that _raw_spin_unlock_irqrestore()
function?
> ....
> ¿
> ¿ Disassembly of section load0:
> ¿
> ¿ ffffffff81e628b0 <load0>:
> ¿ nop
> ¿ push %rbp
> ¿ mov %rsp,%rbp
> ¿ movb $0x0,(%rdi)
> ¿ nop
> ¿ mov %rsi,%rdi
> ¿ push %rdi
> ¿ popfq
> 99.35 ¿ nop
Yeah, that's a good disassembly of a non-debug spin unlock, and the symbols
are fine, but the profile is not valid. That's an interrupt point, right
after the popf that enables interiors again.
I don't know why 'perf' isn't working on your machine, but it clearly
isn't.
Has it ever worked on that machine? What cpu is it? Are you running in some
virtualized environment without performance counters, perhaps?
It's not actually the unlock that is expensive, and there is no contention
on the lock (if there had been, the numbers would have been entirely
different for the debug case, which makes locking an order of magnitude
more expensive). All the cost of everything that happened while interrupts
were disabled is just accounted to the instruction after they were enabled
again.
Linus
4 years, 7 months
[ppdev] 8b7d3a9d90: WARNING: CPU: 0 PID: 153 at fs/sysfs/dir.c:31 sysfs_warn_dup+0x62/0x80
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/gregkh/char-misc.git char-misc-testing
commit 8b7d3a9d903ee1d1f5febc8e74223e4e72720e35 ("ppdev: use new parport device model")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu host -smp 2 -m 4G
caused below changes:
+---------------------------------------------------------+------------+------------+
| | 5ed22cebba | 8b7d3a9d90 |
+---------------------------------------------------------+------------+------------+
| boot_successes | 0 | 19 |
| boot_failures | 1 | 8 |
| BUG:kernel_reboot-without-warning_in_test_stage | 1 | |
| message:BUG:kernel_reboot-without-warning_in_test_stage | 0 | |
| pattern:BUG:kernel_reboot-without-warning_in_test_stage | 0 | |
| WARNING:at_fs/sysfs/dir.c:#sysfs_warn_dup | 0 | 8 |
| message:WARNING:at_fs/sysfs/dir.c:#sysfs_warn_dup | 0 | 0.0 |
| pattern:WARNING:at_fs/sysfs/dir.c:#sysfs_warn_dup | 0 | 0.0 |
| calltrace:parport_pc_init | 0 | 8 |
| message:calltrace:parport_pc_init | 0 | 0.0 |
| pattern:calltrace:parport_pc_init | 0 | 0 |
| calltrace:SyS_finit_module | 0 | 8 |
| message:calltrace:SyS_finit_module | 0 | 0.0 |
| pattern:calltrace:SyS_finit_module | 0 | 0 |
| WARNING:at_lib/kobject.c:#kobject_add_internal | 0 | 8 |
| message:WARNING:at_lib/kobject.c:#kobject_add_internal | 0 | 0.0 |
| pattern:WARNING:at_lib/kobject.c:#kobject_add_internal | 0 | 0.0 |
+---------------------------------------------------------+------------+------------+
[ 8.347735] blk_update_request: I/O error, dev fd0, sector 0
[ 8.349231] floppy: error -5 while reading block 0
[ 8.350671] ------------[ cut here ]------------
[ 8.352075] WARNING: CPU: 0 PID: 153 at fs/sysfs/dir.c:31 sysfs_warn_dup+0x62/0x80
[ 8.354659] sysfs: cannot create duplicate filename '/devices/pnp0/00:04/ppdev/parport0'
[ 8.357017] Modules linked in: ppdev snd_pcm snd_timer crc32c_intel snd soundcore
[ 8.358738] ata2.01: NODEV after polling detection
[ 8.359071] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
[ 8.359795] ata2.00: configured for MWDMA2
[ 8.363714] floppy pcspkr parport_pc(+) serio_raw ata_piix parport libata i2c_piix4 acpi_cpufreq
[ 8.367797] CPU: 0 PID: 153 Comm: systemd-udevd Not tainted 4.8.0-rc2-00102-g8b7d3a9 #1
[ 8.370307] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 8.370387] Kernel tests: Boot OK!
[ 8.374113] 0000000000000000 ffff88010f0cb740 ffffffff8144bb29 ffff88010f0cb790
[ 8.376739] 0000000000000000 ffff88010f0cb780 ffffffff8107e6ab 0000001f0dd7d000
[ 8.379427] ffff88010dd7d000 ffff88010f377110 ffff88010fab69d8 ffff88010fb4f400
[ 8.382066] Call Trace:
[ 8.383085] [<ffffffff8144bb29>] dump_stack+0x63/0x8a
[ 8.384557] [<ffffffff8107e6ab>] __warn+0xcb/0xf0
[ 8.385924] [<ffffffff8107e71f>] warn_slowpath_fmt+0x4f/0x60
[ 8.387368] [<ffffffff8128f1c2>] sysfs_warn_dup+0x62/0x80
[ 8.388780] [<ffffffff8128f2a7>] sysfs_create_dir_ns+0x77/0x90
[ 8.390282] [<ffffffff8144e829>] kobject_add_internal+0xa9/0x320
[ 8.391840] [<ffffffff81457ff3>] ? vsnprintf+0x1e3/0x4d0
[ 8.393256] [<ffffffff8144eb08>] kobject_add+0x68/0xb0
[ 8.394618] [<ffffffff8192bec5>] ? mutex_lock+0x25/0x50
[ 8.395973] [<ffffffff815a5c75>] device_add+0x165/0x630
[ 8.397377] [<ffffffff8119fd61>] ? kfree_const+0x21/0x30
[ 8.398804] [<ffffffff815a6330>] device_create_groups_vargs+0xe0/0xf0
[ 8.400490] [<ffffffffa0079060>] ? dead_read+0x10/0x10 [parport]
[ 8.402022] [<ffffffff815a63a1>] device_create+0x41/0x50
[ 8.403977] [<ffffffff81920b7d>] ? klist_next+0x7d/0x100
[ 8.405376] [<ffffffffa000b0b2>] pp_attach+0x32/0x40 [ppdev]
[ 8.406934] [<ffffffffa0079077>] driver_check+0x17/0x20 [parport]
[ 8.408462] [<ffffffff815a6ecb>] bus_for_each_drv+0x5b/0x90
[ 8.409894] [<ffffffffa0079499>] attach_driver_chain+0x59/0x60 [parport]
[ 8.411537] [<ffffffffa007a7e7>] parport_announce_port+0xc7/0x110 [parport]
[ 8.413173] [<ffffffffa00a3f96>] parport_pc_probe_port+0x6f6/0xca0 [parport_pc]
[ 8.415531] [<ffffffff815a511c>] ? __dev_printk+0x3c/0x80
[ 8.416999] [<ffffffff815a54ac>] ? _dev_info+0x5c/0x60
[ 8.418499] [<ffffffffa00a48f3>] parport_pc_pnp_probe+0x143/0x1e0 [parport_pc]
[ 8.420721] [<ffffffffa00a47b0>] ? parport_pc_pci_probe+0x270/0x270 [parport_pc]
[ 8.422979] [<ffffffff81524865>] pnp_device_probe+0x65/0xc0
[ 8.424555] [<ffffffff815a9323>] driver_probe_device+0x223/0x430
[ 8.426088] [<ffffffff815a960f>] __driver_attach+0xdf/0xf0
[ 8.427541] [<ffffffff815a9530>] ? driver_probe_device+0x430/0x430
[ 8.429072] [<ffffffff815a6e10>] bus_for_each_dev+0x60/0xa0
[ 8.430502] [<ffffffff815a8a5e>] driver_attach+0x1e/0x20
[ 8.431988] [<ffffffff815a84a0>] bus_add_driver+0x170/0x270
[ 8.433549] [<ffffffff815a9f30>] driver_register+0x60/0xe0
[ 8.435027] [<ffffffff815246a0>] pnp_register_driver+0x20/0x30
[ 8.436486] [<ffffffffa00ab36c>] parport_pc_init+0x2b4/0xf48 [parport_pc]
[ 8.438179] [<ffffffffa00ab0b8>] ? parport_parse_param+0xb8/0xb8 [parport_pc]
[ 8.442285] [<ffffffff8100217d>] do_one_initcall+0x3d/0x150
[ 8.443818] [<ffffffff810a4a79>] ? __might_sleep+0x49/0x80
[ 8.445245] [<ffffffff811e68f3>] ? kmem_cache_alloc_trace+0x163/0x1b0
[ 8.446831] [<ffffffff8117b3e0>] do_init_module+0x5f/0x1ef
[ 8.448350] [<ffffffff811092a9>] load_module+0x1439/0x1b50
[ 8.449791] [<ffffffff81105e50>] ? __symbol_put+0x40/0x40
[ 8.451268] [<ffffffff81212f93>] ? kernel_read_file+0x1a3/0x1c0
[ 8.452766] [<ffffffff81213069>] ? kernel_read_file_from_fd+0x49/0x80
Thanks,
Kernel Test Robot
4 years, 7 months
[writeback] ab7724daa9: BUG: spinlock bad magic on CPU#0, umount/538
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/josef/btrfs-next.git kill-btree-inode
commit ab7724daa909923e8dd5baca685ccc1dfa3fa413 ("writeback: introduce super_operations->write_metadata")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -m 512M
caused below changes:
+---------------------------------------+------------+------------+
| | ac04c3c6a3 | ab7724daa9 |
+---------------------------------------+------------+------------+
| boot_successes | 83 | 2 |
| boot_failures | 0 | 31 |
| BUG:spinlock_bad_magic_on_CPU | 0 | 31 |
| message:BUG:spinlock_bad_magic_on_CPU | 0 | 0.0 |
| pattern:BUG:spinlock_bad_magic_on_CPU | 0 | 0 |
+---------------------------------------+------------+------------+
Unmounting remote filesystems...
Deactivating swap...
Unmounting local filesystems...
[ 71.770706] BUG: spinlock bad magic on CPU#0, umount/538
[ 71.771434] lock: 0xffffffff81e57d28, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
[ 71.772491] CPU: 0 PID: 538 Comm: umount Not tainted 4.7.0-11586-gab7724d #2
[ 71.773416] 0000000000000000 ffff88001c3cbcd8 ffffffff8134902b ffff88001c3cbcf8
[ 71.774459] ffffffff81108bd2 ffffffff81e57d28 ffffffff81cc22e0 ffff88001c3cbd18
[ 71.775488] ffffffff81108c4e ffffffff81e57d28 0000000000000001 ffff88001c3cbd48
[ 71.776520] Call Trace:
[ 71.776861] [<ffffffff8134902b>] dump_stack+0x19/0x1b
[ 71.777544] [<ffffffff81108bd2>] spin_dump+0x8e/0xcc
[ 71.778214] [<ffffffff81108c4e>] spin_bug+0x3e/0x43
[ 71.778859] [<ffffffff81108fef>] do_raw_spin_lock+0x1cb/0x1ec
[ 71.779617] [<ffffffff818654a4>] _raw_spin_lock+0x14/0x16
[ 71.780331] [<ffffffff8122b8a7>] deactivate_locked_super+0x93/0xd9
[ 71.781144] [<ffffffff8122c360>] deactivate_super+0xf0/0x100
[ 71.781887] [<ffffffff8125bfbd>] cleanup_mnt+0xad/0xe0
[ 71.782567] [<ffffffff8125d867>] __cleanup_mnt+0x12/0x14
[ 71.783274] [<ffffffff810e8fa6>] task_work_run+0xbf/0x115
[ 71.783982] [<ffffffff81002055>] exit_to_usermode_loop+0x1bc/0x1e3
[ 71.784804] [<ffffffff8125c20c>] ? mntput_no_expire+0x21c/0x2b5
[ 71.785585] [<ffffffff8100232e>] syscall_return_slowpath+0xb6/0xd6
[ 71.786394] [<ffffffff81865690>] entry_SYSCALL_64_fastpath+0xb6/0xb8
Elapsed time: 80
Thanks,
Kernel Test Robot
4 years, 7 months
[writeback] ab7724daa9: BUG: spinlock bad magic on CPU#0, umount/354
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/josef/btrfs-next.git kill-btree-inode
commit ab7724daa909923e8dd5baca685ccc1dfa3fa413
Author: Josef Bacik <jbacik(a)fb.com>
AuthorDate: Wed Aug 17 16:56:35 2016 -0400
Commit: Josef Bacik <jbacik(a)fb.com>
CommitDate: Mon Aug 22 09:18:45 2016 -0400
writeback: introduce super_operations->write_metadata
Now that we have metadata counters in the VM, we need to provide a way to kick
writeback on dirty metadata. Introduce super_operations->write_metadata. This
allows file systems to deal with writing back any dirty metadata we need based
on the writeback needs of the system. Since there is no inode to key off of we
need a list in the bdi for dirty super blocks to be added. From there we can
find any dirty sb's on the bdi we are currently doing writeback on and call into
their ->write_metadata callback.
Signed-off-by: Josef Bacik <jbacik(a)fb.com>
+---------------------------------------+------------+------------+------------+
| | ac04c3c6a3 | ab7724daa9 | bfcea1e771 |
+---------------------------------------+------------+------------+------------+
| boot_successes | 83 | 2 | 6 |
| boot_failures | 0 | 31 | 21 |
| BUG:spinlock_bad_magic_on_CPU | 0 | 31 | 21 |
| message:BUG:spinlock_bad_magic_on_CPU | 0 | 0.0 | 0.0 |
| pattern:BUG:spinlock_bad_magic_on_CPU | 0 | 0 | 0 |
+---------------------------------------+------------+------------+------------+
Kernel tests: Boot OK!
Kernel tests: Boot OK!
udevd[343]: failed to execute '/sbin/modprobe' '/sbin/modprobe -bv acpi:PNP0A06:': No such file or directory
[ 5.957606] BUG: spinlock bad magic on CPU#0, umount/354
[ 5.958745] lock: 0xffffffff81e57d28, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
[ 5.960425] CPU: 0 PID: 354 Comm: umount Not tainted 4.7.0-11586-gab7724d #2
[ 5.961893] 0000000000000000 ffff88001f35fcd8 ffffffff8134902b ffff88001f35fcf8
[ 5.963530] ffffffff81108bd2 ffffffff81e57d28 ffffffff81cc22e0 ffff88001f35fd18
[ 5.966585] ffffffff81108c4e ffffffff81e57d28 0000000000000001 ffff88001f35fd48
[ 5.968219] Call Trace:
[ 5.968757] [<ffffffff8134902b>] dump_stack+0x19/0x1b
[ 5.969816] [<ffffffff81108bd2>] spin_dump+0x8e/0xcc
[ 5.970853] [<ffffffff81108c4e>] spin_bug+0x3e/0x43
[ 5.971875] [<ffffffff81108fef>] do_raw_spin_lock+0x1cb/0x1ec
[ 5.973095] [<ffffffff818654a4>] _raw_spin_lock+0x14/0x16
[ 5.974224] [<ffffffff8122b8a7>] deactivate_locked_super+0x93/0xd9
[ 5.975512] [<ffffffff8122c360>] deactivate_super+0xf0/0x100
[ 5.978605] [<ffffffff8125bfbd>] cleanup_mnt+0xad/0xe0
[ 5.979686] [<ffffffff8125d867>] __cleanup_mnt+0x12/0x14
[ 5.980808] [<ffffffff810e8fa6>] task_work_run+0xbf/0x115
[ 5.981930] [<ffffffff81002055>] exit_to_usermode_loop+0x1bc/0x1e3
[ 5.983229] [<ffffffff8125c20c>] ? mntput_no_expire+0x21c/0x2b5
[ 5.984451] [<ffffffff8100232e>] syscall_return_slowpath+0xb6/0xd6
[ 5.985734] [<ffffffff81865690>] entry_SYSCALL_64_fastpath+0xb6/0xb8
Elapsed time: 20
git bisect start bfcea1e771f165038364750f04524e9a8f44da51 3eab887a55424fc2c27553b7bfe32330df83f7b8 --
git bisect bad b37d27e813bead1516a24524e8cd1f186a5512dd # 04:11 0- 1 Merge 'arm-integrator/apq8060-dragonboard-ethernet' into devel-spot-201609010131
git bisect bad 2a9a76818d4f84c59a8911d85b7198e9012f9185 # 04:16 0- 3 Merge 'char-misc/char-misc-testing' into devel-spot-201609010131
git bisect bad b598532f8700e90bc8d35c0e0d5f02775bbec39e # 04:22 0- 15 Merge 'cryptodev/master' into devel-spot-201609010131
git bisect bad ac86ab4d064cb69d471ccc6e8d40542f578264d3 # 04:29 0- 20 Merge 'slave-dma/topic/err_reporting' into devel-spot-201609010131
git bisect good d94ba5efdad7b30cea41b6d83091576a56df8588 # 04:40 27+ 0 Merge 'iio/testing' into devel-spot-201609010131
git bisect good b9d75b82497aceb03d11b54569955c1725714d02 # 04:45 25+ 0 Merge 'abelloni/rtc-next' into devel-spot-201609010131
git bisect bad d46d323639c89f5faec5fe487a315a086a98b853 # 04:53 0- 5 Merge 'josef-btrfs/kill-btree-inode' into devel-spot-201609010131
git bisect good ac04c3c6a3ed07c0a3a0b0d89337c08ccb3e9886 # 05:00 27+ 0 writeback: allow for dirty metadata accounting
git bisect bad 3fef71185041c3f81e1c10159add01f3312a51a7 # 05:05 0- 3 Btrfs: fix em leak in find_first_block_group
git bisect bad ab7724daa909923e8dd5baca685ccc1dfa3fa413 # 05:07 0- 9 writeback: introduce super_operations->write_metadata
# first bad commit: [ab7724daa909923e8dd5baca685ccc1dfa3fa413] writeback: introduce super_operations->write_metadata
git bisect good ac04c3c6a3ed07c0a3a0b0d89337c08ccb3e9886 # 05:11 79+ 0 writeback: allow for dirty metadata accounting
# extra tests with CONFIG_DEBUG_INFO_REDUCED
git bisect bad ab7724daa909923e8dd5baca685ccc1dfa3fa413 # 05:20 0- 3 writeback: introduce super_operations->write_metadata
# extra tests on HEAD of linux-devel/devel-spot-201609010131
git bisect bad bfcea1e771f165038364750f04524e9a8f44da51 # 05:20 0- 21 0day head guard for 'devel-spot-201609010131'
# extra tests on tree/branch josef-btrfs/kill-btree-inode
git bisect bad 47763aed48f76b160b3ad555f9202c9c69bc28ec # 05:26 0- 6 Bpf: allow access into map value arrays
# extra tests with first bad commit reverted
git bisect good 4673c1393e7544aead75b0e9573b64486f60cc77 # 05:36 82+ 0 Revert "writeback: introduce super_operations->write_metadata"
# extra tests on tree/branch linus/master
git bisect good 071e31e254e0e0c438eecba3dba1d6e2d0da36c2 # 05:43 82+ 0 Merge branch 'linus' of git://git.kernel.org/pub/scm/linux/kernel/git/herbert/crypto-2.6
# extra tests on tree/branch linux-next/master
git bisect good 0f98f121e1670eaa2a2fbb675e07d6ba7f0e146f # 05:49 80+ 3 Add linux-next specific files for 20160825
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
4 years, 7 months
[writeback] 2f0a58af6c: INFO: suspicious RCU usage. ]
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git wb-buf-throttle-v6
commit 2f0a58af6c7396b8a8ee191955c4886b54240974 ("writeback: throttle buffered writeback")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu kvm64,+ssse3 -smp 2 -m 8G
caused below changes:
+--------------------------------------+------------+------------+
| | 0ac0f3e57c | 2f0a58af6c |
+--------------------------------------+------------+------------+
| boot_successes | 6 | 0 |
| boot_failures | 0 | 8 |
| INFO:suspicious_RCU_usage | 0 | 8 |
| message:INFO:suspicious_RCU_usage | 0 | 0.0 |
| pattern:INFO:suspicious_RCU_usage | 0 | 0 |
| calltrace:disk_events_workfn | 0 | 8 |
| message:calltrace:disk_events_workfn | 0 | 0.0 |
| pattern:calltrace:disk_events_workfn | 0 | 0 |
+--------------------------------------+------------+------------+
[ 16.775948] cdrom: Uniform CD-ROM driver Revision: 3.20
[ 16.803762]
[ 16.804540] ===============================
[ 16.805952] [ INFO: suspicious RCU usage. ]
[ 16.807334] 4.8.0-rc4-00008-g2f0a58a #1 Not tainted
[ 16.812162] -------------------------------
[ 16.813593] include/linux/cgroup.h:435 suspicious rcu_dereference_check() usage!
[ 16.816429]
[ 16.816429] other info that might help us debug this:
[ 16.816429]
[ 16.819251]
[ 16.819251] rcu_scheduler_active = 1, debug_locks = 0
[ 16.821484] 3 locks held by kworker/1:1/36:
[ 16.822892] #0: ("events_freezable_power_efficient"){.+.+..}, at: [<ffffffff810fc9d9>] process_one_work+0x151/0x4ee
[ 16.826754] #1: ((&(&ev->dwork)->work)){+.+...}, at: [<ffffffff810fc9d9>] process_one_work+0x151/0x4ee
[ 16.830373] #2: (&(&q->__queue_lock)->rlock){-.....}, at: [<ffffffff81789b1d>] cfq_set_request+0x5e/0x2a3
[ 16.834046]
[ 16.834046] stack backtrace:
[ 16.835770] CPU: 1 PID: 36 Comm: kworker/1:1 Not tainted 4.8.0-rc4-00008-g2f0a58a #1
[ 16.838266] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 16.841039] Workqueue: events_freezable_power_ disk_events_workfn
[ 16.843020] 0000000000000000 ffff880254c738e8 ffffffff8178ed3b ffff880254c6c940
[ 16.846044] 0000000000000001 ffff880254c73918 ffffffff81123472 ffff880254c6c940
[ 16.849044] ffffffff84091180 0000000000000003 ffff880238ceb400 ffff880254c73938
[ 16.852026] Call Trace:
[ 16.853010] [<ffffffff8178ed3b>] dump_stack+0x82/0xb8
[ 16.854640] [<ffffffff81123472>] lockdep_rcu_suspicious+0xf7/0x100
[ 16.856504] [<ffffffff817873f4>] bio_blkcg+0x89/0x93
[ 16.858096] [<ffffffff817891f0>] check_blkcg_changed+0x58/0x1b8
[ 16.859905] [<ffffffff81125fa7>] ? lock_acquire+0x125/0x1be
[ 16.861647] [<ffffffff81125fa7>] ? lock_acquire+0x125/0x1be
[ 16.863355] [<ffffffff811238d3>] ? lock_acquired+0xfc/0x2f2
[ 16.865093] [<ffffffff81789b1d>] ? cfq_set_request+0x5e/0x2a3
[ 16.866878] [<ffffffff81789b90>] cfq_set_request+0xd1/0x2a3
[ 16.868479] [<ffffffff82efb493>] ? _raw_spin_unlock_irq+0x2c/0x3b
[ 16.869796] [<ffffffff81124a52>] ? trace_hardirqs_on_caller+0x17c/0x198
[ 16.871203] [<ffffffff81124a7b>] ? trace_hardirqs_on+0xd/0xf
[ 16.872428] [<ffffffff82efb498>] ? _raw_spin_unlock_irq+0x31/0x3b
[ 16.873723] [<ffffffff8176dd78>] ? ioc_create_icq+0x15e/0x175
[ 16.874933] [<ffffffff81763fe3>] elv_set_request+0x1f/0x24
[ 16.876164] [<ffffffff8176856d>] get_request+0x38f/0x77f
[ 16.877360] [<ffffffff8111b59c>] ? add_wait_queue_exclusive+0x44/0x44
[ 16.878676] [<ffffffff817689c2>] blk_get_request+0x65/0xa8
[ 16.879939] [<ffffffff81c692df>] ide_cd_queue_pc+0x76/0x19d
[ 16.881184] [<ffffffff8112539e>] ? __lock_acquire+0x679/0xed1
[ 16.882366] [<ffffffff81c695ee>] cdrom_check_status+0x51/0x53
[ 16.883625] [<ffffffff81c6a27e>] ide_cdrom_check_events_real+0x20/0x3f
[ 16.884999] [<ffffffff82579f94>] cdrom_update_events+0x18/0x21
[ 16.886292] [<ffffffff82579faf>] cdrom_check_events+0x12/0x1f
[ 16.887580] [<ffffffff81c68317>] idecd_check_events+0x1c/0x1e
[ 16.888812] [<ffffffff81778d12>] disk_check_events+0x47/0x103
[ 16.890038] [<ffffffff81778dea>] disk_events_workfn+0x1c/0x1e
[ 16.891338] [<ffffffff810fcafa>] process_one_work+0x272/0x4ee
[ 16.892599] [<ffffffff810fd247>] worker_thread+0x1eb/0x2c9
[ 16.893835] [<ffffffff810fd05c>] ? rescuer_thread+0x2b3/0x2b3
[ 16.895099] [<ffffffff81101dd4>] kthread+0xc5/0xcd
[ 16.896197] [<ffffffff82efbf2f>] ret_from_fork+0x1f/0x40
[ 16.897331] [<ffffffff81101d0f>] ? kthread_create_on_node+0x1b0/0x1b0
[ 16.899392] Loading iSCSI transport class v2.0-870.
[ 16.915828] rdac: device handler registered
Thanks,
Kernel Test Robot
4 years, 7 months
[ima] efca4e3a3a: BUG: spinlock bad magic on CPU#1, swapper/0/1
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/zohar/linux-integrity.git next-restore-kexec
commit efca4e3a3a4191fd8fd43b32433649719abb2e4e ("ima: store the builtin/custom template definitions in a list")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu host -smp 2 -m 4G
caused below changes:
+---------------------------------------------------------+------------+------------+
| | 9c1fec0473 | efca4e3a3a |
+---------------------------------------------------------+------------+------------+
| boot_successes | 15 | 0 |
| boot_failures | 1 | 16 |
| BUG:kernel_reboot-without-warning_in_test_stage | 1 | |
| message:BUG:kernel_reboot-without-warning_in_test_stage | 0 | |
| pattern:BUG:kernel_reboot-without-warning_in_test_stage | 0 | |
| BUG:spinlock_bad_magic_on_CPU | 0 | 16 |
| message:BUG:spinlock_bad_magic_on_CPU | 0 | 0.0 |
| pattern:BUG:spinlock_bad_magic_on_CPU | 0 | 0 |
| calltrace:init_ima | 0 | 16 |
| message:calltrace:init_ima | 0 | 0.0 |
| pattern:calltrace:init_ima | 0 | 0 |
+---------------------------------------------------------+------------+------------+
[ 250.732810] Key type trusted registered
[ 250.733393] cryptomgr_probe (174) used greatest stack depth: 29040 bytes left
[ 250.782425] Key type encrypted registered
[ 250.792975] BUG: spinlock bad magic on CPU#1, swapper/0/1
[ 250.805549] lock: template_list+0x0/0x80, .magic: 00000000, .owner: swapper/0/1, .owner_cpu: 1
[ 250.819576] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 4.8.0-rc1-00027-gefca4e3 #1
[ 250.830820] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 250.843529] 0000000000000000 ffff88011a7ffd40 ffffffff81b9bf0f ffffffff84a42120
[ 250.857397] ffff88011a7f0040 ffff88011a7ffd78 ffffffff8119aad1 1ffffffff0696400
[ 250.871105] ffffffff84a42120 ffffffff835f21e0 dffffc0000000000 ffffffff835f2240
[ 250.890963] Call Trace:
[ 250.936528] [<ffffffff81b9bf0f>] dump_stack+0x61/0x7d
[ 250.948458] [<ffffffff8119aad1>] spin_dump+0x16b/0x175
[ 250.960423] [<ffffffff8119ab01>] spin_bug+0x26/0x28
[ 250.971503] [<ffffffff8119b0f2>] do_raw_spin_unlock+0x52/0x19e
[ 250.984211] [<ffffffff829a808a>] _raw_spin_unlock+0x22/0x2c
[ 250.996519] [<ffffffff83e20502>] ima_init_template_list+0xa6/0xb4
[ 251.009452] [<ffffffff83e1fc3b>] ? hash_setup+0x103/0x103
[ 251.021219] [<ffffffff83e1fc45>] init_ima+0xa/0x36
[ 251.032037] [<ffffffff83dd282d>] do_one_initcall+0x112/0x1bd
[ 251.044133] [<ffffffff83dd271b>] ? start_kernel+0x5af/0x5af
[ 251.056306] [<ffffffff81140700>] ? parse_args+0x3c5/0x5d4
[ 251.068043] [<ffffffff83dd2cc8>] kernel_init_freeable+0x3f0/0x4a3
[ 251.080939] [<ffffffff8299cebd>] kernel_init+0xc/0x105
[ 251.092221] [<ffffffff829a899f>] ret_from_fork+0x1f/0x40
[ 251.103790] [<ffffffff8299ceb1>] ? rest_init+0xe8/0xe8
[ 251.131376] ima: No TPM chip found, activating TPM-bypass!
[ 251.154124] raid6test: testing the 4-disk case...
Thanks,
Kernel Test Robot
4 years, 7 months