[lkp-robot] [sched/fair] 806486c377: fsmark.app_overhead 39.4% improvement
by kernel test robot
Greeting,
FYI, we noticed a 39.4% improvement of fsmark.app_overhead due to commit:
commit: 806486c377e33ab662de6d47902e9e2a32b79368 ("sched/fair: Do not migrate if the prev_cpu is idle")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
in testcase: fsmark
on test machine: 4 threads Intel(R) Core(TM) i5-2300 CPU @ 2.80GHz with 4G memory
with following parameters:
iterations: 1x
nr_threads: 32t
disk: 1HDD
fs: ext4
filesize: 16MB
test_size: 60G
sync_method: fsyncBeforeClose
nr_directories: 16d
nr_files_per_directory: 256fpd
cpufreq_governor: performance
test-description: The fsmark is a file system benchmark to test synchronous write workloads, for example, mail servers workload.
test-url: https://sourceforge.net/projects/fsmark/
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
=========================================================================================
compiler/cpufreq_governor/disk/filesize/fs/iterations/kconfig/nr_directories/nr_files_per_directory/nr_threads/rootfs/sync_method/tbox_group/test_size/testcase:
gcc-7/performance/1HDD/16MB/ext4/1x/x86_64-rhel-7.2/16d/256fpd/32t/debian-x86_64-2016-08-31.cgz/fsyncBeforeClose/lkp-sb02/60G/fsmark
commit:
3b76c4a339 ("sched/fair: Restructure wake_affine*() to return a CPU id")
806486c377 ("sched/fair: Do not migrate if the prev_cpu is idle")
3b76c4a33959ca98 806486c377e33ab662de6d4790
---------------- --------------------------
fail:runs %reproduction fail:runs
| | |
0:4 -1% 0:4 perf-profile.children.cycles-pp.schedule_timeout
%stddev %change %stddev
\ | \
538776 ± 28% +39.4% 751196 ± 11% fsmark.app_overhead
57.14 +1.7% 58.08 fsmark.time.system_time
292997 ± 13% +205.4% 894676 ± 3% fsmark.time.voluntary_context_switches
75688 ± 9% +16.9% 88488 ± 5% meminfo.DirectMap4k
18.47 ± 48% -11.1 7.40 ± 14% mpstat.cpu.idle%
18446 ± 12% +24.3% 22936 ± 2% vmstat.system.cs
1064 ± 8% +23.9% 1318 ± 11% proc-vmstat.kswapd_low_wmark_hit_quickly
1471 ± 5% +15.5% 1699 ± 6% proc-vmstat.pageoutrun
1.082e+09 ± 3% -3.3% 1.047e+09 perf-stat.cache-misses
9715021 ± 2% +15.0% 11175392 ± 2% perf-stat.context-switches
27238 ± 4% -39.0% 16602 ± 2% perf-stat.cpu-migrations
2.654e+08 ± 31% -44.6% 1.469e+08 ± 11% cpuidle.C3.time
287354 ± 37% -46.0% 155067 ± 10% cpuidle.C3.usage
3.639e+08 ± 61% -67.4% 1.188e+08 ± 20% cpuidle.C6.time
403340 ± 67% -67.9% 129309 ± 18% cpuidle.C6.usage
225.50 ± 58% +66.0% 374.25 ± 12% turbostat.Avg_MHz
8.05 ± 58% +5.1 13.20 ± 11% turbostat.Busy%
872073 ± 58% +50.8% 1315008 ± 2% turbostat.C1E
0.35 ± 59% +144.6% 0.85 ± 31% turbostat.Pkg%pc3
130.50 ± 7% -17.8% 107.30 ± 10% sched_debug.cpu.cpu_load[2].stddev
80.59 ± 3% -12.9% 70.22 ± 10% sched_debug.cpu.cpu_load[3].stddev
7.46 ± 21% +142.8% 18.11 ± 76% sched_debug.cpu.cpu_load[4].min
174257 ± 16% +136.5% 412171 ± 8% sched_debug.cpu.nr_switches.min
511.80 ± 4% -66.6% 170.89 ± 32% sched_debug.cpu.nr_uninterruptible.max
-752.16 -80.6% -145.58 sched_debug.cpu.nr_uninterruptible.min
524.29 ± 7% -76.0% 125.75 ± 25% sched_debug.cpu.nr_uninterruptible.stddev
158052 ± 19% +153.6% 400742 ± 8% sched_debug.cpu.sched_count.min
74333 ± 22% +164.3% 196451 ± 9% sched_debug.cpu.sched_goidle.min
3.54 ± 12% -2.6 0.96 ±102% perf-profile.calltrace.cycles-pp.ret_from_intr.cpuidle_enter_state.do_idle.cpu_startup_entry.start_secondary
6.38 ± 16% -2.4 3.96 ± 33% perf-profile.calltrace.cycles-pp.kswapd.kthread.ret_from_fork
6.36 ± 16% -2.4 3.94 ± 33% perf-profile.calltrace.cycles-pp.shrink_node.kswapd.kthread.ret_from_fork
6.23 ± 16% -2.4 3.87 ± 33% perf-profile.calltrace.cycles-pp.shrink_node_memcg.shrink_node.kswapd.kthread.ret_from_fork
6.23 ± 16% -2.4 3.87 ± 33% perf-profile.calltrace.cycles-pp.shrink_inactive_list.shrink_node_memcg.shrink_node.kswapd.kthread
6.85 ± 12% -2.3 4.57 ± 29% perf-profile.calltrace.cycles-pp.ret_from_fork
6.85 ± 12% -2.3 4.57 ± 29% perf-profile.calltrace.cycles-pp.kthread.ret_from_fork
5.43 ± 18% -2.2 3.26 ± 35% perf-profile.calltrace.cycles-pp.shrink_page_list.shrink_inactive_list.shrink_node_memcg.shrink_node.kswapd
5.72 ± 24% -2.0 3.73 ± 34% perf-profile.calltrace.cycles-pp.pagecache_get_page.grab_cache_page_write_begin.ext4_da_write_begin.generic_perform_write.__generic_file_write_iter
2.83 ± 45% -2.0 0.84 ± 49% perf-profile.calltrace.cycles-pp.wait_for_xmitr.serial8250_console_putchar.uart_console_write.serial8250_console_write.console_unlock
2.46 ± 37% -1.8 0.66 ± 18% perf-profile.calltrace.cycles-pp.uart_console_write.serial8250_console_write.console_unlock.vprintk_emit.printk
2.46 ± 37% -1.8 0.67 ± 19% perf-profile.calltrace.cycles-pp.serial8250_console_write.console_unlock.vprintk_emit.printk.irq_work_run_list
2.44 ± 38% -1.8 0.65 ± 16% perf-profile.calltrace.cycles-pp.serial8250_console_putchar.uart_console_write.serial8250_console_write.console_unlock.vprintk_emit
2.71 ± 37% -1.6 1.11 ± 67% perf-profile.calltrace.cycles-pp.printk.irq_work_run_list.irq_work_run.smp_irq_work_interrupt.irq_work_interrupt
2.71 ± 37% -1.6 1.11 ± 67% perf-profile.calltrace.cycles-pp.vprintk_emit.printk.irq_work_run_list.irq_work_run.smp_irq_work_interrupt
2.71 ± 37% -1.6 1.11 ± 67% perf-profile.calltrace.cycles-pp.console_unlock.vprintk_emit.printk.irq_work_run_list.irq_work_run
4.65 ± 11% -1.5 3.12 ± 32% perf-profile.calltrace.cycles-pp.ext4_block_write_begin.ext4_da_write_begin.generic_perform_write.__generic_file_write_iter.ext4_file_write_iter
2.75 ± 48% -1.2 1.56 ± 27% perf-profile.calltrace.cycles-pp.ext4_do_update_inode.ext4_mark_iloc_dirty.ext4_mark_inode_dirty.ext4_dirty_inode.__mark_inode_dirty
2.84 ± 19% -1.1 1.76 ± 31% perf-profile.calltrace.cycles-pp.block_write_end.generic_write_end.ext4_da_write_end.generic_perform_write.__generic_file_write_iter
3.54 ± 12% -1.0 2.50 ± 26% perf-profile.calltrace.cycles-pp.do_IRQ.ret_from_intr.cpuidle_enter_state.do_idle.cpu_startup_entry
1.68 ± 4% -0.9 0.81 ± 58% perf-profile.calltrace.cycles-pp.create_empty_buffers.ext4_block_write_begin.ext4_da_write_begin.generic_perform_write.__generic_file_write_iter
1.54 ± 29% -0.8 0.73 ± 63% perf-profile.calltrace.cycles-pp.__remove_mapping.shrink_page_list.shrink_inactive_list.shrink_node_memcg.shrink_node
1.29 ± 12% -0.7 0.59 ± 61% perf-profile.calltrace.cycles-pp.alloc_page_buffers.create_empty_buffers.ext4_block_write_begin.ext4_da_write_begin.generic_perform_write
1.23 ± 11% -0.7 0.56 ± 60% perf-profile.calltrace.cycles-pp.alloc_buffer_head.alloc_page_buffers.create_empty_buffers.ext4_block_write_begin.ext4_da_write_begin
1.19 ± 12% -0.7 0.53 ± 60% perf-profile.calltrace.cycles-pp.kmem_cache_alloc.alloc_buffer_head.alloc_page_buffers.create_empty_buffers.ext4_block_write_begin
1.73 ± 23% -0.6 1.10 ± 32% perf-profile.calltrace.cycles-pp.intel_idle.cpuidle_enter_state.do_idle.cpu_startup_entry.start_secondary
1.27 ± 19% -0.6 0.65 ± 64% perf-profile.calltrace.cycles-pp.try_to_free_buffers.shrink_page_list.shrink_inactive_list.shrink_node_memcg.shrink_node
0.84 ± 24% -0.5 0.33 ±100% perf-profile.calltrace.cycles-pp.free_unref_page_commit.free_unref_page_list.shrink_page_list.shrink_inactive_list.shrink_node_memcg
0.96 ± 22% -0.5 0.50 ± 61% perf-profile.calltrace.cycles-pp.free_unref_page_list.shrink_page_list.shrink_inactive_list.shrink_node_memcg.shrink_node
0.77 ± 14% -0.3 0.46 ± 58% perf-profile.calltrace.cycles-pp.isolate_lru_pages.shrink_inactive_list.shrink_node_memcg.shrink_node.kswapd
6.42 ± 16% -2.5 3.94 ± 33% perf-profile.children.cycles-pp.shrink_node
6.30 ± 16% -2.4 3.87 ± 33% perf-profile.children.cycles-pp.shrink_inactive_list
6.38 ± 16% -2.4 3.96 ± 33% perf-profile.children.cycles-pp.kswapd
6.29 ± 16% -2.4 3.87 ± 33% perf-profile.children.cycles-pp.shrink_node_memcg
6.87 ± 12% -2.3 4.57 ± 29% perf-profile.children.cycles-pp.ret_from_fork
6.85 ± 12% -2.3 4.57 ± 29% perf-profile.children.cycles-pp.kthread
5.48 ± 18% -2.2 3.29 ± 36% perf-profile.children.cycles-pp.shrink_page_list
4.72 ± 12% -1.6 3.15 ± 32% perf-profile.children.cycles-pp.ext4_block_write_begin
3.61 ± 21% -1.3 2.30 ± 30% perf-profile.children.cycles-pp.serial8250_console_putchar
3.31 ± 17% -1.3 2.01 ± 25% perf-profile.children.cycles-pp.irq_work_interrupt
3.31 ± 17% -1.3 2.01 ± 25% perf-profile.children.cycles-pp.smp_irq_work_interrupt
3.31 ± 17% -1.3 2.01 ± 25% perf-profile.children.cycles-pp.irq_work_run
3.31 ± 17% -1.3 2.01 ± 25% perf-profile.children.cycles-pp.printk
3.31 ± 17% -1.3 2.01 ± 25% perf-profile.children.cycles-pp.vprintk_emit
3.62 ± 21% -1.3 2.33 ± 29% perf-profile.children.cycles-pp.wait_for_xmitr
2.36 ± 27% -0.9 1.43 ± 25% perf-profile.children.cycles-pp.intel_idle
1.75 ± 4% -0.8 0.93 ± 29% perf-profile.children.cycles-pp.kmem_cache_alloc
1.69 ± 3% -0.8 0.94 ± 30% perf-profile.children.cycles-pp.create_empty_buffers
1.33 ± 11% -0.6 0.69 ± 32% perf-profile.children.cycles-pp.alloc_page_buffers
1.29 ± 8% -0.6 0.68 ± 32% perf-profile.children.cycles-pp.alloc_buffer_head
1.29 ± 19% -0.5 0.76 ± 36% perf-profile.children.cycles-pp.try_to_free_buffers
1.22 ± 17% -0.5 0.76 ± 28% perf-profile.children.cycles-pp.delay_tsc
1.02 ± 20% -0.4 0.66 ± 32% perf-profile.children.cycles-pp.free_unref_page_list
0.87 ± 22% -0.3 0.52 ± 37% perf-profile.children.cycles-pp.free_unref_page_commit
0.56 ± 44% -0.3 0.22 ± 31% perf-profile.children.cycles-pp.scsi_run_queue
0.75 ± 25% -0.3 0.42 ± 29% perf-profile.children.cycles-pp.clear_page_dirty_for_io
1.06 ± 18% -0.3 0.72 ± 25% perf-profile.children.cycles-pp._raw_spin_lock_irqsave
0.61 ± 20% -0.3 0.29 ± 49% perf-profile.children.cycles-pp.page_fault
0.61 ± 21% -0.3 0.29 ± 47% perf-profile.children.cycles-pp.do_page_fault
0.61 ± 21% -0.3 0.29 ± 47% perf-profile.children.cycles-pp.__do_page_fault
0.74 ± 27% -0.3 0.43 ± 38% perf-profile.children.cycles-pp.free_pcppages_bulk
0.55 ± 46% -0.3 0.25 ± 37% perf-profile.children.cycles-pp.__slab_alloc
0.65 ± 35% -0.3 0.36 ± 43% perf-profile.children.cycles-pp.drop_buffers
0.70 ± 22% -0.2 0.45 ± 42% perf-profile.children.cycles-pp._raw_read_lock
0.45 ± 31% -0.2 0.21 ± 13% perf-profile.children.cycles-pp.radix_tree_tag_set
0.55 ± 29% -0.2 0.31 ± 16% perf-profile.children.cycles-pp.__tick_nohz_idle_enter
0.78 ± 11% -0.2 0.55 ± 22% perf-profile.children.cycles-pp.isolate_lru_pages
0.53 ± 20% -0.2 0.31 ± 35% perf-profile.children.cycles-pp.account_page_dirtied
0.43 ± 9% -0.2 0.22 ± 31% perf-profile.children.cycles-pp.blk_run_queue
0.44 ± 9% -0.2 0.24 ± 28% perf-profile.children.cycles-pp.__blk_run_queue
0.44 ± 9% -0.2 0.24 ± 28% perf-profile.children.cycles-pp.scsi_request_fn
0.44 ± 36% -0.2 0.24 ± 42% perf-profile.children.cycles-pp.find_get_entry
0.30 ± 19% -0.2 0.13 ± 41% perf-profile.children.cycles-pp.mem_cgroup_commit_charge
0.32 ± 31% -0.2 0.15 ± 16% perf-profile.children.cycles-pp.dec_zone_page_state
0.32 ± 17% -0.2 0.16 ± 25% perf-profile.children.cycles-pp.blk_peek_request
0.29 ± 40% -0.2 0.13 ± 44% perf-profile.children.cycles-pp.blk_queue_split
0.39 ± 32% -0.2 0.23 ± 24% perf-profile.children.cycles-pp.execve
0.40 ± 11% -0.2 0.24 ± 37% perf-profile.children.cycles-pp.__getblk_gfp
0.30 ± 15% -0.1 0.16 ± 27% perf-profile.children.cycles-pp.scsi_prep_fn
0.27 ± 15% -0.1 0.13 ± 37% perf-profile.children.cycles-pp.__radix_tree_create
0.20 ± 26% -0.1 0.07 ± 60% perf-profile.children.cycles-pp.__mod_node_page_state
0.23 ± 29% -0.1 0.11 ± 59% perf-profile.children.cycles-pp.do_filp_open
0.17 ± 40% -0.1 0.05 ± 62% perf-profile.children.cycles-pp.__brelse
0.22 ± 32% -0.1 0.11 ± 59% perf-profile.children.cycles-pp.path_openat
0.21 ± 19% -0.1 0.10 ± 46% perf-profile.children.cycles-pp.do_sys_open
0.27 ± 9% -0.1 0.16 ± 32% perf-profile.children.cycles-pp.ktime_get
0.24 ± 24% -0.1 0.13 ± 31% perf-profile.children.cycles-pp.blk_rq_map_sg
0.24 ± 29% -0.1 0.14 ± 39% perf-profile.children.cycles-pp.ahci_single_level_irq_intr
0.24 ± 9% -0.1 0.14 ± 19% perf-profile.children.cycles-pp.clockevents_program_event
0.15 ± 26% -0.1 0.05 ± 74% perf-profile.children.cycles-pp.ahci_handle_port_interrupt
0.24 ± 5% -0.1 0.14 ± 43% perf-profile.children.cycles-pp.drm_fb_helper_cfb_imageblit
0.24 ± 5% -0.1 0.14 ± 43% perf-profile.children.cycles-pp.cfb_imageblit
0.14 ± 30% -0.1 0.06 ± 58% perf-profile.children.cycles-pp.__wake_up_common_lock
0.24 ± 20% -0.1 0.15 ± 23% perf-profile.children.cycles-pp.search_binary_handler
0.23 ± 21% -0.1 0.15 ± 23% perf-profile.children.cycles-pp.load_elf_binary
0.27 ± 12% -0.1 0.19 ± 32% perf-profile.children.cycles-pp.bit_putcs
0.18 ± 8% -0.1 0.12 ± 30% perf-profile.children.cycles-pp.__list_add_valid
0.15 ± 19% -0.1 0.10 ± 31% perf-profile.children.cycles-pp.lapic_next_deadline
0.08 ± 26% +0.1 0.14 ± 27% perf-profile.children.cycles-pp.kjournald2
0.08 ± 26% +0.1 0.14 ± 27% perf-profile.children.cycles-pp.jbd2_journal_commit_transaction
0.01 ±173% +0.1 0.08 ± 24% perf-profile.children.cycles-pp.rcu_process_callbacks
0.00 +0.1 0.10 ± 26% perf-profile.children.cycles-pp.filemap_fdatawait_keep_errors
0.32 ± 49% +0.5 0.79 ± 32% perf-profile.children.cycles-pp.wake_up_page_bit
2.34 ± 27% -0.9 1.42 ± 25% perf-profile.self.cycles-pp.intel_idle
2.06 ± 16% -0.7 1.36 ± 33% perf-profile.self.cycles-pp.block_write_end
1.06 ± 29% -0.5 0.59 ± 32% perf-profile.self.cycles-pp.get_page_from_freelist
1.22 ± 17% -0.5 0.76 ± 28% perf-profile.self.cycles-pp.delay_tsc
0.78 ± 12% -0.3 0.51 ± 22% perf-profile.self.cycles-pp.ext4_finish_bio
0.69 ± 22% -0.3 0.43 ± 42% perf-profile.self.cycles-pp._raw_read_lock
0.57 ± 24% -0.2 0.32 ± 41% perf-profile.self.cycles-pp.free_pcppages_bulk
0.59 ± 20% -0.2 0.35 ± 25% perf-profile.self.cycles-pp.ext4_bio_write_page
0.45 ± 31% -0.2 0.21 ± 13% perf-profile.self.cycles-pp.radix_tree_tag_set
0.47 ± 29% -0.2 0.26 ± 31% perf-profile.self.cycles-pp.ext4_journal_check_start
0.39 ± 20% -0.2 0.21 ± 23% perf-profile.self.cycles-pp.__test_set_page_writeback
0.32 ± 31% -0.2 0.15 ± 16% perf-profile.self.cycles-pp.dec_zone_page_state
0.36 ± 26% -0.1 0.22 ± 26% perf-profile.self.cycles-pp.mpage_map_and_submit_buffers
0.20 ± 26% -0.1 0.07 ± 60% perf-profile.self.cycles-pp.__mod_node_page_state
0.32 ± 17% -0.1 0.20 ± 35% perf-profile.self.cycles-pp.cpuidle_enter_state
0.17 ± 40% -0.1 0.05 ± 62% perf-profile.self.cycles-pp.__brelse
0.16 ± 31% -0.1 0.06 ± 60% perf-profile.self.cycles-pp.balance_dirty_pages_ratelimited
0.21 ± 10% -0.1 0.11 ± 34% perf-profile.self.cycles-pp.__radix_tree_create
0.23 ± 26% -0.1 0.12 ± 33% perf-profile.self.cycles-pp.blk_rq_map_sg
0.24 ± 33% -0.1 0.13 ± 17% perf-profile.self.cycles-pp.__remove_mapping
0.24 ± 19% -0.1 0.14 ± 28% perf-profile.self.cycles-pp.jbd2__journal_start
0.24 ± 5% -0.1 0.14 ± 43% perf-profile.self.cycles-pp.cfb_imageblit
0.22 ± 9% -0.1 0.14 ± 38% perf-profile.self.cycles-pp.__find_get_block
0.12 ± 35% -0.1 0.04 ±107% perf-profile.self.cycles-pp.__lru_cache_add
0.11 ± 27% -0.1 0.04 ±107% perf-profile.self.cycles-pp.ktime_get
0.15 ± 22% -0.1 0.07 ± 65% perf-profile.self.cycles-pp.pagecache_get_page
0.11 ± 17% -0.1 0.04 ±100% perf-profile.self.cycles-pp.entry_SYSCALL_64_fastpath
0.18 ± 8% -0.1 0.12 ± 30% perf-profile.self.cycles-pp.__list_add_valid
0.12 ± 24% -0.1 0.07 ± 19% perf-profile.self.cycles-pp.mem_cgroup_commit_charge
0.08 ± 21% -0.1 0.03 ±102% perf-profile.self.cycles-pp.ext4_mark_inode_dirty
0.05 ± 62% +0.1 0.13 ± 27% perf-profile.self.cycles-pp.try_to_wake_up
34.50 ± 37% +19.8 54.29 ± 23% perf-profile.self.cycles-pp.poll_idle
perf-stat.cpu-migrations
30000 +-+-----------------------------------------------------------------+
| + + + + +. |
28000 +-+ + + + : + + + .+ + + + +.+ |
26000 +-+.+ +.+ : + + .+ + + .+ +. .+.+.+. .+ +|
| + + +.+.+.+ + + + +.+.+ |
24000 +-+ + + |
| + |
22000 +-+ |
| |
20000 +-+ |
18000 +-+ O O |
O O O O O O O O O O O O |
16000 +-+ O O O O O O |
| O |
14000 +-+-----------------------------------------------------------------+
fsmark.time.voluntary_context_switches
1e+06 +-+----------------------------------------------------------------+
| O O O |
900000 +-+ O O O O O O |
O O O O O O O O O O O |
800000 +-O |
700000 +-+ |
| |
600000 +-+ |
| |
500000 +-+ |
400000 +-+ |
|.+. .+.+. .+ .+. .+. .+. .+. .+.+. |
300000 +-+ +.+.+ +.+.+.+ + .+ +.+.++ +.+.+ + +.+.+.+ +. |
| + +.|
200000 +-+----------------------------------------------------------------+
time.voluntary_context_switches
1e+06 +-+----------------------------------------------------------------+
| O O O |
900000 +-+ O O O O O O |
O O O O O O O O O O O |
800000 +-O |
700000 +-+ |
| |
600000 +-+ |
| |
500000 +-+ |
400000 +-+ |
|.+. .+.+. .+ .+. .+. .+. .+. .+.+. |
300000 +-+ +.+.+ +.+.+.+ + .+ +.+.++ +.+.+ + +.+.+.+ +. |
| + +.|
200000 +-+----------------------------------------------------------------+
[*] 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.
4 years, 5 months
- 1
- 0
[lkp-robot] [bisect done] f66871fb4c [ 32.038007] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [start-stop-daem:328]
by kernel test robot
Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
https://github.com/0day-ci/linux/commits/Daniel-Colascione/Synchronize-ta...
commit f66871fb4ce1e3784559ed297cfe868615c93102
Author: Daniel Colascione <dancol(a)google.com>
AuthorDate: Wed Feb 21 18:46:20 2018 -0800
Commit: 0day robot <fengguang.wu(a)intel.com>
CommitDate: Thu Feb 22 23:13:23 2018 +0800
Synchronize task mm counters on demand
When SPLIT_RSS_COUNTING is in use (which it is on SMP systems,
generally speaking), we buffer certain changes to mm-wide counters
through counters local to the current struct task, flushing them to
the mm after seeing 64 page faults, as well as on task exit and
exec. This scheme can leave a large amount of memory unaccounted-for
in process memory counters, especially for processes with many threads
(each of which gets 64 "free" faults), and it produces an
inconsistency with the same memory counters scanned VMA-by-VMA using
smaps. This inconsistency can persist for an arbitrarily long time,
since there is no way to force a task to flush its counters to its mm.
This patch flushes counters on get_mm_counter. This way, readers
always have an up-to-date view of the counters for a particular
task. It adds a spinlock-acquire to the add_mm_counter_fast path, but
this spinlock should almost always be uncontended.
Signed-off-by: Daniel Colascione <dancol(a)google.com>
af3e79d295 Merge tag 'leds_for-4.16-rc3' of git://git.kernel.org/pub/scm/linux/kernel/git/j.anaszewski/linux-leds
f66871fb4c Synchronize task mm counters on demand
+------------------------------------------------------------------+------------+------------+
| | af3e79d295 | f66871fb4c |
+------------------------------------------------------------------+------------+------------+
| boot_successes | 264 | 18 |
| boot_failures | 0 | 161 |
| INFO:rcu_sched_detected_stalls_on_CPUs/tasks | 0 | 30 |
| RIP:native_queued_spin_lock_slowpath | 0 | 31 |
| RIP:_raw_spin_lock | 0 | 19 |
| BUG:kernel_hang_in_test_stage | 0 | 107 |
| RIP:native_safe_halt | 0 | 7 |
| BUG:soft_lockup-CPU##stuck_for#s | 0 | 24 |
| RIP:smp_call_function_single | 0 | 17 |
| Kernel_panic-not_syncing:softlockup:hung_tasks | 0 | 25 |
| RIP:add_mm_counter_fast | 0 | 3 |
| BUG:kernel_hang_in_boot_stage | 0 | 24 |
| RIP:get_files_struct | 0 | 1 |
| invoked_oom-killer:gfp_mask=0x | 0 | 4 |
| Mem-Info | 0 | 4 |
| Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 0 | 4 |
+------------------------------------------------------------------+------------+------------+
[ 4.165742] init: Failed to create pty - disabling logging for job
[ 4.167886] init: Temporary process spawn error: No such file or directory
[ 4.173143] init: udev-fallback-graphics main process (307) terminated with status 127
[ 4.217681] init: Failed to create pty - disabling logging for job
[ 4.218983] init: Temporary process spawn error: No such file or directory
[ 32.038007] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [start-stop-daem:328]
[ 32.041497] Modules linked in:
[ 32.042242] CPU: 0 PID: 328 Comm: start-stop-daem Not tainted 4.16.0-rc2-00065-gf66871f #1
[ 32.043963] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 32.045706] RIP: 0010:native_queued_spin_lock_slowpath+0x21/0x190
[ 32.047709] RSP: 0018:ffffc900006bfd28 EFLAGS: 00000202 ORIG_RAX: ffffffffffffff12
[ 32.055282] RAX: 0000000000000001 RBX: ffff88000ab52540 RCX: ffff88000c6fd590
[ 32.058771] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffff88000ab530f8
[ 32.061111] RBP: 0000000000000000 R08: ffff88000c6fd400 R09: 0000000000000000
[ 32.064523] R10: ffff88000abad898 R11: ffffc900006bfe38 R12: 0000000000000000
[ 32.067047] R13: ffff88000ab530f8 R14: ffff88000c6fd590 R15: ffff88000c6fd58c
[ 32.070276] FS: 00007f12bbc21700(0000) GS:ffff880011e00000(0000) knlGS:0000000000000000
[ 32.073731] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 32.076029] CR2: 00000000015f1000 CR3: 000000000aca2000 CR4: 00000000000006f0
[ 32.079350] Call Trace:
[ 32.080289] _raw_spin_lock+0x24/0x30
[ 32.082414] task_dump_owner+0x4a/0xc0
[ 32.084047] ? proc_pid_make_inode+0xb0/0xb0
[ 32.085943] proc_pid_make_inode+0x82/0xb0
[ 32.088277] proc_pid_instantiate+0x1b/0x80
[ 32.089881] proc_fill_cache+0xee/0x160
[ 32.091691] proc_pid_readdir+0x123/0x200
[ 32.092617] iterate_dir+0x95/0x180
[ 32.095430] SyS_getdents+0xa3/0x130
[ 32.097374] ? fillonedir+0x100/0x100
[ 32.098240] ? do_syscall_64+0x74/0x190
[ 32.100710] do_syscall_64+0x74/0x190
[ 32.102491] entry_SYSCALL_64_after_hwframe+0x3d/0xa2
[ 32.104701] RIP: 0033:0x7f12bb7022b5
[ 32.106452] RSP: 002b:00007ffe95124e00 EFLAGS: 00000246 ORIG_RAX: 000000000000004e
[ 32.109292] RAX: ffffffffffffffda RBX: 00000000015f0010 RCX: 00007f12bb7022b5
[ 32.112309] RDX: 0000000000008000 RSI: 00000000015f0038 RDI: 0000000000000003
[ 32.115725] RBP: ffffffffffffffa0 R08: 00000000015f0038 R09: 0000000000000000
[ 32.119289] R10: 00007ffe95124bf0 R11: 0000000000000246 R12: 0000000000000000
[ 32.121343] R13: 00000000015f0038 R14: 0000000000000000 R15: 0000000000000000
[ 32.124407] Code: 00 00 00 00 00 e9 8e fe ff ff 0f 1f 44 00 00 0f 1f 44 00 00 ba 01 00 00 00 8b 07 85 c0 75 0a f0 0f b1 17 85 c0 75 f2 f3 c3 f3 90 <eb> ec 81 fe 00 01 00 00 0f 84 91 00 00 00 41 b8 01 01 00 00 b9
[ 32.132455] Kernel panic - not syncing: softlockup: hung tasks
[ 32.134453] CPU: 0 PID: 328 Comm: start-stop-daem Tainted: G L 4.16.0-rc2-00065-gf66871f #1
[ 32.139276] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 32.142407] Call Trace:
[ 32.143733] <IRQ>
[ 32.145255] dump_stack+0x5c/0x7b
[ 32.147418] panic+0xd5/0x242
[ 32.148273] watchdog_timer_fn+0x20e/0x220
[ 32.151295] ? watchdog+0x30/0x30
[ 32.152081] __hrtimer_run_queues+0xfa/0x290
[ 32.153058] hrtimer_interrupt+0xe5/0x240
[ 32.153979] smp_apic_timer_interrupt+0x62/0x140
[ 32.154994] apic_timer_interrupt+0x87/0x90
[ 32.155939] </IRQ>
[ 32.156568] RIP: 0010:native_queued_spin_lock_slowpath+0x21/0x190
[ 32.157810] RSP: 0018:ffffc900006bfd28 EFLAGS: 00000202 ORIG_RAX: ffffffffffffff12
[ 32.159486] RAX: 0000000000000001 RBX: ffff88000ab52540 RCX: ffff88000c6fd590
[ 32.164597] RDX: 0000000000000001 RSI: 0000000000000001 RDI: ffff88000ab530f8
[ 32.166013] RBP: 0000000000000000 R08: ffff88000c6fd400 R09: 0000000000000000
[ 32.167454] R10: ffff88000abad898 R11: ffffc900006bfe38 R12: 0000000000000000
[ 32.170702] R13: ffff88000ab530f8 R14: ffff88000c6fd590 R15: ffff88000c6fd58c
[ 32.172120] _raw_spin_lock+0x24/0x30
[ 32.172996] task_dump_owner+0x4a/0xc0
[ 32.173874] ? proc_pid_make_inode+0xb0/0xb0
[ 32.174833] proc_pid_make_inode+0x82/0xb0
[ 32.175768] proc_pid_instantiate+0x1b/0x80
[ 32.176724] proc_fill_cache+0xee/0x160
[ 32.177618] proc_pid_readdir+0x123/0x200
[ 32.178532] iterate_dir+0x95/0x180
[ 32.179367] SyS_getdents+0xa3/0x130
[ 32.180190] ? fillonedir+0x100/0x100
[ 32.181067] ? do_syscall_64+0x74/0x190
[ 32.181956] do_syscall_64+0x74/0x190
[ 32.182883] entry_SYSCALL_64_after_hwframe+0x3d/0xa2
[ 32.183969] RIP: 0033:0x7f12bb7022b5
[ 32.184835] RSP: 002b:00007ffe95124e00 EFLAGS: 00000246 ORIG_RAX: 000000000000004e
[ 32.186512] RAX: ffffffffffffffda RBX: 00000000015f0010 RCX: 00007f12bb7022b5
[ 32.187919] RDX: 0000000000008000 RSI: 00000000015f0038 RDI: 0000000000000003
[ 32.189367] RBP: ffffffffffffffa0 R08: 00000000015f0038 R09: 0000000000000000
[ 32.190776] R10: 00007ffe95124bf0 R11: 0000000000000246 R12: 0000000000000000
[ 32.192184] R13: 00000000015f0038 R14: 0000000000000000 R15: 0000000000000000
[ 33.279130] Shutting down cpus with NMI
[ 33.280388] Kernel Offset: disabled
# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start 67da6932ac13398a68f12daf6a69a92f14b2fca3 91ab883eb21325ad80f3473633f794c78ac87f51 --
git bisect bad 9649b0f9608fe7e0111cd78045126d508a57b091 # 13:04 B 5 1 4 10 Merge 'peterz-queue/core/locking' into devel-hourly-2018022305
git bisect good 5f4a2c02e33ce6f69c8d92effc652ed91af8e87d # 01:16 G 28 0 0 6 Merge 'linux-review/Richard-Leitner/usb-core-introduce-per-port-over-current-counters/20180220-210533' into devel-hourly-2018022305
git bisect good 3d8b77d16570ea42bde7e4ed11be362887fc163c # 01:30 G 29 0 0 0 Merge 'linux-review/Kai-Heng-Feng/libata-disable-LPM-for-Crucial-BX100-SSD-500GB-drive/20180219-171709' into devel-hourly-2018022305
git bisect good 0a38e181306212ac44cce9e35f3fa92811383322 # 14:20 G 28 0 0 7 Merge 'linux-review/Bartosz-Golaszewski/nand-davinci-rename-the-platform-driver/20180219-045139' into devel-hourly-2018022305
git bisect good 29671b8f51a009c9be5f6d761ef6fd30b2a72712 # 03:16 G 29 0 0 5 Merge 'wsa/i2c/for-current' into devel-hourly-2018022305
git bisect bad a00ccc43afdfa225afb899e16fb05ec18d7a92ff # 03:31 B 6 1 5 5 Merge 'linux-review/Saeed-Mahameed/Mellanox-mlx5-shared-code-updates-2018-02-21/20180222-225258' into devel-hourly-2018022305
git bisect bad 1134a36e4604a2ac8cdfd6641d7346d91c691e25 # 03:57 B 10 1 4 8 Merge 'dw-mmc/for-ulf' into devel-hourly-2018022305
git bisect good b148b7138edd9d192c79940dd114e7eba48f5e2c # 04:24 G 88 0 0 5 Merge 'linux-review/Lina-Iyer/drivers-qcom-add-command-DB-driver/20180219-041927' into devel-hourly-2018022305
git bisect good 57fc3ee482bcbfbbf47e609c7c60b8549a5872ed # 16:18 G 89 0 0 6 Merge 'hverkuil-media/media-fixes' into devel-hourly-2018022305
git bisect bad e2138614eff5c2e266a110aa6762a3139adc101c # 16:44 B 6 1 4 4 Merge 'linux-review/Daniel-Colascione/Synchronize-task-mm-counters-on-demand/20180222-231321' into devel-hourly-2018022305
git bisect bad f66871fb4ce1e3784559ed297cfe868615c93102 # 17:36 B 2 1 2 4 Synchronize task mm counters on demand
# first bad commit: [f66871fb4ce1e3784559ed297cfe868615c93102] Synchronize task mm counters on demand
git bisect good af3e79d29555b97dd096e2f8e36a0f50213808a8 # 06:20 G 255 0 1 2 Merge tag 'leds_for-4.16-rc3' of git://git.kernel.org/pub/scm/linux/kernel/git/j.anaszewski/linux-leds
# extra tests on HEAD of linux-devel/devel-hourly-2018022305
git bisect bad 67da6932ac13398a68f12daf6a69a92f14b2fca3 # 06:21 B 0 6 29 6 0day head guard for 'devel-hourly-2018022305'
# extra tests on tree/branch linux-review/Daniel-Colascione/Synchronize-task-mm-counters-on-demand/20180222-231321
git bisect bad f66871fb4ce1e3784559ed297cfe868615c93102 # 06:23 B 12 22 0 80 Synchronize task mm counters on demand
# extra tests with first bad commit reverted
git bisect good 8dc66f788762d7e5eed17e38ef429e7787b1b960 # 19:18 G 86 0 0 0 Revert "Synchronize task mm counters on demand"
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
4 years, 5 months
- 1
- 0
91f606a8fa ("x86/mm: Replace compile-time checks for 5-level .."): BUG: kernel reboot-without-warning in boot stage
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/tip/tip.git x86/mm
commit 91f606a8fa68264224cbc76888fa8649cdbe9990
Author: Kirill A. Shutemov <kirill.shutemov(a)linux.intel.com>
AuthorDate: Wed Feb 14 21:25:41 2018 +0300
Commit: Ingo Molnar <mingo(a)kernel.org>
CommitDate: Fri Feb 16 10:48:49 2018 +0100
x86/mm: Replace compile-time checks for 5-level paging with runtime-time checks
This patch converts the of CONFIG_X86_5LEVEL check to runtime checks for
p4d folding.
Signed-off-by: Kirill A. Shutemov <kirill.shutemov(a)linux.intel.com>
Cc: Andy Lutomirski <luto(a)kernel.org>
Cc: Arjan van de Ven <arjan(a)linux.intel.com>
Cc: Borislav Petkov <bp(a)suse.de>
Cc: Dan Williams <dan.j.williams(a)intel.com>
Cc: Dave Hansen <dave.hansen(a)linux.intel.com>
Cc: David Woodhouse <dwmw2(a)infradead.org>
Cc: Josh Poimboeuf <jpoimboe(a)redhat.com>
Cc: Linus Torvalds <torvalds(a)linux-foundation.org>
Cc: Peter Zijlstra <peterz(a)infradead.org>
Cc: Thomas Gleixner <tglx(a)linutronix.de>
Cc: linux-mm(a)kvack.org
Link: http://lkml.kernel.org/r/20180214182542.69302-9-kirill.shutemov@linux.int...
Signed-off-by: Ingo Molnar <mingo(a)kernel.org>
98219dda2a x86/mm: Fold p4d page table layer at runtime
91f606a8fa x86/mm: Replace compile-time checks for 5-level paging with runtime-time checks
1ea4fe8497 Merge branch 'x86/boot' into x86/mm, to unify branches
94991480c2 Merge branch 'x86/pti'
f1753f6424 Add linux-next specific files for 20180226
+------------------------------------------------------------------+------------+------------+------------+------------+---------------+
| | 98219dda2a | 91f606a8fa | 1ea4fe8497 | 94991480c2 | next-20180226 |
+------------------------------------------------------------------+------------+------------+------------+------------+---------------+
| boot_successes | 7 | 0 | 0 | 0 | 0 |
| boot_failures | 5 | 13 | 17 | 13 | 25 |
| invoked_oom-killer:gfp_mask=0x | 4 | | | | |
| Mem-Info | 5 | | | | |
| Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 4 | | | | |
| BUG:kernel_reboot-without-warning_in_boot_stage | 0 | 13 | 17 | 13 | 25 |
+------------------------------------------------------------------+------------+------------+------------+------------+---------------+
output_len: 0x000000000566b910
kernel_total_size: 0x000000000670c000
Decompressing Linux... Parsing ELF... done.
Booting the kernel.
BUG: kernel reboot-without-warning in boot stage
Linux version 4.16.0-rc1-00031-g91f606a #1
Command line: root=/dev/ram0 hung_task_panic=1 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 link=/kbuild-tests/run-queue/yocto-kbuild/x86_64-randconfig-s3-02261607/linux-next:master:91f606a8fa68264224cbc76888fa8649cdbe9990:bisect-linux-22/.vmlinuz-91f606a8fa68264224cbc76888fa8649cdbe9990-20180226205630-1:yocto-kbuild-19 branch=linux-next/master BOOT_IMAGE=/pkg/linux/x86_64-randconfig-s3-02261607/gcc-7/91f606a8fa68264224cbc76888fa8649cdbe9990/vmlinuz-4.16.0-rc1-00031-g91f606a drbd.minor_count=8 rcuperf.shutdown=0
# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start f1753f6424875430d9f411c9a54c953e6465eb93 91ab883eb21325ad80f3473633f794c78ac87f51 --
git bisect good a6ceb636d19729dd1c1b15fbc12b04151c9b1c02 # 17:27 G 11 0 11 11 Merge remote-tracking branch 'nfs-anna/linux-next'
git bisect good cc6a7802eedbf39af3a04e6571050405c87d8171 # 17:49 G 11 0 8 8 Merge remote-tracking branch 'integrity/next-integrity'
git bisect bad b9ad93fa8cc49b00a91f858bc44bd4977733fa28 # 17:58 B 0 2 15 0 Merge remote-tracking branch 'phy-next/next'
git bisect bad 4a292cc22a47ced6fb77685dbb899d151e8b7e45 # 18:17 B 0 6 19 0 Merge remote-tracking branch 'edac-amd/for-next'
git bisect good 0f09e553fecff33502d87af0df252ff904883cbf # 18:36 G 10 0 7 7 Merge remote-tracking branch 'audit/next'
git bisect good 791aa391df0b31d4f5cf23be5d62e2359964fbb4 # 18:55 G 10 0 9 11 Merge remote-tracking branch 'spi/for-next'
git bisect bad 35ea8770bdbcf2b22a91a054f5eaed15ea2ad916 # 19:13 B 0 1 14 0 Merge remote-tracking branch 'tip/auto-latest'
git bisect good b73d26d3ff70dcfa7723c69b9ab9069952beb5ca # 19:38 G 11 0 10 12 Merge branch 'sched/core'
git bisect bad 230bd3e3d1dcc0f7c01cde1c4027e1eb32077514 # 19:46 B 0 2 15 0 Merge branch 'x86/mm'
git bisect bad 39b9552281abfcdfc54162897018890dafe7ffef # 20:03 B 0 1 14 0 x86/mm: Optimize boot-time paging mode switching cost
git bisect good 162434e7f58b21f0b6c9cc5fb02222cd7d9064cc # 20:27 G 10 0 6 6 x86/mm: Make MAX_PHYSADDR_BITS and MAX_PHYSMEM_BITS dynamic
git bisect good 9b46a051e43461a9afda2bdd50e0e0ae349341df # 20:47 G 11 0 5 7 x86/mm: Initialize vmemmap_base at boot-time
git bisect bad 91f606a8fa68264224cbc76888fa8649cdbe9990 # 20:57 B 0 4 17 0 x86/mm: Replace compile-time checks for 5-level paging with runtime-time checks
git bisect good 98219dda2ab56ce2a967fdebf81e838d676d9ddc # 21:20 G 10 0 9 11 x86/mm: Fold p4d page table layer at runtime
# first bad commit: [91f606a8fa68264224cbc76888fa8649cdbe9990] x86/mm: Replace compile-time checks for 5-level paging with runtime-time checks
git bisect good 98219dda2ab56ce2a967fdebf81e838d676d9ddc # 21:46 G 31 0 24 37 x86/mm: Fold p4d page table layer at runtime
# extra tests with debug options
git bisect bad 91f606a8fa68264224cbc76888fa8649cdbe9990 # 21:55 B 0 9 22 0 x86/mm: Replace compile-time checks for 5-level paging with runtime-time checks
# extra tests on HEAD of linux-next/master
git bisect bad f1753f6424875430d9f411c9a54c953e6465eb93 # 21:56 B 0 25 41 0 Add linux-next specific files for 20180226
# extra tests on tree/branch tip/x86/mm
git bisect bad 1ea4fe84973854a7302e4d1c479f10ae25a93e4a # 22:08 B 0 2 15 0 Merge branch 'x86/boot' into x86/mm, to unify branches
# extra tests with first bad commit reverted
git bisect good 9cb27f6ed298cb2fa24f814d8019781024abc06a # 22:53 G 11 0 6 6 Revert "x86/mm: Replace compile-time checks for 5-level paging with runtime-time checks"
# extra tests on tree/branch tip/master
git bisect bad 94991480c27894fbfc13c5d5867a6adec26022dc # 23:06 B 0 1 14 0 Merge branch 'x86/pti'
# extra tests on tree/branch linux-next/master
git bisect bad f1753f6424875430d9f411c9a54c953e6465eb93 # 23:12 B 0 25 41 0 Add linux-next specific files for 20180226
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
4 years, 5 months
- 2
- 1
351ea48b88 ("force skylake for easier testing"): BUG: kernel hang in boot stage
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/ak/linux-misc.git spec/ftrace-stuff-11
commit 351ea48b88b7bded0f83d43bff8cb324e97687ad
Author: Andi Kleen <ak(a)linux.intel.com>
AuthorDate: Thu Feb 8 11:26:13 2018 -0800
Commit: Andi Kleen <ak(a)linux.intel.com>
CommitDate: Mon Feb 26 11:10:55 2018 -0800
force skylake for easier testing
ac15830618 x86/deepchain: Instrument call chain even for notrace functions
351ea48b88 force skylake for easier testing
aebafb2a3a fixup! x86/deepchain: Instrument call chain even for notrace functions
+------------------------------------------------------------------+------------+------------+------------+
| | ac15830618 | 351ea48b88 | aebafb2a3a |
+------------------------------------------------------------------+------------+------------+------------+
| boot_successes | 31 | 0 | 0 |
| boot_failures | 5 | 15 | 15 |
| invoked_oom-killer:gfp_mask=0x | 4 | | |
| Mem-Info | 5 | | |
| Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 4 | | |
| BUG:kernel_hang_in_boot_stage | 0 | 15 | 15 |
+------------------------------------------------------------------+------------+------------+------------+
[ 0.000000] Memory: 275272K/523712K available (12300K kernel code, 2549K rwdata, 4068K rodata, 2944K init, 2508K bss, 43640K reserved, 204800K cma-reserved)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000] Kernel/User page tables isolation: enabled
[ 0.000000] Spectre V2 : Mitigation: Full generic retpoline
[ 0.000000] Spectre V2 : Spectre v2 mitigation: Filling RSB on context switch
BUG: kernel hang in boot stage
# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start 8dd371a965dc4c91e485a26c3d6330f1052c9b7b 4a3928c6f8a53fa1aed28ccba227742486e8ddcb --
git bisect good f1a6e1e53d931aaa977ced2b58cf2b0bce36cc05 # 07:55 G 11 0 3 7 Merge 'linux-review/Finn-Thain/Fixes-cleanup-and-modernization-for-SONIC-ethernet-drivers/20180227-052738' into devel-catchup-201802270613
git bisect bad 4c27d00ce9e7c4928ed1cb67a1aac34b535eee44 # 08:25 B 0 3 17 0 Merge 'arm-soc/fixes' into devel-catchup-201802270613
git bisect good 298664a34b631ce5a74333a50cffe5885c87f8d0 # 08:45 G 10 0 1 5 Merge 'asoc/for-next' into devel-catchup-201802270613
git bisect bad fc5456c4f8f9135e100460bce276b8afd35e6645 # 08:58 B 0 3 18 0 Merge 'linux-review/Tali-Perry/NPCM750-clk-controller-DT-and-binding/20180227-043851' into devel-catchup-201802270613
git bisect bad c9dfdf7a404b53dcf7f75a5d55c2fc75624ab3ae # 09:43 B 0 4 18 0 Merge 'ak/spec/ftrace-stuff-11' into devel-catchup-201802270613
git bisect good 082a2c2093cd479663c74d0aa7312739a40457e1 # 10:28 G 10 0 2 4 x86/deepchain: Reset call depth on fill
git bisect good 42d5ad628cef61b278c78af01bcd4e387e9abba2 # 10:42 G 10 0 0 4 x86/deep-chain: Print call-depth at crashes / sysrq
git bisect good ac15830618c7f63525bfbe1d2aeca4c1e4ab24e9 # 11:00 G 11 0 2 6 x86/deepchain: Instrument call chain even for notrace functions
git bisect bad aebafb2a3a3922872d18aa72060d38026a03e4c0 # 11:25 B 0 1 15 0 fixup! x86/deepchain: Instrument call chain even for notrace functions
git bisect bad 351ea48b88b7bded0f83d43bff8cb324e97687ad # 11:55 B 0 4 18 0 force skylake for easier testing
# first bad commit: [351ea48b88b7bded0f83d43bff8cb324e97687ad] force skylake for easier testing
git bisect good ac15830618c7f63525bfbe1d2aeca4c1e4ab24e9 # 12:28 G 30 0 1 7 x86/deepchain: Instrument call chain even for notrace functions
# extra tests with debug options
git bisect bad 351ea48b88b7bded0f83d43bff8cb324e97687ad # 12:51 B 0 11 25 0 force skylake for easier testing
# extra tests on HEAD of linux-devel/devel-catchup-201802270613
git bisect bad 8dd371a965dc4c91e485a26c3d6330f1052c9b7b # 12:51 B 0 35 84 0 0day head guard for 'devel-catchup-201802270613'
# extra tests on tree/branch ak/spec/ftrace-stuff-11
git bisect bad aebafb2a3a3922872d18aa72060d38026a03e4c0 # 13:00 B 0 15 40 0 fixup! x86/deepchain: Instrument call chain even for notrace functions
# extra tests with first bad commit reverted
git bisect good 3f424cfb33c84e9acac7c0eff0fd03dee1fb3c15 # 13:16 G 10 0 1 1 Revert "force skylake for easier testing"
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
4 years, 5 months
- 1
- 0
[net] cb0789fd8b: INFO:task_blocked_for_more_than#seconds
by kernel test robot
FYI, we noticed the following commit (built with gcc-6):
commit: cb0789fd8b03b59948257b67531d0b5fd87061c5 ("net: phy: Restore phy_resume() locking assumption")
url: https://github.com/0day-ci/linux/commits/Andrew-Lunn/net-phy-Restore-phy_...
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -m 420M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+--------------------------------------------------+------------+------------+
| | a5f7add332 | cb0789fd8b |
+--------------------------------------------------+------------+------------+
| boot_successes | 10 | 0 |
| boot_failures | 0 | 14 |
| INFO:task_blocked_for_more_than#seconds | 0 | 12 |
| Kernel_panic-not_syncing:hung_task:blocked_tasks | 0 | 12 |
| BUG:kernel_hang_in_boot_stage | 0 | 2 |
| RIP:ring_buffer_lock_reserve | 0 | 1 |
| RIP:__sanitizer_cov_trace_pc | 0 | 1 |
+--------------------------------------------------+------------+------------+
[ 246.754333] INFO: task swapper/0:1 blocked for more than 120 seconds.
[ 246.755305] Not tainted 4.16.0-rc2-00146-gcb0789f #2
[ 246.756204] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 246.757066] swapper/0 D13040 1 0 0x80000000
[ 246.757638] Call Trace:
[ 246.757891] ? __schedule+0x611/0x730
[ 246.758301] ? __clear_rsb+0x15/0x3d
[ 246.758719] ? __clear_rsb+0x15/0x3d
[ 246.759103] ? schedule+0x8c/0xa0
[ 246.759475] ? schedule_timeout+0x44/0x48b
[ 246.759886] ? trace_preempt_on+0x16/0x15f
[ 246.760359] ? wait_for_common+0x1a6/0x1d8
[ 246.760805] ? do_task_dead+0x4f/0x4f
[ 246.761222] ? flush_work+0x19d/0x1d7
[ 246.761635] ? flush_workqueue_prep_pwqs+0x13b/0x13b
[ 246.762161] ? driver_deferred_probe_trigger+0xaf/0xaf
[ 246.762880] ? do_early_param+0xbe/0xbe
[ 246.763542] ? deferred_probe_initcall+0x22/0x2c
[ 246.764233] ? do_one_initcall+0xaf/0x191
[ 246.764671] ? do_early_param+0xbe/0xbe
[ 246.765080] ? kernel_init_freeable+0x129/0x1de
[ 246.765564] ? rest_init+0xc4/0xc4
[ 246.765909] ? kernel_init+0x10/0x142
[ 246.766305] ? rest_init+0xc4/0xc4
[ 246.766681] ? ret_from_fork+0x3a/0x50
[ 246.767075] NMI backtrace for cpu 0
[ 246.767504] CPU: 0 PID: 20 Comm: khungtaskd Not tainted 4.16.0-rc2-00146-gcb0789f #2
[ 246.768735] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 246.770035] Call Trace:
[ 246.770480] ? dump_stack+0xb0/0x102
[ 246.771055] ? nmi_cpu_backtrace+0xde/0x117
[ 246.771551] ? lapic_can_unplug_cpu+0x91/0x91
[ 246.771983] ? nmi_trigger_cpumask_backtrace+0xe2/0x1ae
[ 246.772535] ? watchdog+0x366/0x412
[ 246.772884] ? preempt_count_sub+0x44/0x52
[ 246.773308] ? hung_task_panic+0x17/0x17
[ 246.773711] ? kthread+0x13b/0x14a
[ 246.774062] ? kthread_delayed_work_timer_fn+0xb3/0xb3
[ 246.774587] ? ret_from_fork+0x3a/0x50
[ 246.775000] Kernel panic - not syncing: hung_task: blocked tasks
[ 246.775629] CPU: 0 PID: 20 Comm: khungtaskd Not tainted 4.16.0-rc2-00146-gcb0789f #2
[ 246.776398] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 246.777209] Call Trace:
[ 246.777473] ? dump_stack+0xb0/0x102
[ 246.777826] ? panic+0x10f/0x2bf
[ 246.778168] ? watchdog+0x366/0x412
[ 246.778529] ? watchdog+0x372/0x412
[ 246.778879] ? preempt_count_sub+0x44/0x52
[ 246.779302] ? hung_task_panic+0x17/0x17
[ 246.779706] ? kthread+0x13b/0x14a
[ 246.780056] ? kthread_delayed_work_timer_fn+0xb3/0xb3
[ 246.780576] ? ret_from_fork+0x3a/0x50
[ 246.781156] Kernel Offset: disabled
Elapsed time: 250
#!/bin/bash
# To reproduce,
# 1) save job-script and this script (both are attached in 0day report email)
# 2) run this script with your compiled kernel and optional env $INSTALL_MOD_PATH
kernel=$1
initrds=(
/osimage/yocto/yocto-tiny-i386-2016-04-22.cgz
/lkp/lkp/lkp-i386.cgz
/osimage/deps/debian-x86_64-2016-08-31.cgz/run-ipconfig.i386_2016-09-03.cgz
)
HTTP_PREFIX=https://github.com/0day-ci/lkp-qemu/raw/master
wget --timestamping "${initrds[@]/#/$HTTP_PREFIX}"
{
cat "${initrds[@]//*\//}"
[[ $INSTALL_MOD_PATH ]] && (
cd "$INSTALL_MOD_PATH"
find lib | cpio -o -H newc --quiet | gzip
)
echo job-script | cpio -o -H newc --quiet | gzip
} > initrd.img
kvm=(
qemu-system-x86_64
-enable-kvm
-kernel $kernel
-initrd initrd.img
-m 420
-smp 1
-device e1000,netdev=net0
-netdev user,id=net0
-boot order=nc
-no-reboot
-watchdog i6300esb
-watchdog-action debug
-rtc base=localtime
-serial stdio
-display none
-monitor null
)
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
4 years, 5 months
- 2
- 1
[lkp-robot] [bisect done] 54ad80c608 [ 0.052383] BUG: unable to handle kernel paging request at 109e2014
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/paulmck/linux-rcu.git rcu/dev
commit 54ad80c6083c1c9ebe039c0fab01418c45c09033
Author: Paul E. McKenney <paulmck(a)linux.vnet.ibm.com>
AuthorDate: Thu Feb 1 22:05:38 2018 -0800
Commit: Paul E. McKenney <paulmck(a)linux.vnet.ibm.com>
CommitDate: Mon Feb 26 10:25:41 2018 -0800
rcu: Parallelize expedited grace-period initialization
The latency of RCU expedited grace periods grows with increasing numbers
of CPUs, eventually failing to be all that expedited. Much of the growth
in latency is in the initialization phase, so this commit uses workqueues
to carry out this initialization concurrently on a rcu_node-by-rcu_node
basis.
This change makes use of a new rcu_par_gp_wq because flushing a work
item from another work item running from the same workqueue can result
in deadlock.
Signed-off-by: Paul E. McKenney <paulmck(a)linux.vnet.ibm.com>
2a84d1aef4 rcu: Inline rcu_preempt_do_callback() into its sole caller
54ad80c608 rcu: Parallelize expedited grace-period initialization
+------------------------------------------+------------+------------+
| | 2a84d1aef4 | 54ad80c608 |
+------------------------------------------+------------+------------+
| boot_successes | 56 | 6 |
| boot_failures | 0 | 17 |
| BUG:unable_to_handle_kernel | 0 | 17 |
| Oops:#[##] | 0 | 17 |
| EIP:sync_sched_exp_handler | 0 | 17 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 17 |
+------------------------------------------+------------+------------+
[ 0.045812] kvm-stealtime: cpu 1, msr 1e7869c0
[ 0.046791] smp: Brought up 1 node, 2 CPUs
[ 0.047149] smpboot: Max logical packages: 2
[ 0.047505] smpboot: Total of 2 processors activated (10380.30 BogoMIPS)
[ 0.050435] devtmpfs: initialized
[ 0.052383] BUG: unable to handle kernel paging request at 109e2014
[ 0.052924] IP: sync_sched_exp_handler+0x10/0x90
[ 0.053314] *pdpt = 0000000000000000 *pde = 0000000000000000
[ 0.053333] Oops: 0000 [#1] SMP DEBUG_PAGEALLOC
[ 0.053333] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.16.0-rc1-00046-g54ad80c #8
[ 0.053333] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 0.053333] EIP: sync_sched_exp_handler+0x10/0x90
[ 0.053333] EFLAGS: 00210206 CPU: 0
[ 0.053333] EAX: 109e2000 EBX: 4dc04240 ECX: 4ceb9990 EDX: 00000001
[ 0.053333] ESI: 4dc04240 EDI: 4dc04450 EBP: 40049e48 ESP: 40049e48
[ 0.053333] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[ 0.053333] CR0: 80050033 CR2: 109e2014 CR3: 0dda1000 CR4: 000006f0
[ 0.053333] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 0.053333] DR6: fffe0ff0 DR7: 00000400
[ 0.053333] Call Trace:
[ 0.053333] ? sync_rcu_exp_select_cpus+0x1a7/0x280
[ 0.053333] ? _synchronize_rcu_expedited+0x36c/0x3a0
[ 0.053333] ? rcu_stall_kick_kthreads+0xf0/0xf0
[ 0.053333] ? _synchronize_rcu_expedited+0x228/0x3a0
[ 0.053333] ? sched_clock+0x9/0x10
[ 0.053333] ? __bitmap_weight+0x5b/0x70
[ 0.053333] ? rcu_spawn_tasks_kthread+0x3d/0x3d
[ 0.053333] ? synchronize_sched_expedited+0xae/0xb0
[ 0.053333] ? synchronize_sched+0xc7/0x110
[ 0.053333] ? try_to_wake_up+0x30b/0x370
[ 0.053333] ? kthread_create_on_node+0x18/0x20
[ 0.053333] ? rcu_test_sync_prims+0x8/0x30
[ 0.053333] ? rcu_set_runtime_mode+0x8/0x1b
[ 0.053333] ? do_one_initcall+0x8b/0x12d
[ 0.053333] ? parse_args+0x16f/0x2a0
[ 0.053333] ? do_early_param+0x75/0x75
[ 0.053333] ? kernel_init_freeable+0x18a/0x208
[ 0.053333] ? rest_init+0x1f0/0x1f0
[ 0.053333] ? kernel_init+0x8/0xf0
[ 0.053333] ? ret_from_fork+0x19/0x30
[ 0.053333] Code: 00 00 8d 65 f8 5b 5e 5d c3 66 90 f3 c3 8d b4 26 00 00 00 00 8d bc 27 00 00 00 00 55 8b 80 cc 06 00 00 89 e5 64 03 05 08 61 d8 4d <8b> 50 14 8b 52 34 85 50 18 74 67 64 a0 cd 2d d9 4d 84 c0 75 5d
[ 0.053333] EIP: sync_sched_exp_handler+0x10/0x90 SS:ESP: 0068:40049e48
[ 0.053333] CR2: 00000000109e2014
[ 0.053333] ---[ end trace 8ebb26ef4a7b41a3 ]---
[ 0.053333] Kernel panic - not syncing: Fatal exception
# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start 54ad80c6083c1c9ebe039c0fab01418c45c09033 7928b2cbe55b2a410a0f5c1f154610059c57b1b2 --
git bisect good a32e01ee689794a26bdfdbaa7e8c334576cee36c # 03:31 G 11 0 0 0 rcu: Use wrapper for lockdep asserts
git bisect good 338c46403f169dd76bff8ed58fd0be0d600e7aba # 03:40 G 11 0 0 0 Merge branches 'fixes.2018.02.23a', 'srcu.2018.02.20a' and 'torture.2018.02.20a' into HEAD
git bisect good e69aaa0647ec61536fdc88752eb7734977fdb289 # 03:45 G 11 0 0 0 EXP: rcu: Add debugging info to other assertion
git bisect good e6e9ee038aa32e29a4d141c0c975a3d0972dedea # 03:51 G 11 0 0 0 EXP sched: Make non-production PREEMPT cond_resched() help Tasks RCU
git bisect good 2a84d1aef4239554aeccbc6b31a989f8c3be9675 # 03:56 G 11 0 0 0 rcu: Inline rcu_preempt_do_callback() into its sole caller
# first bad commit: [54ad80c6083c1c9ebe039c0fab01418c45c09033] rcu: Parallelize expedited grace-period initialization
git bisect good 2a84d1aef4239554aeccbc6b31a989f8c3be9675 # 03:58 G 31 0 0 0 rcu: Inline rcu_preempt_do_callback() into its sole caller
# extra tests on HEAD of rcu/rcu/dev
git bisect bad 54ad80c6083c1c9ebe039c0fab01418c45c09033 # 03:58 B 0 17 34 0 rcu: Parallelize expedited grace-period initialization
# extra tests on tree/branch rcu/rcu/dev
git bisect bad 54ad80c6083c1c9ebe039c0fab01418c45c09033 # 03:59 B 0 17 34 0 rcu: Parallelize expedited grace-period initialization
# extra tests with first bad commit reverted
git bisect good fb47c4ab15a930e167e7798fa1c572a8ee911b93 # 04:19 G 11 0 0 0 Revert "rcu: Parallelize expedited grace-period initialization"
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
4 years, 5 months
- 2
- 1
[lkp-robot] [bisect done] df95cc69cc [ 0.057279] BUG: unable to handle kernel paging request at ffff90de786a8478
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/paulmck/linux-rcu.git dev.2018.02.23a
commit df95cc69cca894430640237d39453f5d96c40a7d
Author: Paul E. McKenney <paulmck(a)linux.vnet.ibm.com>
AuthorDate: Thu Feb 1 22:05:38 2018 -0800
Commit: Paul E. McKenney <paulmck(a)linux.vnet.ibm.com>
CommitDate: Fri Feb 23 15:19:12 2018 -0800
rcu: Parallelize expedited grace-period initialization
The latency of RCU expedited grace periods grows with increasing numbers
of CPUs, eventually failing to be all that expedited. Much of the growth
in latency is in the initialization phase, so this commit uses workqueues
to carry out this initialization concurrently on a rcu_node-by-rcu_node
basis.
This change makes use of a new rcu_par_gp_wq because flushing a work
item from another work item running from the same workqueue can result
in deadlock.
Signed-off-by: Paul E. McKenney <paulmck(a)linux.vnet.ibm.com>
3fea14045a EXP rcu: Add ->qsmask to assertion
df95cc69cc rcu: Parallelize expedited grace-period initialization
b8a3012ddb rcu: Inline rcu_preempt_do_callback() into its sole caller
+------------------------------------------+------------+------------+------------+
| | 3fea14045a | df95cc69cc | b8a3012ddb |
+------------------------------------------+------------+------------+------------+
| boot_successes | 35 | 0 | 0 |
| boot_failures | 0 | 15 | 15 |
| BUG:unable_to_handle_kernel | 0 | 15 | 15 |
| Oops:#[##] | 0 | 15 | 15 |
| RIP:rcu_report_exp_rdp | 0 | 15 | 15 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 15 | 15 |
+------------------------------------------+------------+------------+------------+
[ 0.047765] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[ 0.048923] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[ 0.050050] Spectre V2 : Mitigation: Full generic retpoline
[ 0.051259] Spectre V2 : Filling RSB on context switch
[ 0.053555] Freeing SMP alternatives memory: 60K
[ 0.057279] BUG: unable to handle kernel paging request at ffff90de786a8478
[ 0.059499] IP: rcu_report_exp_rdp+0x5/0x17
[ 0.059999] PGD 9d27067 P4D 9d27067 PUD 0
[ 0.059999] Oops: 0000 [#1] PREEMPT SMP
[ 0.059999] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.16.0-rc1-00044-gdf95cc6 #1
[ 0.059999] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 0.059999] RIP: 0010:rcu_report_exp_rdp+0x5/0x17
[ 0.059999] RSP: 0000:ffffffff9a003d58 EFLAGS: 00010246
[ 0.059999] RAX: ffffffff9a0a7238 RBX: ffffffff9a0a6f00 RCX: ffffffff989132a8
[ 0.059999] RDX: ffffffff989132a8 RSI: ffff90de786a8450 RDI: ffffffff9a0a7238
[ 0.059999] RBP: ffffffff9a0a6f00 R08: ffffffff9a05ccb8 R09: 000000009ebbacb4
[ 0.059999] R10: 0000000000000001 R11: 0000000000000002 R12: 0000000fffffffe0
[ 0.059999] R13: ffffffff981441e8 R14: ffffffff9a0a7238 R15: 0000000000000003
[ 0.059999] FS: 0000000000000000(0000) GS:ffff90dede600000(0000) knlGS:0000000000000000
[ 0.059999] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 0.059999] CR2: ffff90de786a8478 CR3: 0000000008657000 CR4: 00000000000006b0
[ 0.059999] Call Trace:
[ 0.059999] sync_rcu_exp_select_cpus+0x3fe/0x4d1
[ 0.059999] ? sync_sched_exp_handler+0xb0/0xb0
[ 0.059999] _synchronize_rcu_expedited+0x1c8/0x312
[ 0.059999] ? acpi_hw_read_multiple+0x8c/0xb0
[ 0.059999] ? trace_event_define_fields_vector_free_moved+0xab/0xab
[ 0.059999] synchronize_rcu+0x9c/0xd4
[ 0.059999] ? acpi_read_bit_register+0x73/0x93
[ 0.059999] ? find_next_bit+0x7b/0x85
[ 0.059999] ? ___might_sleep+0x64/0x23d
[ 0.059999] ? trace_event_define_fields_vector_free_moved+0xab/0xab
[ 0.059999] ? synchronize_sched_expedited+0xa8/0xd3
[ 0.059999] rcu_test_sync_prims+0xa/0x23
[ 0.059999] rest_init+0x14/0x290
[ 0.059999] ? trace_event_define_fields_vector_free_moved+0xab/0xab
[ 0.059999] start_kernel+0x681/0x719
[ 0.059999] secondary_startup_64+0xa5/0xb0
[ 0.059999] Code: 48 63 05 36 5d 10 02 48 69 c0 80 03 00 00 48 01 e8 48 39 c3 0f 82 bf fe ff ff 58 5b 5d 41 5c 41 5d 41 5e 41 5f c3 e8 fa d5 4b 01 <48> 8b 56 28 48 8b 76 20 b9 01 00 00 00 e9 09 cf ff ff e8 e3 d5
[ 0.059999] RIP: rcu_report_exp_rdp+0x5/0x17 RSP: ffffffff9a003d58
[ 0.059999] CR2: ffff90de786a8478
[ 0.059999] ---[ end trace 0e30523010e6e679 ]---
[ 0.059999] Kernel panic - not syncing: Fatal exception
# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start a68d1cd03328fec16c711be10a97ad34b002bf28 4a3928c6f8a53fa1aed28ccba227742486e8ddcb --
git bisect bad 0bde07b7d6caea173773c4ec94008c2ec714d17b # 23:40 B 0 3 16 0 Merge 'linux-review/Maciej-Purski/thermal-exynos-Read-soc_type-from-match-data/20180220-224522' into devel-hourly-2018022617
git bisect bad 194c8a0b6ecf861035aa69062ddce26c94683eb0 # 00:08 B 0 6 19 0 Merge 'linux-review/Jonathan-Neusch-fer/PPC32-ioremap-Use-memblock-API-to-check-for-RAM/20180224-000631' into devel-hourly-2018022617
git bisect good 07683dca0895dec660c62d5d4b03f76ea7db1745 # 00:25 G 11 0 0 0 Merge 'linux-review/Maciej-S-Szmigiero/X-509-unpack-RSA-signatureValue-field-from-BIT-STRING/20180225-120020' into devel-hourly-2018022617
git bisect good b387ee547a5a6601c648580c23ba59ee093a6ada # 00:39 G 11 0 11 13 Merge 'pcmoore-selinux/next' into devel-hourly-2018022617
git bisect bad 15bb75ed8c13d791a878937069d4d5da5d08d6aa # 00:57 B 0 9 22 0 Merge 'linux-review/Mark-Rustad/virtio_pci-Add-SR-IOV-support/20180224-061525' into devel-hourly-2018022617
git bisect good 9f89d69b76db288bb7957db57edf06ebc607dd26 # 01:10 G 11 0 11 13 Merge 'linux-review/David-Daney/netdev-octeon-ethernet-Add-Cavium-Octeon-III-support/20180224-103133' into devel-hourly-2018022617
git bisect bad 93095b3b697d121eec82991eb51771d100a1adb1 # 01:25 B 0 8 23 2 Merge 'rcu/rcu/dev' into devel-hourly-2018022617
git bisect good df2221a2a06f6880a2bc10b8532ebf3704a4fc47 # 01:39 G 11 0 11 13 Merge 'kvm/master' into devel-hourly-2018022617
git bisect good 0eef27d7a1920ece93192cfee144e56bbd5b12bd # 01:52 G 10 0 11 10 Merge 'linux-review/Charles-Keepax/regmap-Format-data-for-raw-write-in-regmap_bulk_write/20180224-090645' into devel-hourly-2018022617
git bisect good 5315fe646b13e3868b0e2c7f980d4485827ec50f # 02:07 G 11 0 11 11 Merge 'linux-review/Masahiro-Yamada/kbuild-test-build-id-linker-flag-by-ld-option-instead-of-cc-ldoption/20180224-093211' into devel-hourly-2018022617
git bisect good ad7c946b35ad455417fdd4bc0e17deda4011841b # 02:23 G 11 0 0 0 rcu: Create RCU-specific workqueues with rescuers
git bisect good 85ba6bfe8bb2a4d907f7380a8f37b31616ad694e # 02:40 G 11 0 0 0 torture: Provide more sensible nreader/nwriter defaults for rcuperf
git bisect good 338c46403f169dd76bff8ed58fd0be0d600e7aba # 02:58 G 11 0 0 0 Merge branches 'fixes.2018.02.23a', 'srcu.2018.02.20a' and 'torture.2018.02.20a' into HEAD
git bisect good 8ff74aa7707b443d40120fa4ea780517de7f507a # 03:09 G 11 0 0 2 EXP: rcu: Add ->boost_tasks to assertion
git bisect good 3fea14045aa4f169405262aabbc4a5411c90bae4 # 03:26 G 10 0 0 0 EXP rcu: Add ->qsmask to assertion
git bisect bad df95cc69cca894430640237d39453f5d96c40a7d # 03:34 B 0 1 17 3 rcu: Parallelize expedited grace-period initialization
# first bad commit: [df95cc69cca894430640237d39453f5d96c40a7d] rcu: Parallelize expedited grace-period initialization
git bisect good 3fea14045aa4f169405262aabbc4a5411c90bae4 # 03:47 G 31 0 0 0 EXP rcu: Add ->qsmask to assertion
# extra tests with debug options
git bisect bad df95cc69cca894430640237d39453f5d96c40a7d # 04:02 B 0 2 16 1 rcu: Parallelize expedited grace-period initialization
# extra tests on HEAD of linux-devel/devel-hourly-2018022617
git bisect bad a68d1cd03328fec16c711be10a97ad34b002bf28 # 04:07 B 0 13 29 0 0day head guard for 'devel-hourly-2018022617'
# extra tests on tree/branch rcu/dev.2018.02.23a
git bisect bad b8a3012ddba397d4a18d9fd4a00432f8c2626bd6 # 04:25 B 0 11 26 2 rcu: Inline rcu_preempt_do_callback() into its sole caller
# extra tests with first bad commit reverted
git bisect good 3677c11e199cbe90292d7f14539c74a6ccc08997 # 04:47 G 11 0 0 0 Revert "rcu: Parallelize expedited grace-period initialization"
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
4 years, 5 months
- 1
- 0
[net/ipv6] 15c9251fd2: BUG:unable_to_handle_kernel
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: 15c9251fd2c06777e65c74b2df6aaac5575070cb ("net/ipv6: move metrics from dst to rt6_info")
url: https://github.com/0day-ci/linux/commits/David-Ahern/net-ipv6-Separate-da...
in testcase: trinity
with following parameters:
runtime: 300s
test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/
on test machine: qemu-system-x86_64 -enable-kvm -m 420M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-------------------------------------------------------+------------+------------+
| | 1e903aa017 | 15c9251fd2 |
+-------------------------------------------------------+------------+------------+
| boot_successes | 8 | 0 |
| boot_failures | 0 | 8 |
| BUG:unable_to_handle_kernel | 0 | 8 |
| Oops:#[##] | 0 | 8 |
| EIP:ndisc_router_discovery | 0 | 8 |
| Kernel_panic-not_syncing:Fatal_exception_in_interrupt | 0 | 8 |
+-------------------------------------------------------+------------+------------+
[ 22.641331] BUG: unable to handle kernel paging request at c21c2904
[ 22.642318] IP: ndisc_router_discovery+0x780/0x13d0
[ 22.643089] *pde = 15005063 *pte = 021c2161
[ 22.643762] Oops: 0003 [#1]
[ 22.644195] Modules linked in:
[ 22.644678] CPU: 0 PID: 7 Comm: ksoftirqd/0 Not tainted 4.16.0-rc2-00679-g15c9251 #1
[ 22.645795] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 22.647022] EIP: ndisc_router_discovery+0x780/0x13d0
[ 22.647801] EFLAGS: 00010246 CPU: 0
[ 22.648367] EAX: c21c28e0 EBX: d51afa80 ECX: ccee8800 EDX: 00000040
[ 22.649312] ESI: d5238800 EDI: cccafef6 EBP: d50b7ce0 ESP: d50b7c68
[ 22.650230] DS: 007b ES: 007b FS: 0000 GS: 00e0 SS: 0068
[ 22.651048] CR0: 80050033 CR2: c21c2904 CR3: 0cf7c000 CR4: 000006d0
[ 22.651989] Call Trace:
[ 22.652384] ? validate_chain+0xe8d/0xfd0
[ 22.653088] ndisc_rcv+0xc7d/0xef0
[ 22.653588] ? find_held_lock+0x35/0x110
[ 22.654148] ? skb_checksum+0x40/0x70
[ 22.654674] ? skb_send_sock+0x80/0x80
[ 22.655204] ? reqsk_fastopen_remove+0x2f0/0x2f0
[ 22.655890] ? __skb_checksum_complete+0xba/0x160
[ 22.656590] icmpv6_rcv+0xb9d/0xea0
[ 22.657139] ip6_input_finish+0x84a/0x1050
[ 22.657919] ip6_mc_input+0x261/0x3b0
[ 22.658471] ip6_rcv_finish+0x43a/0x5e0
[ 22.659023] ipv6_rcv+0xf4c/0x12d0
[ 22.659505] ? ip6_rcv_finish+0x5e0/0x5e0
[ 22.660079] __netif_receive_skb_core+0x1349/0x1970
[ 22.660793] __netif_receive_skb+0xe1/0x100
[ 22.661418] netif_receive_skb_internal+0x351/0x3e0
[ 22.662113] ? netif_receive_skb_internal+0x2e0/0x3e0
[ 22.662847] napi_gro_receive+0x2bd/0x390
[ 22.663444] e1000_receive_skb+0x80/0xa0
[ 22.664054] e1000_clean_rx_irq+0x68d/0x830
[ 22.664704] ? e1000_clean_jumbo_rx_irq+0xc00/0xc00
[ 22.665419] e1000_clean+0x67/0x3d0
[ 22.665935] net_rx_action+0x1ad/0x8a0
[ 22.666475] __do_softirq+0x3cb/0x8b9
[ 22.667006] run_ksoftirqd+0x4f/0x100
[ 22.667527] smpboot_thread_fn+0x42d/0x450
[ 22.668115] kthread+0x232/0x250
[ 22.668589] ? sort_range+0x40/0x40
[ 22.669112] ? kthread_create_worker+0x40/0x40
[ 22.669789] ret_from_fork+0x2e/0x38
[ 22.670342] Code: 90 34 01 00 00 8b 45 90 83 15 ac 8d d4 c3 00 85 c0 74 20 0f b6 57 04 83 05 b0 8d d4 c3 01 8b 80 d8 00 00 00 83 15 b4 8d d4 c3 00 <89> 50 24 90 8d 74 26 00 8b 45 a8 8b 88 2c 01 00 00 85 c9 0f 84
[ 22.673109] EIP: ndisc_router_discovery+0x780/0x13d0 SS:ESP: 0068:d50b7c68
[ 22.674093] CR2: 00000000c21c2904
[ 22.674581] ---[ end trace f56f6529cd55c80c ]---
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
4 years, 5 months
- 1
- 0
[lkp-robot] [mm, mlock, vmscan] 9c4e6b1a70: stress-ng.hdd.ops_per_sec -7.9% regression
by kernel test robot
Greeting,
FYI, we noticed a -7.9% regression of stress-ng.hdd.ops_per_sec due to commit:
commit: 9c4e6b1a7027f102990c0395296015a812525f4d ("mm, mlock, vmscan: no more skipping pagevecs")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
in testcase: stress-ng
on test machine: 88 threads Intel(R) Xeon(R) CPU E5-2699 v4 @ 2.20GHz with 128G memory
with following parameters:
nr_threads: 100%
testtime: 1s
class: io
cpufreq_governor: performance
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
=========================================================================================
class/compiler/cpufreq_governor/kconfig/nr_threads/rootfs/tbox_group/testcase/testtime:
io/gcc-7/performance/x86_64-rhel-7.2/100%/debian-x86_64-2016-08-31.cgz/lkp-bdw-ep6/stress-ng/1s
commit:
c3cc39118c ("mm: memcontrol: fix NR_WRITEBACK leak in memcg and system stats")
9c4e6b1a70 ("mm, mlock, vmscan: no more skipping pagevecs")
c3cc39118c3610eb 9c4e6b1a7027f102990c039529
---------------- --------------------------
%stddev %change %stddev
\ | \
1242815 -14.4% 1063699 stress-ng.hdd.ops
645914 -7.9% 594931 stress-ng.hdd.ops_per_sec
473.69 -2.5% 461.99 stress-ng.time.system_time
12569476 -9.4% 11392192 vmstat.memory.cache
802679 ± 7% +40.2% 1125287 ± 12% cpuidle.C3.time
2423 ± 4% +38.7% 3360 ± 15% cpuidle.C3.usage
16584420 -9.1% 15071340 numa-numastat.node1.local_node
16594335 -9.1% 15081279 numa-numastat.node1.numa_hit
2164 ± 6% +42.7% 3087 ± 17% turbostat.C3
0.10 ± 8% +0.0 0.14 ± 15% turbostat.C3%
0.05 ± 8% +33.3% 0.07 ± 17% turbostat.CPU%c3
1.911e+09 -1.1% 1.89e+09 perf-stat.branch-misses
7.536e+09 -3.3% 7.29e+09 perf-stat.cache-references
1.633e+12 -1.6% 1.607e+12 perf-stat.cpu-cycles
0.61 +1.7% 0.62 perf-stat.ipc
2.576e+08 -2.5% 2.513e+08 perf-stat.node-loads
394861 ± 11% -53.2% 184617 ± 22% meminfo.Active
205118 ± 4% -100.0% 4.00 meminfo.Active(file)
14015193 ± 4% -99.8% 21126 ± 2% meminfo.Inactive
13995095 ± 4% -100.0% 403.25 ± 11% meminfo.Inactive(file)
1.303e+08 -10.1% 1.171e+08 meminfo.MemAvailable
3.00 +4.5e+08% 13428597 ± 4% meminfo.Unevictable
2816 ± 53% +561.9% 18643 ±134% sched_debug.cpu.avg_idle.min
3.68 ± 3% -13.5% 3.18 ± 3% sched_debug.cpu.clock.stddev
3.68 ± 3% -13.5% 3.18 ± 3% sched_debug.cpu.clock_task.stddev
0.12 ± 3% -19.3% 0.09 ± 21% sched_debug.rt_rq:/.rt_time.avg
10.04 ± 3% -21.5% 7.88 ± 22% sched_debug.rt_rq:/.rt_time.max
1.06 ± 3% -21.5% 0.84 ± 22% sched_debug.rt_rq:/.rt_time.stddev
204608 ± 11% -62.2% 77341 ± 29% numa-meminfo.node0.Active
102698 ± 4% -100.0% 0.00 numa-meminfo.node0.Active(file)
6913218 ± 5% -99.8% 13623 ± 55% numa-meminfo.node0.Inactive
6903513 ± 5% -100.0% 197.75 ± 24% numa-meminfo.node0.Inactive(file)
190923 ± 14% -43.5% 107793 ± 19% numa-meminfo.node1.Active
102681 ± 4% -100.0% 4.00 numa-meminfo.node1.Active(file)
7063606 ± 4% -99.9% 7736 ±100% numa-meminfo.node1.Inactive
7053168 ± 4% -100.0% 204.00 ± 45% numa-meminfo.node1.Inactive(file)
3.00 +2.2e+08% 6713147 ± 4% numa-meminfo.node1.Unevictable
25680 ± 4% -100.0% 0.00 numa-vmstat.node0.nr_active_file
1730227 ± 6% -100.0% 49.00 ± 24% numa-vmstat.node0.nr_inactive_file
25680 ± 4% -100.0% 0.00 numa-vmstat.node0.nr_zone_active_file
1730144 ± 6% -100.0% 49.00 ± 24% numa-vmstat.node0.nr_zone_inactive_file
7950112 ± 5% -13.4% 6886737 ± 6% numa-vmstat.node0.numa_hit
7943736 ± 5% -13.4% 6880367 ± 6% numa-vmstat.node0.numa_local
25670 ± 4% -100.0% 1.00 numa-vmstat.node1.nr_active_file
1765886 ± 5% -100.0% 50.50 ± 45% numa-vmstat.node1.nr_inactive_file
0.00 +Inf% 1670961 ± 4% numa-vmstat.node1.nr_unevictable
25670 ± 4% -100.0% 1.00 numa-vmstat.node1.nr_zone_active_file
1765833 ± 5% -100.0% 50.50 ± 45% numa-vmstat.node1.nr_zone_inactive_file
0.00 +Inf% 1670970 ± 4% numa-vmstat.node1.nr_zone_unevictable
8050425 ± 5% -13.9% 6933412 ± 5% numa-vmstat.node1.numa_hit
7878053 ± 6% -14.2% 6761044 ± 6% numa-vmstat.node1.numa_local
51353 ± 4% -100.0% 1.00 proc-vmstat.nr_active_file
3257694 -10.2% 2924036 proc-vmstat.nr_dirty_background_threshold
6523354 -10.2% 5855222 proc-vmstat.nr_dirty_threshold
3493404 ± 5% -100.0% 100.25 ± 11% proc-vmstat.nr_inactive_file
0.00 +Inf% 3344234 ± 4% proc-vmstat.nr_unevictable
51353 ± 4% -100.0% 1.00 proc-vmstat.nr_zone_active_file
3493404 ± 5% -100.0% 100.25 ± 11% proc-vmstat.nr_zone_inactive_file
0.00 +Inf% 3344234 ± 4% proc-vmstat.nr_zone_unevictable
1014 ± 32% -40.5% 603.75 ± 26% proc-vmstat.numa_hint_faults
33019247 -9.7% 29815458 proc-vmstat.numa_hit
33002235 -9.7% 29798428 proc-vmstat.numa_local
1298 ± 57% -60.9% 507.75 ± 31% proc-vmstat.numa_pages_migrated
213856 ± 38% -31.2% 147128 ± 12% proc-vmstat.numa_pte_updates
361381 -99.8% 659.50 ± 3% proc-vmstat.pgactivate
33235386 -9.4% 30127871 proc-vmstat.pgfree
1298 ± 57% -60.9% 507.75 ± 31% proc-vmstat.pgmigrate_success
1.00 +3e+09% 30018233 proc-vmstat.unevictable_pgs_culled
28.62 ± 41% -27.8 0.77 ±100% perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe.write
28.62 ± 41% -27.8 0.77 ±100% perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe.write
28.62 ± 41% -27.8 0.77 ±100% perf-profile.calltrace.cycles-pp.sys_write.do_syscall_64.entry_SYSCALL_64_after_hwframe.write
28.85 ± 42% -27.4 1.49 ±117% perf-profile.calltrace.cycles-pp.write
28.12 ± 44% -27.3 0.77 ±100% perf-profile.calltrace.cycles-pp.vfs_write.sys_write.do_syscall_64.entry_SYSCALL_64_after_hwframe.write
28.12 ± 44% -27.3 0.77 ±100% perf-profile.calltrace.cycles-pp.__vfs_write.vfs_write.sys_write.do_syscall_64.entry_SYSCALL_64_after_hwframe
26.31 ± 53% -26.3 0.00 perf-profile.calltrace.cycles-pp.devkmsg_write.__vfs_write.vfs_write.sys_write.do_syscall_64
26.31 ± 53% -26.3 0.00 perf-profile.calltrace.cycles-pp.printk_emit.devkmsg_write.__vfs_write.vfs_write.sys_write
26.31 ± 53% -26.3 0.00 perf-profile.calltrace.cycles-pp.vprintk_emit.printk_emit.devkmsg_write.__vfs_write.vfs_write
26.31 ± 53% -26.3 0.00 perf-profile.calltrace.cycles-pp.console_unlock.vprintk_emit.printk_emit.devkmsg_write.__vfs_write
22.00 ± 68% -22.0 0.00 perf-profile.calltrace.cycles-pp.serial8250_console_write.console_unlock.vprintk_emit.printk_emit.devkmsg_write
21.07 ± 71% -21.1 0.00 perf-profile.calltrace.cycles-pp.uart_console_write.serial8250_console_write.console_unlock.vprintk_emit.printk_emit
21.07 ± 71% -21.1 0.00 perf-profile.calltrace.cycles-pp.serial8250_console_putchar.uart_console_write.serial8250_console_write.console_unlock.vprintk_emit
21.07 ± 71% -21.1 0.00 perf-profile.calltrace.cycles-pp.wait_for_xmitr.serial8250_console_putchar.uart_console_write.serial8250_console_write.console_unlock
14.27 ± 72% -14.3 0.00 perf-profile.calltrace.cycles-pp.io_serial_in.wait_for_xmitr.serial8250_console_putchar.uart_console_write.serial8250_console_write
6.80 ± 73% -6.8 0.00 perf-profile.calltrace.cycles-pp.delay_tsc.wait_for_xmitr.serial8250_console_putchar.uart_console_write.serial8250_console_write
0.81 ±173% +5.1 5.89 ± 40% perf-profile.calltrace.cycles-pp.link_path_walk.path_openat.do_filp_open.do_sys_open.do_syscall_64
33.02 ± 12% +16.8 49.84 ± 5% perf-profile.calltrace.cycles-pp.cpuidle_enter_state.do_idle.cpu_startup_entry.start_secondary.secondary_startup_64
34.45 ± 12% +17.0 51.41 ± 5% perf-profile.calltrace.cycles-pp.secondary_startup_64
33.25 ± 12% +17.7 51.00 ± 6% perf-profile.calltrace.cycles-pp.start_secondary.secondary_startup_64
33.25 ± 12% +17.7 51.00 ± 6% perf-profile.calltrace.cycles-pp.cpu_startup_entry.start_secondary.secondary_startup_64
33.25 ± 12% +17.7 51.00 ± 6% perf-profile.calltrace.cycles-pp.do_idle.cpu_startup_entry.start_secondary.secondary_startup_64
28.62 ± 41% -27.8 0.77 ±100% perf-profile.children.cycles-pp.sys_write
28.85 ± 42% -27.4 1.49 ±117% perf-profile.children.cycles-pp.write
28.12 ± 44% -27.3 0.77 ±100% perf-profile.children.cycles-pp.vfs_write
28.12 ± 44% -27.3 0.77 ±100% perf-profile.children.cycles-pp.__vfs_write
26.31 ± 53% -26.3 0.00 perf-profile.children.cycles-pp.devkmsg_write
26.31 ± 53% -26.3 0.00 perf-profile.children.cycles-pp.printk_emit
26.31 ± 53% -26.3 0.00 perf-profile.children.cycles-pp.vprintk_emit
26.31 ± 53% -26.3 0.00 perf-profile.children.cycles-pp.console_unlock
22.24 ± 68% -22.2 0.00 perf-profile.children.cycles-pp.wait_for_xmitr
22.00 ± 68% -22.0 0.00 perf-profile.children.cycles-pp.serial8250_console_write
21.30 ± 71% -21.3 0.00 perf-profile.children.cycles-pp.serial8250_console_putchar
21.07 ± 71% -21.1 0.00 perf-profile.children.cycles-pp.uart_console_write
59.80 ± 10% -19.5 40.33 ± 5% perf-profile.children.cycles-pp.entry_SYSCALL_64_after_hwframe
59.56 ± 10% -19.2 40.33 ± 5% perf-profile.children.cycles-pp.do_syscall_64
14.51 ± 71% -14.5 0.00 perf-profile.children.cycles-pp.io_serial_in
7.49 ± 63% -7.5 0.00 perf-profile.children.cycles-pp.delay_tsc
0.81 ±173% +5.5 6.31 ± 41% perf-profile.children.cycles-pp.link_path_walk
34.21 ± 12% +16.8 51.03 ± 5% perf-profile.children.cycles-pp.cpuidle_enter_state
34.45 ± 12% +17.0 51.41 ± 5% perf-profile.children.cycles-pp.secondary_startup_64
34.45 ± 12% +17.0 51.41 ± 5% perf-profile.children.cycles-pp.cpu_startup_entry
34.45 ± 12% +17.0 51.41 ± 5% perf-profile.children.cycles-pp.do_idle
33.25 ± 12% +17.7 51.00 ± 6% perf-profile.children.cycles-pp.start_secondary
14.51 ± 71% -14.5 0.00 perf-profile.self.cycles-pp.io_serial_in
7.49 ± 63% -7.5 0.00 perf-profile.self.cycles-pp.delay_tsc
stress-ng.hdd.ops
1.4e+06 +-+---------------------------------------------------------------+
| .+.. .+. .+.. .+.. .+.+..|
1.2e+06 +-+ +.+..+..+..+ +..+. +..+..+..+ +..+..+.+. +. |
O O O O : O : O O O O O O O O O O O O O O
1e+06 +-+ O O O O O O |
| : : |
800000 +-+ : : |
| : : |
600000 +-+ : : |
| : : |
400000 +-+ : : |
| :: |
200000 +-+ :: |
| : |
0 +-+---------------------------------------------------------------+
stress-ng.hdd.ops_per_sec
700000 +-+----------------------------------------------------------------+
|..+..+.+..+..+..+ +..+..+..+..+.+..+..+..+.+..+..+..+..+.+..+..|
600000 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
| : : |
500000 +-+ : : |
| : : |
400000 +-+ : : |
| : : |
300000 +-+ : : |
| : : |
200000 +-+ : : |
| :: |
100000 +-+ : |
| : |
0 +-+----------------------------------------------------------------+
[*] bisect-good sample
[O] bisect-bad sample
Disclaimer:
Results have been estimated based on internal Intel analysis and are provided
for informational purposes only. Any difference in system hardware or software
design or configuration may affect actual performance.
Thanks,
Xiaolong
4 years, 5 months
- 3
- 4
54ad80c608 ("rcu: Parallelize expedited grace-period .."): BUG: unable to handle kernel paging request at 109e2014
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/paulmck/linux-rcu.git rcu/dev
commit 54ad80c6083c1c9ebe039c0fab01418c45c09033
Author: Paul E. McKenney <paulmck(a)linux.vnet.ibm.com>
AuthorDate: Thu Feb 1 22:05:38 2018 -0800
Commit: Paul E. McKenney <paulmck(a)linux.vnet.ibm.com>
CommitDate: Mon Feb 26 10:25:41 2018 -0800
rcu: Parallelize expedited grace-period initialization
The latency of RCU expedited grace periods grows with increasing numbers
of CPUs, eventually failing to be all that expedited. Much of the growth
in latency is in the initialization phase, so this commit uses workqueues
to carry out this initialization concurrently on a rcu_node-by-rcu_node
basis.
This change makes use of a new rcu_par_gp_wq because flushing a work
item from another work item running from the same workqueue can result
in deadlock.
Signed-off-by: Paul E. McKenney <paulmck(a)linux.vnet.ibm.com>
2a84d1aef4 rcu: Inline rcu_preempt_do_callback() into its sole caller
54ad80c608 rcu: Parallelize expedited grace-period initialization
+------------------------------------------+------------+------------+
| | 2a84d1aef4 | 54ad80c608 |
+------------------------------------------+------------+------------+
| boot_successes | 56 | 6 |
| boot_failures | 0 | 17 |
| BUG:unable_to_handle_kernel | 0 | 17 |
| Oops:#[##] | 0 | 17 |
| EIP:sync_sched_exp_handler | 0 | 17 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 17 |
+------------------------------------------+------------+------------+
[ 0.045812] kvm-stealtime: cpu 1, msr 1e7869c0
[ 0.046791] smp: Brought up 1 node, 2 CPUs
[ 0.047149] smpboot: Max logical packages: 2
[ 0.047505] smpboot: Total of 2 processors activated (10380.30 BogoMIPS)
[ 0.050435] devtmpfs: initialized
[ 0.052383] BUG: unable to handle kernel paging request at 109e2014
[ 0.052924] IP: sync_sched_exp_handler+0x10/0x90
[ 0.053314] *pdpt = 0000000000000000 *pde = 0000000000000000
[ 0.053333] Oops: 0000 [#1] SMP DEBUG_PAGEALLOC
[ 0.053333] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.16.0-rc1-00046-g54ad80c #8
[ 0.053333] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 0.053333] EIP: sync_sched_exp_handler+0x10/0x90
[ 0.053333] EFLAGS: 00210206 CPU: 0
[ 0.053333] EAX: 109e2000 EBX: 4dc04240 ECX: 4ceb9990 EDX: 00000001
[ 0.053333] ESI: 4dc04240 EDI: 4dc04450 EBP: 40049e48 ESP: 40049e48
[ 0.053333] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[ 0.053333] CR0: 80050033 CR2: 109e2014 CR3: 0dda1000 CR4: 000006f0
[ 0.053333] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 0.053333] DR6: fffe0ff0 DR7: 00000400
[ 0.053333] Call Trace:
[ 0.053333] ? sync_rcu_exp_select_cpus+0x1a7/0x280
[ 0.053333] ? _synchronize_rcu_expedited+0x36c/0x3a0
[ 0.053333] ? rcu_stall_kick_kthreads+0xf0/0xf0
[ 0.053333] ? _synchronize_rcu_expedited+0x228/0x3a0
[ 0.053333] ? sched_clock+0x9/0x10
[ 0.053333] ? __bitmap_weight+0x5b/0x70
[ 0.053333] ? rcu_spawn_tasks_kthread+0x3d/0x3d
[ 0.053333] ? synchronize_sched_expedited+0xae/0xb0
[ 0.053333] ? synchronize_sched+0xc7/0x110
[ 0.053333] ? try_to_wake_up+0x30b/0x370
[ 0.053333] ? kthread_create_on_node+0x18/0x20
[ 0.053333] ? rcu_test_sync_prims+0x8/0x30
[ 0.053333] ? rcu_set_runtime_mode+0x8/0x1b
[ 0.053333] ? do_one_initcall+0x8b/0x12d
[ 0.053333] ? parse_args+0x16f/0x2a0
[ 0.053333] ? do_early_param+0x75/0x75
[ 0.053333] ? kernel_init_freeable+0x18a/0x208
[ 0.053333] ? rest_init+0x1f0/0x1f0
[ 0.053333] ? kernel_init+0x8/0xf0
[ 0.053333] ? ret_from_fork+0x19/0x30
[ 0.053333] Code: 00 00 8d 65 f8 5b 5e 5d c3 66 90 f3 c3 8d b4 26 00 00 00 00 8d bc 27 00 00 00 00 55 8b 80 cc 06 00 00 89 e5 64 03 05 08 61 d8 4d <8b> 50 14 8b 52 34 85 50 18 74 67 64 a0 cd 2d d9 4d 84 c0 75 5d
[ 0.053333] EIP: sync_sched_exp_handler+0x10/0x90 SS:ESP: 0068:40049e48
[ 0.053333] CR2: 00000000109e2014
[ 0.053333] ---[ end trace 8ebb26ef4a7b41a3 ]---
[ 0.053333] Kernel panic - not syncing: Fatal exception
# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start 54ad80c6083c1c9ebe039c0fab01418c45c09033 7928b2cbe55b2a410a0f5c1f154610059c57b1b2 --
git bisect good a32e01ee689794a26bdfdbaa7e8c334576cee36c # 03:31 G 11 0 0 0 rcu: Use wrapper for lockdep asserts
git bisect good 338c46403f169dd76bff8ed58fd0be0d600e7aba # 03:40 G 11 0 0 0 Merge branches 'fixes.2018.02.23a', 'srcu.2018.02.20a' and 'torture.2018.02.20a' into HEAD
git bisect good e69aaa0647ec61536fdc88752eb7734977fdb289 # 03:45 G 11 0 0 0 EXP: rcu: Add debugging info to other assertion
git bisect good e6e9ee038aa32e29a4d141c0c975a3d0972dedea # 03:51 G 11 0 0 0 EXP sched: Make non-production PREEMPT cond_resched() help Tasks RCU
git bisect good 2a84d1aef4239554aeccbc6b31a989f8c3be9675 # 03:56 G 11 0 0 0 rcu: Inline rcu_preempt_do_callback() into its sole caller
# first bad commit: [54ad80c6083c1c9ebe039c0fab01418c45c09033] rcu: Parallelize expedited grace-period initialization
git bisect good 2a84d1aef4239554aeccbc6b31a989f8c3be9675 # 03:58 G 31 0 0 0 rcu: Inline rcu_preempt_do_callback() into its sole caller
# extra tests on HEAD of rcu/rcu/dev
git bisect bad 54ad80c6083c1c9ebe039c0fab01418c45c09033 # 03:58 B 0 17 34 0 rcu: Parallelize expedited grace-period initialization
# extra tests on tree/branch rcu/rcu/dev
git bisect bad 54ad80c6083c1c9ebe039c0fab01418c45c09033 # 03:59 B 0 17 34 0 rcu: Parallelize expedited grace-period initialization
# extra tests with first bad commit reverted
git bisect good fb47c4ab15a930e167e7798fa1c572a8ee911b93 # 04:19 G 11 0 0 0 Revert "rcu: Parallelize expedited grace-period initialization"
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
4 years, 5 months
- 1
- 0