Re: [PATCH] Instrumenting high latency

[Con Kolivas]

Martin J. Bligh wrote:
> --Con Kolivas <kernel@xxxxxxxxxxx> wrote (on Tuesday, July 13, 2004 00:27:27 +1000):
>
>
> > Martin J. Bligh wrote:
> >
> > > > Because of the recent discussion about latency in the kernel I asked 
> > > > William Lee Irwin III to help create some instrumentation to determine 
> > > > where in the kernel there were still sustained periods of non-preemptible 
> > > > code. He hacked together this simple patch which times periods according 
> > > > to the preempt count. Hopefully we can use this patch in the advice of 
> > > > Linus to avoid the "mental masturbation" at guessing where latency is 
> > > > and track down real problem areas.
> > >
> > >
> > > Is this much different from Rick's schedstat's work, which was itself based
> > > on some earlier patches by Bill? I'd hate to end up with two sets of patches,
> > > and schedstats seemed pretty comprehensive to me. He's on vacation, but his
> > > stuff is here, if you want to take a look:
> > >
> > > http://eaglet.rain.com/rick/linux/schedstats/
> >
> > No I remember his work and this is tackling it via a different area if I 
> > recall correctly. He was looking at scheduler latencies as opposed to 
> > non-preemptible kernel code.
>
>
> Fair enough ... is it worth adding it to the same harness though? He had lots
> of nice analysis tools set up to do comparisons and graphing, etc.

This works very nicely standalone getting us this for example with the 
fixed patch:

6ms non-preemptible critical section violated 1 ms preempt threshold 
starting at exit_mmap+0x1c/0x188 and ending at exit_mmap+0x118/0x188
 [<c011d769>] dec_preempt_count+0x14f/0x151
 [<c014d0d4>] exit_mmap+0x118/0x188
 [<c014d0d4>] exit_mmap+0x118/0x188
 [<c011df0a>] mmput+0x61/0x7b
 [<c01226fa>] do_exit+0x142/0x510
 [<c014c928>] unmap_vma_list+0xe/0x17
 [<c0122b8a>] do_group_exit+0x41/0xf9
 [<c0105fd5>] sysenter_past_esp+0x52/0x71

which then an objdump of the inlined code has allowed us to track it 
down to this:

         profile_exit_mmap(mm);
         lru_add_drain();
c014cfce:       e8 18 72 ff ff          call   c01441eb <lru_add_drain>
         spin_lock(&mm->page_table_lock);
c014cfd3:       e8 16 06 fd ff          call   c011d5ee <inc_preempt_count>


That's pretty specific. I dont think this comes under the umbrella of 
statistics as such. Sure it can be modified to do it but I was looking 
for a tool to find where specific latency hotspots still exist. Of 
course I'm not capable myself of tackling the actual hotspots but those 
who code those areas certainly can tackle them knowing what firm data shows.

Cheers,
Con

Attachment: signature.asc
Description: OpenPGP digital signature