svn commit: r265792 - head/sys/kern

[Slawa Olhovchenkov]

On Tue, Aug 26, 2014 at 10:35:21PM +0300, Alexander Motin wrote:

> On 26.08.2014 21:54, Slawa Olhovchenkov wrote:
> > On Tue, May 20, 2014 at 09:04:25AM -0700, Adrian Chadd wrote:
> > 
> >> On 20 May 2014 08:41, Slawa Olhovchenkov <slw at zxy.spb.ru> wrote:
> >>
> >>>> (But if you try it on 10.0 and it changes things, by all means let me know.)
> >>>
> >>> I am try on 10.0, but not sure about significant improvement (may be
> >>> 10%).
> >>>
> >>> For current CPU (E5-2650 v2 @ 2.60GHz) hwpmc don't working (1. after
> >>> collect some data `pmcstat -R sample.out -G out.txt` don't decode any;
> >>> 2. kldunload hwpmc do kernel crash) and I can't collect detailed
> >>> profile information.
> >>
> >> Yup. I'm starting to get really ticked off at how pmc logging on
> >> multi-core devices just "stops" after a while. I'll talk with other
> >> pmc people and see if we can figure out what the heck is going on. :(
> > 
> > Now I can test you work on CPU w/ working pmc.
> > @ CPU_CLK_UNHALTED_CORE [241440 samples]
> > 
> > 10.59%  [25561]    _mtx_lock_spin_cookie @ /boot/kernel/kernel
> >  94.25%  [24092]     pmclog_reserve @ /boot/kernel/hwpmc.ko
> >   100.0%  [24092]      pmclog_process_callchain
> >    100.0%  [24092]       pmc_process_samples
> >     100.0%  [24092]        pmc_hook_handler
> >      100.0%  [24092]         hardclock_cnt @ /boot/kernel/kernel
> 
> Slava, on large SMP systems you should specify some much bigger division
> rate (like `-n 100000000`) when doing PMC sampling. Otherwise you are
> mostly measuring PMC's internal lock congestion.

OK, now traffic less (15.8 Gbit)
Any other recomendations?

last pid: 27787;  load averages:  8.99,  8.53,  8.43                                                                                   up 0+04:54:59  23:41:50
47 processes:  6 running, 41 sleeping
CPU 0:  17.3% user,  0.0% nice, 36.9% system,  0.8% interrupt, 45.1% idle
CPU 1:  12.9% user,  0.0% nice, 37.3% system,  0.4% interrupt, 49.4% idle
CPU 2:  11.8% user,  0.0% nice, 40.4% system,  0.0% interrupt, 47.8% idle
CPU 3:  11.4% user,  0.0% nice, 40.8% system,  0.4% interrupt, 47.5% idle
CPU 4:  17.3% user,  0.0% nice, 41.2% system,  0.0% interrupt, 41.6% idle
CPU 5:  14.9% user,  0.0% nice, 40.4% system,  0.4% interrupt, 44.3% idle
CPU 6:   0.4% user,  0.0% nice,  5.5% system, 71.0% interrupt, 23.1% idle
CPU 7:   0.4% user,  0.0% nice,  3.5% system, 63.9% interrupt, 32.2% idle
CPU 8:   0.0% user,  0.0% nice,  3.5% system, 65.5% interrupt, 31.0% idle
CPU 9:   0.4% user,  0.0% nice,  3.9% system, 70.2% interrupt, 25.5% idle
CPU 10:  0.0% user,  0.0% nice,  3.9% system, 59.2% interrupt, 36.9% idle
CPU 11:  0.4% user,  0.0% nice,  4.3% system, 69.8% interrupt, 25.5% idle
Mem: 319M Active, 15G Inact, 96G Wired, 13G Free
ARC: 90G Total, 85G MFU, 5233M MRU, 95M Anon, 396M Header, 101M Other
Swap:

@ CPU_CLK_UNHALTED_CORE [79302 samples]

09.97%  [7908]     _mtx_lock_spin_cookie @ /boot/kernel/kernel
 95.73%  [7570]      pmclog_reserve @ /boot/kernel/hwpmc.ko
  100.0%  [7570]       pmclog_process_callchain
   100.0%  [7570]        pmc_process_samples
    100.0%  [7570]         pmc_hook_handler
     100.0%  [7570]          hardclock_cnt @ /boot/kernel/kernel
      100.0%  [7570]           handleevents
       97.54%  [7384]            timercb
        100.0%  [7384]             lapic_handle_timer
       02.46%  [186]             cpu_activeclock
        100.0%  [186]              cpu_idle
         100.0%  [186]               sched_idletd
          100.0%  [186]                fork_exit
 02.66%  [210]       callout_lock
  94.76%  [199]        callout_reset_sbt_on
   99.50%  [198]         tcp_timer_activate
    94.95%  [188]          tcp_do_segment
     100.0%  [188]           tcp_input
      100.0%  [188]            ip_input
       100.0%  [188]             netisr_dispatch_src
        100.0%  [188]              ether_demux
         100.0%  [188]               ether_nh_input
          100.0%  [188]                netisr_dispatch_src
           84.04%  [158]                 ixgbe_rxeof @ /boot/kernel/if_ixgbe.ko
            100.0%  [158]                  ixgbe_msix_que
             100.0%  [158]                   intr_event_execute_handlers @ /boot/kernel/kernel
              100.0%  [158]                    ithread_loop
               100.0%  [158]                     fork_exit
           15.96%  [30]                  tcp_lro_flush
            96.67%  [29]                   ixgbe_rxeof @ /boot/kernel/if_ixgbe.ko
             100.0%  [29]                    ixgbe_msix_que
              100.0%  [29]                     intr_event_execute_handlers @ /boot/kernel/kernel
               100.0%  [29]                      ithread_loop
            03.33%  [1]                    tcp_lro_rx
             100.0%  [1]                     ixgbe_rxeof @ /boot/kernel/if_ixgbe.ko
              100.0%  [1]                      ixgbe_msix_que
               100.0%  [1]                       intr_event_execute_handlers @ /boot/kernel/kernel
    05.05%  [10]           tcp_output
     100.0%  [10]            tcp_do_segment
      100.0%  [10]             tcp_input
       100.0%  [10]              ip_input
        100.0%  [10]               netisr_dispatch_src
         100.0%  [10]                ether_demux
          100.0%  [10]                 ether_nh_input
           100.0%  [10]                  netisr_dispatch_src
            100.0%  [10]                   ixgbe_rxeof @ /boot/kernel/if_ixgbe.ko
             100.0%  [10]                    ixgbe_msix_que
              100.0%  [10]                     intr_event_execute_handlers @ /boot/kernel/kernel
               100.0%  [10]                      ithread_loop