Bill Huey (hui) wrote: > On Tue, Dec 26, 2006 at 04:51:21PM -0800, Chen, Tim C wrote: >> Ingo Molnar wrote: >>> If you'd like to profile this yourself then the lowest-cost way of >>> profiling lock contention on -rt is to use the yum kernel and run >>> the attached trace-it-lock-prof.c code on the box while your >>> workload is in 'steady state' (and is showing those extended idle >>> times): >>> >>> ./trace-it-lock-prof > trace.txt >> >> Thanks for the pointer. Will let you know of any relevant traces. > > Tim, > http://mmlinux.sourceforge.net/public/patch-2.6.20-rc2-rt2.lock_stat.pat ch > > You can also apply this patch to get more precise statistics down to > the lock. For example: > Bill,
I'm having some problem getting this patch to run stablely. I'm encoutering errors like that in the trace that follow: Thanks. Tim Unable to handle kernel NULL pointer dereference at 0000000000000008 RIP: [<ffffffff802cd6e4>] lock_stat_note_contention+0x12d/0x1c3 PGD 0 Oops: 0000 [1] PREEMPT SMP CPU 1 Modules linked in: autofs4 sunrpc dm_mirror dm_mod video sbs i2c_ec dock button battery ac uhci_hcd ehci_hcd i2dPid: 0, comm: swapper Not tainted 2.6.20-rc2-rt2 #4 RIP: 0010:[<ffffffff802cd6e4>] [<ffffffff802cd6e4>] lock_stat_note_contention+0x12d/0x1c3 RSP: 0018:ffff81013fdb3d28 EFLAGS: 00010097 RAX: ffff81013fd68018 RBX: ffff81013fd68000 RCX: 0000000000000000 RDX: ffffffff8026762e RSI: 0000000000000000 RDI: ffffffff8026762e RBP: ffff81013fdb3df8 R08: ffff8100092bab60 R09: ffff8100092aafc8 R10: 0000000000000001 R11: 0000000000000000 R12: ffff81013fd68030 R13: 0000000000000000 R14: 0000000000000046 R15: 0000002728d5ecd0 FS: 0000000000000000(0000) GS:ffff81013fd078c0(0000) knlGS:0000000000000000 CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b CR2: 0000000000000008 CR3: 0000000000201000 CR4: 00000000000006e0 Process swapper (pid: 0, threadinfo ffff81013fdb2000, task ffff81013fdb14e0) Stack: 0000000000000000 0000000200000001 0000000000000000 0000000000000000 0000000000000000 0000000000000000 0000000000000100 000000000000000e 000000000000000e 0000000000000000 0000000000000000 ffff8100092bc440 Call Trace: [<ffffffff802af471>] rt_mutex_slowtrylock+0x84/0x9b [<ffffffff80266909>] rt_mutex_trylock+0x2e/0x30 [<ffffffff8026762e>] rt_spin_trylock+0x9/0xb [<ffffffff8029beef>] get_next_timer_interrupt+0x34/0x226 [<ffffffff802a8b4d>] hrtimer_stop_sched_tick+0xb6/0x138 [<ffffffff8024b1ce>] cpu_idle+0x1b/0xdd [<ffffffff80278edd>] start_secondary+0x2ed/0x2f9 --------------------------- | preempt count: 00000003 ] | 3-level deep critical section nesting: ---------------------------------------- .. [<ffffffff8024b28a>] .... cpu_idle+0xd7/0xdd .....[<ffffffff80278edd>] .. ( <= start_secondary+0x2ed/0x2f9) .. [<ffffffff80267837>] .... __spin_lock_irqsave+0x18/0x42 .....[<ffffffff802af406>] .. ( <= rt_mutex_slowtrylock+0x19/0x9b) .. [<ffffffff802678db>] .... __spin_trylock+0x14/0x4c .....[<ffffffff80268540>] .. ( <= oops_begin+0x23/0x6f) skipping trace printing on CPU#1 != -1 Code: 49 8b 45 08 8b 78 18 75 0d 49 8b 04 24 f0 ff 80 94 00 00 00 RIP [<ffffffff802cd6e4>] lock_stat_note_contention+0x12d/0x1c3 RSP <ffff81013fdb3d28> CR2: 0000000000000008 <3>BUG: sleeping function called from invalid context swapper(0) at kernel/rtmutex.c:1312 in_atomic():1 [00000002], irqs_disabled():1 Call Trace: [<ffffffff8026ec53>] dump_trace+0xbe/0x3cd [<ffffffff8026eff3>] show_trace+0x3a/0x58 [<ffffffff8026f026>] dump_stack+0x15/0x17 [<ffffffff8020b75e>] __might_sleep+0x103/0x10a [<ffffffff80266e44>] rt_mutex_lock_with_ip+0x1e/0xac [<ffffffff802aff07>] __rt_down_read+0x49/0x4d [<ffffffff802aff16>] rt_down_read+0xb/0xd [<ffffffff8029fc96>] blocking_notifier_call_chain+0x19/0x3f [<ffffffff80296301>] profile_task_exit+0x15/0x17 [<ffffffff80215572>] do_exit+0x25/0x8de [<ffffffff8026a2c1>] do_page_fault+0x7d4/0x856 [<ffffffff802681ad>] error_exit+0x0/0x84 [<ffffffff802cd6e4>] lock_stat_note_contention+0x12d/0x1c3 [<ffffffff802af471>] rt_mutex_slowtrylock+0x84/0x9b [<ffffffff80266909>] rt_mutex_trylock+0x2e/0x30 [<ffffffff8026762e>] rt_spin_trylock+0x9/0xb [<ffffffff8029beef>] get_next_timer_interrupt+0x34/0x226 [<ffffffff802a8b4d>] hrtimer_stop_sched_tick+0xb6/0x138 [<ffffffff8024b1ce>] cpu_idle+0x1b/0xdd [<ffffffff80278edd>] start_secondary+0x2ed/0x2f9 - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
