lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite for Android: free password hash cracker in your pocket
[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <20210209054925.GB13872@xsang-OptiPlex-9020>
Date:   Tue, 9 Feb 2021 13:49:25 +0800
From:   kernel test robot <oliver.sang@...el.com>
To:     Petr Mladek <pmladek@...e.com>
Cc:     Linus Torvalds <torvalds@...ux-foundation.org>,
        Andy Shevchenko <andriy.shevchenko@...ux.intel.com>,
        Vineet Gupta <vgupta@...opsys.com>,
        Thomas Meyer <thomas@...3r.de>,
        Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
        Sergey Senozhatsky <sergey.senozhatsky@...il.com>,
        LKML <linux-kernel@...r.kernel.org>, lkp@...ts.01.org,
        lkp@...el.com, ying.huang@...el.com, feng.tang@...el.com,
        zhengjun.xing@...el.com
Subject: [init/console]  a91bd6223e:  unixbench.score -5.9% regression


Greeting,

FYI, we noticed a -5.9% regression of unixbench.score due to commit:


commit: a91bd6223ecd46addc71ee6fcd432206d39365d2 ("Revert "init/console: Use ttynull as a fallback when there is no console"")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master


in testcase: unixbench
on test machine: 16 threads Intel(R) Xeon(R) E-2278G CPU @ 3.40GHz with 32G memory
with following parameters:

	runtime: 300s
	nr_task: 30%
	test: dhry2reg
	cpufreq_governor: performance
	ucode: 0xde

test-description: UnixBench is the original BYTE UNIX benchmark suite aims to test performance of Unix-like system.
test-url: https://github.com/kdlucas/byte-unixbench



If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang@...el.com>


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 split-job --compatible job.yaml
        bin/lkp run                    compatible-job.yaml

=========================================================================================
compiler/cpufreq_governor/kconfig/nr_task/rootfs/runtime/tbox_group/test/testcase/ucode:
  gcc-9/performance/x86_64-rhel-8.3/30%/debian-10.4-x86_64-20200603.cgz/300s/lkp-cfl-e1/dhry2reg/unixbench/0xde

commit: 
  c4cc3b1de3 ("Merge tag 'gcc-plugins-v5.11-rc3' of git://git.kernel.org/pub/scm/linux/kernel/git/kees/linux")
  a91bd6223e ("Revert "init/console: Use ttynull as a fallback when there is no console"")

c4cc3b1de31b76f4 a91bd6223ecd46addc71ee6fcd4 
---------------- --------------------------- 
       fail:runs  %reproduction    fail:runs
           |             |             |    
          0:4            2%           0:4     perf-profile.children.cycles-pp.error_entry
         %stddev     %change         %stddev
             \          |                \  
     19487            -5.9%      18336        unixbench.score
 8.875e+10            -5.9%  8.351e+10        unixbench.workload
      0.50            +0.1        0.61 ±  3%  mpstat.cpu.all.irq%
     44280 ±  4%     +15.9%      51322 ±  3%  softirqs.CPU0.SCHED
     29624 ±  3%      +9.6%      32476        vmstat.system.in
 2.711e+08 ± 52%     -98.6%    3760693 ± 83%  cpuidle.C1.time
    960301 ± 15%     -98.0%      19480 ± 51%  cpuidle.C1.usage
 4.015e+08 ± 47%     -70.6%  1.181e+08 ± 23%  cpuidle.C1E.time
   6356038 ± 12%     -69.8%    1917995 ± 72%  cpuidle.C3.usage
 3.359e+09 ± 12%     +30.3%  4.378e+09 ±  8%  cpuidle.C6.time
   4237110 ± 16%     +73.6%    7357532 ± 16%  cpuidle.C6.usage
   1442441 ±147%     -91.1%     127672 ±  3%  cpuidle.POLL.time
    211.25 ± 12%     -14.7%     180.24 ± 16%  sched_debug.cfs_rq:/.load_avg.stddev
     12.81 ± 45%     -68.4%       4.04 ±143%  sched_debug.cfs_rq:/.removed.runnable_avg.avg
     36.99 ± 48%     -63.2%      13.61 ±139%  sched_debug.cfs_rq:/.removed.runnable_avg.stddev
     12.81 ± 45%     -68.5%       4.04 ±143%  sched_debug.cfs_rq:/.removed.util_avg.avg
     36.99 ± 48%     -63.2%      13.60 ±139%  sched_debug.cfs_rq:/.removed.util_avg.stddev
      2207 ±1927%   +3559.5%      80796 ± 18%  sched_debug.cfs_rq:/.spread0.avg
    135343 ± 38%     +61.1%     218075 ± 16%  sched_debug.cfs_rq:/.spread0.max
      0.01 ± 31%     +78.3%       0.01 ± 22%  perf-sched.sch_delay.avg.ms.do_nanosleep.hrtimer_nanosleep.__x64_sys_nanosleep.do_syscall_64
      0.01 ±  7%     +22.8%       0.02 ±  2%  perf-sched.sch_delay.avg.ms.do_task_dead.do_exit.do_group_exit.__x64_sys_exit_group.do_syscall_64
      0.02 ± 15%     +27.1%       0.02 ± 11%  perf-sched.sch_delay.avg.ms.do_wait.kernel_wait4.__do_sys_wait4.do_syscall_64
      0.02 ± 44%    +113.3%       0.04 ± 12%  perf-sched.sch_delay.avg.ms.exit_to_user_mode_prepare.syscall_exit_to_user_mode.entry_SYSCALL_64_after_hwframe.[unknown]
      0.02 ± 10%     +56.1%       0.03 ± 25%  perf-sched.sch_delay.avg.ms.schedule_hrtimeout_range_clock.poll_schedule_timeout.constprop.0.do_select
      0.02 ± 44%    +113.3%       0.04 ± 12%  perf-sched.sch_delay.max.ms.exit_to_user_mode_prepare.syscall_exit_to_user_mode.entry_SYSCALL_64_after_hwframe.[unknown]
      0.01 ± 11%     +37.5%       0.01 ± 19%  perf-sched.total_sch_delay.average.ms
      2001          +120.7%       4416 ± 33%  perf-sched.wait_and_delay.max.ms.do_task_dead.do_exit.do_group_exit.__x64_sys_exit_group.do_syscall_64
      0.05 ± 54%     +56.5%       0.08 ±  7%  perf-sched.wait_time.avg.ms.schedule_timeout.khugepaged.kthread.ret_from_fork
      2001          +120.7%       4416 ± 33%  perf-sched.wait_time.max.ms.do_task_dead.do_exit.do_group_exit.__x64_sys_exit_group.do_syscall_64
      0.05 ± 54%     +56.5%       0.08 ±  7%  perf-sched.wait_time.max.ms.schedule_timeout.khugepaged.kthread.ret_from_fork
    718504 ±  3%      +9.0%     783430        interrupts.CPU0.LOC:Local_timer_interrupts
    718516 ±  3%      +9.0%     783357        interrupts.CPU1.LOC:Local_timer_interrupts
    334.50 ± 24%     -45.4%     182.50 ± 34%  interrupts.CPU1.RES:Rescheduling_interrupts
    717807 ±  3%      +9.2%     783709        interrupts.CPU10.LOC:Local_timer_interrupts
    736.75 ±102%     -73.5%     195.25 ± 17%  interrupts.CPU10.RES:Rescheduling_interrupts
    717666 ±  3%      +9.2%     783362        interrupts.CPU11.LOC:Local_timer_interrupts
    717664 ±  3%      +9.2%     783781        interrupts.CPU12.LOC:Local_timer_interrupts
    717135 ±  3%      +9.2%     783332        interrupts.CPU13.LOC:Local_timer_interrupts
    717271 ±  3%      +9.2%     783544        interrupts.CPU14.LOC:Local_timer_interrupts
    716867 ±  3%      +9.3%     783686        interrupts.CPU15.LOC:Local_timer_interrupts
    440.50 ± 41%     -60.2%     175.50 ± 15%  interrupts.CPU15.RES:Rescheduling_interrupts
    716970 ±  3%      +9.2%     783066        interrupts.CPU2.LOC:Local_timer_interrupts
    717346 ±  3%      +9.2%     783093        interrupts.CPU3.LOC:Local_timer_interrupts
    682.25 ± 65%     -68.3%     216.50 ± 20%  interrupts.CPU3.RES:Rescheduling_interrupts
    717415 ±  3%      +9.2%     783331        interrupts.CPU4.LOC:Local_timer_interrupts
    717222 ±  3%      +9.1%     782450        interrupts.CPU5.LOC:Local_timer_interrupts
      4460 ± 69%     -83.6%     732.25 ± 97%  interrupts.CPU5.NMI:Non-maskable_interrupts
      4460 ± 69%     -83.6%     732.25 ± 97%  interrupts.CPU5.PMI:Performance_monitoring_interrupts
    717168 ±  3%      +9.3%     783638        interrupts.CPU6.LOC:Local_timer_interrupts
    426.25 ± 67%    +715.8%       3477 ± 71%  interrupts.CPU6.NMI:Non-maskable_interrupts
    426.25 ± 67%    +715.8%       3477 ± 71%  interrupts.CPU6.PMI:Performance_monitoring_interrupts
    716671 ±  3%      +9.3%     783574        interrupts.CPU7.LOC:Local_timer_interrupts
    718995 ±  3%      +9.0%     783595        interrupts.CPU8.LOC:Local_timer_interrupts
    718744 ±  3%      +9.0%     783527        interrupts.CPU9.LOC:Local_timer_interrupts
  11481965 ±  3%      +9.2%   12534482        interrupts.LOC:Local_timer_interrupts
     36638 ±  6%     +18.6%      43447 ± 10%  interrupts.NMI:Non-maskable_interrupts
     36638 ±  6%     +18.6%      43447 ± 10%  interrupts.PMI:Performance_monitoring_interrupts
      7283 ± 52%     -45.6%       3960 ± 23%  interrupts.RES:Rescheduling_interrupts
 6.085e+09            -6.6%  5.682e+09        perf-stat.i.branch-instructions
   3869577 ±  4%     +17.8%    4558585 ±  3%  perf-stat.i.branch-misses
      4.04 ±  5%      -1.0        2.99 ±  3%  perf-stat.i.cache-miss-rate%
  21667091 ±  6%     +39.2%   30171049 ±  3%  perf-stat.i.cache-references
      1.26 ±  2%      -7.2%       1.17        perf-stat.i.cpi
 1.424e+10            -4.4%  1.361e+10        perf-stat.i.cpu-cycles
 7.776e+09            -6.3%  7.288e+09        perf-stat.i.dTLB-loads
      0.03 ± 12%      -0.0        0.02 ± 14%  perf-stat.i.dTLB-store-miss-rate%
     83017 ± 11%     -36.6%      52610 ± 11%  perf-stat.i.dTLB-store-misses
 8.033e+09            -5.9%  7.558e+09        perf-stat.i.dTLB-stores
     68.55            -6.8       61.76        perf-stat.i.iTLB-load-miss-rate%
    306356 ±  4%     -11.2%     272189 ±  3%  perf-stat.i.iTLB-load-misses
    151646           +10.6%     167664        perf-stat.i.iTLB-loads
 3.019e+10            -6.3%  2.829e+10        perf-stat.i.instructions
     91804 ±  4%     +10.4%     101373 ±  2%  perf-stat.i.instructions-per-iTLB-miss
      1.83            -1.7%       1.80        perf-stat.i.ipc
      0.89            -4.4%       0.85        perf-stat.i.metric.GHz
      1369            -6.2%       1284        perf-stat.i.metric.M/sec
      0.04 ± 86%      -0.0        0.01 ± 29%  perf-stat.i.node-load-miss-rate%
      1.32 ± 61%     -73.1%       0.36 ± 24%  perf-stat.i.node-load-misses
      1.22 ± 68%     -65.9%       0.42 ± 24%  perf-stat.i.node-store-misses
      0.72 ±  7%     +48.6%       1.07 ±  3%  perf-stat.overall.MPKI
      0.06 ±  4%      +0.0        0.08 ±  3%  perf-stat.overall.branch-miss-rate%
      4.52 ±  5%      -1.1        3.40 ±  2%  perf-stat.overall.cache-miss-rate%
      0.47            +2.0%       0.48        perf-stat.overall.cpi
      0.00 ± 11%      -0.0        0.00 ± 11%  perf-stat.overall.dTLB-store-miss-rate%
     66.86            -5.0       61.87        perf-stat.overall.iTLB-load-miss-rate%
      2.12            -1.9%       2.08        perf-stat.overall.ipc
      0.01 ± 66%      -0.0        0.00 ± 25%  perf-stat.overall.node-load-miss-rate%
      0.00 ± 61%      -0.0        0.00 ± 21%  perf-stat.overall.node-store-miss-rate%
 6.069e+09            -6.6%  5.667e+09        perf-stat.ps.branch-instructions
   3872647 ±  4%     +17.6%    4555828 ±  3%  perf-stat.ps.branch-misses
  21619892 ±  6%     +39.2%   30101345 ±  3%  perf-stat.ps.cache-references
 1.421e+10            -4.4%  1.358e+10        perf-stat.ps.cpu-cycles
 7.755e+09            -6.3%  7.268e+09        perf-stat.ps.dTLB-loads
     82808 ± 11%     -36.6%      52482 ± 11%  perf-stat.ps.dTLB-store-misses
 8.011e+09            -5.9%  7.537e+09        perf-stat.ps.dTLB-stores
    305587 ±  4%     -11.1%     271518 ±  3%  perf-stat.ps.iTLB-load-misses
    151265           +10.6%     167232        perf-stat.ps.iTLB-loads
 3.011e+10            -6.3%  2.821e+10        perf-stat.ps.instructions
      1.32 ± 61%     -73.0%       0.36 ± 24%  perf-stat.ps.node-load-misses
      1.22 ± 68%     -65.8%       0.42 ± 24%  perf-stat.ps.node-store-misses
 1.179e+13            -6.3%  1.105e+13        perf-stat.total.instructions
      9.04 ± 11%      -4.0        5.02 ± 48%  perf-profile.calltrace.cycles-pp.main
      6.39 ± 13%      -2.9        3.44 ± 48%  perf-profile.calltrace.cycles-pp.Proc_1
      3.85 ± 21%      -1.7        2.14 ± 50%  perf-profile.calltrace.cycles-pp.Proc_8
      1.67 ± 25%      -1.2        0.47 ±100%  perf-profile.calltrace.cycles-pp.Func_1
      1.90 ± 22%      -1.0        0.95 ± 81%  perf-profile.calltrace.cycles-pp.Func_2
     10.37 ±  8%      -4.1        6.22 ± 47%  perf-profile.children.cycles-pp.main
      6.17 ± 10%      -2.4        3.74 ± 48%  perf-profile.children.cycles-pp.Proc_1
      3.91 ± 12%      -1.5        2.39 ± 50%  perf-profile.children.cycles-pp.Proc_8
      2.19 ± 10%      -0.9        1.24 ± 49%  perf-profile.children.cycles-pp.Func_2
      0.59 ± 12%      -0.3        0.33 ± 40%  perf-profile.children.cycles-pp.strcmp@plt
      0.08 ± 24%      +0.1        0.13 ± 12%  perf-profile.children.cycles-pp.enqueue_hrtimer
      0.01 ±173%      +0.1        0.07 ± 16%  perf-profile.children.cycles-pp.rb_erase
      0.01 ±173%      +0.1        0.07 ± 21%  perf-profile.children.cycles-pp.__hrtimer_get_next_event
      0.04 ±101%      +0.1        0.10 ±  8%  perf-profile.children.cycles-pp.update_ts_time_stats
      0.08 ± 26%      +0.1        0.14 ± 15%  perf-profile.children.cycles-pp.timerqueue_del
      0.12 ± 22%      +0.1        0.18 ± 14%  perf-profile.children.cycles-pp.__remove_hrtimer
      0.01 ±173%      +0.1        0.08 ± 20%  perf-profile.children.cycles-pp.perf_event_task_tick
      0.10 ± 18%      +0.1        0.17 ± 17%  perf-profile.children.cycles-pp.__hrtimer_next_event_base
      0.21 ±  8%      +0.1        0.34 ± 13%  perf-profile.children.cycles-pp.tick_irq_enter
      0.22 ±  6%      +0.1        0.35 ± 14%  perf-profile.children.cycles-pp.irq_enter_rcu
      0.07 ±173%      +0.2        0.27 ± 21%  perf-profile.children.cycles-pp.io_serial_in
      0.07 ±173%      +0.2        0.30 ± 21%  perf-profile.children.cycles-pp.serial8250_console_putchar
      0.07 ±173%      +0.2        0.31 ± 20%  perf-profile.children.cycles-pp.wait_for_xmitr
      0.08 ±173%      +0.2        0.32 ± 21%  perf-profile.children.cycles-pp.uart_console_write
      0.08 ±173%      +0.2        0.33 ± 21%  perf-profile.children.cycles-pp.serial8250_console_write
      0.09 ±173%      +0.2        0.33 ± 22%  perf-profile.children.cycles-pp.asm_sysvec_irq_work
      0.09 ±173%      +0.2        0.33 ± 22%  perf-profile.children.cycles-pp.sysvec_irq_work
      0.09 ±173%      +0.2        0.33 ± 22%  perf-profile.children.cycles-pp.__sysvec_irq_work
      0.09 ±173%      +0.2        0.33 ± 22%  perf-profile.children.cycles-pp.irq_work_run
      0.09 ±173%      +0.2        0.33 ± 22%  perf-profile.children.cycles-pp.irq_work_single
      0.09 ±173%      +0.2        0.33 ± 22%  perf-profile.children.cycles-pp.printk
      0.09 ±173%      +0.2        0.33 ± 22%  perf-profile.children.cycles-pp.vprintk_emit
      0.09 ±173%      +0.2        0.33 ± 22%  perf-profile.children.cycles-pp.console_unlock
      0.09 ±173%      +0.3        0.34 ± 24%  perf-profile.children.cycles-pp.irq_work_run_list
      8.83 ±  8%      -3.6        5.24 ± 47%  perf-profile.self.cycles-pp.main
      5.21 ± 10%      -2.1        3.09 ± 51%  perf-profile.self.cycles-pp.Proc_1
      3.35 ± 11%      -1.3        2.06 ± 52%  perf-profile.self.cycles-pp.Proc_8
      1.67 ± 10%      -0.8        0.91 ± 48%  perf-profile.self.cycles-pp.Func_2
      0.60 ± 22%      -0.3        0.33 ± 34%  perf-profile.self.cycles-pp.Proc_6
      0.58 ± 12%      -0.3        0.33 ± 40%  perf-profile.self.cycles-pp.strcmp@plt
      0.01 ±173%      +0.1        0.07 ± 13%  perf-profile.self.cycles-pp.rb_erase
      0.08 ± 19%      +0.1        0.15 ± 14%  perf-profile.self.cycles-pp.__hrtimer_next_event_base
      0.01 ±173%      +0.1        0.08 ± 20%  perf-profile.self.cycles-pp.perf_event_task_tick
      0.37 ±  5%      +0.1        0.52 ± 20%  perf-profile.self.cycles-pp.cpuidle_enter_state
      0.07 ±173%      +0.2        0.27 ± 21%  perf-profile.self.cycles-pp.io_serial_in


                                                                                
                                   unixbench.score                              
                                                                                
  19800 +-------------------------------------------------------------------+   
        |                                                                   |   
  19600 |...  ..+...  ..+...+...+...+.      +...+             ..+...+       |   
  19400 |-+ +.      +.                ..  ..    :         ..+.              |   
        |                                .       :      +.                  |   
  19200 |-+                             +        :     :                    |   
        |                                         :    :                    |   
  19000 |-+                                       :   :                     |   
        |   O                                      :  :                     |   
  18800 |-+                                        : :                      |   
  18600 |-+             O                           ::                      |   
        |       O               O       O           +                       |   
  18400 |-+                                                     O           |   
        |           O       O       O       O   O   O   O   O           O   |   
  18200 +-------------------------------------------------------------------+   
                                                                                
                                                                                
[*] 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,
Oliver Sang


View attachment "config-5.11.0-rc2-00181-ga91bd6223ecd" of type "text/plain" (172414 bytes)

View attachment "job-script" of type "text/plain" (7625 bytes)

View attachment "job.yaml" of type "text/plain" (5171 bytes)

View attachment "reproduce" of type "text/plain" (280 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ