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?
3 years
Test monitoring on custom github repo
by Thomas Garnier
Hi,
I am working on KASLR (PIE for x86_64). I previously used Kees (CCed)
branches for lkp bot testing but someone told be I could ask you to add a
custom github path to monitor all branches on it.
I pushed my changes to: https://github.com/thgarnie/linux (kasrl_pie_v2
right now)
Can you add it? Anything I need to do?
Thanks,
--
Thomas
3 years, 5 months
[lkp-robot] [brd] 316ba5736c: aim7.jobs-per-min -11.2% regression
by kernel test robot
Greeting,
FYI, we noticed a -11.2% regression of aim7.jobs-per-min due to commit:
commit: 316ba5736c9caa5dbcd84085989862d2df57431d ("brd: Mark as non-rotational")
https://git.kernel.org/cgit/linux/kernel/git/axboe/linux-block.git for-4.18/block
in testcase: aim7
on test machine: 40 threads Intel(R) Xeon(R) CPU E5-2690 v2 @ 3.00GHz with 384G memory
with following parameters:
disk: 1BRD_48G
fs: btrfs
test: disk_rw
load: 1500
cpufreq_governor: performance
test-description: AIM7 is a traditional UNIX system level benchmark suite which is used to test and measure the performance of multiuser system.
test-url: https://sourceforge.net/projects/aimbench/files/aim-suite7/
Details are as below:
-------------------------------------------------------------------------------------------------->
=========================================================================================
compiler/cpufreq_governor/disk/fs/kconfig/load/rootfs/tbox_group/test/testcase:
gcc-7/performance/1BRD_48G/btrfs/x86_64-rhel-7.2/1500/debian-x86_64-2016-08-31.cgz/lkp-ivb-ep01/disk_rw/aim7
commit:
522a777566 ("block: consolidate struct request timestamp fields")
316ba5736c ("brd: Mark as non-rotational")
522a777566f56696 316ba5736c9caa5dbcd8408598
---------------- --------------------------
%stddev %change %stddev
\ | \
28321 -11.2% 25147 aim7.jobs-per-min
318.19 +12.6% 358.23 aim7.time.elapsed_time
318.19 +12.6% 358.23 aim7.time.elapsed_time.max
1437526 ± 2% +14.6% 1646849 ± 2% aim7.time.involuntary_context_switches
11986 +14.2% 13691 aim7.time.system_time
73.06 ± 2% -3.6% 70.43 aim7.time.user_time
2449470 ± 2% -25.0% 1837521 ± 4% aim7.time.voluntary_context_switches
20.25 ± 58% +1681.5% 360.75 ±109% numa-meminfo.node1.Mlocked
456062 -16.3% 381859 softirqs.SCHED
9015 ± 7% -21.3% 7098 ± 22% meminfo.CmaFree
47.50 ± 58% +1355.8% 691.50 ± 92% meminfo.Mlocked
5.24 ± 3% -1.2 3.99 ± 2% mpstat.cpu.idle%
0.61 ± 2% -0.1 0.52 ± 2% mpstat.cpu.usr%
16627 +12.8% 18762 ± 4% slabinfo.Acpi-State.active_objs
16627 +12.9% 18775 ± 4% slabinfo.Acpi-State.num_objs
57.00 ± 2% +17.5% 67.00 vmstat.procs.r
20936 -24.8% 15752 ± 2% vmstat.system.cs
45474 -1.7% 44681 vmstat.system.in
6.50 ± 59% +1157.7% 81.75 ± 75% numa-vmstat.node0.nr_mlock
242870 ± 3% +13.2% 274913 ± 7% numa-vmstat.node0.nr_written
2278 ± 7% -22.6% 1763 ± 21% numa-vmstat.node1.nr_free_cma
4.75 ± 58% +1789.5% 89.75 ±109% numa-vmstat.node1.nr_mlock
88018135 ± 3% -48.9% 44980457 ± 7% cpuidle.C1.time
1398288 ± 3% -51.1% 683493 ± 9% cpuidle.C1.usage
3499814 ± 2% -38.5% 2153158 ± 5% cpuidle.C1E.time
52722 ± 4% -45.6% 28692 ± 6% cpuidle.C1E.usage
9865857 ± 3% -40.1% 5905155 ± 5% cpuidle.C3.time
69656 ± 2% -42.6% 39990 ± 5% cpuidle.C3.usage
590856 ± 2% -12.3% 517910 cpuidle.C6.usage
46160 ± 7% -53.7% 21372 ± 11% cpuidle.POLL.time
1716 ± 7% -46.6% 916.25 ± 14% cpuidle.POLL.usage
197656 +4.1% 205732 proc-vmstat.nr_active_file
191867 +4.1% 199647 proc-vmstat.nr_dirty
509282 +1.6% 517318 proc-vmstat.nr_file_pages
2282 ± 8% -24.4% 1725 ± 22% proc-vmstat.nr_free_cma
357.50 +10.6% 395.25 ± 2% proc-vmstat.nr_inactive_file
11.50 ± 58% +1397.8% 172.25 ± 93% proc-vmstat.nr_mlock
970355 ± 4% +14.6% 1111549 ± 8% proc-vmstat.nr_written
197984 +4.1% 206034 proc-vmstat.nr_zone_active_file
357.50 +10.6% 395.25 ± 2% proc-vmstat.nr_zone_inactive_file
192282 +4.1% 200126 proc-vmstat.nr_zone_write_pending
7901465 ± 3% -14.0% 6795016 ± 16% proc-vmstat.pgalloc_movable
886101 +10.2% 976329 proc-vmstat.pgfault
2.169e+12 +15.2% 2.497e+12 perf-stat.branch-instructions
0.41 -0.1 0.35 perf-stat.branch-miss-rate%
31.19 ± 2% +1.6 32.82 perf-stat.cache-miss-rate%
9.116e+09 +8.3% 9.869e+09 perf-stat.cache-misses
2.924e+10 +2.9% 3.008e+10 ± 2% perf-stat.cache-references
6712739 ± 2% -15.4% 5678643 ± 2% perf-stat.context-switches
4.02 +2.7% 4.13 perf-stat.cpi
3.761e+13 +17.3% 4.413e+13 perf-stat.cpu-cycles
606958 -13.7% 523758 ± 2% perf-stat.cpu-migrations
2.476e+12 +13.4% 2.809e+12 perf-stat.dTLB-loads
0.18 ± 2% -0.0 0.16 ± 9% perf-stat.dTLB-store-miss-rate%
1.079e+09 ± 2% -9.6% 9.755e+08 ± 9% perf-stat.dTLB-store-misses
5.933e+11 +1.6% 6.029e+11 perf-stat.dTLB-stores
9.349e+12 +14.2% 1.068e+13 perf-stat.instructions
11247 ± 11% +19.8% 13477 ± 9% perf-stat.instructions-per-iTLB-miss
0.25 -2.6% 0.24 perf-stat.ipc
865561 +10.3% 954350 perf-stat.minor-faults
2.901e+09 ± 3% +9.8% 3.186e+09 ± 3% perf-stat.node-load-misses
3.682e+09 ± 3% +11.0% 4.088e+09 ± 3% perf-stat.node-loads
3.778e+09 +4.8% 3.959e+09 ± 2% perf-stat.node-store-misses
5.079e+09 +6.4% 5.402e+09 perf-stat.node-stores
865565 +10.3% 954352 perf-stat.page-faults
51.75 ± 5% -12.5% 45.30 ± 10% sched_debug.cfs_rq:/.load_avg.avg
316.35 ± 3% +17.2% 370.81 ± 8% sched_debug.cfs_rq:/.util_est_enqueued.stddev
15294 ± 30% +234.9% 51219 ± 76% sched_debug.cpu.avg_idle.min
299443 ± 3% -7.3% 277566 ± 5% sched_debug.cpu.avg_idle.stddev
1182 ± 19% -26.3% 872.02 ± 13% sched_debug.cpu.nr_load_updates.stddev
1.22 ± 8% +21.7% 1.48 ± 6% sched_debug.cpu.nr_running.avg
2.75 ± 10% +26.2% 3.47 ± 6% sched_debug.cpu.nr_running.max
0.58 ± 7% +24.2% 0.73 ± 6% sched_debug.cpu.nr_running.stddev
77148 -20.0% 61702 ± 7% sched_debug.cpu.nr_switches.avg
70024 -24.8% 52647 ± 8% sched_debug.cpu.nr_switches.min
6662 ± 6% +61.9% 10789 ± 24% sched_debug.cpu.nr_switches.stddev
80.45 ± 18% -19.1% 65.05 ± 6% sched_debug.cpu.nr_uninterruptible.stddev
76819 -19.3% 62008 ± 8% sched_debug.cpu.sched_count.avg
70616 -23.5% 53996 ± 8% sched_debug.cpu.sched_count.min
5494 ± 9% +85.3% 10179 ± 26% sched_debug.cpu.sched_count.stddev
16936 -52.9% 7975 ± 9% sched_debug.cpu.sched_goidle.avg
19281 -49.9% 9666 ± 7% sched_debug.cpu.sched_goidle.max
15417 -54.8% 6962 ± 10% sched_debug.cpu.sched_goidle.min
875.00 ± 6% -35.0% 569.09 ± 13% sched_debug.cpu.sched_goidle.stddev
40332 -23.5% 30851 ± 7% sched_debug.cpu.ttwu_count.avg
35074 -26.3% 25833 ± 6% sched_debug.cpu.ttwu_count.min
3239 ± 8% +67.4% 5422 ± 28% sched_debug.cpu.ttwu_count.stddev
5232 +27.4% 6665 ± 13% sched_debug.cpu.ttwu_local.avg
15877 ± 12% +77.5% 28184 ± 27% sched_debug.cpu.ttwu_local.max
2530 ± 10% +95.9% 4956 ± 27% sched_debug.cpu.ttwu_local.stddev
2.52 ± 7% -0.6 1.95 ± 3% perf-profile.calltrace.cycles-pp.btrfs_dirty_pages.__btrfs_buffered_write.btrfs_file_write_iter.__vfs_write.vfs_write
1.48 ± 12% -0.5 1.01 ± 4% perf-profile.calltrace.cycles-pp.btrfs_get_extent.btrfs_dirty_pages.__btrfs_buffered_write.btrfs_file_write_iter.__vfs_write
1.18 ± 16% -0.4 0.76 ± 7% perf-profile.calltrace.cycles-pp.btrfs_search_slot.btrfs_lookup_file_extent.btrfs_get_extent.btrfs_dirty_pages.__btrfs_buffered_write
1.18 ± 16% -0.4 0.76 ± 7% perf-profile.calltrace.cycles-pp.btrfs_lookup_file_extent.btrfs_get_extent.btrfs_dirty_pages.__btrfs_buffered_write.btrfs_file_write_iter
0.90 ± 17% -0.3 0.56 ± 4% perf-profile.calltrace.cycles-pp.__dentry_kill.dentry_kill.dput.__fput.task_work_run
0.90 ± 17% -0.3 0.56 ± 4% perf-profile.calltrace.cycles-pp.evict.__dentry_kill.dentry_kill.dput.__fput
0.90 ± 17% -0.3 0.56 ± 4% perf-profile.calltrace.cycles-pp.dentry_kill.dput.__fput.task_work_run.exit_to_usermode_loop
0.90 ± 18% -0.3 0.56 ± 4% perf-profile.calltrace.cycles-pp.btrfs_evict_inode.evict.__dentry_kill.dentry_kill.dput
0.90 ± 17% -0.3 0.57 ± 5% perf-profile.calltrace.cycles-pp.exit_to_usermode_loop.do_syscall_64.entry_SYSCALL_64_after_hwframe
0.90 ± 17% -0.3 0.57 ± 5% perf-profile.calltrace.cycles-pp.task_work_run.exit_to_usermode_loop.do_syscall_64.entry_SYSCALL_64_after_hwframe
0.90 ± 17% -0.3 0.57 ± 5% perf-profile.calltrace.cycles-pp.__fput.task_work_run.exit_to_usermode_loop.do_syscall_64.entry_SYSCALL_64_after_hwframe
0.90 ± 17% -0.3 0.57 ± 5% perf-profile.calltrace.cycles-pp.dput.__fput.task_work_run.exit_to_usermode_loop.do_syscall_64
1.69 -0.1 1.54 ± 2% perf-profile.calltrace.cycles-pp.lock_and_cleanup_extent_if_need.__btrfs_buffered_write.btrfs_file_write_iter.__vfs_write.vfs_write
0.87 ± 4% -0.1 0.76 ± 2% perf-profile.calltrace.cycles-pp.__clear_extent_bit.clear_extent_bit.lock_and_cleanup_extent_if_need.__btrfs_buffered_write.btrfs_file_write_iter
0.87 ± 4% -0.1 0.76 ± 2% perf-profile.calltrace.cycles-pp.clear_extent_bit.lock_and_cleanup_extent_if_need.__btrfs_buffered_write.btrfs_file_write_iter.__vfs_write
0.71 ± 6% -0.1 0.61 ± 2% perf-profile.calltrace.cycles-pp.clear_state_bit.__clear_extent_bit.clear_extent_bit.lock_and_cleanup_extent_if_need.__btrfs_buffered_write
0.69 ± 6% -0.1 0.60 ± 2% perf-profile.calltrace.cycles-pp.btrfs_clear_bit_hook.clear_state_bit.__clear_extent_bit.clear_extent_bit.lock_and_cleanup_extent_if_need
96.77 +0.6 97.33 perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe
0.00 +0.6 0.56 ± 3% perf-profile.calltrace.cycles-pp.can_overcommit.reserve_metadata_bytes.btrfs_delalloc_reserve_metadata.__btrfs_buffered_write.btrfs_file_write_iter
96.72 +0.6 97.29 perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe
43.13 +0.8 43.91 perf-profile.calltrace.cycles-pp.btrfs_inode_rsv_release.__btrfs_buffered_write.btrfs_file_write_iter.__vfs_write.vfs_write
42.37 +0.8 43.16 perf-profile.calltrace.cycles-pp.native_queued_spin_lock_slowpath._raw_spin_lock.block_rsv_release_bytes.btrfs_inode_rsv_release.__btrfs_buffered_write
43.11 +0.8 43.89 perf-profile.calltrace.cycles-pp.block_rsv_release_bytes.btrfs_inode_rsv_release.__btrfs_buffered_write.btrfs_file_write_iter.__vfs_write
42.96 +0.8 43.77 perf-profile.calltrace.cycles-pp._raw_spin_lock.block_rsv_release_bytes.btrfs_inode_rsv_release.__btrfs_buffered_write.btrfs_file_write_iter
95.28 +0.9 96.23 perf-profile.calltrace.cycles-pp.ksys_write.do_syscall_64.entry_SYSCALL_64_after_hwframe
95.22 +1.0 96.18 perf-profile.calltrace.cycles-pp.vfs_write.ksys_write.do_syscall_64.entry_SYSCALL_64_after_hwframe
94.88 +1.0 95.85 perf-profile.calltrace.cycles-pp.__vfs_write.vfs_write.ksys_write.do_syscall_64.entry_SYSCALL_64_after_hwframe
94.83 +1.0 95.80 perf-profile.calltrace.cycles-pp.btrfs_file_write_iter.__vfs_write.vfs_write.ksys_write.do_syscall_64
94.51 +1.0 95.50 perf-profile.calltrace.cycles-pp.__btrfs_buffered_write.btrfs_file_write_iter.__vfs_write.vfs_write.ksys_write
42.44 +1.1 43.52 perf-profile.calltrace.cycles-pp._raw_spin_lock.reserve_metadata_bytes.btrfs_delalloc_reserve_metadata.__btrfs_buffered_write.btrfs_file_write_iter
42.09 +1.1 43.18 perf-profile.calltrace.cycles-pp.native_queued_spin_lock_slowpath._raw_spin_lock.reserve_metadata_bytes.btrfs_delalloc_reserve_metadata.__btrfs_buffered_write
44.07 +1.2 45.29 perf-profile.calltrace.cycles-pp.btrfs_delalloc_reserve_metadata.__btrfs_buffered_write.btrfs_file_write_iter.__vfs_write.vfs_write
43.42 +1.3 44.69 perf-profile.calltrace.cycles-pp.reserve_metadata_bytes.btrfs_delalloc_reserve_metadata.__btrfs_buffered_write.btrfs_file_write_iter.__vfs_write
2.06 ± 18% -0.9 1.21 ± 6% perf-profile.children.cycles-pp.btrfs_search_slot
2.54 ± 7% -0.6 1.96 ± 3% perf-profile.children.cycles-pp.btrfs_dirty_pages
1.05 ± 24% -0.5 0.52 ± 9% perf-profile.children.cycles-pp._raw_spin_lock_irqsave
1.50 ± 12% -0.5 1.03 ± 4% perf-profile.children.cycles-pp.btrfs_get_extent
1.22 ± 15% -0.4 0.79 ± 8% perf-profile.children.cycles-pp.btrfs_lookup_file_extent
0.81 ± 5% -0.4 0.41 ± 6% perf-profile.children.cycles-pp.btrfs_calc_reclaim_metadata_size
0.74 ± 24% -0.4 0.35 ± 9% perf-profile.children.cycles-pp.btrfs_lock_root_node
0.74 ± 24% -0.4 0.35 ± 9% perf-profile.children.cycles-pp.btrfs_tree_lock
0.90 ± 17% -0.3 0.56 ± 4% perf-profile.children.cycles-pp.__dentry_kill
0.90 ± 17% -0.3 0.56 ± 4% perf-profile.children.cycles-pp.evict
0.90 ± 17% -0.3 0.56 ± 4% perf-profile.children.cycles-pp.dentry_kill
0.90 ± 18% -0.3 0.56 ± 4% perf-profile.children.cycles-pp.btrfs_evict_inode
0.91 ± 18% -0.3 0.57 ± 4% perf-profile.children.cycles-pp.exit_to_usermode_loop
0.52 ± 20% -0.3 0.18 ± 14% perf-profile.children.cycles-pp.do_idle
0.90 ± 17% -0.3 0.57 ± 5% perf-profile.children.cycles-pp.task_work_run
0.90 ± 17% -0.3 0.57 ± 5% perf-profile.children.cycles-pp.__fput
0.90 ± 18% -0.3 0.57 ± 4% perf-profile.children.cycles-pp.dput
0.51 ± 20% -0.3 0.18 ± 14% perf-profile.children.cycles-pp.secondary_startup_64
0.51 ± 20% -0.3 0.18 ± 14% perf-profile.children.cycles-pp.cpu_startup_entry
0.50 ± 21% -0.3 0.17 ± 16% perf-profile.children.cycles-pp.start_secondary
0.47 ± 20% -0.3 0.16 ± 13% perf-profile.children.cycles-pp.cpuidle_enter_state
0.47 ± 19% -0.3 0.16 ± 13% perf-profile.children.cycles-pp.intel_idle
0.61 ± 20% -0.3 0.36 ± 11% perf-profile.children.cycles-pp.btrfs_tree_read_lock
0.47 ± 26% -0.3 0.21 ± 10% perf-profile.children.cycles-pp.prepare_to_wait_event
0.64 ± 18% -0.2 0.39 ± 9% perf-profile.children.cycles-pp.btrfs_read_lock_root_node
0.40 ± 22% -0.2 0.21 ± 5% perf-profile.children.cycles-pp.btrfs_clear_path_blocking
0.38 ± 23% -0.2 0.19 ± 13% perf-profile.children.cycles-pp.finish_wait
1.51 ± 3% -0.2 1.35 ± 2% perf-profile.children.cycles-pp.__clear_extent_bit
1.71 -0.1 1.56 ± 2% perf-profile.children.cycles-pp.lock_and_cleanup_extent_if_need
0.29 ± 25% -0.1 0.15 ± 10% perf-profile.children.cycles-pp.btrfs_orphan_del
0.27 ± 27% -0.1 0.12 ± 8% perf-profile.children.cycles-pp.btrfs_del_orphan_item
0.33 ± 18% -0.1 0.19 ± 9% perf-profile.children.cycles-pp.queued_read_lock_slowpath
0.33 ± 19% -0.1 0.20 ± 4% perf-profile.children.cycles-pp.__wake_up_common_lock
0.45 ± 15% -0.1 0.34 ± 2% perf-profile.children.cycles-pp.btrfs_alloc_data_chunk_ondemand
0.47 ± 16% -0.1 0.36 ± 4% perf-profile.children.cycles-pp.btrfs_check_data_free_space
0.91 ± 4% -0.1 0.81 ± 3% perf-profile.children.cycles-pp.clear_extent_bit
1.07 ± 5% -0.1 0.97 perf-profile.children.cycles-pp.__set_extent_bit
0.77 ± 6% -0.1 0.69 ± 3% perf-profile.children.cycles-pp.btrfs_clear_bit_hook
0.17 ± 20% -0.1 0.08 ± 10% perf-profile.children.cycles-pp.queued_write_lock_slowpath
0.16 ± 22% -0.1 0.08 ± 24% perf-profile.children.cycles-pp.btrfs_lookup_inode
0.21 ± 17% -0.1 0.14 ± 19% perf-profile.children.cycles-pp.__btrfs_update_delayed_inode
0.26 ± 12% -0.1 0.18 ± 13% perf-profile.children.cycles-pp.btrfs_async_run_delayed_root
0.52 ± 5% -0.1 0.45 perf-profile.children.cycles-pp.set_extent_bit
0.45 ± 5% -0.1 0.40 ± 3% perf-profile.children.cycles-pp.alloc_extent_state
0.11 ± 17% -0.1 0.06 ± 11% perf-profile.children.cycles-pp.btrfs_clear_lock_blocking_rw
0.28 ± 9% -0.0 0.23 ± 3% perf-profile.children.cycles-pp.btrfs_drop_pages
0.07 -0.0 0.03 ±100% perf-profile.children.cycles-pp.btrfs_set_lock_blocking_rw
0.39 ± 3% -0.0 0.34 ± 3% perf-profile.children.cycles-pp.get_alloc_profile
0.33 ± 7% -0.0 0.29 perf-profile.children.cycles-pp.btrfs_set_extent_delalloc
0.38 ± 2% -0.0 0.35 ± 4% perf-profile.children.cycles-pp.__set_page_dirty_nobuffers
0.49 ± 3% -0.0 0.46 ± 3% perf-profile.children.cycles-pp.pagecache_get_page
0.18 ± 4% -0.0 0.15 ± 2% perf-profile.children.cycles-pp.truncate_inode_pages_range
0.08 ± 5% -0.0 0.05 ± 9% perf-profile.children.cycles-pp.btrfs_set_path_blocking
0.08 ± 6% -0.0 0.06 ± 6% perf-profile.children.cycles-pp.truncate_cleanup_page
0.80 ± 4% +0.2 0.95 ± 2% perf-profile.children.cycles-pp.can_overcommit
96.84 +0.5 97.37 perf-profile.children.cycles-pp.entry_SYSCALL_64_after_hwframe
96.80 +0.5 97.35 perf-profile.children.cycles-pp.do_syscall_64
43.34 +0.8 44.17 perf-profile.children.cycles-pp.btrfs_inode_rsv_release
43.49 +0.8 44.32 perf-profile.children.cycles-pp.block_rsv_release_bytes
95.32 +0.9 96.26 perf-profile.children.cycles-pp.ksys_write
95.26 +0.9 96.20 perf-profile.children.cycles-pp.vfs_write
94.91 +1.0 95.88 perf-profile.children.cycles-pp.__vfs_write
94.84 +1.0 95.81 perf-profile.children.cycles-pp.btrfs_file_write_iter
94.55 +1.0 95.55 perf-profile.children.cycles-pp.__btrfs_buffered_write
86.68 +1.0 87.70 perf-profile.children.cycles-pp.native_queued_spin_lock_slowpath
44.08 +1.2 45.31 perf-profile.children.cycles-pp.btrfs_delalloc_reserve_metadata
43.49 +1.3 44.77 perf-profile.children.cycles-pp.reserve_metadata_bytes
87.59 +1.8 89.38 perf-profile.children.cycles-pp._raw_spin_lock
0.47 ± 19% -0.3 0.16 ± 13% perf-profile.self.cycles-pp.intel_idle
0.33 ± 6% -0.1 0.18 ± 6% perf-profile.self.cycles-pp.get_alloc_profile
0.27 ± 8% -0.0 0.22 ± 4% perf-profile.self.cycles-pp.btrfs_drop_pages
0.07 -0.0 0.03 ±100% perf-profile.self.cycles-pp.btrfs_set_lock_blocking_rw
0.14 ± 5% -0.0 0.12 ± 6% perf-profile.self.cycles-pp.clear_page_dirty_for_io
0.09 ± 5% -0.0 0.07 ± 10% perf-profile.self.cycles-pp._raw_spin_lock_irqsave
0.17 ± 4% +0.1 0.23 ± 3% perf-profile.self.cycles-pp.reserve_metadata_bytes
0.31 ± 7% +0.1 0.45 ± 2% perf-profile.self.cycles-pp.can_overcommit
86.35 +1.0 87.39 perf-profile.self.cycles-pp.native_queued_spin_lock_slowpath
aim7.jobs-per-min
29000 +-+-----------------------------------------------------------------+
28500 +-+ +.. + +..+.. +.. |
|..+ +.+..+.. : .. + .+.+..+..+.+.. .+..+.. + + + |
28000 +-+ + .. : + +. + + + |
27500 +-+ + + |
| |
27000 +-+ |
26500 +-+ |
26000 +-+ |
| |
25500 +-+ O O O O O |
25000 +-+ O O O O O O O O O
| O O O O O O O O |
24500 O-+O O O O |
24000 +-+-----------------------------------------------------------------+
[*] 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
3 years, 6 months
d50d82faa0 [ 33.671845] WARNING: possible circular locking dependency detected
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/torvalds/linux.git master
commit d50d82faa0c964e31f7a946ba8aba7c715ca7ab0
Author: Mikulas Patocka <mpatocka(a)redhat.com>
AuthorDate: Wed Jun 27 23:26:09 2018 -0700
Commit: Linus Torvalds <torvalds(a)linux-foundation.org>
CommitDate: Thu Jun 28 11:16:44 2018 -0700
slub: fix failure when we delete and create a slab cache
In kernel 4.17 I removed some code from dm-bufio that did slab cache
merging (commit 21bb13276768: "dm bufio: remove code that merges slab
caches") - both slab and slub support merging caches with identical
attributes, so dm-bufio now just calls kmem_cache_create and relies on
implicit merging.
This uncovered a bug in the slub subsystem - if we delete a cache and
immediatelly create another cache with the same attributes, it fails
because of duplicate filename in /sys/kernel/slab/. The slub subsystem
offloads freeing the cache to a workqueue - and if we create the new
cache before the workqueue runs, it complains because of duplicate
filename in sysfs.
This patch fixes the bug by moving the call of kobject_del from
sysfs_slab_remove_workfn to shutdown_cache. kobject_del must be called
while we hold slab_mutex - so that the sysfs entry is deleted before a
cache with the same attributes could be created.
Running device-mapper-test-suite with:
dmtest run --suite thin-provisioning -n /commit_failure_causes_fallback/
triggered:
Buffer I/O error on dev dm-0, logical block 1572848, async page read
device-mapper: thin: 253:1: metadata operation 'dm_pool_alloc_data_block' failed: error = -5
device-mapper: thin: 253:1: aborting current metadata transaction
sysfs: cannot create duplicate filename '/kernel/slab/:a-0000144'
CPU: 2 PID: 1037 Comm: kworker/u48:1 Not tainted 4.17.0.snitm+ #25
Hardware name: Supermicro SYS-1029P-WTR/X11DDW-L, BIOS 2.0a 12/06/2017
Workqueue: dm-thin do_worker [dm_thin_pool]
Call Trace:
dump_stack+0x5a/0x73
sysfs_warn_dup+0x58/0x70
sysfs_create_dir_ns+0x77/0x80
kobject_add_internal+0xba/0x2e0
kobject_init_and_add+0x70/0xb0
sysfs_slab_add+0xb1/0x250
__kmem_cache_create+0x116/0x150
create_cache+0xd9/0x1f0
kmem_cache_create_usercopy+0x1c1/0x250
kmem_cache_create+0x18/0x20
dm_bufio_client_create+0x1ae/0x410 [dm_bufio]
dm_block_manager_create+0x5e/0x90 [dm_persistent_data]
__create_persistent_data_objects+0x38/0x940 [dm_thin_pool]
dm_pool_abort_metadata+0x64/0x90 [dm_thin_pool]
metadata_operation_failed+0x59/0x100 [dm_thin_pool]
alloc_data_block.isra.53+0x86/0x180 [dm_thin_pool]
process_cell+0x2a3/0x550 [dm_thin_pool]
do_worker+0x28d/0x8f0 [dm_thin_pool]
process_one_work+0x171/0x370
worker_thread+0x49/0x3f0
kthread+0xf8/0x130
ret_from_fork+0x35/0x40
kobject_add_internal failed for :a-0000144 with -EEXIST, don't try to register things with the same name in the same directory.
kmem_cache_create(dm_bufio_buffer-16) failed with error -17
Link: http://lkml.kernel.org/r/alpine.LRH.2.02.1806151817130.6333@file01.intran...
Signed-off-by: Mikulas Patocka <mpatocka(a)redhat.com>
Reported-by: Mike Snitzer <snitzer(a)redhat.com>
Tested-by: Mike Snitzer <snitzer(a)redhat.com>
Cc: Christoph Lameter <cl(a)linux.com>
Cc: Pekka Enberg <penberg(a)kernel.org>
Cc: David Rientjes <rientjes(a)google.com>
Cc: Joonsoo Kim <iamjoonsoo.kim(a)lge.com>
Cc: <stable(a)vger.kernel.org>
Signed-off-by: Andrew Morton <akpm(a)linux-foundation.org>
Signed-off-by: Linus Torvalds <torvalds(a)linux-foundation.org>
28557cc106 Revert mm/vmstat.c: fix vmstat_update() preemption BUG
d50d82faa0 slub: fix failure when we delete and create a slab cache
84df9525b0 Linux 4.19
8c60c36d0b Add linux-next specific files for 20181019
+-------------------------------------------------------+------------+------------+-------+---------------+
| | 28557cc106 | d50d82faa0 | v4.19 | next-20181019 |
+-------------------------------------------------------+------------+------------+-------+---------------+
| boot_successes | 228 | 67 | 72 | 0 |
| boot_failures | 1 | 13 | 8 | 1 |
| BUG:kernel_hang_in_test_stage | 1 | | | |
| WARNING:possible_circular_locking_dependency_detected | 0 | 12 | 8 | 1 |
| INFO:rcu_preempt_detected_stalls_on_CPUs/tasks | 0 | 1 | | |
+-------------------------------------------------------+------------+------------+-------+---------------+
[ 29.227068] random: get_random_bytes called from key_alloc+0x2b0/0x44d with crng_init=1
[ 32.046253] random: get_random_bytes called from __ip_select_ident+0x45/0x93 with crng_init=1
[ 33.592007] random: get_random_bytes called from key_alloc+0x2b0/0x44d with crng_init=1
[ 33.670288]
[ 33.670642] ======================================================
[ 33.671845] WARNING: possible circular locking dependency detected
[ 33.673016] 4.18.0-rc2-00135-gd50d82f #1 Tainted: G T
[ 33.674215] ------------------------------------------------------
[ 33.675386] trinity-c3/689 is trying to acquire lock:
[ 33.676347] (____ptrval____) (slab_mutex){+.+.}, at: slab_attr_store+0x5a/0xd1
[ 33.677710]
[ 33.677710] but task is already holding lock:
[ 33.678812] (____ptrval____) (kn->count#32){++++}, at: kernfs_fop_write+0xf3/0x1b0
[ 33.680230]
[ 33.680230] which lock already depends on the new lock.
[ 33.680230]
[ 33.681766]
[ 33.681766] the existing dependency chain (in reverse order) is:
[ 33.683151]
[ 33.683151] -> #1 (kn->count#32){++++}:
[ 33.684170] kernfs_remove+0x1f/0x2c
[ 33.684968] sysfs_remove_dir+0x5b/0x62
[ 33.685797] kobject_del+0x20/0x4c
[ 33.686543] shutdown_cache+0x116/0x12c
[ 33.687364] kmem_cache_destroy+0x19c/0x1d1
[ 33.688277] ovs_flow_exit+0x11/0x1d
[ 33.689048] dp_init+0x2a5/0x2fc
[ 33.689766] do_one_initcall+0xc8/0x296
[ 33.690592] kernel_init_freeable+0x16c/0x2c4
[ 33.691534] kernel_init+0xb/0x13d
[ 33.692279] ret_from_fork+0x3a/0x50
[ 33.693046]
[ 33.693046] -> #0 (slab_mutex){+.+.}:
[ 33.694022] __mutex_lock+0x6e/0x257
[ 33.694826] slab_attr_store+0x5a/0xd1
[ 33.695634] sysfs_kf_write+0x58/0x73
[ 33.696430] kernfs_fop_write+0x149/0x1b0
[ 33.697288] __vfs_write+0x46/0x8d
[ 33.698056] vfs_write+0xd5/0x10a
[ 33.698786] ksys_pwrite64+0x77/0xa0
[ 33.699564] do_syscall_64+0x107/0x11c
[ 33.700373] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 33.701438]
[ 33.701438] other info that might help us debug this:
[ 33.701438]
[ 33.702922] Possible unsafe locking scenario:
[ 33.702922]
[ 33.704028] CPU0 CPU1
[ 33.704904] ---- ----
[ 33.705755] lock(kn->count#32);
[ 33.706393] lock(slab_mutex);
[ 33.707451] lock(kn->count#32);
[ 33.708566] lock(slab_mutex);
[ 33.709165]
[ 33.709165] *** DEADLOCK ***
[ 33.709165]
[ 33.710276] 3 locks held by trinity-c3/689:
[ 33.711072] #0: (____ptrval____) (sb_writers#5){.+.+}, at: file_start_write+0x3b/0x41
[ 33.712562] #1: (____ptrval____) (&of->mutex){+.+.}, at: kernfs_fop_write+0xeb/0x1b0
[ 33.714021] #2: (____ptrval____) (kn->count#32){++++}, at: kernfs_fop_write+0xf3/0x1b0
[ 33.715546]
[ 33.715546] stack backtrace:
[ 33.716371] CPU: 0 PID: 689 Comm: trinity-c3 Tainted: G T 4.18.0-rc2-00135-gd50d82f #1
[ 33.718083] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 33.719629] Call Trace:
[ 33.720111] print_circular_bug+0x1c6/0x1d3
[ 33.721043] __lock_acquire+0xbb0/0xe59
[ 33.721790] ? lock_acquire+0x53/0x6f
[ 33.722490] lock_acquire+0x53/0x6f
[ 33.723150] ? slab_attr_store+0x5a/0xd1
[ 33.723897] __mutex_lock+0x6e/0x257
[ 33.724604] ? slab_attr_store+0x5a/0xd1
[ 33.725350] ? slab_attr_store+0x5a/0xd1
[ 33.726089] ? lock_acquire+0x53/0x6f
[ 33.726785] ? lock_acquire+0x53/0x6f
[ 33.727480] ? kernfs_fop_write+0xeb/0x1b0
[ 33.728290] ? slab_attr_store+0x5a/0xd1
[ 33.729028] ? alloc_node_mismatch_store+0x16/0x1a
[ 33.729927] slab_attr_store+0x5a/0xd1
[ 33.730639] sysfs_kf_write+0x58/0x73
[ 33.731361] kernfs_fop_write+0x149/0x1b0
[ 33.732110] ? sysfs_file_ops+0x6c/0x6c
[ 33.732841] ? copy_overflow+0x22/0x22
[ 33.733555] __vfs_write+0x46/0x8d
[ 33.734216] vfs_write+0xd5/0x10a
[ 33.734862] ksys_pwrite64+0x77/0xa0
[ 33.735544] do_syscall_64+0x107/0x11c
[ 33.736260] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 33.737204] RIP: 0033:0x457389
[ 33.737797] Code: 00 f3 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 2b 84 00 00 c3 66 2e 0f 1f 84 00 00 00 00
[ 33.741375] RSP: 002b:00007ffe1c922d48 EFLAGS: 00000246 ORIG_RAX: 0000000000000012
[ 33.742776] RAX: ffffffffffffffda RBX: 0000000000000012 RCX: 0000000000457389
[ 33.744108] RDX: 00000000000001c1 RSI: 0000000001344710 RDI: 000000000000010a
[ 33.745463] RBP: 00007ffe1c922df0 R08: 00000000f4c64000 R09: bbed0ee996d421b9
[ 33.746783] R10: 0000000000000800 R11: 0000000000000246 R12: 0000000000000002
[ 33.748124] R13: 00007fcb40b97058 R14: 000000000104a830 R15: 00007fcb40b97000
[ 35.830419] raw_sendmsg: trinity-c3 forgot to set AF_INET. Fix it!
[ 54.240043] random: get_random_bytes called from __prandom_timer+0x15/0x5a with crng_init=1
[ 58.674359] random: get_random_bytes called from key_alloc+0x2b0/0x44d with crng_init=1
# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start v4.18 v4.17 --
git bisect good c81b995f00c7a1c2ca9ad67f5bb4a50d02f98f84 # 18:03 G 74 0 0 0 Merge branch 'perf-urgent-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad 47f7dc4b845a9fe60c53b84b8c88cf14efd0de7f # 18:13 B 18 3 0 0 Merge tag 'for-linus' of git://git.kernel.org/pub/scm/virt/kvm/kvm
git bisect bad 0fa3ecd87848c9c93c2c828ef4c3a8ca36ce46c7 # 18:35 B 7 1 0 0 Fix up non-directory creation in SGID directories
git bisect bad 1904148a361a07fb2d7cba1261d1d2c2f33c8d2e # 18:52 B 6 1 0 0 Merge tag 'powerpc-4.18-3' of git://git.kernel.org/pub/scm/linux/kernel/git/powerpc/linux
git bisect good a11e1d432b51f63ba698d044441284a661f01144 # 19:19 G 73 0 2 2 Revert changes to convert to ->poll_mask() and aio IOCB_CMD_POLL
git bisect bad ff23908bb78bbc0999ff35e6f319f1648c4ded93 # 19:31 B 0 1 15 0 Merge tag 'for-4.18/dm-fixes' of git://git.kernel.org/pub/scm/linux/kernel/git/device-mapper/linux-dm
git bisect bad e26aac3caeadc476b96a1f384715e96b4a607342 # 19:40 B 2 1 0 0 Merge tag 'sound-4.18-rc3' of git://git.kernel.org/pub/scm/linux/kernel/git/tiwai/sound
git bisect bad ea5f39f2f994e6fb8cb8d0304aa5f422ae3bbf83 # 19:49 B 0 1 15 0 Merge branch 'akpm' (patches from Andrew)
git bisect bad 124049decbb121ec32742c94fb5d9d6bed8f24d8 # 20:03 B 6 1 0 0 x86/e820: put !E820_TYPE_RAM regions into memblock.reserved
git bisect good 28557cc106e6d2aa8b8c5c7687ea9f8055ff3911 # 20:33 G 74 0 1 1 Revert mm/vmstat.c: fix vmstat_update() preemption BUG
git bisect bad d50d82faa0c964e31f7a946ba8aba7c715ca7ab0 # 20:53 B 18 1 0 0 slub: fix failure when we delete and create a slab cache
# first bad commit: [d50d82faa0c964e31f7a946ba8aba7c715ca7ab0] slub: fix failure when we delete and create a slab cache
git bisect good 28557cc106e6d2aa8b8c5c7687ea9f8055ff3911 # 21:23 G 219 0 0 1 Revert mm/vmstat.c: fix vmstat_update() preemption BUG
# extra tests with debug options
git bisect bad d50d82faa0c964e31f7a946ba8aba7c715ca7ab0 # 21:43 B 6 1 0 0 slub: fix failure when we delete and create a slab cache
# extra tests on HEAD of linux-devel/devel-catchup-201810172056
git bisect bad f64798c97c207879a5b2b2cc901f4903cb2663fd # 21:43 B 21 2 0 0 0day head guard for 'devel-catchup-201810172056'
# extra tests on tree/branch linus/master
git bisect bad 84df9525b0c27f3ebc2ebb1864fa62a97fdedb7d # 21:52 B 2 1 0 0 Linux 4.19
# extra tests with first bad commit reverted
git bisect good 55027183adca08c0fc99c4d7bd3733af80f11b75 # 22:25 G 80 0 0 0 Revert "slub: fix failure when we delete and create a slab cache"
# extra tests on tree/branch linux-next/master
git bisect bad 8c60c36d0b8c92599b8f0ec391b5250bc40e8e05 # 22:33 B 0 1 15 0 Add linux-next specific files for 20181019
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
3 years, 7 months
0babe16c6c ("mtd: rawnand: Fill memorg during detection"): divide error: 0000 [#1] DEBUG_PAGEALLOC PTI
by kernel test robot
Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
https://github.com/bbrezillon/linux-0day nand/cleanup
commit 0babe16c6c4b5563ea0f6377363c220d4b3aa177
Author: Boris Brezillon <boris.brezillon(a)bootlin.com>
AuthorDate: Thu Oct 25 17:10:37 2018 +0200
Commit: Boris Brezillon <boris.brezillon(a)bootlin.com>
CommitDate: Tue Oct 30 09:26:53 2018 +0100
mtd: rawnand: Fill memorg during detection
If we want to use the generic NAND layer, we need to have the memorg
struct appropriately filled. Patch the detection code to fill this
struct.
Signed-off-by: Boris Brezillon <boris.brezillon(a)bootlin.com>
8080d39ecf mtd: rawnand: Prepare things to reuse the generic NAND layer
0babe16c6c mtd: rawnand: Fill memorg during detection
af58f3a427 mtd: rawnand: Get rid of chip->phys_erase_shift
+------------------------------------------+------------+------------+------------+
| | 8080d39ecf | 0babe16c6c | af58f3a427 |
+------------------------------------------+------------+------------+------------+
| boot_successes | 1 | 0 | 0 |
| boot_failures | 12 | 11 | 11 |
| Mem-Info | 12 | | |
| divide_error:#[##] | 0 | 11 | 11 |
| EIP:nand_detect | 0 | 11 | 11 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 11 | 11 |
+------------------------------------------+------------+------------+------------+
[ 10.547860] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 10.548983] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 10.550148] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 10.551462] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 10.552632] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 10.553865] divide error: 0000 [#1] DEBUG_PAGEALLOC PTI
[ 10.554517] CPU: 0 PID: 1 Comm: swapper Tainted: G S 4.19.0-rc2-00111-g0babe16 #1
[ 10.554775] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 10.554775] EIP: nand_detect+0x2ce/0x598
[ 10.554775] Code: d2 31 db 0f af 86 98 03 00 00 89 c1 8b 47 10 0f a4 c2 14 c1 e0 14 85 d2 89 44 24 10 74 08 89 d0 31 d2 f7 f1 89 c3 8b 44 24 10 <f7> f1 89 da 31 db 89 86 9c 03 00 00 89 da 8b 4f 10 89 c8 0f a4 ca
[ 10.554775] EAX: 08000000 EBX: 00000000 ECX: 00000000 EDX: 00000000
[ 10.554775] ESI: cb533000 EDI: c28ab030 EBP: c20e7ae8 ESP: cf06bedc
[ 10.554775] DS: 007b ES: 007b FS: 0000 GS: 00e0 SS: 0068 EFLAGS: 00210246
[ 10.554775] CR0: 80050033 CR2: 00000000 CR3: 02a90000 CR4: 00140690
[ 10.554775] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 10.554775] DR6: fffe0ff0 DR7: 00000400
[ 10.554775] Call Trace:
[ 10.554775] ? debug_mutex_init+0x24/0x2d
[ 10.554775] ? nand_scan_with_ids+0x243/0x395
[ 10.554775] ? ns_init_module+0x3a/0x675
[ 10.554775] ? init_nandsim+0x5bc/0x5bc
[ 10.554775] ? ns_init_module+0x3f5/0x675
[ 10.554775] ? init_nandsim+0x5bc/0x5bc
[ 10.554775] ? do_one_initcall+0x66/0x138
[ 10.554775] ? kernel_init_freeable+0xc1/0x15d
[ 10.554775] ? kernel_init_freeable+0xe3/0x15d
[ 10.554775] ? rest_init+0xf6/0xf6
[ 10.554775] ? kernel_init+0x5/0xd1
[ 10.554775] ? ret_from_fork+0x19/0x24
[ 10.569737] ---[ end trace 71d9b0e89fb7d89a ]---
[ 10.570301] EIP: nand_detect+0x2ce/0x598
# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start b7ca9507a4033cc34488ae87865ca15c423c24bd 84df9525b0c27f3ebc2ebb1864fa62a97fdedb7d --
git bisect bad 11e1a653217395cef14d229be450c8d72bfe182a # 07:37 B 0 11 27 2 Merge 'linux-review/fdmanana-kernel-org/Btrfs-fix-deadlock-on-tree-root-leaf-when-finding-free-extent/20181022-173150' into devel-hourly-2018103103
git bisect bad 5947dbb2444a42ca8527d7c63347ff98230a01dd # 07:46 B 0 1 15 0 Merge 'linux-review/Colin-King/um-trap-fix-spelling-mistake-EACCESS-EACCES/20181027-035232' into devel-hourly-2018103103
git bisect good dae5cd9f8a8d13b3050c7912f2a83adec2fe1c4d # 08:03 G 10 0 9 9 Merge 'cgroup/for-4.20' into devel-hourly-2018103103
git bisect bad 9e9fe8f469e83baf545aefeffd9bd6f919fe82c2 # 08:19 B 0 3 17 0 Merge 'linux-review/Balakrishna-Godavarthi/Bluetooth-hci_qca-Add-helper-to-set-device-address/20181027-011103' into devel-hourly-2018103103
git bisect good 59e26eb4a17648c8f9d8b71b982022ecb42b687e # 08:38 G 10 0 10 11 Merge 'superna9999/amlogic/v4.20/drm-primary-scaling' into devel-hourly-2018103103
git bisect bad edcffdfcc2d3050d6100c35d103b0778f4627b7e # 08:47 B 0 2 16 0 Merge 'abelloni/rtc-next' into devel-hourly-2018103103
git bisect bad 9aaebfc0cad27474786795d35302f0cd2bfc4daa # 09:07 B 0 10 24 0 Merge 'bbrezillon-0day/nand/cleanup' into devel-hourly-2018103103
git bisect good b3087eb48bbebe893eb704e2c9660b04a9895020 # 09:22 G 11 0 9 9 Merge 'balbi-usb/testing/fixes' into devel-hourly-2018103103
git bisect good 8ae3fbf81b9cfdd1fec0451181213742b73fdf1a # 09:41 G 10 0 5 5 mtd: rawnand: Move JEDEC code to nand_jedec.c
git bisect good d31d9288d308f34ddf3130aa1f8183e519d9dbd1 # 09:53 G 11 0 10 10 mtd: rawnand: Move ->setup_data_interface() to nand_controller_ops
git bisect good 13cde0ee288b9ae6aee02aeb2c223c862bbf9f1d # 10:12 G 11 0 8 8 mtd: rawnand: Use nand_to_mtd() in nand_{set,get}_flash_node()
git bisect bad 4137c89a88f3966b26ffddd3dd0209f210879a7e # 10:25 B 0 11 25 0 mtd: rawnand: Provide an helper to get chip->data_buf
git bisect bad 894db31915925ff2a848cb3e46689d4718807501 # 10:38 B 0 11 25 0 mtd: nand: Add an helper returning the number of eraseblocks per target
git bisect bad 0babe16c6c4b5563ea0f6377363c220d4b3aa177 # 10:55 B 0 11 25 0 mtd: rawnand: Fill memorg during detection
git bisect good 8080d39ecf366730f46b1c6754966638fdd50993 # 11:17 G 11 0 11 11 mtd: rawnand: Prepare things to reuse the generic NAND layer
# first bad commit: [0babe16c6c4b5563ea0f6377363c220d4b3aa177] mtd: rawnand: Fill memorg during detection
git bisect good 8080d39ecf366730f46b1c6754966638fdd50993 # 11:20 G 31 0 30 41 mtd: rawnand: Prepare things to reuse the generic NAND layer
# extra tests with debug options
git bisect bad 0babe16c6c4b5563ea0f6377363c220d4b3aa177 # 11:31 B 0 4 18 0 mtd: rawnand: Fill memorg during detection
# extra tests on HEAD of linux-devel/devel-hourly-2018103103
git bisect bad b7ca9507a4033cc34488ae87865ca15c423c24bd # 11:36 B 0 15 32 0 0day head guard for 'devel-hourly-2018103103'
# extra tests on tree/branch bbrezillon-0day/nand/cleanup
git bisect bad af58f3a427692cec6540c808326f7377669cebe8 # 11:47 B 0 3 17 0 mtd: rawnand: Get rid of chip->phys_erase_shift
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
3 years, 8 months
[mm] 68c37ccedc: BUG:kernel_hang_in_early-boot_stage, last_printk:early_console_in_setup_code
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: 68c37ccedcde10514898f4ba3b28c0de85c590d1 ("mm: nobootmem: remove bootmem allocation APIs")
https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu host -smp 2 -m 2G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-----------------------------------------------------------------------------+------------+------------+
| | 6881a1e729 | 68c37ccedc |
+-----------------------------------------------------------------------------+------------+------------+
| boot_successes | 4 | 0 |
| boot_failures | 0 | 4 |
| BUG:kernel_hang_in_early-boot_stage,last_printk:early_console_in_setup_code | 0 | 4 |
+-----------------------------------------------------------------------------+------------+------------+
early console in setup code
BUG: kernel hang in early-boot stage, last printk: early console in setup code
Linux version 4.19.0-rc8-12429-g68c37cc #2
Command line: ip=::::vm-vp-2G-10::dhcp root=/dev/ram0 user=lkp job=/lkp/jobs/scheduled/vm-vp-2G-10/boot-1-debian-x86_64-2018-04-03.cgz-68c37ccedcde10514898f4ba3b28c0de85c590d1-20181029-86192-158289k-3.yaml ARCH=x86_64 kconfig=x86_64-randconfig-a0-10272028 branch=linux-devel/devel-catchup-201810280034 commit=68c37ccedcde10514898f4ba3b28c0de85c590d1 BOOT_IMAGE=/pkg/linux/x86_64-randconfig-a0-10272028/gcc-7/68c37ccedcde10514898f4ba3b28c0de85c590d1/vmlinuz-4.19.0-rc8-12429-g68c37cc max_uptime=600 RESULT_ROOT=/result/boot/1/vm-vp-2G/debian-x86_64-2018-04-03.cgz/x86_64-randconfig-a0-10272028/gcc-7/68c37ccedcde10514898f4ba3b28c0de85c590d1/3 LKP_SERVER=inn debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 net.ifnames=0 printk.devkmsg=on panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 drbd.minor_count=8 systemd.log_level=err ignore_loglevel console=tty0 earlyprintk=ttyS0,115200 console=ttyS0,115200 vga=normal rw rcuperf.shutdown=0
Elapsed time: 670
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
lkp
3 years, 8 months
[mm] ca7277e7ae: pigz.throughput 1.2% improvement
by kernel test robot
Greeting,
FYI, we noticed a 1.2% improvement of pigz.throughput due to commit:
commit: ca7277e7aea43bbfb96a378bac115f6d51c4e1a0 ("mm: do not add anon pages to LRU")
git://bee.sh.intel.com/git/aaron/linux.git zone_range_lock
in testcase: reaim
on test machine: 256 threads Phi with 96G memory
with following parameters:
runtime: 300s
nr_task: 100%
test: aim9
cpufreq_governor: performance
test-description: REAIM is an updated and improved version of AIM 7 benchmark.
test-url: https://sourceforge.net/projects/re-aim-7/
Details are as below:
-------------------------------------------------------------------------------------------------->
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
=========================================================================================
blocksize/compiler/cpufreq_governor/kconfig/nr_threads/rootfs/tbox_group/testcase/ucode:
512K/gcc-7/performance/x86_64-rhel-7.2/25%/debian-x86_64-2018-04-03.cgz/lkp-ivb-d03/pigz/0x20
commit:
v4.19
ca7277e7ae ("mm: do not add anon pages to LRU")
v4.19 ca7277e7aea43bbfb96a378bac
---------------- --------------------------
fail:runs %reproduction fail:runs
| | |
0:10 1% 0:4 perf-profile.children.cycles-pp.schedule_timeout
%stddev %change %stddev
\ | \
19488588 +1.2% 19718296 pigz.throughput
5706 ± 2% +15.7% 6600 pigz.time.minor_page_faults
15157 +1.2% 15336 pigz.time.voluntary_context_switches
1011862 ± 27% +52.3% 1541212 ± 38% cpuidle.C1E.usage
8.85 ± 28% +4.0 12.88 ± 20% perf-stat.cache-miss-rate%
1011860 ± 27% +52.3% 1541211 ± 38% turbostat.C1E
7.60 ±197% +214.4% 23.91 ± 99% turbostat.CPU%c6
489.11 ± 5% -100.0% 0.00 uptime.boot
1602 ± 6% -100.0% 0.00 uptime.idle
246712 -94.7% 13016 ± 7% meminfo.Active
246708 -94.7% 13012 ± 7% meminfo.Active(anon)
181716 -99.7% 512.00 ±173% meminfo.AnonHugePages
0.01 ±300% +0.1 0.15 ± 28% perf-profile.children.cycles-pp.update_curr
0.08 ±117% +0.2 0.28 ± 71% perf-profile.children.cycles-pp._dl_addr
0.01 ±300% +0.1 0.15 ± 28% perf-profile.self.cycles-pp.update_curr
0.07 ±108% +0.2 0.28 ± 71% perf-profile.self.cycles-pp._dl_addr
61731 -94.7% 3273 ± 7% proc-vmstat.nr_active_anon
60876 -1.5% 59968 proc-vmstat.nr_anon_pages
985.20 -2.4% 961.75 proc-vmstat.nr_page_table_pages
61735 -94.7% 3290 ± 7% proc-vmstat.nr_zone_active_anon
2367750 +1.6% 2405509 proc-vmstat.numa_hit
2367750 +1.6% 2405509 proc-vmstat.numa_local
46131 ± 7% -100.0% 0.00 proc-vmstat.pgalloc_dma32
reaim.time.involuntary_context_switches
270000 +-+----------------------------------------------------------------+
| O |
265000 O-+ O |
| O O O |
260000 +-+ O O |
| O |
255000 +-+ |
| O O O O O O |
250000 +-+ O O O O O |
| O O O O O
245000 +-+ |
| .+.. |
240000 +-+ .+..+..+. |
|..+..+. .+.. .+..+ +.+..+.. .+. .+..+..+.. .+.. |
235000 +-+----------------------------------------------------------------+
reaim.time.user_time
11750 +-+-----------------------------------------------------------------+
| O O O O O O |
11700 +-+O O O O O O O O O O O O O O
O O O O O |
11650 +-+ |
| |
11600 +-+ |
| |
11550 +-+ .+..+.. |
|.. .+. +..+. .+.. .+..+.. .+ |
11500 +-++.. +.+. +..+. +.. +.+. +.. +.+. |
| .. .. .. |
11450 +-+ + + + |
| |
11400 +-+-----------------------------------------------------------------+
reaim.time.system_time
10200 +-+-----------------------------------------------------------------+
| |
10000 +-++..+..+.+..+..+..+..+..+. .+..+..+..+..+.+..+..+..+..+..+.+..+ |
9800 +-+ +. |
| |
9600 +-+ |
| |
9400 +-+ |
| |
9200 +-+ |
9000 +-+ |
| |
8800 +-+ O O O O O O O O |
| O O O O O O O O O O O O O O O
8600 O-+--------O--------------------------------------------------------+
reaim.time.percent_of_cpu_this_job_got
7000 +-+------------------------------------------------------------------+
|..+..+..+..+.+..+..+..+..+..+.. .+.+..+..+..+..+..+..+..+.+..+..+ |
| +. |
6950 +-+ |
| |
| |
6900 +-+ |
| |
6850 +-+ |
| |
| |
6800 +-+ O O O O |
| O O O O O O O O O O O
| O O O O O O O |
6750 O-+-----------------------O--------O---------------------------------+
reaim.time.elapsed_time
308 +-+-------------------------------------------------------------------+
|..+..+..+. +. +. +..+..+..+. +..+.+..+..+. + |
307 +-+ |
306 +-+ |
| |
305 +-+ |
| |
304 +-+ |
| |
303 +-+ |
302 +-+ O O O O O |
| O O O O O O O O O
301 O-+O O O O O O O O O O |
| |
300 +-+-------------------------------------------------------------------+
reaim.time.elapsed_time.max
308 +-+-------------------------------------------------------------------+
|..+..+..+. +. +. +..+..+..+. +..+.+..+..+. + |
307 +-+ |
306 +-+ |
| |
305 +-+ |
| |
304 +-+ |
| |
303 +-+ |
302 +-+ O O O O O |
| O O O O O O O O O
301 O-+O O O O O O O O O O |
| |
300 +-+-------------------------------------------------------------------+
reaim.time.voluntary_context_switches
2.86e+06 +-+--------------------------------------------------------------+
| |
2.85e+06 +-+ .+.+..+..+.+..+..+..+. .+..+. .+ |
2.84e+06 +-++.+..+..+. +..+..+.+. +..+..+..+ |
| |
2.83e+06 +-+ |
| |
2.82e+06 +-+ |
| |
2.81e+06 +-+ |
2.8e+06 +-+ O O O O O O O
| O O O O O O O O O O |
2.79e+06 +-+ O O O O |
O O O O |
2.78e+06 +-+--------------------------------------------------------------+
reaim.parent_time
15.95 +-+-----------------------------------------------------------------+
15.9 +-+ .+.. .+..+..+..+. .+.. .+.. .+.. |
|..+..+..+ +. +. +..+..+..+ +..+..+..+..+ + |
15.85 +-+ |
15.8 +-+ |
| |
15.75 +-+ |
15.7 +-+ |
15.65 +-+ |
| |
15.6 +-+ O |
15.55 +-+ O O O O O O O O O O O O
O O O O O O O O O |
15.5 +-+ O O O |
15.45 +-+-----------------------------------------------------------------+
reaim.child_systime
590 +-+-------------------------------------------------------------------+
|..+. +..+..+..+.+..+..+..+..+..+..+. +..+..+..+.+. +..+..+ |
580 +-+ |
570 +-+ |
| |
560 +-+ |
550 +-+ |
| |
540 +-+ |
530 +-+ |
| |
520 +-+ O O O O O O |
510 +-+O O O O O O O O O O O O
O O O O O O O |
500 +-+-------------------------------------------------------------------+
reaim.child_utime
690 +-+-------------------------------------------------------------------+
| O O O O O O O O O |
688 +-+O O O O O O O O O O O O
686 O-+ O O O |
| |
684 +-+ |
682 +-+ |
| |
680 +-+ |
678 +-+ .+.+.. |
|.. .+. +..+.. .+.. .+..+. .+ |
676 +-++ +..+. +..+. + +..+. + +..+. |
674 +-+ + + + + + + |
| + + + + + + |
672 +-+-------------------------------------------------------------------+
reaim.jobs_per_min
119000 +-+--------O--------O-O--------------------------------------------+
O O O O O O O O O |
118500 +-+ O O O O O O O O O O
| O O O |
118000 +-+ |
| |
117500 +-+ |
| |
117000 +-+ |
| |
116500 +-+ |
| +.. |
116000 +-++..+.+..+..+.. .+. .. .+.+..+..+..+.+..+..+..+..+.+..+ |
| +. +..+ +. |
115500 +-+----------------------------------------------------------------+
reaim.jobs_per_min_child
466 +-+-------------------------------------------------------------------+
| O O |
464 O-+O O O O O O O O |
| O O O O O O O O O O O
462 +-+ O O O |
| |
460 +-+ |
| |
458 +-+ |
| |
456 +-+ |
| |
454 +-+ .+..+.. +.. .+..+.. .+..+.. |
|..+. +..+..+.+..+.. .. .+..+. +..+..+.+. +..+ |
452 +-+-------------------------------------------------------------------+
reaim.std_dev_time
0.7 +-+------------------------------------------------------------------+
| |
0.68 +-++..+.. .+.+..+..+..+..+..+..+..+.+..+.. .+..+..+..+..+. .+..+ |
0.66 +-+ +. +. +. |
| |
0.64 +-+ |
0.62 +-+ |
| |
0.6 +-+ |
0.58 +-+ |
| |
0.56 +-+ |
0.54 +-+ 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.52 +-+------------------------------------------------------------------+
reaim.std_dev_percent
4.6 +-+-------------------------------------------------------------------+
4.5 +-++.. .+..+.. .+..+..+.. .+..+..+.. .+..+..+.+.. .+..+ |
| +..+. + +. +..+. +..+. |
4.4 +-+ |
4.3 +-+ |
| |
4.2 +-+ |
4.1 +-+ |
4 +-+ |
| |
3.9 +-+ |
3.8 +-+ |
| O O O O |
3.7 +-+ O O O O O O O O O O O O O O O
3.6 O-+O--O--O--O----------------------------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,
Rong Chen
3 years, 8 months
[cfg80211] d3e95c31e6: hwsim.wnm_bss_tm_nei_11a.fail
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: d3e95c31e68e09731b3ac5dec3b8835211bb2072 ("[PATCH] cfg80211: Prevent regulatory restore during STA disconnect in concurrent interfaces")
url: https://github.com/0day-ci/linux/commits/Sriram-R/cfg80211-Prevent-regula...
base: https://git.kernel.org/cgit/linux/kernel/git/jberg/mac80211-next.git master
in testcase: hwsim
with following parameters:
group: hwsim-12
on test machine: qemu-system-x86_64 -enable-kvm -cpu host -smp 2 -m 4G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
2018-10-28 12:00:43 export USER=root
2018-10-28 12:00:43 ./build.sh
Building TNC testing tools
Building wlantest
Building hostapd
Building wpa_supplicant
2018-10-28 12:02:49 ./start.sh
ignored_by_lkp sigma_dut_ap_cipher_ccmp_gcmp_2
ignored_by_lkp sigma_dut_ap_cipher_gcmp_128
ignored_by_lkp sigma_dut_ap_cipher_gcmp_256
ignored_by_lkp sigma_dut_ap_cipher_gcmp_256_group_ccmp
ignored_by_lkp sigma_dut_ap_dpp_pkex_responder
ignored_by_lkp sigma_dut_ap_dpp_qr
ignored_by_lkp sigma_dut_ap_dpp_qr_legacy
ignored_by_lkp sigma_dut_ap_dpp_qr_legacy_psk
ignored_by_lkp sigma_dut_ap_dpp_self_config
ignored_by_lkp sigma_dut_ap_eap
ignored_by_lkp sigma_dut_ap_eap_osen
ignored_by_lkp sigma_dut_ap_eap_sha256
ignored_by_lkp sigma_dut_ap_ent_ft_eap
ignored_by_lkp sigma_dut_ap_ft_eap
ignored_by_lkp sigma_dut_ap_ft_psk
ignored_by_lkp sigma_dut_ap_osen
ignored_by_lkp sigma_dut_ap_override_rsne
ignored_by_lkp sigma_dut_ap_owe
ignored_by_lkp sigma_dut_ap_owe_ecgroupid
ignored_by_lkp sigma_dut_ap_owe_transition_mode
ignored_by_lkp sigma_dut_ap_owe_transition_mode_2
ignored_by_lkp sigma_dut_ap_psk
ignored_by_lkp sigma_dut_ap_psk_sae
ignored_by_lkp sigma_dut_ap_psk_sha256
ignored_by_lkp sigma_dut_ap_pskhex
ignored_by_lkp sigma_dut_ap_sae
ignored_by_lkp sigma_dut_ap_sae_group
ignored_by_lkp sigma_dut_ap_sae_password
ignored_by_lkp sigma_dut_ap_suite_b
ignored_by_lkp sigma_dut_basic
ignored_by_lkp sigma_dut_dpp_incompatible_roles_init
ignored_by_lkp sigma_dut_dpp_incompatible_roles_resp
ignored_by_lkp sigma_dut_dpp_pkex_init_configurator
ignored_by_lkp sigma_dut_dpp_pkex_responder_proto
ignored_by_lkp sigma_dut_dpp_proto_initiator
ignored_by_lkp sigma_dut_dpp_proto_initiator_pkex
ignored_by_lkp sigma_dut_dpp_proto_peer_disc_req
ignored_by_lkp sigma_dut_dpp_proto_responder
ignored_by_lkp sigma_dut_dpp_proto_responder_pkex
ignored_by_lkp sigma_dut_dpp_proto_stop_at_initiator
ignored_by_lkp sigma_dut_dpp_proto_stop_at_initiator_enrollee
ignored_by_lkp sigma_dut_dpp_proto_stop_at_responder
ignored_by_lkp sigma_dut_dpp_qr_init_configurator_1
ignored_by_lkp sigma_dut_dpp_qr_init_configurator_2
ignored_by_lkp sigma_dut_dpp_qr_init_configurator_3
ignored_by_lkp sigma_dut_dpp_qr_init_configurator_4
ignored_by_lkp sigma_dut_dpp_qr_init_configurator_5
ignored_by_lkp sigma_dut_dpp_qr_init_configurator_6
ignored_by_lkp sigma_dut_dpp_qr_init_configurator_7
ignored_by_lkp sigma_dut_dpp_qr_init_configurator_both
ignored_by_lkp sigma_dut_dpp_qr_init_configurator_neg_freq
ignored_by_lkp sigma_dut_dpp_qr_init_enrollee
ignored_by_lkp sigma_dut_dpp_qr_init_enrollee_psk
ignored_by_lkp sigma_dut_dpp_qr_init_enrollee_sae
ignored_by_lkp sigma_dut_dpp_qr_mutual_init_enrollee
ignored_by_lkp sigma_dut_dpp_qr_mutual_init_enrollee_check
ignored_by_lkp sigma_dut_dpp_qr_mutual_init_enrollee_pending
ignored_by_lkp sigma_dut_dpp_qr_mutual_resp_enrollee
ignored_by_lkp sigma_dut_dpp_qr_mutual_resp_enrollee_pending
ignored_by_lkp sigma_dut_dpp_qr_resp_1
ignored_by_lkp sigma_dut_dpp_qr_resp_2
ignored_by_lkp sigma_dut_dpp_qr_resp_3
ignored_by_lkp sigma_dut_dpp_qr_resp_4
ignored_by_lkp sigma_dut_dpp_qr_resp_5
ignored_by_lkp sigma_dut_dpp_qr_resp_6
ignored_by_lkp sigma_dut_dpp_qr_resp_7
ignored_by_lkp sigma_dut_dpp_qr_resp_chan_list
ignored_by_lkp sigma_dut_dpp_self_config
ignored_by_lkp sigma_dut_hs20_assoc_24
ignored_by_lkp sigma_dut_hs20_assoc_5
ignored_by_lkp sigma_dut_open
ignored_by_lkp sigma_dut_owe
ignored_by_lkp sigma_dut_preconfigured_profile
ignored_by_lkp sigma_dut_psk_pmf
ignored_by_lkp sigma_dut_psk_pmf_bip_cmac_128
ignored_by_lkp sigma_dut_psk_pmf_bip_cmac_256
ignored_by_lkp sigma_dut_psk_pmf_bip_gmac_128
ignored_by_lkp sigma_dut_psk_pmf_bip_gmac_256
ignored_by_lkp sigma_dut_psk_pmf_bip_gmac_256_mismatch
ignored_by_lkp sigma_dut_sae
ignored_by_lkp sigma_dut_sae_password
ignored_by_lkp sigma_dut_sta_override_rsne
ignored_by_lkp sigma_dut_sta_scan_bss
ignored_by_lkp sigma_dut_suite_b
ignored_by_lkp sigma_dut_suite_b_rsa
ignored_by_lkp sigma_dut_venue_url
ignored_by_lkp sigma_dut_wps_pbc
2018-10-28 12:02:50 ./run-tests.py ssid_1_octet
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START ssid_1_octet 1/1
Test: SSID with one octet
Starting AP wlan3
Connect STA wlan0 to AP
PASS ssid_1_octet 0.469068 2018-10-28 12:02:52.353460
passed all 1 test case(s)
2018-10-28 12:02:52 ./run-tests.py ssid_32_octets
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START ssid_32_octets 1/1
Test: SSID with 32 octets
Starting AP wlan3
Connect STA wlan0 to AP
PASS ssid_32_octets 0.416617 2018-10-28 12:02:53.187065
passed all 1 test case(s)
2018-10-28 12:02:53 ./run-tests.py ssid_hex_encoded
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START ssid_hex_encoded 1/1
Test: SSID configuration using hex encoded version
Starting AP wlan3
Connect STA wlan0 to AP
Connect STA wlan1 to AP
PASS ssid_hex_encoded 0.576768 2018-10-28 12:02:54.111255
passed all 1 test case(s)
2018-10-28 12:02:54 ./run-tests.py ssid_hidden
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START ssid_hidden 1/1
Test: Hidden SSID
Starting AP wlan3
Connect STA wlan1 to AP
Connect STA wlan0 to AP
PASS ssid_hidden 1.619968 2018-10-28 12:02:56.141386
passed all 1 test case(s)
2018-10-28 12:02:56 ./run-tests.py ssid_hidden2
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START ssid_hidden2 1/1
Test: Hidden SSID using zero octets as payload
Starting AP wlan3
Connect STA wlan1 to AP
Connect STA wlan0 to AP
PASS ssid_hidden2 1.648897 2018-10-28 12:02:58.194421
passed all 1 test case(s)
2018-10-28 12:02:58 ./run-tests.py ssid_hidden_wpa2
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START ssid_hidden_wpa2 1/1
Test: Hidden SSID with WPA2-PSK
Starting AP wlan3
Connect STA wlan1 to AP
Connect STA wlan0 to AP
PASS ssid_hidden_wpa2 1.69057 2018-10-28 12:03:00.312712
passed all 1 test case(s)
2018-10-28 12:03:00 ./run-tests.py ssid_printf_encoded
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START ssid_printf_encoded 1/1
Test: SSID configuration using printf encoded version
Starting AP wlan3
Connect STA wlan0 to AP
Connect STA wlan1 to AP
Connect STA wlan2 to AP
PASS ssid_printf_encoded 0.930009 2018-10-28 12:03:01.714338
passed all 1 test case(s)
2018-10-28 12:03:01 ./run-tests.py ssid_utf8
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START ssid_utf8 1/1
Test: SSID with UTF8 encoding
Starting AP wlan3
Connect STA wlan0 to AP
Connect STA wlan1 to AP
PASS ssid_utf8 0.750463 2018-10-28 12:03:02.908392
passed all 1 test case(s)
2018-10-28 12:03:02 ./run-tests.py sta_ap_scan_0
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START sta_ap_scan_0 1/1
Test: Dynamically added wpa_supplicant interface with AP_SCAN 0 connection
Starting AP wlan3
Create a dynamic wpa_supplicant interface and connect
Connect STA wlan5 to AP
PASS sta_ap_scan_0 1.142476 2018-10-28 12:03:04.468008
passed all 1 test case(s)
2018-10-28 12:03:04 ./run-tests.py sta_ap_scan_2
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START sta_ap_scan_2 1/1
Test: Dynamically added wpa_supplicant interface with AP_SCAN 2 connection
Starting AP wlan3
Create a dynamic wpa_supplicant interface and connect
Connect STA wlan5 to AP
PASS sta_ap_scan_2 2.559885 2018-10-28 12:03:07.477257
passed all 1 test case(s)
2018-10-28 12:03:07 ./run-tests.py sta_ap_scan_2b
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START sta_ap_scan_2b 1/1
Test: Dynamically added wpa_supplicant interface with AP_SCAN 2 operation
Starting AP wlan3
Create a dynamic wpa_supplicant interface and connect
Connect STA wlan5 to AP
PASS sta_ap_scan_2b 13.738109 2018-10-28 12:03:21.630069
passed all 1 test case(s)
2018-10-28 12:03:21 ./run-tests.py sta_dynamic
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START sta_dynamic 1/1
Test: Dynamically added wpa_supplicant interface
Starting AP wlan3
Create a dynamic wpa_supplicant interface and connect
Connect STA wlan5 to AP
PASS sta_dynamic 0.721891 2018-10-28 12:03:22.758197
passed all 1 test case(s)
2018-10-28 12:03:22 ./run-tests.py sta_dynamic_down_up
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START sta_dynamic_down_up 1/1
Test: Dynamically added wpa_supplicant interface down/up
Starting AP wlan3
Create a dynamic wpa_supplicant interface and connect
Connect STA wlan5 to AP
PASS sta_dynamic_down_up 1.15274 2018-10-28 12:03:24.319761
passed all 1 test case(s)
2018-10-28 12:03:24 ./run-tests.py sta_dynamic_ext_mac_addr_change
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START sta_dynamic_ext_mac_addr_change 1/1
Test: Dynamically added wpa_supplicant interface with external MAC address change
Starting AP wlan3
Create a dynamic wpa_supplicant interface and connect
Connect STA wlan5 to AP
PASS sta_dynamic_ext_mac_addr_change 1.251325 2018-10-28 12:03:26.046355
passed all 1 test case(s)
2018-10-28 12:03:26 ./run-tests.py sta_dynamic_random_mac_addr
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START sta_dynamic_random_mac_addr 1/1
Test: Dynamically added wpa_supplicant interface and random MAC address
Starting AP wlan3
Connect STA wlan5 to AP
Connect STA wlan5 to AP
PASS sta_dynamic_random_mac_addr 1.363314 2018-10-28 12:03:27.829346
passed all 1 test case(s)
2018-10-28 12:03:27 ./run-tests.py sta_dynamic_random_mac_addr_keep_oui
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START sta_dynamic_random_mac_addr_keep_oui 1/1
Test: Dynamically added wpa_supplicant interface and random MAC address (keep OUI)
Starting AP wlan3
Connect STA wlan5 to AP
Connect STA wlan5 to AP
PASS sta_dynamic_random_mac_addr_keep_oui 1.370933 2018-10-28 12:03:29.644521
passed all 1 test case(s)
2018-10-28 12:03:29 ./run-tests.py sta_dynamic_random_mac_addr_scan
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START sta_dynamic_random_mac_addr_scan 1/1
Test: Dynamically added wpa_supplicant interface and random MAC address for scan
Starting AP wlan3
Connect STA wlan5 to AP
PASS sta_dynamic_random_mac_addr_scan 0.989996 2018-10-28 12:03:31.179899
passed all 1 test case(s)
2018-10-28 12:03:31 ./run-tests.py sta_dynamic_random_mac_addr_scan_keep_oui
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START sta_dynamic_random_mac_addr_scan_keep_oui 1/1
Test: Dynamically added wpa_supplicant interface and random MAC address for scan (keep OUI)
Starting AP wlan3
Connect STA wlan5 to AP
PASS sta_dynamic_random_mac_addr_scan_keep_oui 0.918663 2018-10-28 12:03:32.568132
passed all 1 test case(s)
2018-10-28 12:03:32 ./run-tests.py suite_b
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b 1/1
Test: WPA2/GCMP connection at Suite B 128-bit level
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b 0.931645 2018-10-28 12:03:34.052579
passed all 1 test case(s)
2018-10-28 12:03:34 ./run-tests.py suite_b_192
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_192 1/1
Test: WPA2/GCMP-256 connection at Suite B 192-bit level
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_192 1.121564 2018-10-28 12:03:35.753060
passed all 1 test case(s)
2018-10-28 12:03:35 ./run-tests.py suite_b_192_mic_failure
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_192_mic_failure 1/1
Test: WPA2/GCMP connection at Suite B 192-bit level and MIC derivation failure
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_192_mic_failure 0.713166 2018-10-28 12:03:37.006557
passed all 1 test case(s)
2018-10-28 12:03:37 ./run-tests.py suite_b_192_pmkid_failure
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_192_pmkid_failure 1/1
Test: WPA2/GCMP-256 connection at Suite B 192-bit level and PMKID derivation failure
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_192_pmkid_failure 0.639846 2018-10-28 12:03:38.153704
passed all 1 test case(s)
2018-10-28 12:03:38 ./run-tests.py suite_b_192_radius
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_192_radius 1/1
Test: WPA2/GCMP-256 (RADIUS) connection at Suite B 192-bit level
Starting AP wlan4
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_192_radius 0.975543 2018-10-28 12:03:39.552257
passed all 1 test case(s)
2018-10-28 12:03:39 ./run-tests.py suite_b_192_radius_and_p256_cert
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_192_radius_and_p256_cert 1/1
Test: Suite B 192-bit level and p256 client cert
Starting AP wlan4
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_192_radius_and_p256_cert 0.976882 2018-10-28 12:03:41.032750
passed all 1 test case(s)
2018-10-28 12:03:41 ./run-tests.py suite_b_192_rsa
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_192_rsa 1/1
Test: WPA2/GCMP-256 connection at Suite B 192-bit level and RSA
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_192_rsa 0.848577 2018-10-28 12:03:42.511323
passed all 1 test case(s)
2018-10-28 12:03:42 ./run-tests.py suite_b_192_rsa_dhe
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_192_rsa_dhe 1/1
Test: WPA2/GCMP-256 connection at Suite B 192-bit level and RSA (DHE)
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_192_rsa_dhe 0.956581 2018-10-28 12:03:43.954524
passed all 1 test case(s)
2018-10-28 12:03:44 ./run-tests.py suite_b_192_rsa_dhe_radius_rsa2048_client
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_192_rsa_dhe_radius_rsa2048_client 1/1
Test: Suite B 192-bit level and RSA (DHE) and RSA2048 client
Starting AP wlan4
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_192_rsa_dhe_radius_rsa2048_client 0.878744 2018-10-28 12:03:45.321909
passed all 1 test case(s)
2018-10-28 12:03:45 ./run-tests.py suite_b_192_rsa_ecdhe
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_192_rsa_ecdhe 1/1
Test: WPA2/GCMP-256 connection at Suite B 192-bit level and RSA (ECDHE)
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_192_rsa_ecdhe 1.079896 2018-10-28 12:03:46.950174
passed all 1 test case(s)
2018-10-28 12:03:47 ./run-tests.py suite_b_192_rsa_ecdhe_radius_rsa2048_client
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_192_rsa_ecdhe_radius_rsa2048_client 1/1
Test: Suite B 192-bit level and RSA (ECDHE) and RSA2048 client
Starting AP wlan4
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_192_rsa_ecdhe_radius_rsa2048_client 1.131369 2018-10-28 12:03:48.617713
passed all 1 test case(s)
2018-10-28 12:03:48 ./run-tests.py suite_b_192_rsa_insufficient_dh
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_192_rsa_insufficient_dh 1/1
Test: WPA2/GCMP-256 connection at Suite B 192-bit level and RSA with insufficient DH key length
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_192_rsa_insufficient_dh 0.761804 2018-10-28 12:03:49.803313
passed all 1 test case(s)
2018-10-28 12:03:49 ./run-tests.py suite_b_192_rsa_insufficient_key
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_192_rsa_insufficient_key 1/1
Test: WPA2/GCMP-256 connection at Suite B 192-bit level and RSA with insufficient key length
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_192_rsa_insufficient_key 0.716303 2018-10-28 12:03:51.024431
passed all 1 test case(s)
2018-10-28 12:03:51 ./run-tests.py suite_b_192_rsa_radius
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_192_rsa_radius 1/1
Test: WPA2/GCMP-256 (RADIUS) connection at Suite B 192-bit level and RSA (ECDHE)
Starting AP wlan4
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_192_rsa_radius 1.294771 2018-10-28 12:03:52.864967
passed all 1 test case(s)
2018-10-28 12:03:52 ./run-tests.py suite_b_mic_failure
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_mic_failure 1/1
Test: WPA2/GCMP connection at Suite B 128-bit level and MIC derivation failure
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_mic_failure 0.853263 2018-10-28 12:03:54.271571
passed all 1 test case(s)
2018-10-28 12:03:54 ./run-tests.py suite_b_pmkid_failure
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_pmkid_failure 1/1
Test: WPA2/GCMP connection at Suite B 128-bit level and PMKID derivation failure
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_pmkid_failure 0.782954 2018-10-28 12:03:55.602313
passed all 1 test case(s)
2018-10-28 12:03:55 ./run-tests.py suite_b_radius
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START suite_b_radius 1/1
Test: WPA2/GCMP (RADIUS) connection at Suite B 128-bit level
Starting AP wlan4
Starting AP wlan3
Connect STA wlan0 to AP
PASS suite_b_radius 1.013984 2018-10-28 12:03:57.075159
passed all 1 test case(s)
ignored_by_lkp tdls_chan_switch
2018-10-28 12:03:57 ./run-tests.py tnc_fast
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START tnc_fast 1/1
Test: TNC FAST
Starting AP wlan3
Connect STA wlan0 to AP
Connection timed out
Traceback (most recent call last):
File "./run-tests.py", line 466, in main
t(dev, apdev)
File "/lkp/benchmarks/hwsim/tests/hwsim/test_tnc.py", line 194, in test_tnc_fast
dev[0].wait_connected(timeout=10)
File "/lkp/benchmarks/hwsim/tests/hwsim/wpasupplicant.py", line 1276, in wait_connected
raise Exception(error)
Exception: Connection timed out
FAIL tnc_fast 10.377092 2018-10-28 12:04:07.904561
passed 0 test case(s)
skipped 0 test case(s)
failed tests: tnc_fast
2018-10-28 12:04:07 ./run-tests.py tnc_peap_soh
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START tnc_peap_soh 1/1
Test: TNC PEAP-SoH
Starting AP wlan3
Connect STA wlan0 to AP
Connection timed out
Traceback (most recent call last):
File "./run-tests.py", line 466, in main
t(dev, apdev)
File "/lkp/benchmarks/hwsim/tests/hwsim/test_tnc.py", line 26, in test_tnc_peap_soh
dev[0].wait_connected(timeout=10)
File "/lkp/benchmarks/hwsim/tests/hwsim/wpasupplicant.py", line 1276, in wait_connected
raise Exception(error)
Exception: Connection timed out
FAIL tnc_peap_soh 10.416039 2018-10-28 12:04:18.850401
passed 0 test case(s)
skipped 0 test case(s)
failed tests: tnc_peap_soh
2018-10-28 12:04:18 ./run-tests.py tnc_peap_soh_errors
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START tnc_peap_soh_errors 1/1
Test: TNC PEAP-SoH local error cases
Starting AP wlan3
Connect STA wlan0 to AP
Failure not triggered
Traceback (most recent call last):
File "./run-tests.py", line 466, in main
t(dev, apdev)
File "/lkp/benchmarks/hwsim/tests/hwsim/test_tnc.py", line 60, in test_tnc_peap_soh_errors
wait_fail_trigger(dev[0], "GET_ALLOC_FAIL")
File "/lkp/benchmarks/hwsim/tests/hwsim/utils.py", line 62, in wait_fail_trigger
raise Exception(note)
Exception: Failure not triggered
FAIL tnc_peap_soh_errors 2.543831 2018-10-28 12:04:21.980850
passed 0 test case(s)
skipped 0 test case(s)
failed tests: tnc_peap_soh_errors
2018-10-28 12:04:22 ./run-tests.py tnc_ttls
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START tnc_ttls 1/1
Test: TNC TTLS
Starting AP wlan3
Connect STA wlan0 to AP
Connection timed out
Traceback (most recent call last):
File "./run-tests.py", line 466, in main
t(dev, apdev)
File "/lkp/benchmarks/hwsim/tests/hwsim/test_tnc.py", line 91, in test_tnc_ttls
dev[0].wait_connected(timeout=10)
File "/lkp/benchmarks/hwsim/tests/hwsim/wpasupplicant.py", line 1276, in wait_connected
raise Exception(error)
Exception: Connection timed out
FAIL tnc_ttls 10.453996 2018-10-28 12:04:32.939168
passed 0 test case(s)
skipped 0 test case(s)
failed tests: tnc_ttls
2018-10-28 12:04:33 ./run-tests.py tnc_ttls_errors
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START tnc_ttls_errors 1/1
Test: TNC TTLS local error cases
Starting AP wlan3
Connect STA wlan0 to AP
Allocation failure not triggered for: 1:eap_ttls_process_phase2_eap;eap_ttls_process_tnc_start
Traceback (most recent call last):
File "./run-tests.py", line 466, in main
t(dev, apdev)
File "/lkp/benchmarks/hwsim/tests/hwsim/test_tnc.py", line 167, in test_tnc_ttls_errors
note="Allocation failure not triggered for: %d:%s" % (count, func))
File "/lkp/benchmarks/hwsim/tests/hwsim/utils.py", line 62, in wait_fail_trigger
raise Exception(note)
Exception: Allocation failure not triggered for: 1:eap_ttls_process_phase2_eap;eap_ttls_process_tnc_start
FAIL tnc_ttls_errors 2.607626 2018-10-28 12:04:36.056599
passed 0 test case(s)
skipped 0 test case(s)
failed tests: tnc_ttls_errors
2018-10-28 12:04:36 ./run-tests.py tnc_ttls_fragmentation
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START tnc_ttls_fragmentation 1/1
Test: TNC TTLS with fragmentation
Starting AP wlan3
Connect STA wlan0 to AP
Connection timed out
Traceback (most recent call last):
File "./run-tests.py", line 466, in main
t(dev, apdev)
File "/lkp/benchmarks/hwsim/tests/hwsim/test_tnc.py", line 111, in test_tnc_ttls_fragmentation
dev[0].wait_connected(timeout=10)
File "/lkp/benchmarks/hwsim/tests/hwsim/wpasupplicant.py", line 1276, in wait_connected
raise Exception(error)
Exception: Connection timed out
FAIL tnc_ttls_fragmentation 10.423287 2018-10-28 12:04:47.018479
passed 0 test case(s)
skipped 0 test case(s)
failed tests: tnc_ttls_fragmentation
2018-10-28 12:04:47 ./run-tests.py tspec
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START tspec 1/1
Test: Basic addts/delts tests
Starting AP wlan3
Connect STA wlan0 to AP
PASS tspec 0.775814 2018-10-28 12:04:48.287804
passed all 1 test case(s)
2018-10-28 12:04:48 ./run-tests.py tspec_ap_fail
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START tspec_ap_fail 1/1
Test: AP failing to send tspec response
Starting AP wlan3
Connect STA wlan0 to AP
PASS tspec_ap_fail 1.526823 2018-10-28 12:04:50.392410
passed all 1 test case(s)
2018-10-28 12:04:50 ./run-tests.py tspec_ap_parsing
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START tspec_ap_parsing 1/1
Test: TSPEC AP parsing tests
Starting AP wlan3
Connect STA wlan0 to AP
PASS tspec_ap_parsing 0.72163 2018-10-28 12:04:51.663684
passed all 1 test case(s)
2018-10-28 12:04:51 ./run-tests.py tspec_ap_roam_open
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START tspec_ap_roam_open 1/1
Test: Roam between two open APs while having tspecs
Starting AP wlan3
Connect STA wlan0 to AP
Starting AP wlan4
PASS tspec_ap_roam_open 5.374646 2018-10-28 12:04:57.611491
passed all 1 test case(s)
2018-10-28 12:04:57 ./run-tests.py tspec_not_enabled
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START tspec_not_enabled 1/1
Test: addts failing if AP does not support WMM
Starting AP wlan3
Connect STA wlan0 to AP
PASS tspec_not_enabled 0.731853 2018-10-28 12:04:58.814328
passed all 1 test case(s)
2018-10-28 12:04:58 ./run-tests.py tspec_protocol
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START tspec_protocol 1/1
Test: Protocol tests for addts/delts
Starting AP wlan3
Connect STA wlan0 to AP
PASS tspec_protocol 1.723449 2018-10-28 12:05:01.037510
passed all 1 test case(s)
2018-10-28 12:05:01 ./run-tests.py tspec_reassoc
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START tspec_reassoc 1/1
Test: Reassociation to same BSS while having tspecs
Starting AP wlan3
Connect STA wlan0 to AP
PASS tspec_reassoc 4.699278 2018-10-28 12:05:06.226323
passed all 1 test case(s)
2018-10-28 12:05:06 ./run-tests.py wep_ht_vht
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wep_ht_vht 1/1
Test: WEP and HT/VHT
Starting AP wlan3
Connect STA wlan0 to AP
hostapd STATUS: {'olbc_ht': '0', 'cac_time_left_seconds': 'N/A', 'num_sta_no_short_slot_time': '1', 'olbc': '0', 'num_sta_non_erp': '0', 'supported_rates': '0c 12 18 24 30 48 60 6c', 'ht_op_mode': '0x13', 'state': 'ENABLED', 'num_sta_ht40_intolerant': '0', 'channel': '36', 'bssid[0]': '02:00:00:00:03:00', 'ieee80211n': '0', 'cac_time_seconds': '0', 'num_sta[0]': '1', 'ieee80211ac': '0', 'phy': 'phy3', 'max_txpower': '20', 'num_sta_ht_no_gf': '0', 'freq': '5180', 'num_sta_ht_20_mhz': '0', 'num_sta_no_short_preamble': '1', 'secondary_channel': '0', 'ssid[0]': 'test-vht40-wep', 'dtim_period': '2', 'beacon_int': '100', 'num_sta_no_ht': '1', 'bss[0]': 'wlan3'}
PASS wep_ht_vht 1.086451 2018-10-28 12:05:07.754182
passed all 1 test case(s)
2018-10-28 12:05:07 ./run-tests.py wep_ifdown
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wep_ifdown 1/1
Test: AP with WEP and external ifconfig down
Starting AP wlan3
Connect STA wlan0 to AP
PASS wep_ifdown 1.179304 2018-10-28 12:05:09.475904
passed all 1 test case(s)
2018-10-28 12:05:09 ./run-tests.py wep_open_auth
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wep_open_auth 1/1
Test: WEP Open System authentication
Starting AP wlan3
Connect STA wlan0 to AP
PASS wep_open_auth 0.508769 2018-10-28 12:05:10.426938
passed all 1 test case(s)
2018-10-28 12:05:10 ./run-tests.py wep_shared_key_auth
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wep_shared_key_auth 1/1
Test: WEP Shared Key authentication
Starting AP wlan3
Connect STA wlan0 to AP
Connect STA wlan1 to AP
PASS wep_shared_key_auth 0.82823 2018-10-28 12:05:11.676748
passed all 1 test case(s)
2018-10-28 12:05:11 ./run-tests.py wep_shared_key_auth_multi_key
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wep_shared_key_auth_multi_key 1/1
Test: WEP Shared Key authentication with multiple keys
Starting AP wlan3
Connect STA wlan0 to AP
Connect STA wlan1 to AP
Connect STA wlan2 to AP
PASS wep_shared_key_auth_multi_key 1.247324 2018-10-28 12:05:13.337600
passed all 1 test case(s)
2018-10-28 12:05:13 ./run-tests.py wep_shared_key_auth_not_allowed
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wep_shared_key_auth_not_allowed 1/1
Test: WEP Shared Key authentication not allowed
Starting AP wlan3
Connect STA wlan0 to AP
PASS wep_shared_key_auth_not_allowed 1.348489 2018-10-28 12:05:15.151311
passed all 1 test case(s)
2018-10-28 12:05:15 ./run-tests.py wext_open
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wext_open 1/1
Test: WEXT driver interface with open network
Starting AP wlan3
Connect STA wlan5 to AP
PASS wext_open 4.644343 2018-10-28 12:05:20.226635
passed all 1 test case(s)
2018-10-28 12:05:20 ./run-tests.py wext_pmf
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wext_pmf 1/1
Test: WEXT driver interface with WPA2-PSK and PMF
Starting AP wlan3
Connect STA wlan5 to AP
PASS wext_pmf 8.845238 2018-10-28 12:05:29.666662
passed all 1 test case(s)
2018-10-28 12:05:29 ./run-tests.py wext_pmksa_cache
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wext_pmksa_cache 1/1
Test: PMKSA caching with WEXT
Starting AP wlan3
Connect STA wlan5 to AP
Starting AP wlan4
Roam to AP2
Roam back to AP1
PASS wext_pmksa_cache 32.945808 2018-10-28 12:06:03.243617
passed all 1 test case(s)
2018-10-28 12:06:03 ./run-tests.py wext_rfkill
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wext_rfkill 1/1
Test: WEXT and rfkill block/unblock
Starting AP wlan3
Connect STA wlan5 to AP
rfkill block
rfkill unblock
PASS wext_rfkill 8.952556 2018-10-28 12:06:12.756213
passed all 1 test case(s)
2018-10-28 12:06:12 ./run-tests.py wext_scan_hidden
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wext_scan_hidden 1/1
Test: WEXT with hidden SSID
Starting AP wlan3
Starting AP wlan4
Connect STA wlan5 to AP
Connect STA wlan5 to AP
PASS wext_scan_hidden 18.402832 2018-10-28 12:06:31.751499
passed all 1 test case(s)
2018-10-28 12:06:31 ./run-tests.py wext_wep_open_auth
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wext_wep_open_auth 1/1
Test: WEP Open System authentication
Starting AP wlan3
Connect STA wlan5 to AP
PASS wext_wep_open_auth 4.813233 2018-10-28 12:06:37.087342
passed all 1 test case(s)
2018-10-28 12:06:37 ./run-tests.py wext_wep_shared_key_auth
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wext_wep_shared_key_auth 1/1
Test: WEP Shared Key authentication
Starting AP wlan3
Connect STA wlan5 to AP
Connect STA wlan5 to AP
PASS wext_wep_shared_key_auth 5.042088 2018-10-28 12:06:42.655147
passed all 1 test case(s)
2018-10-28 12:06:42 ./run-tests.py wext_wpa2_psk
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wext_wpa2_psk 1/1
Test: WEXT driver interface with WPA2-PSK
Starting AP wlan3
Connect STA wlan5 to AP
PASS wext_wpa2_psk 4.706991 2018-10-28 12:06:47.905331
passed all 1 test case(s)
2018-10-28 12:06:47 ./run-tests.py wext_wpa_psk
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wext_wpa_psk 1/1
Test: WEXT driver interface with WPA-PSK
Starting AP wlan3
Connect STA wlan5 to AP
PASS wext_wpa_psk 5.769256 2018-10-28 12:06:54.220483
passed all 1 test case(s)
2018-10-28 12:06:54 ./run-tests.py wifi_display
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wifi_display 1/1
Test: Wi-Fi Display extensions to P2P
wlan0: Trying to discover peer 02:00:00:00:01:00
wlan1: Trying to discover peer 02:00:00:00:00:00
PASS wifi_display 5.12075 2018-10-28 12:06:59.916120
passed all 1 test case(s)
2018-10-28 12:06:59 ./run-tests.py wifi_display_disable
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wifi_display_disable 1/1
Test: Peer disabling Wi-Fi Display advertisement
PASS wifi_display_disable 1.498646 2018-10-28 12:07:01.917863
passed all 1 test case(s)
2018-10-28 12:07:01 ./run-tests.py wifi_display_go_invite
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wifi_display_go_invite 1/1
Test: P2P GO with Wi-Fi Display inviting a client to join
wlan0: Trying to discover peer 02:00:00:00:01:00
wlan1: Trying to discover peer 02:00:00:00:00:00
Authorize invitation
Try to connect the client to the GO
wlan2: Trying to discover peer 02:00:00:00:00:00
Client connected
Invite peer to join the group
PASS wifi_display_go_invite 3.399298 2018-10-28 12:07:05.829763
passed all 1 test case(s)
2018-10-28 12:07:05 ./run-tests.py wifi_display_invalid_subelem
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wifi_display_invalid_subelem 1/1
Test: Wi-Fi Display and invalid subelement parsing
PASS wifi_display_invalid_subelem 0.368611 2018-10-28 12:07:06.697400
passed all 1 test case(s)
2018-10-28 12:07:06 ./run-tests.py wifi_display_parsing
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wifi_display_parsing 1/1
Test: Wi-Fi Display extensions to P2P and special parsing cases
wlan1: Trying to discover peer 02:00:00:00:00:00
wlan2: Trying to discover peer 02:00:00:00:00:00
PASS wifi_display_parsing 2.652806 2018-10-28 12:07:09.825581
passed all 1 test case(s)
2018-10-28 12:07:09 ./run-tests.py wifi_display_persistent_group
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wifi_display_persistent_group 1/1
Test: P2P persistent group formation and re-invocation with Wi-Fi Display enabled
Form a persistent group
Start GO negotiation wlan0 -> wlan1
wlan1: Trying to discover peer 02:00:00:00:00:00
wlan0: Trying to discover peer 02:00:00:00:01:00
Group formed
Terminate persistent group
Re-invoke persistent group from client
wlan1: Trying to discover peer 02:00:00:00:00:00
Terminate persistent group
Re-invoke persistent group from GO
wlan0: Trying to discover peer 02:00:00:00:01:00
Terminate persistent group
Try to connect the client to the GO
wlan2: Trying to discover peer 02:00:00:00:00:00
Client connected
wlan1: Trying to discover peer 02:00:00:00:00:00
PASS wifi_display_persistent_group 8.358167 2018-10-28 12:07:18.734524
passed all 1 test case(s)
2018-10-28 12:07:18 ./run-tests.py wifi_display_r2
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wifi_display_r2 1/1
Test: Wi-Fi Display extensions to P2P with R2 subelems
wlan0: Trying to discover peer 02:00:00:00:01:00
wlan1: Trying to discover peer 02:00:00:00:00:00
PASS wifi_display_r2 2.029335 2018-10-28 12:07:21.294642
passed all 1 test case(s)
ignored_by_lkp wmediumd_path_rann
2018-10-28 12:07:21 ./run-tests.py wmediumd_path_simple
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wmediumd_path_simple 1/1
Test: test a mesh path
PASS wmediumd_path_simple 1.785899 2018-10-28 12:07:23.579587
passed all 1 test case(s)
2018-10-28 12:07:23 ./run-tests.py wmediumd_path_ttl
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wmediumd_path_ttl 1/1
Test: Mesh path request TTL
PASS wmediumd_path_ttl 10.094398 2018-10-28 12:07:34.185400
passed all 1 test case(s)
2018-10-28 12:07:34 ./run-tests.py wmediumd_simple
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wmediumd_simple 1/1
Test: test a simple wmediumd configuration
Starting AP wlan3
Connect STA wlan0 to AP
Starting AP wlan3
Connect STA wlan0 to AP
PASS wmediumd_simple 1.282524 2018-10-28 12:07:36.029586
passed all 1 test case(s)
2018-10-28 12:07:36 ./run-tests.py wmm_disabled
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wmm_disabled 1/1
Test: WMM disabled and unexpected TSPEC
Starting AP wlan3 (old add_ap argument type)
Connect STA wlan0 to AP
PASS wmm_disabled 0.563496 2018-10-28 12:07:37.129336
passed all 1 test case(s)
2018-10-28 12:07:37 ./run-tests.py wmm_element
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wmm_element 1/1
Test: hostapd FTM range request timeout
Starting AP wlan3 (old add_ap argument type)
Connect STA wlan0 to AP
Connect STA wlan0 to AP
Connect STA wlan0 to AP
PASS wmm_element 0.788016 2018-10-28 12:07:38.402345
passed all 1 test case(s)
2018-10-28 12:07:38 ./run-tests.py wnm_action_proto
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_action_proto 1/1
Test: WNM Action protocol testing
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_action_proto 0.666706 2018-10-28 12:07:39.580035
passed all 1 test case(s)
2018-10-28 12:07:39 ./run-tests.py wnm_action_proto_no_pmf
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_action_proto_no_pmf 1/1
Test: WNM Action protocol testing (PMF disabled)
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_action_proto_no_pmf 0.852016 2018-10-28 12:07:41.033369
passed all 1 test case(s)
2018-10-28 12:07:41 ./run-tests.py wnm_action_proto_pmf
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_action_proto_pmf 1/1
Test: WNM Action protocol testing (PMF enabled)
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_action_proto_pmf 0.723645 2018-10-28 12:07:42.316429
passed all 1 test case(s)
2018-10-28 12:07:42 ./run-tests.py wnm_bss_keep_alive
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_keep_alive 1/1
Test: WNM keep-alive
Starting AP wlan3
Connect STA wlan0 to AP
timeout_next=NULLFUNC POLL rx_packets=8 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=8 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=8 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=8 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=8 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=8 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=NULLFUNC POLL rx_packets=9 tx_packets=4
timeout_next=DISASSOC rx_packets=9 tx_packets=5
PASS wnm_bss_keep_alive 18.610134 2018-10-28 12:08:01.364287
passed all 1 test case(s)
2018-10-28 12:08:01 ./run-tests.py wnm_bss_tm
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm 1/1
Test: WNM BSS Transition Management
Starting AP wlan3
Connect STA wlan0 to AP
Starting AP wlan4
No neighbor list entries
Neighbor list entry, but not claimed as Preferred Candidate List
Preferred Candidate List (no matching neighbor) without Disassociation Imminent
Preferred Candidate List (matching neighbor for another BSS) without Disassociation Imminent
Preferred Candidate List with two matches, no roam needed
Preferred Candidate List with two matches and extra frequency (160 MHz), no roam needed
PASS wnm_bss_tm 2.867458 2018-10-28 12:08:04.685365
passed all 1 test case(s)
2018-10-28 12:08:04 ./run-tests.py wnm_bss_tm_ap_proto
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_ap_proto 1/1
Test: WNM BSS TM - protocol testing for AP message parsing
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_bss_tm_ap_proto 0.59005 2018-10-28 12:08:05.782304
passed all 1 test case(s)
2018-10-28 12:08:05 ./run-tests.py wnm_bss_tm_connect_cmd
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_connect_cmd 1/1
Test: WNM BSS Transition Management and cfg80211 connect command
Starting AP wlan3
Starting AP wlan4
Connect STA wlan5 to AP
Preferred Candidate List (matching neighbor for another BSS) without Disassociation Imminent
PASS wnm_bss_tm_connect_cmd 1.3009 2018-10-28 12:08:07.551933
passed all 1 test case(s)
2018-10-28 12:08:07 ./run-tests.py wnm_bss_tm_country_cn
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_country_cn 1/1
Test: WNM BSS Transition Management (CN)
Starting AP wlan3
Connect STA wlan0 to AP
Preferred Candidate List (no matching neighbor, known channels)
Preferred Candidate List (no matching neighbor, unknown channels)
PASS wnm_bss_tm_country_cn 6.351981 2018-10-28 12:08:14.444079
passed all 1 test case(s)
2018-10-28 12:08:14 ./run-tests.py wnm_bss_tm_country_fi
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_country_fi 1/1
Test: WNM BSS Transition Management (FI)
Starting AP wlan3
Connect STA wlan0 to AP
Preferred Candidate List (no matching neighbor, known channels)
Preferred Candidate List (no matching neighbor, unknown channels)
Preferred Candidate List (no matching neighbor, unknown channels 2)
PASS wnm_bss_tm_country_fi 6.838004 2018-10-28 12:08:21.875460
passed all 1 test case(s)
2018-10-28 12:08:21 ./run-tests.py wnm_bss_tm_country_jp
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_country_jp 1/1
Test: WNM BSS Transition Management (JP)
Starting AP wlan3
Connect STA wlan0 to AP
Preferred Candidate List (no matching neighbor, known channels)
Preferred Candidate List (no matching neighbor, unknown channels)
PASS wnm_bss_tm_country_jp 7.111868 2018-10-28 12:08:29.613278
passed all 1 test case(s)
ignored_by_lkp wnm_bss_tm_country_us
2018-10-28 12:08:29 ./run-tests.py wnm_bss_tm_errors
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_errors 1/1
Test: WNM BSS Transition Management errors
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_bss_tm_errors 0.725001 2018-10-28 12:08:31.074478
passed all 1 test case(s)
2018-10-28 12:08:31 ./run-tests.py wnm_bss_tm_global
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_global 1/1
Test: WNM BSS Transition Management (global)
Starting AP wlan3
Connect STA wlan0 to AP
Preferred Candidate List (no matching neighbor, known channels)
Preferred Candidate List (no matching neighbor, unknown channels)
Preferred Candidate List (no matching neighbor, unknown channels 2)
PASS wnm_bss_tm_global 7.304235 2018-10-28 12:08:38.996287
passed all 1 test case(s)
2018-10-28 12:08:39 ./run-tests.py wnm_bss_tm_global4
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_global4 1/1
Test: WNM BSS Transition Management (global; indicate table E-4)
Starting AP wlan3
Connect STA wlan0 to AP
Preferred Candidate List (no matching neighbor, known channels)
Preferred Candidate List (no matching neighbor, unknown channels)
Preferred Candidate List (no matching neighbor, unknown channels 2)
PASS wnm_bss_tm_global4 2.79861 2018-10-28 12:08:42.269785
passed all 1 test case(s)
2018-10-28 12:08:42 ./run-tests.py wnm_bss_tm_nei_11a
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_nei_11a 1/1
Test: WNM BSS Transition Management and 11a neighbor
Starting AP wlan3
Starting AP wlan4
AP startup failed
Traceback (most recent call last):
File "./run-tests.py", line 466, in main
t(dev, apdev)
File "/lkp/benchmarks/hwsim/tests/hwsim/test_wnm.py", line 795, in test_wnm_bss_tm_nei_11a
run_wnm_bss_tm_scan_not_needed(dev, apdev, ht=False, nei_info="115,36,4")
File "/lkp/benchmarks/hwsim/tests/hwsim/test_wnm.py", line 834, in run_wnm_bss_tm_scan_not_needed
hapd2 = hostapd.add_ap(apdev[1], params)
File "/lkp/benchmarks/hwsim/tests/hwsim/hostapd.py", line 427, in add_ap
raise Exception("AP startup failed")
Exception: AP startup failed
FAIL wnm_bss_tm_nei_11a 10.75536 2018-10-28 12:08:53.690255
passed 0 test case(s)
skipped 0 test case(s)
failed tests: wnm_bss_tm_nei_11a
2018-10-28 12:08:53 ./run-tests.py wnm_bss_tm_nei_11b
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_nei_11b 1/1
Test: WNM BSS Transition Management and 11g neighbor
Starting AP wlan3
Starting AP wlan4
Connect STA wlan0 to AP
Preferred Candidate List (matching neighbor for another BSS) without Disassociation Imminent
PASS wnm_bss_tm_nei_11b 11.615235 2018-10-28 12:09:06.070069
passed all 1 test case(s)
2018-10-28 12:09:06 ./run-tests.py wnm_bss_tm_nei_11g
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_nei_11g 1/1
Test: WNM BSS Transition Management and 11g neighbor
Starting AP wlan3
Starting AP wlan4
Connect STA wlan0 to AP
Preferred Candidate List (matching neighbor for another BSS) without Disassociation Imminent
PASS wnm_bss_tm_nei_11g 11.497865 2018-10-28 12:09:18.072521
passed all 1 test case(s)
2018-10-28 12:09:18 ./run-tests.py wnm_bss_tm_nei_vht
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_nei_vht 1/1
Test: WNM BSS Transition Management and VHT neighbor
Starting AP wlan3
Starting AP wlan4
AP startup failed
Traceback (most recent call last):
File "./run-tests.py", line 466, in main
t(dev, apdev)
File "/lkp/benchmarks/hwsim/tests/hwsim/test_wnm.py", line 791, in test_wnm_bss_tm_nei_vht
run_wnm_bss_tm_scan_not_needed(dev, apdev, vht=True, nei_info="115,36,9")
File "/lkp/benchmarks/hwsim/tests/hwsim/test_wnm.py", line 834, in run_wnm_bss_tm_scan_not_needed
hapd2 = hostapd.add_ap(apdev[1], params)
File "/lkp/benchmarks/hwsim/tests/hwsim/hostapd.py", line 427, in add_ap
raise Exception("AP startup failed")
Exception: AP startup failed
FAIL wnm_bss_tm_nei_vht 10.522934 2018-10-28 12:09:29.087800
passed 0 test case(s)
skipped 0 test case(s)
failed tests: wnm_bss_tm_nei_vht
2018-10-28 12:09:29 ./run-tests.py wnm_bss_tm_op_class_0
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_op_class_0 1/1
Test: WNM BSS Transition Management with invalid operating class
Starting AP wlan3
Connect STA wlan0 to AP
Preferred Candidate List (no matching neighbor, invalid op class specified for channels)
PASS wnm_bss_tm_op_class_0 6.003448 2018-10-28 12:09:35.580689
passed all 1 test case(s)
2018-10-28 12:09:35 ./run-tests.py wnm_bss_tm_reject
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_reject 1/1
Test: WNM BSS Transition Management request getting rejected
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_bss_tm_reject 5.898884 2018-10-28 12:09:41.983279
passed all 1 test case(s)
2018-10-28 12:09:42 ./run-tests.py wnm_bss_tm_req
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_req 1/1
Test: BSS Transition Management Request
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_bss_tm_req 3.484342 2018-10-28 12:09:45.940828
passed all 1 test case(s)
2018-10-28 12:09:46 ./run-tests.py wnm_bss_tm_req_with_mbo_ie
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_req_with_mbo_ie 1/1
Test: WNM BSS transition request with MBO IE and reassociation delay attribute
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_bss_tm_req_with_mbo_ie 6.640216 2018-10-28 12:09:53.133134
passed all 1 test case(s)
2018-10-28 12:09:53 ./run-tests.py wnm_bss_tm_rsn
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_rsn 1/1
Test: WNM BSS Transition Management with RSN
Starting AP wlan3
Starting AP wlan4
AP startup failed
Traceback (most recent call last):
File "./run-tests.py", line 466, in main
t(dev, apdev)
File "/lkp/benchmarks/hwsim/tests/hwsim/test_wnm.py", line 1163, in test_wnm_bss_tm_rsn
hapd2 = hostapd.add_ap(apdev[1], params)
File "/lkp/benchmarks/hwsim/tests/hwsim/hostapd.py", line 427, in add_ap
raise Exception("AP startup failed")
Exception: AP startup failed
FAIL wnm_bss_tm_rsn 10.730249 2018-10-28 12:10:04.336376
passed 0 test case(s)
skipped 0 test case(s)
failed tests: wnm_bss_tm_rsn
ignored_by_lkp wnm_bss_tm_scan_needed
ignored_by_lkp wnm_bss_tm_scan_needed_e4
ignored_by_lkp wnm_bss_tm_scan_not_needed
2018-10-28 12:10:04 ./run-tests.py wnm_bss_tm_security_mismatch
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_security_mismatch 1/1
Test: WNM BSS Transition Management and security mismatch
Starting AP wlan3
Starting AP wlan4
Connect STA wlan0 to AP
Preferred Candidate List (matching neighbor for another BSS) without Disassociation Imminent
PASS wnm_bss_tm_security_mismatch 1.481285 2018-10-28 12:10:06.336375
passed all 1 test case(s)
2018-10-28 12:10:06 ./run-tests.py wnm_bss_tm_termination
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_tm_termination 1/1
Test: WNM BSS Transition Management and BSS termination
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_bss_tm_termination 1.043985 2018-10-28 12:10:08.051759
passed all 1 test case(s)
2018-10-28 12:10:08 ./run-tests.py wnm_bss_transition_mgmt
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_transition_mgmt 1/1
Test: WNM BSS Transition Management
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_bss_transition_mgmt 1.7073 2018-10-28 12:10:10.522504
passed all 1 test case(s)
2018-10-28 12:10:10 ./run-tests.py wnm_bss_transition_mgmt_oom
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_transition_mgmt_oom 1/1
Test: WNM BSS Transition Management OOM
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_bss_transition_mgmt_oom 0.931991 2018-10-28 12:10:12.377147
passed all 1 test case(s)
2018-10-28 12:10:12 ./run-tests.py wnm_bss_transition_mgmt_query
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_transition_mgmt_query 1/1
Test: WNM BSS Transition Management query
Starting AP wlan3
Starting AP wlan4
Connect STA wlan0 to AP
PASS wnm_bss_transition_mgmt_query 1.334503 2018-10-28 12:10:14.345372
passed all 1 test case(s)
2018-10-28 12:10:14 ./run-tests.py wnm_bss_transition_mgmt_query_with_unknown_candidates
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_bss_transition_mgmt_query_with_unknown_candidates 1/1
Test: WNM BSS Transition Management query with unknown candidates
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_bss_transition_mgmt_query_with_unknown_candidates 0.84895 2018-10-28 12:10:15.877206
passed all 1 test case(s)
2018-10-28 12:10:16 ./run-tests.py wnm_disassoc_imminent
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_disassoc_imminent 1/1
Test: WNM Disassociation Imminent
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_disassoc_imminent 0.979628 2018-10-28 12:10:17.546748
passed all 1 test case(s)
2018-10-28 12:10:17 ./run-tests.py wnm_disassoc_imminent_fail
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_disassoc_imminent_fail 1/1
Test: WNM Disassociation Imminent failure
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_disassoc_imminent_fail 0.707111 2018-10-28 12:10:19.107410
passed all 1 test case(s)
2018-10-28 12:10:19 ./run-tests.py wnm_ess_disassoc_imminent
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_ess_disassoc_imminent 1/1
Test: WNM ESS Disassociation Imminent
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_ess_disassoc_imminent 0.898813 2018-10-28 12:10:20.641968
passed all 1 test case(s)
2018-10-28 12:10:20 ./run-tests.py wnm_ess_disassoc_imminent_fail
DEV: wlan0: 02:00:00:00:00:00
DEV: wlan1: 02:00:00:00:01:00
DEV: wlan2: 02:00:00:00:02:00
APDEV: wlan3
APDEV: wlan4
START wnm_ess_disassoc_imminent_fail 1/1
Test: WNM ESS Disassociation Imminent failure
Starting AP wlan3
Connect STA wlan0 to AP
PASS wnm_ess_disassoc_imminent_fail 0.852755 2018-10-28 12:10:22.162744
passed all 1 test case(s)
2018-10-28 12:10:22 ./stop.sh
2018-10-28 12:10:23 ./start.sh channels=4
2018-10-28 12:10:24 ./stop.sh
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
Rong Chen
3 years, 8 months
[mm/vmalloc] 8dab1f5c1e: BUG:soft_lockup-CPU##stuck_for#s
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: 8dab1f5c1e6a0b2cb17237035efaf019553d79ea ("[RFC PATCH 1/2] mm/vmalloc: keep track of free blocks for allocation")
url: https://github.com/0day-ci/linux/commits/Uladzislau-Rezki-Sony/improve-vm...
base: https://github.com/thesofproject/linux master
in testcase: ftq
with following parameters:
nr_task: 100%
samples: 100000ss
test: add
freq: 1000
ucode: 0xb00002e
cpufreq_governor: performance
test-description: The FTQ benchmarks measure hardware and software interference or 'noise' on a node from the applications perspective.
test-url: https://github.com/rminnich/ftq
on test machine: 192 threads Intel(R) Xeon(R) CPU E7-8890 v4 @ 2.20GHz with 512G memory
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-----------------------------------------------------------------+------------+------------+
| | dd52cb8790 | 8dab1f5c1e |
+-----------------------------------------------------------------+------------+------------+
| boot_successes | 36 | 0 |
| boot_failures | 11 | 12 |
| WARNING:stack_recursion | 11 | |
| WARNING:at#for_ip_swapgs_restore_regs_and_return_to_usermode/0x | 10 | |
| WARNING:stack_going_in_the_wrong_direction?ip=_cond_resched/0x | 1 | |
| WARNING:stack_going_in_the_wrong_direction?ip=__schedule/0x | 1 | |
| BUG:soft_lockup-CPU##stuck_for#s | 0 | 11 |
| RIP:pcpu_get_vm_areas | 0 | 12 |
| Kernel_panic-not_syncing:softlockup:hung_tasks | 0 | 11 |
| kernel_BUG_at_mm/vmalloc.c | 0 | 1 |
| invalid_opcode:#[##] | 0 | 1 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 1 |
+-----------------------------------------------------------------+------------+------------+
[ 37.496001] watchdog: BUG: soft lockup - CPU#97 stuck for 22s! [kworker/97:1:825]
[ 37.496001] Modules linked in:
[ 37.496001] CPU: 97 PID: 825 Comm: kworker/97:1 Not tainted 4.17.0-rc7-00044-g8dab1f5 #1
[ 37.496001] Hardware name: Intel Corporation BRICKLAND/BRICKLAND, BIOS BRBDXSD1.86B.0338.R00.1603162127 03/16/2016
[ 37.496001] Workqueue: events pcpu_balance_workfn
[ 37.496001] RIP: 0010:pcpu_get_vm_areas+0x464/0xa90
[ 37.496001] RSP: 0000:ffffc9000e57bd50 EFLAGS: 00000296 ORIG_RAX: ffffffffffffff13
[ 37.496001] RAX: ffff885bf9eaa078 RBX: ffff885bf9eaa048 RCX: ffff885bf9eaa078
[ 37.496001] RDX: ffff885bf9eaa088 RSI: ffffe8c00d000000 RDI: 0000000000000000
[ 37.496001] RBP: ffffe8e00d000000 R08: ffffffff82516cd0 R09: ffff883bf9b19260
[ 37.496001] R10: ffff881c0ec03038 R11: ffff881c0ec03028 R12: ffff885bf9a8b1c0
[ 37.496001] R13: ffff885bf9b9fea0 R14: 0000000000000010 R15: ffff885bf9a8b1a0
[ 37.496001] FS: 0000000000000000(0000) GS:ffff881c0f840000(0000) knlGS:0000000000000000
[ 37.496001] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 37.496001] CR2: 0000000000000000 CR3: 000000000240a001 CR4: 00000000003606e0
[ 37.496001] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 37.496001] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 37.496001] Call Trace:
[ 37.496001] ? __kmalloc+0x1ee/0x230
[ 37.496001] pcpu_create_chunk+0x10a/0x1b0
[ 37.496001] pcpu_balance_workfn+0x27a/0x620
[ 37.496001] ? pick_next_task_fair+0x134/0x600
[ 37.496001] ? __switch_to+0x92/0x4d0
[ 37.496001] ? put_prev_entity+0x20/0x100
[ 37.496001] process_one_work+0x182/0x3a0
[ 37.496001] worker_thread+0x3a/0x3b0
[ 37.496001] ? process_one_work+0x3a0/0x3a0
[ 37.496001] kthread+0x11e/0x140
[ 37.496001] ? kthread_associate_blkcg+0xb0/0xb0
[ 37.496001] ret_from_fork+0x35/0x40
[ 37.496001] Code: ea 01 48 21 d0 48 89 43 08 48 8b 05 7f e0 c7 01 48 85 c0 0f 84 bd 03 00 00 48 8b 33 eb 03 48 89 c8 48 3b 70 e8 48 8d 50 10 72 12 <48> 8b 78 e0 48 39 7b 08 0f 86 91 05 00 00 48 8d 50 08 48 8b 0a
[ 37.496001] Kernel panic - not syncing: softlockup: hung tasks
[ 37.496001] CPU: 97 PID: 825 Comm: kworker/97:1 Tainted: G L 4.17.0-rc7-00044-g8dab1f5 #1
[ 37.496001] Hardware name: Intel Corporation BRICKLAND/BRICKLAND, BIOS BRBDXSD1.86B.0338.R00.1603162127 03/16/2016
[ 37.496001] Workqueue: events pcpu_balance_workfn
[ 37.496001] Call Trace:
[ 37.496001] <IRQ>
[ 37.496001] dump_stack+0x5c/0x7b
[ 37.496001] panic+0xd5/0x242
[ 37.496001] watchdog_timer_fn+0x20f/0x220
[ 37.496001] ? watchdog+0x30/0x30
[ 37.496001] __hrtimer_run_queues+0xfa/0x290
[ 37.496001] hrtimer_interrupt+0xe5/0x240
[ 37.496001] smp_apic_timer_interrupt+0x62/0x140
[ 37.496001] apic_timer_interrupt+0xf/0x20
[ 37.496001] </IRQ>
[ 37.496001] RIP: 0010:pcpu_get_vm_areas+0x464/0xa90
[ 37.496001] RSP: 0000:ffffc9000e57bd50 EFLAGS: 00000296 ORIG_RAX: ffffffffffffff13
[ 37.496001] RAX: ffff885bf9eaa078 RBX: ffff885bf9eaa048 RCX: ffff885bf9eaa078
[ 37.496001] RDX: ffff885bf9eaa088 RSI: ffffe8c00d000000 RDI: 0000000000000000
[ 37.496001] RBP: ffffe8e00d000000 R08: ffffffff82516cd0 R09: ffff883bf9b19260
[ 37.496001] R10: ffff881c0ec03038 R11: ffff881c0ec03028 R12: ffff885bf9a8b1c0
[ 37.496001] R13: ffff885bf9b9fea0 R14: 0000000000000010 R15: ffff885bf9a8b1a0
[ 37.496001] ? __kmalloc+0x1ee/0x230
[ 37.496001] pcpu_create_chunk+0x10a/0x1b0
[ 37.496001] pcpu_balance_workfn+0x27a/0x620
[ 37.496001] ? pick_next_task_fair+0x134/0x600
[ 37.496001] ? __switch_to+0x92/0x4d0
[ 37.496001] ? put_prev_entity+0x20/0x100
[ 37.496001] process_one_work+0x182/0x3a0
[ 37.496001] worker_thread+0x3a/0x3b0
[ 37.496001] ? process_one_work+0x3a0/0x3a0
[ 37.496001] kthread+0x11e/0x140
[ 37.496001] ? kthread_associate_blkcg+0xb0/0xb0
[ 37.496001] ret_from_fork+0x35/0x40
ACPI MEMORY or I/O RESET_REG.
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
Thanks,
Rong Chen
3 years, 8 months
499ac3b60f [ 2.479301] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:328 __debug_object_init
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/torvalds/linux.git master
commit 499ac3b60f657dae82055fc81c7b01e6242ac9bc
Author: Paul Blakey <paulb(a)mellanox.com>
AuthorDate: Sun Mar 4 17:29:49 2018 +0200
Commit: David S. Miller <davem(a)davemloft.net>
CommitDate: Wed Mar 7 10:44:03 2018 -0500
test_rhashtable: add test case for rhltable with duplicate objects
Tries to insert duplicates in the middle of bucket's chain:
bucket 1: [[val 21 (tid=1)]] -> [[ val 1 (tid=2), val 1 (tid=0) ]]
Reuses tid to distinguish the elements insertion order.
Signed-off-by: Paul Blakey <paulb(a)mellanox.com>
Acked-by: Herbert Xu <herbert(a)gondor.apana.org.au>
Signed-off-by: David S. Miller <davem(a)davemloft.net>
d3dcf8eb61 rhashtable: Fix rhlist duplicates insertion
499ac3b60f test_rhashtable: add test case for rhltable with duplicate objects
69d5b97c59 HID: we do not randomly make new drivers 'default y'
8c60c36d0b Add linux-next specific files for 20181019
+--------------------------------------------------------------------+------------+------------+------------+---------------+
| | d3dcf8eb61 | 499ac3b60f | 69d5b97c59 | next-20181019 |
+--------------------------------------------------------------------+------------+------------+------------+---------------+
| boot_successes | 31 | 0 | 0 | 0 |
| boot_failures | 0 | 11 | 11 | 11 |
| WARNING:at_lib/debugobjects.c:#__debug_object_init | 0 | 11 | 11 | 11 |
| EIP:__debug_object_init | 0 | 11 | 11 | 11 |
| WARNING:suspicious_RCU_usage | 0 | 11 | | |
| lib/test_rhashtable.c:#suspicious_rcu_dereference_protected()usage | 0 | 11 | | |
+--------------------------------------------------------------------+------------+------------+------------+---------------+
[ 2.446663] Duration of test: 327878701 ns
[ 2.477209] test if its possible to exceed max_size 8192: no, ok
[ 2.478020] Average test time: 316717656
[ 2.478351] test inserting duplicates
[ 2.478695] ODEBUG: object is on stack, but not annotated
[ 2.479301] WARNING: CPU: 0 PID: 1 at lib/debugobjects.c:328 __debug_object_init+0x1c3/0x390
[ 2.480022] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.16.0-rc4-00130-g499ac3b #1
[ 2.480022] EIP: __debug_object_init+0x1c3/0x390
[ 2.480022] EFLAGS: 00210082 CPU: 0
[ 2.480022] EAX: 0000002d EBX: 401e7e08 ECX: 4018dea8 EDX: 00000000
[ 2.480022] ESI: 4cc18e94 EDI: 4bf60600 EBP: 401e7d64 ESP: 401e7d40
[ 2.480022] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[ 2.480022] CR0: 80050033 CR2: 00000000 CR3: 0c3df000 CR4: 001406b0
[ 2.480022] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 2.480022] DR6: fffe0ff0 DR7: 00000400
[ 2.480022] Call Trace:
[ 2.480022] ? config_sync_direct_show+0x40/0x40
[ 2.480022] ? debug_object_init+0x1a/0x20
[ 2.480022] ? __init_work+0x16/0x30
[ 2.480022] ? rhashtable_init+0x163/0x2d0
[ 2.480022] ? rhltable_init+0x12/0x30
[ 2.480022] ? test_insert_dup+0x43/0x67d
[ 2.480022] ? sched_clock_cpu+0x10f/0x130
[ 2.480022] ? config_sync_direct_show+0x40/0x40
[ 2.480022] ? jhash+0x130/0x130
[ 2.480022] ? my_hashfn+0x30/0x30
[ 2.480022] ? test_rht_init+0x2b8/0x563
[ 2.480022] ? kfree+0x22a/0x2a0
[ 2.480022] ? igb_xmit_frame_ring+0x382/0xb90
[ 2.480022] ? test_rhashtable+0x773/0x773
[ 2.480022] ? do_one_initcall+0x90/0x13b
[ 2.480022] ? parse_args+0x1c0/0x2c0
[ 2.480022] ? do_early_param+0x78/0x78
[ 2.480022] ? kernel_init_freeable+0xf3/0x166
[ 2.480022] ? rest_init+0x1f0/0x1f0
[ 2.480022] ? kernel_init+0xd/0xf0
[ 2.480022] ? ret_from_fork+0x2e/0x38
[ 2.480022] Code: 39 d3 0f 83 03 01 00 00 83 7d dc 01 0f 84 d4 fe ff ff 68 00 06 f6 4b 83 c0 01 89 4d e4 a3 2c 49 c0 4c e8 90 43 d7 ff 5f 8b 4d e4 <0f> 0b e9 b4 fe ff ff 8d b6 00 00 00 00 a3 74 45 18 4c e9 fa fe
[ 2.480022] ---[ end trace e4315fcaa0eaa1bc ]---
[ 2.507561]
# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start v4.16 v4.15 --
git bisect good 1388c80438e69fc01d83fbe98da3cac24c3c8731 # 01:00 G 11 0 0 0 Merge branch 'sched-urgent-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good 98577c6aa2cddf73d55b6f1e2825a1f333ea1723 # 01:14 G 11 0 0 0 Merge tag 'chrome-platform-4.16-rc4-fixes' of git://git.kernel.org/pub/scm/linux/kernel/git/bleung/chrome-platform
git bisect good efac2483e8f289cd879e750075e63a9d16897e65 # 01:26 G 11 0 0 0 Merge branch 'for-4.16-fixes' of git://git.kernel.org/pub/scm/linux/kernel/git/tj/libata
git bisect bad f1869a890cdedb92a3fab969db5d0fd982850273 # 02:03 B 0 10 24 0 tty: vt: fix up tabstops properly
git bisect bad 9ec7ccc8f4f89843991cf692e89fc1fcbca85c83 # 02:38 B 0 11 25 0 Merge tag 'drm-fixes-for-v4.16-rc7' of git://people.freedesktop.org/~airlied/linux
git bisect good 76c0b6a36a1239494a5ae3c0dc83208a8112c483 # 02:51 G 11 0 0 0 Merge tag 'scsi-fixes' of git://git.kernel.org/pub/scm/linux/kernel/git/jejb/scsi
git bisect good 9ce207880d8e4b20b6c1bcd82c749970c2b9e6d2 # 03:02 G 11 0 0 0 Merge tag 'mmc-v4.16-rc4' of git://git.kernel.org/pub/scm/linux/kernel/git/ulfh/mmc
git bisect bad 394c73d396284897207dbb1bad2a43e621cb9dac # 03:35 B 0 7 21 0 Merge tag 'modules-for-v4.16-rc7' of git://git.kernel.org/pub/scm/linux/kernel/git/jeyu/linux
git bisect bad c4f4d2f917729e9b7b8bb452bf4971be93e7a15f # 04:09 B 0 4 18 0 Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net
git bisect bad 5a9f8df68ee6927f21dd3f2c75c16feb8b53a9e8 # 04:51 B 0 2 17 1 net: dsa: Fix dsa_is_user_port() test inversion
git bisect bad 652dfb2b31b076153c73106863a4a57e5318c152 # 05:31 B 0 3 17 0 Merge tag 'wireless-drivers-for-davem-2018-03-08' of git://git.kernel.org/pub/scm/linux/kernel/git/kvalo/wireless-drivers
git bisect bad 17cfe79a65f98abe535261856c5aef14f306dff7 # 06:09 B 0 1 15 0 l2tp: do not accept arbitrary sockets
git bisect bad 89036a2a9852f70dcec97d5962974fe806828382 # 06:50 B 0 5 19 0 Merge branch 'for-upstream' of git://git.kernel.org/pub/scm/linux/kernel/git/bluetooth/bluetooth
git bisect good 25b5cdfcce1b57971840505dfc78556bd12dea6d # 07:09 G 11 0 0 0 dt-bindings: net: renesas-ravb: Make stream buffer optional
git bisect bad 803fafbe0cd522fa6b9e41ca3b96cfb2e2a2222d # 07:46 B 0 2 16 0 fsl/fman: avoid sleeping in atomic context while adding an address
git bisect bad 499ac3b60f657dae82055fc81c7b01e6242ac9bc # 08:26 B 0 1 15 0 test_rhashtable: add test case for rhltable with duplicate objects
git bisect good d3dcf8eb615537526bd42ff27a081d46d337816e # 08:47 G 11 0 0 0 rhashtable: Fix rhlist duplicates insertion
# first bad commit: [499ac3b60f657dae82055fc81c7b01e6242ac9bc] test_rhashtable: add test case for rhltable with duplicate objects
git bisect good d3dcf8eb615537526bd42ff27a081d46d337816e # 09:07 G 31 0 0 0 rhashtable: Fix rhlist duplicates insertion
# extra tests with debug options
git bisect bad 499ac3b60f657dae82055fc81c7b01e6242ac9bc # 09:40 B 0 2 16 0 test_rhashtable: add test case for rhltable with duplicate objects
# extra tests on HEAD of linux-devel/devel-catchup-201810272014
git bisect bad bde3aebf99e207edd8f1d6a67d5a3e8663f31a52 # 09:45 B 0 21 38 0 0day head guard for 'devel-catchup-201810272014'
# extra tests on tree/branch linus/master
git bisect bad 69d5b97c597307773fe6c59775a5d5a88bb7e6b3 # 10:21 B 0 11 25 0 HID: we do not randomly make new drivers 'default y'
# extra tests on tree/branch linux-next/master
git bisect bad 8c60c36d0b8c92599b8f0ec391b5250bc40e8e05 # 10:55 B 0 1 15 0 Add linux-next specific files for 20181019
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
3 years, 8 months