January 2016 - LKP - Ml01.01.Org

[lkp] [sched] ed4ab8ce76: +112.7% unixbench.score

by kernel test robot

FYI, we noticed the below changes on https://git.kernel.org/pub/scm/linux/kernel/git/mel/linux-balancenuma sched-disable-schedstats-v2r1 commit ed4ab8ce76b14db0f82f17d6bf20898532f24040 ("sched: Make schedstats a runtime tunable that is disabled by default") ========================================================================================= 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-4.9/performance/1HDD/5K/btrfs/1x/x86_64-rhel/16d/256fpd/32t/debian-x86_64-2015-02-07.cgz/fsyncBeforeClose/lkp-ne04/400M/fsmark commit: v4.5-rc1 ed4ab8ce76b14db0f82f17d6bf20898532f24040 v4.5-rc1 ed4ab8ce76b14db0f82f17d6bf ---------------- -------------------------- %stddev %change %stddev \ | \ 1473135 ± 4% -27.2% 1072149 ± 0% fsmark.app_overhead 351.48 ± 0% -2.4% 342.91 ± 0% fsmark.files_per_sec 3063192 ± 0% -4.5% 2926520 ± 1% fsmark.time.file_system_outputs 47561 ± 5% -71.1% 13740 ± 2% fsmark.time.involuntary_context_switches 10586 ± 0% -9.5% 9583 ± 0% fsmark.time.minor_page_faults 21.60 ± 16% -67.6% 7.00 ± 0% fsmark.time.percent_of_cpu_this_job_got 54.52 ± 3% -67.8% 17.54 ± 0% fsmark.time.system_time 1100909 ± 2% -52.8% 520080 ± 2% fsmark.time.voluntary_context_switches 4096 ± 2% -100.0% 0.00 ± 0% proc-vmstat.numa_pte_updates 393712 ± 17% -19.6% 316676 ± 1% numa-numastat.node1.local_node 393716 ± 17% -19.6% 316678 ± 1% numa-numastat.node1.numa_hit 2881 ± 15% -73.5% 762.80 ± 9% slabinfo.btrfs_trans_handle.active_objs 2895 ± 15% -73.7% 762.80 ± 9% slabinfo.btrfs_trans_handle.num_objs 47946 ± 6% -34.1% 31613 ± 0% softirqs.RCU 51042 ± 7% -37.0% 32159 ± 5% softirqs.SCHED 106261 ± 8% -22.8% 82065 ± 8% softirqs.TIMER 332.10 ± 15% -76.0% 79.70 ± 50% turbostat.Avg_MHz 20.95 ± 15% -72.5% 5.76 ± 50% turbostat.CPU%c1 6.73 ± 8% +260.6% 24.28 ± 7% turbostat.Pkg%pc3 10377 ± 1% -7.4% 9608 ± 1% vmstat.io.bo 12577 ± 2% -40.6% 7470 ± 1% vmstat.system.cs 1436 ± 2% -28.2% 1031 ± 0% vmstat.system.in 47561 ± 5% -71.1% 13740 ± 2% time.involuntary_context_switches 10586 ± 0% -9.5% 9583 ± 0% time.minor_page_faults 21.60 ± 16% -67.6% 7.00 ± 0% time.percent_of_cpu_this_job_got 54.52 ± 3% -67.8% 17.54 ± 0% time.system_time 0.75 ± 6% +14.2% 0.85 ± 4% time.user_time 1100909 ± 2% -52.8% 520080 ± 2% time.voluntary_context_switches 2.861e+08 ± 2% -81.1% 54100491 ± 11% cpuidle.C1-NHM.time 167488 ± 5% -75.3% 41433 ± 5% cpuidle.C1-NHM.usage 55038510 ± 6% -41.2% 32338858 ± 12% cpuidle.C1E-NHM.time 50732 ± 7% -22.4% 39376 ± 6% cpuidle.C1E-NHM.usage 3.415e+08 ± 1% -18.4% 2.788e+08 ± 3% cpuidle.C3-NHM.time 199101 ± 1% -12.3% 174545 ± 1% cpuidle.C3-NHM.usage 3.389e+08 ± 4% -74.3% 86968082 ± 7% cpuidle.POLL.time 352604 ± 4% -78.7% 74952 ± 6% cpuidle.POLL.usage 75411 ± 13% +15.1% 86761 ± 3% numa-vmstat.node0.nr_active_file 140558 ± 15% +23.0% 172844 ± 2% numa-vmstat.node0.nr_dirtied 818.00 ± 17% +27.2% 1040 ± 1% numa-vmstat.node0.nr_dirty 199274 ± 11% +16.2% 231531 ± 1% numa-vmstat.node0.nr_file_pages 122909 ± 10% +16.5% 143210 ± 0% numa-vmstat.node0.nr_inactive_file 24133 ± 13% +17.3% 28307 ± 1% numa-vmstat.node0.nr_slab_reclaimable 139704 ± 15% +23.0% 171771 ± 2% numa-vmstat.node0.nr_written 30848 ± 9% -43.8% 17343 ± 4% numa-vmstat.node1.nr_active_file 43238 ± 16% -69.9% 12996 ± 14% numa-vmstat.node1.nr_dirtied 316.70 ± 19% -67.7% 102.30 ± 22% numa-vmstat.node1.nr_dirty 103100 ± 6% -29.5% 72713 ± 2% numa-vmstat.node1.nr_file_pages 70905 ± 5% -22.9% 54635 ± 2% numa-vmstat.node1.nr_inactive_file 9936 ± 9% -33.4% 6622 ± 7% numa-vmstat.node1.nr_slab_reclaimable 42907 ± 16% -70.0% 12890 ± 14% numa-vmstat.node1.nr_written 313222 ± 7% -12.3% 274716 ± 2% numa-vmstat.node1.numa_hit 309494 ± 7% -12.5% 270899 ± 2% numa-vmstat.node1.numa_local 318673 ± 13% +15.0% 366549 ± 3% numa-meminfo.node0.Active 301654 ± 13% +15.0% 347052 ± 3% numa-meminfo.node0.Active(file) 3274 ± 17% +27.2% 4165 ± 1% numa-meminfo.node0.Dirty 797112 ± 11% +16.2% 926133 ± 1% numa-meminfo.node0.FilePages 495267 ± 10% +16.9% 578895 ± 1% numa-meminfo.node0.Inactive 491645 ± 10% +16.5% 572849 ± 0% numa-meminfo.node0.Inactive(file) 980996 ± 10% +15.0% 1127768 ± 1% numa-meminfo.node0.MemUsed 96537 ± 13% +17.3% 113231 ± 1% numa-meminfo.node0.SReclaimable 138003 ± 8% -40.5% 82163 ± 5% numa-meminfo.node1.Active 123397 ± 9% -43.8% 69374 ± 4% numa-meminfo.node1.Active(file) 1268 ± 19% -67.5% 411.80 ± 22% numa-meminfo.node1.Dirty 412410 ± 6% -29.5% 290854 ± 2% numa-meminfo.node1.FilePages 288842 ± 4% -23.4% 221309 ± 3% numa-meminfo.node1.Inactive 283626 ± 5% -22.9% 218545 ± 2% numa-meminfo.node1.Inactive(file) 523063 ± 5% -25.7% 388503 ± 3% numa-meminfo.node1.MemUsed 39748 ± 9% -33.3% 26492 ± 7% numa-meminfo.node1.SReclaimable 58456 ± 7% -21.7% 45747 ± 5% numa-meminfo.node1.Slab 73085 ± 0% -100.0% 0.00 ± -1% latency_stats.avg.wait_log_commit.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 30118 ± 0% -100.0% 0.00 ± -1% latency_stats.avg.write_all_supers.[btrfs].write_ctree_super.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 78833 ± 0% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_start_ordered_extent.[btrfs].btrfs_wait_ordered_range.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 10142 ± 1% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 57499 ± 9% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_new_inode.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath 56081 ± 8% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].insert_with_overflow.[btrfs].btrfs_insert_dir_item.[btrfs].btrfs_add_link.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open 72520 ± 3% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_new_inode.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath 41230 ± 48% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].insert_with_overflow.[btrfs].btrfs_insert_dir_item.[btrfs].btrfs_add_link.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open 9324 ± 6% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].copy_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync 11745 ± 4% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].insert_with_overflow.[btrfs].btrfs_insert_dir_item.[btrfs].btrfs_add_link.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open 10752 ± 5% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_xattr.[btrfs].__btrfs_getxattr.[btrfs].btrfs_xattr_handler_get.[btrfs].generic_getxattr.cap_inode_need_killpriv.security_inode_need_killpriv.dentry_needs_remove_privs.file_remove_privs.btrfs_file_write_iter.[btrfs] 18352 ± 89% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_read_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_dir_item.[btrfs].btrfs_lookup_dentry.[btrfs].btrfs_lookup.[btrfs].lookup_real.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath 50807 ± 3% -100.0% 0.00 ± -1% latency_stats.hits.btrfs_tree_read_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_xattr.[btrfs].__btrfs_getxattr.[btrfs].btrfs_xattr_handler_get.[btrfs].generic_getxattr.cap_inode_need_killpriv.security_inode_need_killpriv.dentry_needs_remove_privs.file_remove_privs.btrfs_file_write_iter.[btrfs].__vfs_write 35878 ± 27% -100.0% 0.00 ± -1% latency_stats.hits.pipe_wait.pipe_read.__vfs_read.vfs_read.SyS_read.entry_SYSCALL_64_fastpath 79830 ± 0% -100.0% 0.00 ± -1% latency_stats.hits.wait_log_commit.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 84552 ± 0% -100.0% 0.00 ± -1% latency_stats.hits.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_ordered_range.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 8386 ± 28% -100.0% 0.00 ± -1% latency_stats.max.btrfs_start_ordered_extent.[btrfs].btrfs_wait_ordered_range.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 8798 ± 16% -100.0% 0.00 ± -1% latency_stats.max.wait_for_writer.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 258437 ± 5% -100.0% 0.00 ± -1% latency_stats.max.wait_log_commit.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 16354 ± 3% -100.0% 0.00 ± -1% latency_stats.max.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_marked_extents.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 1622499 ± 29% -100.0% 0.00 ± -1% latency_stats.max.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_ordered_range.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 173227 ± 12% -100.0% 0.00 ± -1% latency_stats.max.write_all_supers.[btrfs].write_ctree_super.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 17461880 ± 5% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_start_ordered_extent.[btrfs].btrfs_wait_ordered_range.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 7972317 ± 1% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 8859 ±100% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].alloc_reserved_file_extent.[btrfs].__btrfs_run_delayed_refs.[btrfs].btrfs_run_delayed_refs.[btrfs].btrfs_commit_transaction.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync 6913 ± 43% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_csum_file_blocks.[btrfs].copy_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync 229131 ± 21% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_insert_delayed_items.[btrfs].btrfs_commit_inode_delayed_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync 1850677 ± 9% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_new_inode.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath 65647 ± 10% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].copy_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync 1695583 ± 8% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].insert_with_overflow.[btrfs].btrfs_insert_dir_item.[btrfs].btrfs_add_link.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open 212868 ± 50% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].insert_with_overflow.[btrfs].btrfs_insert_dir_item.[btrfs].btrfs_add_link.[btrfs].btrfs_mkdir.[btrfs].vfs_mkdir.SyS_mkdir.entry_SYSCALL_64_fastpath 12786 ± 12% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_truncate_inode_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 45005 ± 13% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].drop_objectid_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 215659 ± 14% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_insert_delayed_items.[btrfs].btrfs_commit_inode_delayed_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync 1367601 ± 4% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_new_inode.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath 668316 ± 56% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].insert_with_overflow.[btrfs].btrfs_insert_dir_item.[btrfs].btrfs_add_link.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open 271351 ± 6% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_inode.[btrfs].__btrfs_update_delayed_inode.[btrfs].btrfs_commit_inode_delayed_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync 93978 ± 8% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_forward.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 8958 ± 10% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_csum_file_blocks.[btrfs].copy_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync 21415 ± 12% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_insert_delayed_items.[btrfs].btrfs_commit_inode_delayed_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync 235483 ± 5% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].btrfs_new_inode.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath 98497 ± 8% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].copy_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync 314718 ± 5% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_insert_empty_items.[btrfs].insert_with_overflow.[btrfs].btrfs_insert_dir_item.[btrfs].btrfs_add_link.[btrfs].btrfs_create.[btrfs].vfs_create.path_openat.do_filp_open.do_sys_open 108828 ± 8% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 51098 ± 4% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_csum.[btrfs].btrfs_csum_file_blocks.[btrfs].copy_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync 175287 ± 7% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_dir_item.[btrfs].btrfs_lookup_dentry.[btrfs].btrfs_lookup.[btrfs].lookup_real.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath 118581 ± 9% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_inode.[btrfs].__btrfs_update_delayed_inode.[btrfs].btrfs_commit_inode_delayed_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync 257043 ± 6% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_xattr.[btrfs].__btrfs_getxattr.[btrfs].btrfs_xattr_handler_get.[btrfs].generic_getxattr.cap_inode_need_killpriv.security_inode_need_killpriv.dentry_needs_remove_privs.file_remove_privs.btrfs_file_write_iter.[btrfs] 42705 ± 5% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].btrfs_truncate_inode_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 66105 ± 8% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_read_lock_root_node.[btrfs].btrfs_search_slot.[btrfs].drop_objectid_items.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 56090 ± 7% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_search_forward.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 43378 ± 13% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_log_inode.[btrfs].btrfs_log_inode_parent.[btrfs].btrfs_log_dentry_safe.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 377987 ± 89% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_dir_item.[btrfs].btrfs_lookup_dentry.[btrfs].btrfs_lookup.[btrfs].lookup_real.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath 889722 ± 3% -100.0% 0.00 ± -1% latency_stats.sum.btrfs_tree_read_lock.[btrfs].btrfs_search_slot.[btrfs].btrfs_lookup_xattr.[btrfs].__btrfs_getxattr.[btrfs].btrfs_xattr_handler_get.[btrfs].generic_getxattr.cap_inode_need_killpriv.security_inode_need_killpriv.dentry_needs_remove_privs.file_remove_privs.btrfs_file_write_iter.[btrfs].__vfs_write 1588928 ± 30% -100.0% 0.00 ± -1% latency_stats.sum.do_wait.SyS_wait4.entry_SYSCALL_64_fastpath 10889 ± 29% -100.0% 0.00 ± -1% latency_stats.sum.ep_poll.SyS_epoll_wait.entry_SYSCALL_64_fastpath 2505908 ± 31% -100.0% 0.00 ± -1% latency_stats.sum.pipe_wait.pipe_read.__vfs_read.vfs_read.SyS_read.entry_SYSCALL_64_fastpath 19734 ± 7% -100.0% 0.00 ± -1% latency_stats.sum.pipe_wait.wait_for_partner.fifo_open.do_dentry_open.vfs_open.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath 393857 ± 14% -100.0% 0.00 ± -1% latency_stats.sum.wait_for_writer.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 5.835e+09 ± 0% -100.0% 0.00 ± -1% latency_stats.sum.wait_log_commit.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 23983772 ± 0% -100.0% 0.00 ± -1% latency_stats.sum.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_marked_extents.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 7.308e+08 ± 4% -100.0% 0.00 ± -1% latency_stats.sum.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_range.btrfs_wait_ordered_range.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath 1.384e+08 ± 0% -100.0% 0.00 ± -1% latency_stats.sum.write_all_supers.[btrfs].write_ctree_super.[btrfs].btrfs_sync_log.[btrfs].btrfs_sync_file.[btrfs].vfs_fsync_range.do_fsync.SyS_fsync.entry_SYSCALL_64_fastpath ========================================================================================= compiler/kconfig/nr_task/rootfs/tbox_group/test/testcase: gcc-4.9/x86_64-rhel/100%/debian-x86_64-2015-02-07.cgz/nhm-white2/context1/unixbench commit: v4.5-rc1 ed4ab8ce76b14db0f82f17d6bf20898532f24040 v4.5-rc1 ed4ab8ce76b14db0f82f17d6bf ---------------- -------------------------- %stddev %change %stddev \ | \ 1514 ± 0% +112.7% 3222 ± 0% unixbench.score 80462 ± 33% +1766.4% 1501718 ± 53% unixbench.time.involuntary_context_switches 388.27 ± 0% -3.2% 375.73 ± 0% unixbench.time.system_time 10.93 ± 1% +101.5% 22.03 ± 0% unixbench.time.user_time 60435954 ± 0% +109.5% 1.266e+08 ± 1% unixbench.time.voluntary_context_switches 906365 ± 2% +96.9% 1784406 ± 14% vmstat.system.cs 80462 ± 33% +1766.4% 1501718 ± 53% time.involuntary_context_switches 10.93 ± 1% +101.5% 22.03 ± 0% time.user_time 60435954 ± 0% +109.5% 1.266e+08 ± 1% time.voluntary_context_switches 1.209e+08 ± 0% -100.0% 0.00 ± -1% latency_stats.hits.pipe_wait.pipe_read.__vfs_read.vfs_read.SyS_read.entry_SYSCALL_64_fastpath 233697 ± 4% -100.0% 0.00 ± -1% latency_stats.sum.do_wait.SyS_wait4.entry_SYSCALL_64_fastpath 31068 ± 11% -100.0% 0.00 ± -1% latency_stats.sum.ep_poll.SyS_epoll_wait.entry_SYSCALL_64_fastpath 2.42e+08 ± 0% -100.0% 0.00 ± -1% latency_stats.sum.pipe_wait.pipe_read.__vfs_read.vfs_read.SyS_read.entry_SYSCALL_64_fastpath 17252 ± 5% -100.0% 0.00 ± -1% latency_stats.sum.pipe_wait.wait_for_partner.fifo_open.do_dentry_open.vfs_open.path_openat.do_filp_open.do_sys_open.SyS_open.entry_SYSCALL_64_fastpath 1095198 ±296% -100.0% 0.00 ± -1% latency_stats.sum.wait_on_page_bit.__filemap_fdatawait_range.filemap_fdatawait_keep_errors.sync_inodes_sb.sync_inodes_one_sb.iterate_supers.sys_sync.entry_SYSCALL_64_fastpath lkp-ne04: Nehalem-EP Memory: 12G nhm-white2: Nehalem Memory: 4G unixbench.time.system_time 390 ++--------------------------------------------------------------------+ 388 *+*.*.. .*.*.*.*..*. *.*.*. .*.*.*.*.*..*.*.*. .*.*..*.*.* | * *.*.*.*. + *. * | 386 ++ *..* | 384 ++ | | | 382 ++ | 380 ++ | 378 ++ | | O O O O | 376 O+ O O O O O O O O O O O | 374 ++ O O O O O O O | | O | 372 ++ O | 370 ++--------------------------------------------------------------------+ unixbench.time.voluntary_context_switches 1.3e+08 ++------O----------------------------O---O---O----O---------------+ O O O O O O O O O O O O O O O O O O O | 1.2e+08 ++ O | | | 1.1e+08 ++ | | | 1e+08 ++ | | | 9e+07 ++ | | | 8e+07 ++ | | | 7e+07 ++ | | .*.*.*.*.*.*. | 6e+07 *+*-*-*-*-*-*-*--*-------------*-*-*-*-*-*-*-*-*--*-*-*-*-*-*-*-*-* [*] bisect-good sample [O] bisect-bad sample To reproduce: git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git cd lkp-tests bin/lkp install job.yaml # job file is attached in this email bin/lkp run job.yaml 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, Ying Huang

4 years, 4 months

1
0
0 / 0

[lkp] [mm, vmscan] d81d90cdf6: +110.6% turbostat.%Busy

by kernel test robot

FYI, we noticed the below changes on https://git.kernel.org/pub/scm/linux/kernel/git/mel/linux-balancenuma mm-vmscan-node-lru-v2r25 commit d81d90cdf683f40d14b064cdcecb840a386e00c3 ("mm, vmscan: Only wakeup kswapd once per node for the requested classzone") ========================================================================================= compiler/cpufreq_governor/disk/filesize/fs/iterations/kconfig/nr_threads/rootfs/sync_method/tbox_group/test_size/testcase: gcc-4.9/performance/1BRD_48G/4M/xfs/1x/x86_64-rhel/64t/debian-x86_64-2015-02-07.cgz/NoSync/ivb44/40G/fsmark commit: da9d35c7cc19983b355c3d79f9c2d3314718934f d81d90cdf683f40d14b064cdcecb840a386e00c3 da9d35c7cc19983b d81d90cdf683f40d14b064cdce ---------------- -------------------------- %stddev %change %stddev \ | \ 10242 ± 25% +449.1% 56234 ± 42% fsmark.time.file_system_inputs 206.88 ± 3% +25.0% 258.50 ± 2% fsmark.time.percent_of_cpu_this_job_got 41.96 ± 1% +24.9% 52.40 ± 1% fsmark.time.system_time 40698 ± 11% +23.2% 50158 ± 10% softirqs.RCU 3.88 ± 86% +3061.3% 122.50 ± 55% sched_debug.cfs_rq:/.util_avg.24 234.62 ± 60% -64.8% 82.50 ± 58% sched_debug.cpu.ttwu_local.16 2831861 ± 29% -46.9% 1504545 ± 10% numa-vmstat.node0.nr_file_pages 2817819 ± 29% -47.1% 1490984 ± 11% numa-vmstat.node0.nr_inactive_file 90864 ± 13% -32.4% 61413 ± 9% numa-vmstat.node0.nr_slab_reclaimable 10242 ± 25% +449.1% 56234 ± 42% time.file_system_inputs 206.88 ± 3% +25.0% 258.50 ± 2% time.percent_of_cpu_this_job_got 41.96 ± 1% +24.9% 52.40 ± 1% time.system_time 11329789 ± 29% -46.9% 6018095 ± 11% numa-meminfo.node0.FilePages 11277226 ± 29% -47.1% 5968386 ± 11% numa-meminfo.node0.Inactive 11273648 ± 29% -47.1% 5963859 ± 11% numa-meminfo.node0.Inactive(file) 363543 ± 13% -32.4% 245672 ± 9% numa-meminfo.node0.SReclaimable 413977 ± 11% -28.7% 295254 ± 7% numa-meminfo.node0.Slab 5418592 ± 2% -20.6% 4301600 ± 14% slabinfo.buffer_head.active_objs 138939 ± 2% -20.6% 110304 ± 14% slabinfo.buffer_head.active_slabs 5418650 ± 2% -20.6% 4301893 ± 14% slabinfo.buffer_head.num_objs 138939 ± 2% -20.6% 110304 ± 14% slabinfo.buffer_head.num_slabs 6333 ± 1% -13.4% 5485 ± 8% slabinfo.xfs_inode.active_objs 6436 ± 1% -13.7% 5556 ± 7% slabinfo.xfs_inode.num_objs 427.12 ± 40% +525.3% 2670 ± 65% vmstat.io.bi 1578153 ± 2% +2.5% 1617055 ± 1% vmstat.io.bo 23143986 ± 2% -20.4% 18431559 ± 14% vmstat.memory.cache 24826852 ± 2% +19.1% 29569065 ± 9% vmstat.memory.free 8802 ± 7% +1954.0% 180812 ± 9% vmstat.system.cs 4468 ± 3% +61.0% 7192 ± 7% vmstat.system.in 3760 ± 26% +9446.2% 358948 ± 10% cpuidle.C1-IVT.usage 15921601 ± 18% +47.6% 23505095 ± 5% cpuidle.C1E-IVT.time 9827 ± 17% +73.3% 17034 ± 5% cpuidle.C1E-IVT.usage 11201827 ± 9% +22.8% 13753015 ± 5% cpuidle.C3-IVT.time 4247 ± 15% +36.6% 5801 ± 5% cpuidle.C3-IVT.usage 9.214e+08 ± 2% -11.0% 8.201e+08 ± 3% cpuidle.C6-IVT.time 417275 ± 78% +13463.9% 56598978 ± 22% cpuidle.POLL.time 3552 ± 67% +20425.7% 729251 ± 11% cpuidle.POLL.usage 6.94 ± 1% +110.6% 14.61 ± 10% turbostat.%Busy 219.25 ± 1% +104.8% 449.00 ± 10% turbostat.Avg_MHz 11.93 ± 8% +85.4% 22.11 ± 4% turbostat.CPU%c1 1.91 ± 9% +23.7% 2.36 ± 6% turbostat.CPU%c3 79.23 ± 1% -23.1% 60.93 ± 4% turbostat.CPU%c6 69.46 ± 1% +24.8% 86.66 ± 1% turbostat.CorWatt 16.74 ± 19% -73.6% 4.42 ± 31% turbostat.Pkg%pc2 101.45 ± 1% +16.9% 118.57 ± 1% turbostat.PkgWatt 702680 ± 2% -18.0% 576354 ± 12% meminfo.Active 698293 ± 2% -18.1% 572094 ± 12% meminfo.Active(file) 22145325 ± 2% -20.2% 17670757 ± 13% meminfo.Cached 26033970 ± 2% +17.5% 30581446 ± 8% meminfo.Inactive 26033970 ± 2% +17.5% 30581446 ± 8% meminfo.Inactive(anon) 27171589 ± 2% +15.8% 31466704 ± 7% meminfo.MemAvailable 26033979 ± 2% +17.5% 30581451 ± 8% meminfo.MemFree 698293 ± 2% -18.1% 572094 ± 12% meminfo.SReclaimable 796237 ± 1% -16.0% 668770 ± 10% meminfo.Slab 3745917 ± 4% +46.8% 5499519 ± 31% proc-vmstat.kswapd_inodesteal 3389 ±129% +57644.8% 1957115 ± 9% proc-vmstat.kswapd_low_wmark_hit_quickly 5535200 ± 2% -20.2% 4417021 ± 13% proc-vmstat.nr_file_pages 6511739 ± 2% +17.5% 7648296 ± 8% proc-vmstat.nr_free_pages 5507008 ± 2% -20.3% 4389409 ± 13% proc-vmstat.nr_inactive_file 174533 ± 2% -18.1% 142996 ± 12% proc-vmstat.nr_slab_reclaimable 132190 ± 36% +1467.4% 2071908 ± 8% proc-vmstat.pageoutrun 3894864 ± 4% +45.6% 5669363 ± 31% proc-vmstat.pgfree 9573 ± 41% +528.1% 60129 ± 64% proc-vmstat.pgpgin ivb44: Ivytown Ivy Bridge-EP Memory: 64G vm-lkp-wsx03-yocto-x86_64: qemu-system-x86_64 -enable-kvm -cpu SandyBridge Memory: 320M vmstat.system.in 11000 ++------------------------------------------------------------------+ O | 10000 ++ O O | | O O | 9000 ++ | | O O OO O O | 8000 ++ O O O O | | O O O O O OO O | 7000 ++ O O O O O O O O O O O | | O O O | 6000 ++ | | | 5000 ++ .*. | |.* .*.*.**.*.* .*.**.*.*.**. .* .*.* .*. .**.*.**.*.** *.**.*.**.* 4000 *+-*-----------*-------------*--*----*---*--------------------------+ vmstat.system.cs 300000 ++-----------------------------------------------------------------+ | | 250000 ++ O O | O O O | | O O O O O O O | 200000 ++ O O O O O O O OO OO O | | O O O O O OO O O OO O | 150000 ++ O | | | 100000 ++ | | | | | 50000 ++ | |.* .*. .*. .* | 0 *+-*-*-**-*-**-*-**-*-**---**---*-**-*--*-*-**-*-**-*-**-*-**-*-**-* proc-vmstat.kswapd_low_wmark_hit_quickly 3e+06 ++----------------------------------------------------------------+ | O O | 2.5e+06 ++ O O | O O O O O | | O O O O O O O O O | 2e+06 ++ O O O OO OO O O O O O OO O O O | | O O | 1.5e+06 ++ | | | 1e+06 ++ | | | | | 500000 ++ | | | 0 *+**-*-**-*-**-*-**-**-*-**-*-**-*-**-*-**-*-**-*-**-**-*-**-*-**-* proc-vmstat.pageoutrun 3e+06 ++----------------------------------------------------------------+ | O O O O | 2.5e+06 O+ O O | | O O O | | O O O O O OO O O O O O OO OO O O | 2e+06 ++ O OO O O O OO | | O | 1.5e+06 ++ | | | 1e+06 ++ | | | | | 500000 ++ | | .* .*.**.**.*.* .*. .* 0 *+**-*-**-*-**-*-**-**-*-**-*-**-*-**-*-**-*--*------------*---**-+ cpuidle.POLL.time 9e+07 ++------------------------------------------------------------------+ | O | 8e+07 ++ O O O | 7e+07 ++ O O O O | O OO O O | 6e+07 ++ O O O O O O O | 5e+07 ++ O O O O O O OO | | O O O O O O O | 4e+07 ++ O O | 3e+07 ++ | | | 2e+07 ++ | 1e+07 ++ | | | 0 *+**-*-*-**-*-**-*-**-*-*-**-*-**-*-**-*-*-**-*-**-*-**-*-*-**-*-**-* cpuidle.POLL.usage 1.2e+06 ++----------------------------------------------------------------+ | O | 1e+06 ++ O O O | O O O | | O O | 800000 ++ O O O O O O O O O O O | | O O OO O O O O O OO O O | 600000 ++ O O O O | | | 400000 ++ | | | | | 200000 ++ | | | 0 *+**-*-**-*-**-*-**-**-*-**-*-**-*-**-*-**-*-**-*-**-**-*-**-*-**-* turbostat.Avg_MHz 550 ++----------------------------O-------------O-------------------------+ | O O O | 500 ++ O O OO O OO | | O O O | 450 O+ O O O O O O | | O O O O O O O O O O | 400 ++O O O O O | | | 350 ++ | | | 300 ++ | | | 250 ++ | *.*.**.*.*.**.*.*.**.*.*.**.*.*.**.*.*.**.*.*.**.*.*.**.*.*.**.*.*.**.* 200 ++--------------------------------------------------------------------+ turbostat._Busy 18 ++----------------------------O-------------O--------------------------+ | O O O | 16 ++ O O O O O O O | | O O O | O O O O O O O O O | 14 ++ O O O O O O O O | | O O O O O | 12 ++ | | | 10 ++ | | | | | 8 ++ | *.*.**.*.*.**.*.*.*.**.*.*.**.*.*.*.**.*.*.**.*.*.**.*.*.*.**.*.*.**.*.* 6 ++---------------------------------------------------------------------+ turbostat.CPU_c1 26 ++---------------------------------------------------------------------+ | | 24 ++ O O O O O O O O O | 22 O+ O O O O O O O | | O O O O OO O O O O O O OO O O | 20 ++ O O O O | | | 18 ++ | | | 16 ++ | 14 ++ | | .* | 12 *+*. *.*.*.* *.*. .*.*. .**.*.*. *.*.*. *.*.*.* *.*.*. | | * *. .*.*.* *.** * * * **.*.* 10 ++------------*--------------------------------------------------------+ turbostat.CPU_c6 85 ++---------------------------------------------------------------------+ | | 80 ++ .**.*.*. .* *. .* .* .*.* *.*.**.*.* * *.*.*.* *.*.*.**.*.*.**.*.* *.*.*.*. *.*.* * | | * | 75 ++ | | | 70 ++ | | | 65 ++ O O | | O O O O O O O O O | | O O O O O O O O O | 60 O+ O O O O O O O O O | | O O O O O O O | 55 ++---------------------------------------------------------------------+ turbostat.PkgWatt 130 ++--------------------------------------------------------------------+ | O O | 125 ++ O O | O O O O O O | 120 ++O O O O O O O O O O O | | O O O O O O O O O O O O O | 115 ++ O | | O O | 110 ++ | | | 105 ++ * | |.*.**. +: * .*. .**.*. *.*.*. .* .*.**. .* .* 100 *+ *.* :.* + : ** * *.* **.* + *.* *.* * | | * + .** : + * | 95 ++--------------*------*----------------------------------------------+ turbostat.CorWatt 95 ++----------------------------O-------------O--------------------------+ | | 90 ++ OO O O O O O O | O O O O O O O O O O O O O O O O | 85 ++ O O O O O O O O O | | O O | 80 ++ | | | 75 ++ | | *. .* *. *. | 70 ++ **.*.* : * *. *. + *.**. + **.*. .**. .*. .**.*. *.*.* * *.*. .*.* + + * * * * * * *.* | 65 ++ * * | | | 60 ++---------------------------------------------------------------------+ fsmark.time.system_time 56 ++---------------------------------------------------------------------+ | O O O O O O O OO | 54 ++ O O O O O O | 52 ++ O O O OO O O O O O OO O | | O O O O | 50 ++ O O | 48 O+O O | | | 46 ++ | 44 ++ | *. .* *. .*.*. .**.*. .*. .*. .* *. *. .* | 42 ++* *.*.*.* * **.*.* * ** * *.*.* : *.*.*.* * + *. .* 40 ++ +: * * | | * | 38 ++---------------------------------------------------------------------+ [*] bisect-good sample [O] bisect-bad sample To reproduce: git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git cd lkp-tests bin/lkp install job.yaml # job file is attached in this email bin/lkp run job.yaml 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, Ying Huang

4 years, 4 months

1
0
0 / 0

[lkp] [mm, vmscan] 8b5971caa7: BUG: unable to handle kernel paging request at 0000000000015f11

by kernel test robot

FYI, we noticed the below changes on https://git.kernel.org/pub/scm/linux/kernel/git/mel/linux-balancenuma mm-vmscan-node-lru-v2r26 commit 8b5971caa736f046f66f388c0fa704b12bb0a64d ("mm, vmscan: Move LRU lists to node") +------------------------------------------------+------------+------------+ | | 32d9c363c6 | 8b5971caa7 | +------------------------------------------------+------------+------------+ | boot_successes | 2 | 0 | | boot_failures | 6 | 8 | | IP-Config:Auto-configuration_of_network_failed | 6 | | | BUG:unable_to_handle_kernel | 0 | 8 | | Oops | 0 | 8 | | RIP:cpu_vm_stats_fold | 0 | 8 | | Kernel_panic-not_syncing:Fatal_exception | 0 | 8 | | backtrace:debug_hotplug_cpu | 0 | 8 | | backtrace:kernel_init_freeable | 0 | 8 | +------------------------------------------------+------------+------------+ [ 66.072566] tty ptytc: hash matches [ 66.077445] BIOS EDD facility v0.16 2004-Jun-25, 2 devices found [ 66.079753] Unregister pv shared memory for cpu 0 [ 66.090173] BUG: unable to handle kernel paging request at 0000000000015f11 [ 66.091031] IP: [<ffffffff812c57e9>] cpu_vm_stats_fold+0x159/0x1f0 [ 66.091762] PGD 0 [ 66.092022] Oops: 0000 [#1] SMP DEBUG_PAGEALLOC [ 66.092618] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 4.5.0-rc1-00005-g8b5971c #1 [ 66.093425] task: ffff880074cc8000 ti: ffff880074cbc000 task.ti: ffff880074cbc000 [ 66.094266] RIP: 0010:[<ffffffff812c57e9>] [<ffffffff812c57e9>] cpu_vm_stats_fold+0x159/0x1f0 [ 66.095234] RSP: 0000:ffff880074cbfcb0 EFLAGS: 00010246 [ 66.095815] RAX: ffff880078c03000 RBX: 0000000000000000 RCX: 0000000000000000 [ 66.096593] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff833561a0 [ 66.097399] RBP: ffff880074cbfd60 R08: ffff880078c24f88 R09: 0000000000015f10 [ 66.098201] R10: fffffffffffd4fc0 R11: 00000000002363b0 R12: ffff880074cbfcd4 [ 66.098981] R13: 0000000000000000 R14: 0000000000000001 R15: ffffffff82db44d0 [ 66.099809] FS: 0000000000000000(0000) GS:ffff880078500000(0000) knlGS:0000000000000000 [ 66.100685] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b [ 66.101316] CR2: 0000000000015f11 CR3: 0000000002c0a000 CR4: 00000000000006a0 [ 66.102155] Stack: [ 66.102383] 0000000074cbfce8 0000000000000000 0000000000000000 0000000000000000 [ 66.103291] fffffffc00000000 00000000fffffffc 0000000000000000 0000000000000000 [ 66.104165] 0000000c00000000 0000000000000004 0000000000000001 0000000000000000 [ 66.105043] Call Trace: [ 66.105319] [<ffffffff81297441>] page_alloc_cpu_notify+0x61/0x80 [ 66.106012] [<ffffffff81130ae4>] notifier_call_chain+0xf4/0x140 [ 66.106671] [<ffffffff81131596>] __raw_notifier_call_chain+0x16/0x20 [ 66.107378] [<ffffffff810f2d6b>] cpu_notify_nofail+0x2b/0x90 [ 66.108042] [<ffffffff810f383e>] _cpu_down+0x2ee/0x450 [ 66.108645] [<ffffffff810f3f1e>] cpu_down+0x4e/0x80 [ 66.109203] [<ffffffff81012ae5>] _debug_hotplug_cpu+0xd5/0x130 [ 66.109856] [<ffffffff8337b65b>] ? pci_iommu_alloc+0xbb/0xbb [ 66.110493] [<ffffffff8337b66f>] debug_hotplug_cpu+0x14/0x1f [ 66.111148] [<ffffffff833729ab>] do_one_initcall+0x16b/0x293 [ 66.111810] [<ffffffff83372caf>] kernel_init_freeable+0x1dc/0x2d0 [ 66.112520] [<ffffffff82188ad0>] ? rest_init+0x200/0x200 [ 66.113142] [<ffffffff82188ae6>] kernel_init+0x16/0x1b0 [ 66.113769] [<ffffffff8219e25f>] ret_from_fork+0x3f/0x70 [ 66.114401] [<ffffffff82188ad0>] ? rest_init+0x200/0x200 [ 66.115037] Code: 03 01 e8 db cd ff ff 48 85 c0 74 7c 48 83 05 0e 6c 09 03 01 4c 8d 80 88 1f 02 00 31 d2 4c 8b 88 80 1f 02 00 48 8b 35 df 6b 09 03 <41> 0f be 4c 11 01 48 83 c6 01 48 89 35 ce 6b 09 03 84 c9 74 1d [ 66.118288] RIP [<ffffffff812c57e9>] cpu_vm_stats_fold+0x159/0x1f0 [ 66.119039] RSP <ffff880074cbfcb0> [ 66.119456] CR2: 0000000000015f11 [ 66.119853] ---[ end trace b6d769b825583457 ]--- [ 66.120356] Kernel panic - not syncing: Fatal exception Thanks, Ying Huang

4 years, 4 months

1
0
0 / 0

[lkp] [wext] ee7e25b578: BUG: spinlock bad magic on CPU#0, swapper/1

by kernel test robot

FYI, we noticed the below changes on https://github.com/0day-ci/linux Johannes-Berg/wext-fix-message-delay-ordering/20160127-204511 commit ee7e25b5789c6c2f4d5ebd9d69f9c2f313ce32d6 ("wext: fix message delay/ordering") [ 0.920828] NET: Registered protocol family 8 [ 0.921515] NET: Registered protocol family 20 [ 0.921515] NET: Registered protocol family 20 [ 0.922281] BUG: spinlock bad magic on CPU#0, swapper/1 [ 0.922281] BUG: spinlock bad magic on CPU#0, swapper/1 [ 0.923186] lock: init_net+0x2d4/0x520, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0 [ 0.923186] lock: init_net+0x2d4/0x520, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0 [ 0.924551] CPU: 0 PID: 1 Comm: swapper Not tainted 4.4.0-03441-gee7e25b5 #1 [ 0.924551] CPU: 0 PID: 1 Comm: swapper Not tainted 4.4.0-03441-gee7e25b5 #1 [ 0.925718] 00000000 [ 0.925718] 00000000 b1b6af20 b1b6af20 b0069e68 b0069e68 b12f102b b12f102b b0069e90 b0069e90 b104a1d3 b104a1d3 b1b0ddde b1b0ddde b1ccf5b4 b1ccf5b4 [ 0.927032] 00000000 [ 0.927032] 00000000 b1b6af20 b1b6af20 ffffffff ffffffff 00000000 00000000 b1ccf5b4 b1ccf5b4 b1ccf5a8 b1ccf5a8 b0069ea0 b0069ea0 b104a1fa b104a1fa [ 0.928303] b1b0de40 [ 0.928303] b1b0de40 b1ccf5b4 b1ccf5b4 b0069ebc b0069ebc b104a295 b104a295 b023a5c6 b023a5c6 b0069f30 b0069f30 00000286 00000286 b1ccf5a8 b1ccf5a8 [ 0.929613] Call Trace: [ 0.929613] Call Trace: [ 0.929995] [<b12f102b>] dump_stack+0x16/0x18 [ 0.929995] [<b12f102b>] dump_stack+0x16/0x18 [ 0.930662] [<b104a1d3>] spin_dump+0x6c/0x76 [ 0.930662] [<b104a1d3>] spin_dump+0x6c/0x76 [ 0.931405] [<b104a1fa>] spin_bug+0x1d/0x21 [ 0.931405] [<b104a1fa>] spin_bug+0x1d/0x21 [ 0.932053] [<b104a295>] do_raw_spin_lock+0x1e/0xbc [ 0.932053] [<b104a295>] do_raw_spin_lock+0x1e/0xbc [ 0.932869] [<b1849d27>] _raw_spin_lock_irqsave+0x1f/0x24 [ 0.932869] [<b1849d27>] _raw_spin_lock_irqsave+0x1f/0x24 [ 0.933751] [<b16b9185>] skb_dequeue+0x12/0x2d [ 0.933751] [<b16b9185>] skb_dequeue+0x12/0x2d [ 0.934448] [<b17e84d5>] wireless_nlevent_flush+0x47/0x71 [ 0.934448] [<b17e84d5>] wireless_nlevent_flush+0x47/0x71 [ 0.935275] [<b17e8507>] wext_netdev_notifier_call+0x8/0xf [ 0.935275] [<b17e8507>] wext_netdev_notifier_call+0x8/0xf [ 0.936120] [<b16beea0>] call_netdevice_notifier+0xd/0x11 [ 0.936120] [<b16beea0>] call_netdevice_notifier+0xd/0x11 [ 0.936988] [<b16c0bdf>] register_netdevice_notifier+0x72/0x13b [ 0.936988] [<b16c0bdf>] register_netdevice_notifier+0x72/0x13b [ 0.937885] [<b1ce4b5f>] ? do_one_initcall+0x84/0x168 [ 0.937885] [<b1ce4b5f>] ? do_one_initcall+0x84/0x168 [ 0.938654] [<b1d26dc6>] ? wext_pernet_init+0x3e/0x3e [ 0.938654] [<b1d26dc6>] ? wext_pernet_init+0x3e/0x3e [ 0.939429] [<b1d26dd3>] wireless_nlevent_init+0xd/0x1d [ 0.939429] [<b1d26dd3>] wireless_nlevent_init+0xd/0x1d [ 0.940232] [<b1ce4c34>] do_one_initcall+0x159/0x168 [ 0.940232] [<b1ce4c34>] do_one_initcall+0x159/0x168 [ 0.941043] [<b103b074>] ? parse_args+0x1c2/0x28a [ 0.941043] [<b103b074>] ? parse_args+0x1c2/0x28a [ 0.941766] [<b1ce4d7f>] kernel_init_freeable+0x13c/0x1b9 [ 0.941766] [<b1ce4d7f>] kernel_init_freeable+0x13c/0x1b9 [ 0.942595] [<b18454e1>] kernel_init+0x8/0xb5 [ 0.942595] [<b18454e1>] kernel_init+0x8/0xb5 [ 0.943268] [<b184a0c8>] ret_from_kernel_thread+0x20/0x34 [ 0.943268] [<b184a0c8>] ret_from_kernel_thread+0x20/0x34 [ 0.944095] [<b18454d9>] ? rest_init+0x65/0x65 [ 0.944095] [<b18454d9>] ? rest_init+0x65/0x65 Elapsed time: 10 qemu-system-i386 -enable-kvm -cpu Haswell,+smep,+smap -kernel /pkg/linux/i386-randconfig-h1-01272117/gcc-5/ee7e25b5789c6c2f4d5ebd9d69f9c2f313ce32d6/vmlinuz-4.4.0-03441-gee7e25b5 -append 'root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-vp-quantal-i386-19/rand_boot-1-quantal-core-i386.cgz-i386-randconfig-h1-01272117-ee7e25b5789c6c2f4d5ebd9d69f9c2f313ce32d6-20160128-88657-1ugcywb-1.yaml ARCH=i386 kconfig=i386-randconfig-h1-01272117 branch=linux-devel/devel-spot-201601272037 commit=ee7e25b5789c6c2f4d5ebd9d69f9c2f313ce32d6 BOOT_IMAGE=/pkg/linux/i386-randconfig-h1-01272117/gcc-5/ee7e25b5789c6c2f4d5ebd9d69f9c2f313ce32d6/vmlinuz-4.4.0-03441-gee7e25b5 max_uptime=600 RESULT_ROOT=/result/boot/1/vm-vp-quantal-i386/quantal-core-i386.cgz/i386-randconfig-h1-01272117/gcc-5/ee7e25b5789c6c2f4d5ebd9d69f9c2f313ce32d6/0 LKP_SERVER=inn earlyprintk=ttyS0,115200 systemd.log_level=err debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 console=ttyS0,115200 console=tty0 vga=normal rw ip=::::vm-vp-quantal-i386-19::dhcp drbd.minor_count=8' -initrd /fs/sdh1/initrd-vm-vp-quantal-i386-19 -m 360 -smp 1 -device e1000,netdev=net0 -netdev user,id=net0 -boot order=nc -no-reboot -watchdog i6300esb -rtc base=localtime -pidfile /dev/shm/kboot/pid-vm-vp-quantal-i386-19 -serial file:/dev/shm/kboot/serial-vm-vp-quantal-i386-19 -daemonize -display none -monitor null Thanks, Kernel Test Robot

4 years, 4 months

1
0
0 / 0

[lkp] [kallsyms] 06862f34f6: BUG: unable to handle kernel NULL pointer dereference at (null)

by kernel test robot

FYI, we noticed the below changes on https://git.linaro.org/people/ard.biesheuvel/linux-arm kallsyms-text-relative commit 06862f34f614bb6ff6a9fc9c4b0d849e2ee2018d ("kallsyms: add support for relative offsets in kallsyms address table") +-----------------------------------------------------------+------------+------------+ | | 30f05309bd | 06862f34f6 | +-----------------------------------------------------------+------------+------------+ | boot_successes | 0 | 0 | | boot_failures | 6 | 8 | | Kernel_panic-not_syncing:Attempted_to_kill_init!exitcode= | 4 | | | BUG:kernel_test_oversize | 2 | | | BUG:unable_to_handle_kernel | 0 | 8 | +-----------------------------------------------------------+------------+------------+ [ 0.568228] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0 [ 0.568971] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0 [ 0.569835] CPU: Intel Xeon E312xx (Sandy Bridge) (family: 0x6, model: 0x2a, stepping: 0x1) [ 0.598441] BUG: unable to handle kernel NULL pointer dereference at (null) [ 0.599646] IP: [ 0.599884] BUG: unable to handle kernel NULL pointer dereference at (null) [ 0.610184] IP: Elapsed time: 10 qemu-system-x86_64 -enable-kvm -cpu SandyBridge -kernel /pkg/linux/x86_64-randconfig-s4-01220217/gcc-5/06862f34f614bb6ff6a9fc9c4b0d849e2ee2018d/vmlinuz-4.4.0-10063-g06862f34 -append 'root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-kbuild-yocto-x86_64-62/bisect_boot-1-yocto-minimal-x86_64.cgz-x86_64-randconfig-s4-01220217-06862f34f614bb6ff6a9fc9c4b0d849e2ee2018d-20160122-39812-uowsx2-0.yaml ARCH=x86_64 kconfig=x86_64-randconfig-s4-01220217 branch=linux-devel/devel-spot-201601220143 commit=06862f34f614bb6ff6a9fc9c4b0d849e2ee2018d BOOT_IMAGE=/pkg/linux/x86_64-randconfig-s4-01220217/gcc-5/06862f34f614bb6ff6a9fc9c4b0d849e2ee2018d/vmlinuz-4.4.0-10063-g06862f34 max_uptime=600 RESULT_ROOT=/result/boot/1/vm-kbuild-yocto-x86_64/yocto-minimal-x86_64.cgz/x86_64-randconfig-s4-01220217/gcc-5/06862f34f614bb6ff6a9fc9c4b0d849e2ee2018d/0 LKP_SERVER=inn earlyprintk=ttyS0,115200 systemd.log_level=err debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 console=ttyS0,115200 console=tty0 vga=normal rw ip=::::vm-kbuild-yocto-x86_64-62::dhcp drbd.minor_count=8' -initrd /fs/sdg1/initrd-vm-kbuild-yocto-x86_64-62 -m 320 -smp 1 -device e1000,netdev=net0 -netdev user,id=net0 -boot order=nc -no-reboot -watchdog i6300esb -rtc base=localtime -drive file=/fs/sdg1/disk0-vm-kbuild-yocto-x86_64-62,media=disk,if=virtio -pidfile /dev/shm/kboot/pid-vm-kbuild-yocto-x86_64-62 -serial file:/dev/shm/kboot/serial-vm-kbuild-yocto-x86_64-62 -daemonize -display none -monitor null Thanks, Ying Huang

4 years, 4 months

3
3
0 / 0

[lkp] [x86] 20c5a315cf: rodata_test: test data was not read only

by kernel test robot

FYI, we noticed the below changes on https://git.kernel.org/pub/scm/linux/kernel/git/kees/linux.git kspp/postinit-readonly commit 20c5a315cf30093ea5bcad5fb0a79ad4c5e86b59 ("x86: make CONFIG_DEBUG_RODATA non-optional") We found the following new message in kernel after your commit. [ 26.152569] rodata_test: test data was not read only Thanks, Ying Huang

4 years, 4 months

1
0
0 / 0

[lkp] [mm, vmscan] 7afa13d0ba: kasan: GPF could be caused by NULL-ptr deref or user memory accessgeneral protection fault: 0000 [#1] SMP KASAN

by kernel test robot

FYI, we noticed the below changes on https://git.kernel.org/pub/scm/linux/kernel/git/mel/linux-balancenuma mm-vmscan-node-lru-v2r25 commit 7afa13d0bac733288e6b45bbb17a7f4c3960523e ("mm, vmscan: Move LRU lists to node") +------------------------------------------------------------------------+------------+------------+ | | 47f7608253 | 7afa13d0ba | +------------------------------------------------------------------------+------------+------------+ | boot_successes | 2 | 0 | | boot_failures | 8 | 12 | | IP-Config:Auto-configuration_of_network_failed | 8 | | | ptr_deref_or_user_memory_accessgeneral_protection_fault:#[##]SMP_KASAN | 0 | 12 | | RIP:cpu_vm_stats_fold | 0 | 12 | | Kernel_panic-not_syncing:Fatal_exception | 0 | 12 | | backtrace:debug_hotplug_cpu | 0 | 12 | | backtrace:kernel_init_freeable | 0 | 12 | +------------------------------------------------------------------------+------------+------------+ [ 5.548506] rtc-test rtc-test.0: setting system clock to 2016-01-26 09:20:10 UTC (1453800010) [ 5.550633] Unregister pv shared memory for cpu 0 [ 5.558220] kasan: CONFIG_KASAN_INLINE enabled [ 5.558752] kasan: GPF could be caused by NULL-ptr deref or user memory accessgeneral protection fault: 0000 [#1] SMP KASAN [ 5.561515] Modules linked in: [ 5.562365] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 4.5.0-rc1-00005-g7afa13d #1 [ 5.563991] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014 [ 5.565751] task: ffff88002e608000 ti: ffff88002e610000 task.ti: ffff88002e610000 [ 5.567367] RIP: 0010:[<ffffffff8521af67>] [<ffffffff8521af67>] cpu_vm_stats_fold+0x285/0x35a [ 5.569171] RSP: 0018:ffff88002e617a98 EFLAGS: 00010202 [ 5.570174] RAX: 000000000001efe0 RBX: 000000000001efe1 RCX: 0000000000003dfc [ 5.571369] RDX: dffffc0000000000 RSI: 0000000000000001 RDI: ffff880038740c80 [ 5.572566] RBP: ffff88002e617bf0 R08: 0000000000000001 R09: 0000000000000002 [ 5.573759] R10: ffff88002e6bfb90 R11: ffffed0005cc2f6d R12: ffff880038740c88 [ 5.574952] R13: dffffc0000000000 R14: ffff88003873d000 R15: ffff88002e617ae8 [ 5.576150] FS: 0000000000000000(0000) GS:ffff88002eb00000(0000) knlGS:0000000000000000 [ 5.577836] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 5.578888] CR2: 00007fa3ebbe4a30 CR3: 0000000005e0c000 CR4: 00000000000406a0 [ 5.580082] Stack: [ 5.580740] 1ffffffff0c07388 ffffffff86039c40 ffff88002ea1f051 ffff88002e617b08 [ 5.582615] 1ffff10005cc2f59 ffff88003873dd78 0000000041b58ab3 ffffffff85c86100 [ 5.584480] ffffffff8521ace2 ffffea0000fff000 0000000000000000 0000000000000000 [ 5.586355] Call Trace: [ 5.587070] [<ffffffff8521ace2>] ? inc_node_state+0x15/0x15 [ 5.588112] [<ffffffff851f90b7>] ? free_pcppages_bulk+0x1fb/0x27c [ 5.589210] [<ffffffff85217d44>] ? next_zone+0x46/0x49 [ 5.590210] [<ffffffff851f9370>] page_alloc_cpu_notify+0x2e/0x3c [ 5.591301] [<ffffffff8510c1b4>] notifier_call_chain+0xb0/0xf6 [ 5.592374] [<ffffffff8510c282>] __raw_notifier_call_chain+0x9/0xb [ 5.593485] [<ffffffff850d345f>] __cpu_notify+0x1b/0x30 [ 5.594497] [<ffffffff850d3482>] cpu_notify+0xe/0x10 [ 5.595476] [<ffffffff850d35e2>] cpu_notify_nofail+0x9/0x11 [ 5.596517] [<ffffffff850d39eb>] _cpu_down+0x2d6/0x58e [ 5.597514] [<ffffffff8525d77e>] ? free_debug_processing+0x19a/0x21b [ 5.598646] [<ffffffff850d3715>] ? cpu_hotplug_done+0x1d/0x1d [ 5.599706] [<ffffffff8511485f>] ? ___might_sleep+0x64/0x23a [ 5.600759] [<ffffffff850d3cc8>] cpu_down+0x25/0x32 [ 5.601730] [<ffffffff85010e77>] _debug_hotplug_cpu+0x4b/0x141 [ 5.602796] [<ffffffff86066975>] ? topology_init+0xd3/0xd3 [ 5.603836] [<ffffffff86066982>] debug_hotplug_cpu+0xd/0x11 [ 5.604883] [<ffffffff850004d5>] do_one_initcall+0x1aa/0x265 [ 5.605939] [<ffffffff8500032b>] ? try_to_run_init_process+0x31/0x31 [ 5.607069] [<ffffffff85109600>] ? parse_args+0x4e1/0x62b [ 5.608098] [<ffffffff8605e731>] kernel_init_freeable+0x2b9/0x34f [ 5.609196] [<ffffffff859d6cd8>] ? rest_init+0xaf/0xaf [ 5.610195] [<ffffffff859d6ce4>] kernel_init+0xc/0xee [ 5.611180] [<ffffffff859d6cd8>] ? rest_init+0xaf/0xaf [ 5.612183] [<ffffffff859e000f>] ret_from_fork+0x3f/0x70 [ 5.613208] [<ffffffff859d6cd8>] ? rest_init+0xaf/0xaf [ 5.614207] Code: 00 00 4d 8d a6 88 3c 00 00 4c 8d bd f8 fe ff ff 49 bd 00 00 00 00 00 fc ff df 48 8d 58 01 48 89 d9 48 89 de 48 c1 e9 03 83 e6 07 <42> 8a 0c 29 40 38 f1 7f 0c 84 c9 74 08 48 89 df e8 6f 53 04 00 [ 5.621660] RIP [<ffffffff8521af67>] cpu_vm_stats_fold+0x285/0x35a [ 5.622832] RSP <ffff88002e617a98> [ 5.623669] ---[ end trace 757bbc84cd1f3edc ]--- [ 5.624617] Kernel panic - not syncing: Fatal exception Thanks, Ying Huang

4 years, 4 months

1
0
0 / 0

[lkp] [mm] ecfea70873: BUG: using smp_processor_id() in preemptible [00000000 00000000] code: kworker/u64:0/6

by kernel test robot

FYI, we noticed the below changes on https://git.kernel.org/pub/scm/linux/kernel/git/rt/linux-rt-devel.git linux-4.4.y-rt commit ecfea7087396e8d4d38225296e971af4ada316a2 ("mm: page_alloc: rt-friendly per-cpu pages") +----------------------------------------------------------------+------------+------------+ | | a87bd6aded | ecfea70873 | +----------------------------------------------------------------+------------+------------+ | boot_successes | 81 | 0 | | boot_failures | 42 | 70 | | INFO:possible_irq_lock_inversion_dependency_detected | 39 | 34 | | backtrace:_do_fork | 39 | 46 | | backtrace:do_mount | 32 | 34 | | backtrace:SyS_mount | 32 | 34 | | backtrace:cgroup_setup_root | 39 | 34 | | backtrace:cgroup_init | 39 | 34 | | backtrace:smpboot_thread_fn | 39 | 33 | | backtrace:user_path_at_empty | 6 | | | backtrace:SyS_name_to_handle_at | 6 | | | BUG:unable_to_handle_kernel | 3 | 3 | | Oops | 3 | 3 | | RIP:__lock_acquire | 3 | 3 | | Kernel_panic-not_syncing:Fatal_exception | 3 | 3 | | backtrace:fd_timer_workfn | 3 | 3 | | backtrace:SYSC_mkdirat | 1 | | | backtrace:SyS_mkdir | 1 | | | BUG:using_smp_processor_id()in_preemptible[##]code:kworker/u4 | 0 | 53 | | backtrace:call_usermodehelper_exec_work | 0 | 45 | | backtrace:pgd_alloc | 0 | 34 | | backtrace:mm_init | 0 | 34 | | BUG:using_smp_processor_id()in_preemptible[##]code:kworker/u8 | 0 | 8 | | BUG:using_smp_processor_id()in_preemptible[##]code:kworker/u32 | 0 | 4 | | backtrace:vfs_read | 0 | 1 | | backtrace:SyS_read | 0 | 1 | | BUG:using_smp_processor_id()in_preemptible[##]code:kworker/u64 | 0 | 4 | | backtrace:debug_smp_processor_id | 0 | 2 | | inconsistent{HARDIRQ-ON-W}->{IN-HARDIRQ-W}usage | 0 | 1 | | backtrace:cpu_startup_entry | 0 | 1 | +----------------------------------------------------------------+------------+------------+ [ 23.717099] systemd-sysv-generator[619]: Ignoring K02urandom symlink in rc6.d, not generating urandom.service. [ 23.717107] systemd-sysv-generator[619]: Ignoring K07hwclock.sh symlink in rc6.d, not generating hwclock.service. [ 23.717115] systemd-sysv-generator[619]: Ignoring K01watchdog symlink in rc6.d, not generating watchdog.service. [ 24.405406] BUG: using smp_processor_id() in preemptible [00000000 00000000] code: kworker/u64:0/6 [ 24.405413] caller is debug_smp_processor_id+0x17/0x19 [ 24.405416] CPU: 0 PID: 6 Comm: kworker/u64:0 Not tainted 4.4.0-rc6-00060-gecfea70 #2 [ 24.405418] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014 [ 24.405425] Workqueue: events_unbound call_usermodehelper_exec_work [ 24.405429] 0000000000000000 ffff880247553a18 ffffffff8173deed 0000000000000000 [ 24.405431] ffff880247553a48 ffffffff8176207c 0000000000000006 ffff88025eef7f80 [ 24.405434] ffff880247553b48 0000000000000957 ffff880247553a58 ffffffff817620a8 [ 24.405435] Call Trace: [ 24.405441] [<ffffffff8173deed>] dump_stack+0x4e/0x79 [ 24.405443] [<ffffffff8176207c>] check_preemption_disabled+0x119/0x12e [ 24.405445] [<ffffffff817620a8>] debug_smp_processor_id+0x17/0x19 [ 24.405452] [<ffffffff811b2be0>] get_page_from_freelist+0x441/0x7f9 [ 24.405454] [<ffffffff8173dce6>] ? cpumask_next_and+0x16/0x48 [ 24.405461] [<ffffffff810fd683>] ? ___might_sleep+0xce/0x217 [ 24.405463] [<ffffffff811b3862>] __alloc_pages_nodemask+0x160/0x2d3 [ 24.405466] [<ffffffff811b3a37>] __alloc_pages_node+0x62/0x69 [ 24.405468] [<ffffffff811b3a58>] alloc_kmem_pages_node+0x1a/0x1c [ 24.405472] [<ffffffff810d7f5c>] copy_process+0x163/0x195f [ 24.405474] [<ffffffff810ec4a6>] ? call_usermodehelper+0x45/0x45 [ 24.405479] [<ffffffff811170a9>] ? mark_lock+0x24/0x201 [ 24.405481] [<ffffffff81117da3>] ? __lock_acquire+0x65b/0xdee [ 24.405483] [<ffffffff810d98b0>] _do_fork+0x82/0x2f7 [ 24.405485] [<ffffffff811188c8>] ? lock_acquire+0x106/0x192 [ 24.405487] [<ffffffff811188c8>] ? lock_acquire+0x106/0x192 [ 24.405489] [<ffffffff810d9b4e>] kernel_thread+0x29/0x2b [ 24.405491] [<ffffffff810ec38c>] call_usermodehelper_exec_work+0x7d/0x90 [ 24.405497] [<ffffffff810f0126>] process_one_work+0x247/0x47c [ 24.405500] [<ffffffff810f0808>] worker_thread+0x1f5/0x2a7 [ 24.405501] [<ffffffff810f0613>] ? rescuer_thread+0x289/0x289 [ 24.405505] [<ffffffff810f5700>] kthread+0xc5/0xcd [ 24.405508] [<ffffffff810f563b>] ? kthread_parkme+0x24/0x24 [ 24.405511] [<ffffffff82e2f69f>] ret_from_fork+0x3f/0x70 [ 24.405513] [<ffffffff810f563b>] ? kthread_parkme+0x24/0x24 [ 24.406071] BUG: using smp_processor_id() in preemptible [00000000 00000000] code: kworker/u64:0/627 [ 24.406077] caller is debug_smp_processor_id+0x17/0x19 [ 24.406080] CPU: 2 PID: 627 Comm: kworker/u64:0 Not tainted 4.4.0-rc6-00060-gecfea70 #2 [ 24.406082] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014 [ 24.406086] 0000000000000000 ffff880217dffc70 ffffffff8173deed 0000000000000002 [ 24.406088] ffff880217dffca0 ffffffff8176207c 0000000000000273 ffff88025eef7f80 [ 24.406091] ffff880217dffda0 0000000000000957 ffff880217dffcb0 ffffffff817620a8 [ 24.406092] Call Trace: [ 24.406099] [<ffffffff8173deed>] dump_stack+0x4e/0x79 [ 24.406101] [<ffffffff8176207c>] check_preemption_disabled+0x119/0x12e [ 24.406103] [<ffffffff817620a8>] debug_smp_processor_id+0x17/0x19 [ 24.406110] [<ffffffff811b2a5c>] get_page_from_freelist+0x2bd/0x7f9 [ 24.406116] [<ffffffff810fd683>] ? ___might_sleep+0xce/0x217 [ 24.406119] [<ffffffff811b3862>] __alloc_pages_nodemask+0x160/0x2d3 [ 24.406124] [<ffffffff811eb13b>] alloc_pages_current+0xae/0xe2 [ 24.406127] [<ffffffff811af2df>] __get_free_pages+0x16/0x52 [ 24.406132] [<ffffffff8109d3a1>] pgd_alloc+0x1d/0xcb [ 24.406137] [<ffffffff810d76b9>] mm_init+0x181/0x1c1 [ 24.406139] [<ffffffff810d7b19>] mm_alloc+0x3f/0x41 [ 24.406143] [<ffffffff81204c0c>] do_execveat_common+0x26b/0x6db [ 24.406145] [<ffffffff8120509f>] do_execve+0x23/0x25 [ 24.406149] [<ffffffff810ec5a6>] call_usermodehelper_exec_async+0x100/0x12d [ 24.406151] [<ffffffff810ec4a6>] ? call_usermodehelper+0x45/0x45 [ 24.406155] [<ffffffff82e2f69f>] ret_from_fork+0x3f/0x70 [ 24.406157] [<ffffffff810ec4a6>] ? call_usermodehelper+0x45/0x45 [ 24.406211] BUG: using smp_processor_id() in preemptible [00000000 00000000] code: kworker/u64:0/627 [ 24.406212] caller is debug_smp_processor_id+0x17/0x19 [ 24.406214] CPU: 2 PID: 627 Comm: kworker/u64:0 Not tainted 4.4.0-rc6-00060-gecfea70 #2 [ 24.406215] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014 [ 24.406217] 0000000000000000 ffff880217dffa58 ffffffff8173deed 0000000000000002 [ 24.406220] ffff880217dffa88 ffffffff8176207c 0000000000000273 ffff88025eef7f80 [ 24.406222] ffff880217dffb88 0000000000000957 ffff880217dffa98 ffffffff817620a8 [ 24.406223] Call Trace: [ 24.406225] [<ffffffff8173deed>] dump_stack+0x4e/0x79 [ 24.406227] [<ffffffff8176207c>] check_preemption_disabled+0x119/0x12e [ 24.406229] [<ffffffff817620a8>] debug_smp_processor_id+0x17/0x19 [ 24.406231] [<ffffffff811b2a5c>] get_page_from_freelist+0x2bd/0x7f9 [ 24.406234] [<ffffffff810fd683>] ? ___might_sleep+0xce/0x217 [ 24.406236] [<ffffffff811b3862>] __alloc_pages_nodemask+0x160/0x2d3 [ 24.406238] [<ffffffff811eb13b>] alloc_pages_current+0xae/0xe2 [ 24.406241] [<ffffffff811af2df>] __get_free_pages+0x16/0x52 [ 24.406242] [<ffffffff811af331>] get_zeroed_page+0x16/0x18 [ 24.406250] [<ffffffff811d1b15>] __pud_alloc+0x20/0xa3 [ 24.406252] [<ffffffff811d1bbd>] pud_alloc+0x25/0x30 [ 24.406255] [<ffffffff811d3378>] handle_mm_fault+0xa7/0xbf1 [ 24.406262] [<ffffffff81215bbc>] ? touch_atime+0x97/0xa0 [ 24.406265] [<ffffffff811ce94e>] ? follow_page_mask+0x490/0x4be [ 24.406269] [<ffffffff81114b60>] ? lock_is_held+0x49/0x50 [ 24.406271] [<ffffffff811cee37>] __get_user_pages+0x4bb/0x568 [ 24.406273] [<ffffffff81117da3>] ? __lock_acquire+0x65b/0xdee [ 24.406275] [<ffffffff811cf23b>] get_user_pages+0x42/0x44 [ 24.406282] [<ffffffff81203acc>] copy_strings+0x189/0x2b9 [ 24.406284] [<ffffffff81203c30>] copy_strings_kernel+0x34/0x40 [ 24.406286] [<ffffffff81204d94>] do_execveat_common+0x3f3/0x6db [ 24.406288] [<ffffffff8120509f>] do_execve+0x23/0x25 [ 24.406290] [<ffffffff810ec5a6>] call_usermodehelper_exec_async+0x100/0x12d [ 24.406292] [<ffffffff810ec4a6>] ? call_usermodehelper+0x45/0x45 [ 24.406293] [<ffffffff82e2f69f>] ret_from_fork+0x3f/0x70 [ 24.406295] [<ffffffff810ec4a6>] ? call_usermodehelper+0x45/0x45 [ 24.406304] BUG: using smp_processor_id() in preemptible [00000000 00000000] code: kworker/u64:0/627 [ 24.406305] caller is debug_smp_processor_id+0x17/0x19 [ 24.406307] CPU: 2 PID: 627 Comm: kworker/u64:0 Not tainted 4.4.0-rc6-00060-gecfea70 #2 [ 24.406308] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014 [ 24.406310] 0000000000000000 ffff880217dffa70 ffffffff8173deed 0000000000000002 [ 24.406313] ffff880217dffaa0 ffffffff8176207c 0000000000000273 ffff88025eef7f80 [ 24.406315] ffff880217dffba0 0000000000000957 ffff880217dffab0 ffffffff817620a8 [ 24.406316] Call Trace: [ 24.406318] [<ffffffff8173deed>] dump_stack+0x4e/0x79 [ 24.406319] [<ffffffff8176207c>] check_preemption_disabled+0x119/0x12e [ 24.406321] [<ffffffff817620a8>] debug_smp_processor_id+0x17/0x19 [ 24.406323] [<ffffffff811b2a5c>] get_page_from_freelist+0x2bd/0x7f9 [ 24.406326] [<ffffffff810fd683>] ? ___might_sleep+0xce/0x217 [ 24.406328] [<ffffffff811b3862>] __alloc_pages_nodemask+0x160/0x2d3 [ 24.406331] [<ffffffff811eb13b>] alloc_pages_current+0xae/0xe2 [ 24.406333] [<ffffffff811d21bb>] __pmd_alloc+0x24/0x161 [ 24.406335] [<ffffffff811d231d>] pmd_alloc+0x25/0x30 [ 24.406337] [<ffffffff811d3390>] handle_mm_fault+0xbf/0xbf1 [ 24.406339] [<ffffffff81215bbc>] ? touch_atime+0x97/0xa0 [ 24.406341] [<ffffffff811ce94e>] ? follow_page_mask+0x490/0x4be [ 24.406343] [<ffffffff81114b60>] ? lock_is_held+0x49/0x50 [ 24.406345] [<ffffffff811cee37>] __get_user_pages+0x4bb/0x568 [ 24.406347] [<ffffffff81117da3>] ? __lock_acquire+0x65b/0xdee [ 24.406349] [<ffffffff811cf23b>] get_user_pages+0x42/0x44 [ 24.406351] [<ffffffff81203acc>] copy_strings+0x189/0x2b9 [ 24.406354] [<ffffffff81203c30>] copy_strings_kernel+0x34/0x40 [ 24.406356] [<ffffffff81204d94>] do_execveat_common+0x3f3/0x6db [ 24.406357] [<ffffffff8120509f>] do_execve+0x23/0x25 [ 24.406359] [<ffffffff810ec5a6>] call_usermodehelper_exec_async+0x100/0x12d [ 24.406361] [<ffffffff810ec4a6>] ? call_usermodehelper+0x45/0x45 [ 24.406363] [<ffffffff82e2f69f>] ret_from_fork+0x3f/0x70 [ 24.406365] [<ffffffff810ec4a6>] ? call_usermodehelper+0x45/0x45 [ 24.406374] BUG: using smp_processor_id() in preemptible [00000000 00000000] code: kworker/u64:0/627 [ 24.406376] caller is debug_smp_processor_id+0x17/0x19 [ 24.406377] CPU: 2 PID: 627 Comm: kworker/u64:0 Not tainted 4.4.0-rc6-00060-gecfea70 #2 [ 24.406379] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014 [ 24.406381] 0000000000000000 ffff880217dffa80 ffffffff8173deed 0000000000000002 [ 24.406384] ffff880217dffab0 ffffffff8176207c 0000000000000273 ffff88025eef7f80 [ 24.406386] ffff880217dffbb0 0000000000000957 ffff880217dffac0 ffffffff817620a8 [ 24.406387] Call Trace: [ 24.406389] [<ffffffff8173deed>] dump_stack+0x4e/0x79 [ 24.406391] [<ffffffff8176207c>] check_preemption_disabled+0x119/0x12e [ 24.406393] [<ffffffff817620a8>] debug_smp_processor_id+0x17/0x19 [ 24.406395] [<ffffffff811b2a5c>] get_page_from_freelist+0x2bd/0x7f9 [ 24.406398] [<ffffffff810fd683>] ? ___might_sleep+0xce/0x217 [ 24.406400] [<ffffffff811b3862>] __alloc_pages_nodemask+0x160/0x2d3 [ 24.406403] [<ffffffff811eb13b>] alloc_pages_current+0xae/0xe2 [ 24.406405] [<ffffffff8109d1f9>] pte_alloc_one+0x17/0x7b [ 24.406407] [<ffffffff811d20c4>] __pte_alloc+0x1e/0xf1 [ 24.406408] [<ffffffff811d33ee>] handle_mm_fault+0x11d/0xbf1 [ 24.406410] [<ffffffff81215bbc>] ? touch_atime+0x97/0xa0 [ 24.406412] [<ffffffff811ce94e>] ? follow_page_mask+0x490/0x4be [ 24.406414] [<ffffffff81114b60>] ? lock_is_held+0x49/0x50 [ 24.406416] [<ffffffff811cee37>] __get_user_pages+0x4bb/0x568 [ 24.406418] [<ffffffff81117da3>] ? __lock_acquire+0x65b/0xdee [ 24.406420] [<ffffffff811cf23b>] get_user_pages+0x42/0x44 [ 24.406422] [<ffffffff81203acc>] copy_strings+0x189/0x2b9 [ 24.406425] [<ffffffff81203c30>] copy_strings_kernel+0x34/0x40 [ 24.406426] [<ffffffff81204d94>] do_execveat_common+0x3f3/0x6db [ 24.406428] [<ffffffff8120509f>] do_execve+0x23/0x25 [ 24.406430] [<ffffffff810ec5a6>] call_usermodehelper_exec_async+0x100/0x12d [ 24.406432] [<ffffffff810ec4a6>] ? call_usermodehelper+0x45/0x45 [ 24.406434] [<ffffffff82e2f69f>] ret_from_fork+0x3f/0x70 [ 24.406436] [<ffffffff810ec4a6>] ? call_usermodehelper+0x45/0x45 [ 24.406454] BUG: using smp_processor_id() in preemptible [00000000 00000000] code: kworker/u64:0/627 [ 24.406456] caller is debug_smp_processor_id+0x17/0x19 [ 24.406457] CPU: 2 PID: 627 Comm: kworker/u64:0 Not tainted 4.4.0-rc6-00060-gecfea70 #2 [ 24.406459] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014 [ 24.406461] 0000000000000000 ffff880217dffaa8 ffffffff8173deed 0000000000000002 [ 24.406464] ffff880217dffad8 ffffffff8176207c 0000000000000273 ffff88025eef7f80 [ 24.406466] ffff880217dffbd8 0000000000000957 ffff880217dffae8 ffffffff817620a8 [ 24.406467] Call Trace: [ 24.406469] [<ffffffff8173deed>] dump_stack+0x4e/0x79 [ 24.406471] [<ffffffff8176207c>] check_preemption_disabled+0x119/0x12e [ 24.406473] [<ffffffff817620a8>] debug_smp_processor_id+0x17/0x19 [ 24.406475] [<ffffffff811b2a5c>] get_page_from_freelist+0x2bd/0x7f9 [ 24.406478] [<ffffffff811d85a7>] ? expand_downwards+0x146/0x1d5 [ 24.406480] [<ffffffff810fd683>] ? ___might_sleep+0xce/0x217 [ 24.406483] [<ffffffff811b3862>] __alloc_pages_nodemask+0x160/0x2d3 [ 24.406486] [<ffffffff811ec0e4>] alloc_pages_vma+0xca/0x108 [ 24.406488] [<ffffffff811d34f9>] handle_mm_fault+0x228/0xbf1 [ 24.406489] [<ffffffff81215bbc>] ? touch_atime+0x97/0xa0 [ 24.406492] [<ffffffff811ce94e>] ? follow_page_mask+0x490/0x4be [ 24.406493] [<ffffffff81114b60>] ? lock_is_held+0x49/0x50 [ 24.406495] [<ffffffff811cee37>] __get_user_pages+0x4bb/0x568 [ 24.406497] [<ffffffff81117da3>] ? __lock_acquire+0x65b/0xdee [ 24.406499] [<ffffffff811cf23b>] get_user_pages+0x42/0x44 [ 24.406501] [<ffffffff81203acc>] copy_strings+0x189/0x2b9 [ 24.406504] [<ffffffff81203c30>] copy_strings_kernel+0x34/0x40 [ 24.406506] [<ffffffff81204d94>] do_execveat_common+0x3f3/0x6db [ 24.406507] [<ffffffff8120509f>] do_execve+0x23/0x25 [ 24.406510] [<ffffffff810ec5a6>] call_usermodehelper_exec_async+0x100/0x12d [ 24.406511] [<ffffffff810ec4a6>] ? call_usermodehelper+0x45/0x45 [ 24.406513] [<ffffffff82e2f69f>] ret_from_fork+0x3f/0x70 [ 24.406515] [<ffffffff810ec4a6>] ? call_usermodehelper+0x45/0x45 [ 24.406621] BUG: using smp_processor_id() in preemptible [00000000 00000000] code: kworker/u64:0/627 [ 24.406623] caller is debug_smp_processor_id+0x17/0x19 [ 24.406625] CPU: 2 PID: 627 Comm: kworker/u64:0 Not tainted 4.4.0-rc6-00060-gecfea70 #2 [ 24.406626] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014 [ 24.406629] 0000000000000000 ffff880217dffc28 ffffffff8173deed 0000000000000002 [ 24.406632] ffff880217dffc58 ffffffff8176207c 0000000000000273 0000000000000000 [ 24.406634] ffffea00028d6c28 00000000000bab13 ffff880217dffc68 ffffffff817620a8 [ 24.406635] Call Trace: [ 24.406637] [<ffffffff8173deed>] dump_stack+0x4e/0x79 [ 24.406639] [<ffffffff8176207c>] check_preemption_disabled+0x119/0x12e Thanks, Ying Huang

4 years, 4 months

1
0
0 / 0

[lkp] [of] 78b8dbaa57: INFO: task swapper:1 blocked for more than 120 seconds.

by kernel test robot

FYI, we noticed the below changes on https://git.kernel.org/pub/scm/linux/kernel/git/geert/renesas-drivers.git topic/overlays commit 78b8dbaa5715c56d5bc6e9d361856f8d92fe490c ("of: unittest: changeset helpers") +-------------------------------------------------------+------------+------------+ | | d2ab96ea3d | 78b8dbaa57 | +-------------------------------------------------------+------------+------------+ | boot_successes | 62 | 0 | | boot_failures | 1 | 26 | | BUG:unable_to_handle_kernel | 1 | | | Oops | 1 | | | EIP_is_at_perf_prepare_sample | 1 | | | Kernel_panic-not_syncing:Fatal_exception_in_interrupt | 1 | | | INFO:task_blocked_for_more_than#seconds | 0 | 26 | | EIP_is_at_default_send_IPI_mask_logical | 0 | 22 | | Kernel_panic-not_syncing:hung_task:blocked_tasks | 0 | 22 | | backtrace:of_unittest | 0 | 26 | | backtrace:kernel_init_freeable | 0 | 26 | | backtrace:watchdog | 0 | 22 | | BUG:kernel_boot_hang | 0 | 4 | +-------------------------------------------------------+------------+------------+ [ 3.504995] /testcase-data/phandle-tests/consumer-a: arguments longer than property [ 3.982145] tsc: Refined TSC clocksource calibration: 2693.505 MHz [ 3.983012] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x26d346f670a, max_idle_ns: 440795255135 ns [ 240.329025] INFO: task swapper:1 blocked for more than 120 seconds. [ 240.333860] Not tainted 4.5.0-rc1-00021-g78b8dba #107 [ 240.335123] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 240.336933] swapper D 00000000 5856 1 0 0x00000000 [ 240.338565] d3dffe00 00000046 cab95a00 00000000 d3dffe40 c8991cec c88912e0 00000000 [ 240.341284] 00000000 cab95a00 d3e10000 c76a1c90 d3e00000 d3e10000 d3dffe10 c827847b [ 240.343539] c76a1c90 c8991cc0 d3dffe18 c827891f d3dffe5c c827e8b6 00000000 00000001 [ 240.345131] Call Trace: [ 240.345609] [<c76a1c90>] ? native_save_fl+0x30/0x30 [ 240.346306] [<c827847b>] schedule+0x7b/0x180 [ 240.346923] [<c76a1c90>] ? native_save_fl+0x30/0x30 [ 240.347597] [<c827891f>] schedule_preempt_disabled+0x2f/0x60 [ 240.348429] [<c827e8b6>] mutex_lock_nested+0x446/0x940 [ 240.349156] [<c8137825>] ? of_changeset_apply+0x25/0x70 [ 240.349850] [<c8137825>] ? of_changeset_apply+0x25/0x70 [ 240.350564] [<c8137825>] of_changeset_apply+0x25/0x70 [ 240.351278] [<c8a95a55>] of_unittest+0xde4/0x16ee [ 240.351945] [<c78f225a>] ? kfree+0x54a/0x680 [ 240.352563] [<c81cd6ab>] ? add_sysfs_fw_map_entry+0xad/0x102 [ 240.353324] [<c760219d>] ? do_one_initcall+0xcd/0x480 [ 240.354021] [<c8a94c71>] ? of_unittest_platform_populate+0x603/0x603 [ 240.354830] [<c76021d6>] do_one_initcall+0x106/0x480 [ 240.355522] [<c8a94c71>] ? of_unittest_platform_populate+0x603/0x603 [ 240.356352] [<c8a06e6d>] ? kernel_init_freeable+0x422/0x5be [ 240.357095] [<c8a06e9b>] kernel_init_freeable+0x450/0x5be [ 240.357807] [<c827204e>] kernel_init+0x1e/0x200 [ 240.358462] [<c77207ff>] ? schedule_tail+0x1f/0xc0 [ 240.359153] [<c8284348>] ret_from_kernel_thread+0x20/0x34 [ 240.359868] [<c8272030>] ? rest_init+0x160/0x160 [ 240.360531] 2 locks held by swapper/1: [ 240.361090] #0: (of_mutex){......}, at: [<c8a95a40>] of_unittest+0xdcf/0x16ee [ 240.362439] #1: (of_mutex){......}, at: [<c8137825>] of_changeset_apply+0x25/0x70 [ 360.362993] INFO: task swapper:1 blocked for more than 120 seconds. [ 360.367053] Not tainted 4.5.0-rc1-00021-g78b8dba #107 [ 360.368384] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 360.370464] swapper D 00000000 5856 1 0 0x00000000 [ 360.372220] d3dffe00 00000046 cab95a00 00000000 d3dffe40 c8991cec c88912e0 00000000 [ 360.376046] 00000000 cab95a00 d3e10000 c76a1c90 d3e00000 d3e10000 d3dffe10 c827847b [ 360.383960] c76a1c90 c8991cc0 d3dffe18 c827891f d3dffe5c c827e8b6 00000000 00000001 [ 360.386894] Call Trace: [ 360.387688] [<c76a1c90>] ? native_save_fl+0x30/0x30 [ 360.388936] [<c827847b>] schedule+0x7b/0x180 [ 360.391087] [<c76a1c90>] ? native_save_fl+0x30/0x30 [ 360.392315] [<c827891f>] schedule_preempt_disabled+0x2f/0x60 [ 360.393739] [<c827e8b6>] mutex_lock_nested+0x446/0x940 [ 360.395015] [<c8137825>] ? of_changeset_apply+0x25/0x70 [ 360.396296] [<c8137825>] ? of_changeset_apply+0x25/0x70 [ 360.397643] [<c8137825>] of_changeset_apply+0x25/0x70 [ 360.398905] [<c8a95a55>] of_unittest+0xde4/0x16ee [ 360.400138] [<c78f225a>] ? kfree+0x54a/0x680 [ 360.401252] [<c81cd6ab>] ? add_sysfs_fw_map_entry+0xad/0x102 [ 360.402666] [<c760219d>] ? do_one_initcall+0xcd/0x480 [ 360.403926] [<c8a94c71>] ? of_unittest_platform_populate+0x603/0x603 [ 360.405410] [<c76021d6>] do_one_initcall+0x106/0x480 [ 360.406710] [<c8a94c71>] ? of_unittest_platform_populate+0x603/0x603 [ 360.408193] [<c8a06e6d>] ? kernel_init_freeable+0x422/0x5be [ 360.409587] [<c8a06e9b>] kernel_init_freeable+0x450/0x5be [ 360.410902] [<c827204e>] kernel_init+0x1e/0x200 [ 360.412094] [<c77207ff>] ? schedule_tail+0x1f/0xc0 [ 360.413298] [<c8284348>] ret_from_kernel_thread+0x20/0x34 [ 360.414665] [<c8272030>] ? rest_init+0x160/0x160 [ 360.415841] 2 locks held by swapper/1: [ 360.416856] #0: (of_mutex){......}, at: [<c8a95a40>] of_unittest+0xdcf/0x16ee [ 360.419407] #1: (of_mutex){......}, at: [<c8137825>] of_changeset_apply+0x25/0x70 Elapsed time: 440 BUG: kernel boot hang qemu-system-i386 -enable-kvm -cpu Haswell,+smep,+smap -kernel /pkg/linux/i386-randconfig-s0-201604/gcc-5/78b8dbaa5715c56d5bc6e9d361856f8d92fe490c/vmlinuz-4.5.0-rc1-00021-g78b8dba -append 'root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-vp-quantal-i386-8/rand_boot-1-quantal-core-i386.cgz-i386-randconfig-s0-201604-78b8dbaa5715c56d5bc6e9d361856f8d92fe490c-20160126-108904-l5r34w-1.yaml ARCH=i386 kconfig=i386-randconfig-s0-201604 branch=linux-devel/devel-catchup-201601262142 commit=78b8dbaa5715c56d5bc6e9d361856f8d92fe490c BOOT_IMAGE=/pkg/linux/i386-randconfig-s0-201604/gcc-5/78b8dbaa5715c56d5bc6e9d361856f8d92fe490c/vmlinuz-4.5.0-rc1-00021-g78b8dba max_uptime=600 RESULT_ROOT=/result/boot/1/vm-vp-quantal-i386/quantal-core-i386.cgz/i386-randconfig-s0-201604/gcc-5/78b8dbaa5715c56d5bc6e9d361856f8d92fe490c/0 LKP_SERVER=inn earlyprintk=ttyS0,115200 systemd.log_level=err debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 console=ttyS0,115200 console=tty0 vga=normal rw ip=::::vm-vp-quantal-i386-8::dhcp drbd.minor_count=8' -initrd /fs/sdd1/initrd-vm-vp-quantal-i386-8 -m 360 -smp 1 -device e1000,netdev=net0 -netdev user,id=net0 -boot order=nc -no-reboot -watchdog i6300esb -rtc base=localtime -pidfile /dev/shm/kboot/pid-vm-vp-quantal-i386-8 -serial file:/dev/shm/kboot/serial-vm-vp-quantal-i386-8 -daemonize -display none -monitor null Thanks, Kernel Test Robot

4 years, 4 months

1
0
0 / 0

[of: unittest] 78b8dbaa57: INFO: task swapper:1 blocked for more than 120 seconds.

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/geert/renesas-drivers.git topic/overlays commit 78b8dbaa5715c56d5bc6e9d361856f8d92fe490c Author: Pantelis Antoniou <pantelis.antoniou(a)konsulko.com> AuthorDate: Wed Oct 14 13:16:15 2015 +0300 Commit: Geert Uytterhoeven <geert+renesas(a)glider.be> CommitDate: Tue Jan 26 12:23:43 2016 +0100 of: unittest: changeset helpers Signed-off-by: Pantelis Antoniou <pantelis.antoniou(a)konsulko.com> +-------------------------------------------------------+------------+------------+------------+ | | d2ab96ea3d | 78b8dbaa57 | 40c044e6c0 | +-------------------------------------------------------+------------+------------+------------+ | boot_successes | 62 | 0 | 0 | | boot_failures | 1 | 26 | 13 | | BUG:unable_to_handle_kernel | 1 | | | | Oops | 1 | | | | EIP_is_at_perf_prepare_sample | 1 | | | | Kernel_panic-not_syncing:Fatal_exception_in_interrupt | 1 | | | | INFO:task_blocked_for_more_than#seconds | 0 | 26 | 13 | | EIP_is_at_default_send_IPI_mask_logical | 0 | 22 | 13 | | Kernel_panic-not_syncing:hung_task:blocked_tasks | 0 | 22 | 13 | | backtrace:of_unittest | 0 | 26 | 13 | | backtrace:kernel_init_freeable | 0 | 26 | 13 | | backtrace:watchdog | 0 | 22 | 13 | | BUG:kernel_boot_hang | 0 | 4 | | +-------------------------------------------------------+------------+------------+------------+ [ 2.503003] /testcase-data/phandle-tests/consumer-a: arguments longer than property [ 2.693232] tsc: Refined TSC clocksource calibration: 2693.500 MHz [ 2.694070] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x26d3422dad3, max_idle_ns: 440795300981 ns [ 240.528031] INFO: task swapper:1 blocked for more than 120 seconds. [ 240.530238] Not tainted 4.5.0-rc1-00021-g78b8dba #107 [ 240.531563] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 240.533501] swapper D 00000000 5776 1 0 0x00000000 [ 240.535541] cf5ffe00 00000046 c0085a00 00000000 cf5ffe40 c5191cec c50912e0 00000000 [ 240.539136] 00000000 c0085a00 cf610000 c3ea1c90 cf600000 cf610000 cf5ffe10 c4a7847b [ 240.542247] c3ea1c90 c5191cc0 cf5ffe18 c4a7891f cf5ffe5c c4a7e8b6 00000000 00000001 [ 240.545956] Call Trace: [ 240.547051] [<c3ea1c90>] ? native_save_fl+0x30/0x30 [ 240.548740] [<c4a7847b>] schedule+0x7b/0x180 [ 240.549797] [<c3ea1c90>] ? native_save_fl+0x30/0x30 [ 240.550970] [<c4a7891f>] schedule_preempt_disabled+0x2f/0x60 [ 240.552246] [<c4a7e8b6>] mutex_lock_nested+0x446/0x940 [ 240.553783] [<c4937825>] ? of_changeset_apply+0x25/0x70 [ 240.555519] [<c4937825>] ? of_changeset_apply+0x25/0x70 [ 240.557321] [<c4937825>] of_changeset_apply+0x25/0x70 [ 240.558954] [<c5295a55>] of_unittest+0xde4/0x16ee [ 240.560628] [<c40f225a>] ? kfree+0x54a/0x680 [ 240.562242] [<c49cd6ab>] ? add_sysfs_fw_map_entry+0xad/0x102 [ 240.563760] [<c3e0219d>] ? do_one_initcall+0xcd/0x480 [ 240.564922] [<c5294c71>] ? of_unittest_platform_populate+0x603/0x603 [ 240.566302] [<c3e021d6>] do_one_initcall+0x106/0x480 [ 240.567451] [<c5294c71>] ? of_unittest_platform_populate+0x603/0x603 [ 240.568825] [<c5206e6d>] ? kernel_init_freeable+0x422/0x5be [ 240.570116] [<c5206e9b>] kernel_init_freeable+0x450/0x5be [ 240.571750] [<c4a7204e>] kernel_init+0x1e/0x200 [ 240.573376] [<c3f207ff>] ? schedule_tail+0x1f/0xc0 [ 240.575089] [<c4a84348>] ret_from_kernel_thread+0x20/0x34 [ 240.576959] [<c4a72030>] ? rest_init+0x160/0x160 [ 240.578546] 2 locks held by swapper/1: [ 240.579962] #0: (of_mutex){......}, at: [<c5295a40>] of_unittest+0xdcf/0x16ee [ 240.583331] #1: (of_mutex){......}, at: [<c4937825>] of_changeset_apply+0x25/0x70 [ 240.586821] Sending NMI to all CPUs: [ 240.588355] NMI backtrace for cpu 0 [ 240.589691] CPU: 0 PID: 10 Comm: khungtaskd Not tainted 4.5.0-rc1-00021-g78b8dba #107 [ 240.592371] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014 [ 240.595288] task: cf64a400 ti: cf688000 task.ti: cf688000 [ 240.597114] EIP: 0060:[<c3e9347b>] EFLAGS: 00000046 CPU: 0 [ 240.598964] EIP is at default_send_IPI_mask_logical+0x20b/0x350 [ 240.600914] EAX: fffff000 EBX: 01000000 ECX: 00000000 EDX: fffff000 [ 240.602895] ESI: 00000c00 EDI: 00000800 EBP: cf689eb4 ESP: cf689ea0 [ 240.604949] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068 [ 240.606758] CR0: 80050033 CR2: 00000000 CR3: 052f6000 CR4: 000406b0 [ 240.608764] Stack: [ 240.609720] 00000246 00000000 c3e94a60 00000000 000003ff cf689ebc c3e94a84 cf689ed8 [ 240.612411] c44ca0cf c4e1af85 c4e747a6 00007fff cf610000 00007fff cf689ee0 c3e94b13 [ 240.615102] cf689f1c c3fd9824 c4df1510 c5351424 c4ed4966 00000004 c4ed49a7 00000078 [ 240.617783] Call Trace: [ 240.618616] [<c3e94a60>] ? setup_vector_irq+0x400/0x400 [ 240.620413] [<c3e94a84>] nmi_raise_cpu_backtrace+0x24/0x40 [ 240.622241] [<c44ca0cf>] nmi_trigger_all_cpu_backtrace+0x2df/0x340 [ 240.624265] [<c3e94b13>] arch_trigger_all_cpu_backtrace+0x23/0x40 [ 240.626255] [<c3fd9824>] watchdog+0x854/0x890 [ 240.627764] [<c3fd8fd0>] ? reset_hung_task_detector+0x30/0x30 [ 240.629688] [<c3f0b429>] kthread+0x119/0x160 [ 240.631243] [<c4a84348>] ret_from_kernel_thread+0x20/0x34 [ 240.633058] [<c3f0b310>] ? kthread_create_on_node+0x290/0x290 [ 240.634624] Code: 18 89 98 10 d3 ff ff 83 fe 02 0f 84 88 00 00 00 09 fe 83 05 00 90 33 c5 01 83 15 04 90 33 c5 00 a1 f8 26 f0 c4 89 b0 00 d3 ff ff <8b> 1d c8 f6 ef c4 b8 8c ac 1c c5 83 05 10 90 33 c5 01 83 15 14 [ 240.639285] Kernel panic - not syncing: hung_task: blocked tasks [ 240.641018] CPU: 0 PID: 10 Comm: khungtaskd Not tainted 4.5.0-rc1-00021-g78b8dba #107 [ 240.643464] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014 [ 240.645772] 00007fff cf689ec8 c44c1965 cf689ee0 c404df1b 00007fff cf610000 00007fff [ 240.648832] 000003ff cf689f1c c3fd983e c4de78ff c5351424 c4ed4966 00000004 c4ed49a7 [ 240.652178] 00000078 cf610000 0000016f 00000004 cf610214 cf404920 00000000 c3fd8fd0 [ 240.654902] Call Trace: [ 240.655608] [<c44c1965>] dump_stack+0x32/0x4d [ 240.656629] [<c404df1b>] panic+0x178/0x406 [ 240.657652] [<c3fd983e>] watchdog+0x86e/0x890 [ 240.658678] [<c3fd8fd0>] ? reset_hung_task_detector+0x30/0x30 [ 240.659927] [<c3f0b429>] kthread+0x119/0x160 [ 240.660937] [<c4a84348>] ret_from_kernel_thread+0x20/0x34 [ 240.662125] [<c3f0b310>] ? kthread_create_on_node+0x290/0x290 [ 240.663370] Kernel Offset: 0x2e00000 from 0xc1000000 (relocation range: 0xc0000000-0xd07dffff) Elapsed time: 250 git bisect start 40c044e6c002e03e1eeeac539452480af262dcfd 92e963f50fc74041b5e9e744c330dca48e04f08d -- git bisect good 06f1993433138c464960dd0739ddec1814c5e467 # 22:14 22+ 0 Merge 'linux-review/Adrian-Hunter/perf-tools-Fix-seg-fault-with-Intel-PT/20160126-201736' into devel-catchup-201601262142 git bisect good a510fe537154ddbbc9bb205fed5877701aa0f43a # 22:18 22+ 2 Merge 'linux-review/Andy-Shevchenko/dmaengine-idma64-clear-LLP_-SD-_EN-bits-in-last-descriptor/20160126-194617' into devel-catchup-201601262142 git bisect good b1e7aec92c6b05f12ce4dedb02e0e4b75da4c3dc # 22:24 22+ 4 Merge 'wireless-drivers/master' into devel-catchup-201601262142 git bisect bad 4045a22f8a2119d8018d25e6b106f3cba4cf9b3c # 22:31 0- 22 Merge 'renesas-drivers/topic/overlays' into devel-catchup-201601262142 git bisect good 753ae50a660a142802c5b5481a6211238b92fb43 # 22:35 22+ 0 Merge 'renesas-drivers/topic/renesas-overlays' into devel-catchup-201601262142 git bisect good a8212834f64c7dde6fee6efabb38ff4b5a0a5f88 # 22:41 20+ 2 doc: dt: Document the target root overlay method git bisect bad db869b5b3fbb3fa878306214b5a0c54509a4d8a1 # 22:47 0- 9 of: configfs: Use %zu to format size_t git bisect good d2ab96ea3dcb35ccb7adc3054320b06b9ef25d4e # 22:54 22+ 0 of: Maintainer fixes for dynamic git bisect bad 02e60109bd304c905b2e313e8f56ce1549136337 # 23:03 0- 22 of: rename *_node_sysfs to _node_post git bisect bad 78b8dbaa5715c56d5bc6e9d361856f8d92fe490c # 23:10 0- 22 of: unittest: changeset helpers # first bad commit: [78b8dbaa5715c56d5bc6e9d361856f8d92fe490c] of: unittest: changeset helpers git bisect good d2ab96ea3dcb35ccb7adc3054320b06b9ef25d4e # 23:12 63+ 1 of: Maintainer fixes for dynamic # extra tests with DEBUG_INFO git bisect bad 78b8dbaa5715c56d5bc6e9d361856f8d92fe490c # 23:21 0- 23 of: unittest: changeset helpers # extra tests on HEAD of linux-devel/devel-catchup-201601262142 git bisect bad 40c044e6c002e03e1eeeac539452480af262dcfd # 23:21 0- 13 0day head guard for 'devel-catchup-201601262142' # extra tests on tree/branch renesas-drivers/topic/overlays git bisect bad 95b88a4200def5643d3a3768c56c30a731662c6d # 23:31 0- 54 kbuild: Create a rule for building device tree overlay objects # extra tests with first bad commit reverted git bisect good 19264b9e65f3b3bb0d44de030fdb76b14fea633c # 23:37 66+ 3 Revert "of: unittest: changeset helpers" # extra tests on tree/branch linus/master git bisect good 92e963f50fc74041b5e9e744c330dca48e04f08d # 23:39 60+ 0 Linux 4.5-rc1 # extra tests on tree/branch linux-next/master git bisect good e216cada8e1b4d6c278a2a9af051aeba9b7f1bbe # 23:46 66+ 2 Add linux-next specific files for 20160125 This script may reproduce the error. ---------------------------------------------------------------------------- #!/bin/bash kernel=$1 initrd=yocto-minimal-i386.cgz wget --no-clobber https://github.com/fengguang/reproduce-kernel-bug/raw/master/initrd/$initrd kvm=( qemu-system-x86_64 -enable-kvm -cpu Haswell,+smep,+smap -kernel $kernel -initrd $initrd -m 256 -smp 1 -device e1000,netdev=net0 -netdev user,id=net0 -boot order=nc -no-reboot -watchdog i6300esb -rtc base=localtime -serial stdio -display none -monitor null ) append=( hung_task_panic=1 earlyprintk=ttyS0,115200 systemd.log_level=err debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 console=ttyS0,115200 console=tty0 vga=normal root=/dev/ram0 rw drbd.minor_count=8 ) "${kvm[@]}" --append "${append[*]}" ---------------------------------------------------------------------------- --- 0-DAY kernel test infrastructure Open Source Technology Center https://lists.01.org/pipermail/lkp Intel Corporation

4 years, 4 months

1
0
0 / 0

2020

2019

2018

2017

2016

2015

2014

2013

LKP January 2016