Re: [PATCH] Instrumenting high latency

From: Con Kolivas
Date: Mon Jul 12 2004 - 09:45:22 EST


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