Re: [PATCH 1/2] trace: Add trap entry/exit tracepoints

[Vaibhav Nagarnaik]

On Thu, Apr 28, 2011 at 5:33 PM, Thomas Gleixner <tglx@xxxxxxxxxxxxx> wrote:
> On Fri, 22 Apr 2011, Vaibhav Nagarnaik wrote:
>>  #include <asm/uaccess.h>
>>  #include <asm/pgtable.h>
>>  #include <asm/system.h>
>> @@ -1330,8 +1332,10 @@ void send_sigtrap(struct task_struct *tsk, struct pt_regs *regs,
>>       struct siginfo info;
>>
>>       fill_sigtrap_info(tsk, regs, error_code, si_code, &info);
>> +     trace_trap_entry(tsk->thread.trap_no);
>
> What the heck? How is that a trap? The code is sending SIGTRAP not
> entering a trap at all. What are you trying to measure ? The time it
> takes to send SIGTRAP? So how is that useful as an extra event?
>

It is not a trap. But it did get called from the do_debug trap handler. I have
moved these tracepoints to the do_debug function which is a better place for
them.

>>       /* Send us the fake SIGTRAP */
>>       force_sig_info(SIGTRAP, &info, tsk);
>> +     trace_trap_exit(tsk->thread.trap_no);
>>  }
>>
>>
>> diff --git a/arch/x86/kernel/traps.c b/arch/x86/kernel/traps.c
>> index 4857ff6..d450349 100644
>> --- a/arch/x86/kernel/traps.c
>> +++ b/arch/x86/kernel/traps.c
>> @@ -33,6 +33,9 @@
>>  #include <linux/io.h>
>>  #include <trace/events/irq.h>
>>
>> +#define CREATE_TRACE_POINTS
>> +#include <trace/events/trap.h>
>> +
>>  #ifdef CONFIG_EISA
>>  #include <linux/ioport.h>
>>  #include <linux/eisa.h>
>> @@ -123,6 +126,7 @@ do_trap(int trapnr, int signr, char *str, struct pt_regs *regs,
>>  {
>>       struct task_struct *tsk = current;
>>
>> +     trace_trap_entry(trapnr);
>
> While the event of do_trap() itself might be interesting, it does not
> matter at all how long it takes to handle it. That code is really not
> so interesting.
>
I have updated the use case in the patch. We actually can find the instances
when the system moved between kernel and user spaces. The fact that we also
get timestamps is an added advantage.

>> @@ -286,7 +293,9 @@ do_general_protection(struct pt_regs *regs, long error_code)
>>               printk("\n");
>>       }
>>
>> +     trace_trap_entry(tsk->thread.trap_no);
>>       force_sig(SIGSEGV, tsk);
>> +     trace_trap_exit(tsk->thread.trap_no);
>
> We really do not care how long the force_sig() call takes. It's
> irrelevant. The only interesting thing here is that we ran into a GP
> trap.
>
I agree, but it does provide the task which caused this and another data point
where the system had to move to kernel space.

>> +
>> +dotraplinkage void __kprobes
>> +do_page_fault(struct pt_regs *regs, unsigned long error_code)
>> +{
>> +     trace_trap_entry(14);
>
> Yuck. Magic number 14 ? Why not 42 ?

Sorry for that. I thought that this patch would have lower resistance than the
next patch which converts the numbers to enum values. I have corrected it now
and am sending the enum patch first and use that as the base patch to use the
enum value (INTR_PAGE_FAULT) instead of magic number.

>
>> +     __do_page_fault(regs, error_code);
>> +     trace_trap_exit(14);
>> +}
>
> That page fault thing is the only interesting event in terms of
> runtime, but I have yet to see a proper rationale for the whole thing
> aside of that completly bogus changelog which tells what output I can
> produce, but not why the hell it is a good idea to add all that trace
> points.
>
I have updated the patch description. Hopefully it is better worded and
provides more context and support for the usefulness of it.

> Thanks,
>
>        tglx
>
>

Thanks for looking at the patches.

Vaibhav Nagarnaik
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/