Re: [PATCH] Do not force shutdown/reboot to boot cpu.

[Robin Holt <holt@sgi.com>]

On Thu, Apr 11, 2013 at 02:00:27PM +0200, Ingo Molnar wrote:
> 
> * Robin Holt <holt@sgi.com> wrote:
> 
> > > Ok, so it looks profilable.
> > > 
> > > The result above is not surprising: most CPUs sit in idle and don't do anything, 
> > > while the loop goes on, right?
> > > 
> > > The interesting thing to profile would be the parallel bring-down, with the 
> > > simplest global lock solution you mentioned. In that case most CPUs should be 
> > > doing 'something' all the time - maybe spinning on the lock, maybe something else, 
> > > right?
> > 
> > Again, mostly looks idle.
> 
> Forgot to suggest:
> 
>   perf record -a /sbin/reboot

I used perf record -a /sbin/reboot -f -d -n

Robin
> 
> ... to capture remote CPU activity too.
> 
> > Events: 5M cycles
> >     31.69%          swapper  [kernel.kallsyms]        [k] update_cfs_rq_blocked_load
> >     14.22%          swapper  [kernel.kallsyms]        [k] load_balance
> >     12.95%          swapper  [kernel.kallsyms]        [k] ktime_get
> >      4.64%          swapper  [kernel.kallsyms]        [k] idle_cpu
> >      3.46%          swapper  [kernel.kallsyms]        [k] uv_read_rtc
> >      2.26%          swapper  [kernel.kallsyms]        [k] ktime_get_update_offsets
> >      2.25%          swapper  [kernel.kallsyms]        [k] rcu_check_callbacks
> >      1.72%          swapper  [kernel.kallsyms]        [k] _raw_spin_lock_irqsave
> >      1.57%          swapper  [kernel.kallsyms]        [k] native_write_msr_safe
> >      1.53%          swapper  [kernel.kallsyms]        [k] native_safe_halt
> >      1.52%          swapper  [kernel.kallsyms]        [k] apic_timer_interrupt
> >      1.52%          swapper  [kernel.kallsyms]        [k] update_blocked_averages
> >      1.51%          swapper  [kernel.kallsyms]        [k] __lock_text_start
> >      1.48%          swapper  [kernel.kallsyms]        [k] rcu_process_gp_end
> >      1.40%          swapper  [kernel.kallsyms]        [k] rcu_process_callbacks
> >      1.19%           reboot  [kernel.kallsyms]        [k] kmem_cache_alloc_node
> >      0.63%          swapper  [kernel.kallsyms]        [k] check_for_new_grace_period
> >      0.58%          swapper  [kernel.kallsyms]        [k] rebalance_domains
> >      0.55%          swapper  [kernel.kallsyms]        [k] cpumask_next_and
> >      0.54%          swapper  [kernel.kallsyms]        [k] __tick_nohz_idle_enter
> >      0.53%          swapper  [kernel.kallsyms]        [k] perf_adjust_freq_unthr_context
> >      0.49%          swapper  [kernel.kallsyms]        [k] _raw_spin_lock
> 
> If even perf record -a shows a mostly idle system, then the overhead must be in 
> sleep/wakeup latencies - for that the next step would be to figure out where all 
> the waiting happens, for example via call-graph context-switch profiling:
> 
>    perf stat --null perf record -a -g -e sched:sched_switch /sbin/reboot
> 
> (the perf stat --null will tell us the runtime of the whole operation.)
> 
> Thanks,
> 
> 	Ingo