October 2018 - LKP - Ml01.01.Org

Re: [LKP] [rcu] kernel BUG at include/linux/pagemap.h:149!

by Frederic Weisbecker

On Fri, Sep 11, 2015 at 10:19:47AM +0800, Boqun Feng wrote: > Subject: [PATCH 01/27] rcu: Don't disable preemption for Tiny and Tree RCU > readers > > Because preempt_disable() maps to barrier() for non-debug builds, > it forces the compiler to spill and reload registers. Because Tree > RCU and Tiny RCU now only appear in CONFIG_PREEMPT=n builds, these > barrier() instances generate needless extra code for each instance of > rcu_read_lock() and rcu_read_unlock(). This extra code slows down Tree > RCU and bloats Tiny RCU. > > This commit therefore removes the preempt_disable() and preempt_enable() > from the non-preemptible implementations of __rcu_read_lock() and > __rcu_read_unlock(), respectively. > > For debug purposes, preempt_disable() and preempt_enable() are still > kept if CONFIG_PREEMPT_COUNT=y, which makes the detection of sleeping > inside atomic sections still work in non-preemptible kernels. > > Signed-off-by: Boqun Feng <boqun.feng(a)gmail.com> > Signed-off-by: Paul E. McKenney <paulmck(a)linux.vnet.ibm.com> > --- > include/linux/rcupdate.h | 6 ++++-- > include/linux/rcutiny.h | 1 + > kernel/rcu/tree.c | 9 +++++++++ > 3 files changed, 14 insertions(+), 2 deletions(-) > > diff --git a/include/linux/rcupdate.h b/include/linux/rcupdate.h > index d63bb77..6c3cece 100644 > --- a/include/linux/rcupdate.h > +++ b/include/linux/rcupdate.h > @@ -297,12 +297,14 @@ void synchronize_rcu(void); > > static inline void __rcu_read_lock(void) > { > - preempt_disable(); > + if (IS_ENABLED(CONFIG_PREEMPT_COUNT)) > + preempt_disable(); preempt_disable() is a no-op when !CONFIG_PREEMPT_COUNT, right? Or rather it's a barrier(), which is anyway implied by rcu_read_lock(). So perhaps we can get rid of the IS_ENABLED() check?

1 year, 10 months

4
4
0 / 0

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

2 years, 2 months

3
4
0 / 0

[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

2 years, 3 months

2
2
0 / 0

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

2 years, 4 months

3
3
0 / 0

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

2 years, 5 months

1
0
0 / 0

[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

2 years, 5 months

2
1
0 / 0

[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

2 years, 5 months

1
0
0 / 0

[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

2 years, 5 months

1
0
0 / 0

[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

2 years, 5 months

1
0
0 / 0

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

2 years, 5 months

1
0
0 / 0

2021

2020

2019

2018

2017

2016

2015

2014

2013

LKP October 2018