Re: [bug] very high non-preempt latency in context_struct_compute_av()

[Ingo Molnar <mingo@elte.hu>]

* James Morris <jmorris@namei.org> wrote:

> > the latency is caused by a _very_ long loop in the SELinux code:
> > 
> >     sshd-4828  0.N.. 465894us : avtab_search_node (context_struct_compute_av)
> 
> What do the 0DNs fields mean and what did you use to create this 
> trace?

i used the latency tracer from -rt. Here's the meaning of the fields:

                  _------=> CPU#
                 / _-----=> irqs-off
                | / _----=> need-resched 
                || / _---=> hardirq/softirq
                ||| / _--=> preempt-depth
                |||| /
                |||||     delay
    cmd     pid ||||| time  |   caller
       \   /    |||||   \   |   /
 trace-it-4751  0D...    0us : __next_cpu (user_trace_start)

it's very easy to interpret: it traces all the function calls the kernel 
executes, and puts the symbolic function name (and its parent function) 
into the trace, time ordered. So it's a proper execution trace. Normally 
you can ignore the 'DN' type of flags - what matters in this case is the 
observed 130 msecs latency and the functions that were called while that 
latency happened.

	Ingo