lkml.org 
[lkml]   [2008]   [Nov]   [26]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    Date
    From
    SubjectRe: [PATCH 4/4] tracing/function-return-tracer: Support for dynamic ftrace on function return tracer

    [
    Sorry Tim to reply again, but alpine broke on Frederic's funny
    characters in his email address, and it chopped off all the Cc's :-(
    ]

    On Wed, 26 Nov 2008, Tim Bird wrote:
    >
    > Very sorry I'm coming to this thread late. I didn't notice it until
    > today.
    >
    > Not to question the whole approach, and sorry if this was
    > discussed before, but why wasn't -finstrument-functions used
    > to instrument the function exits. This worked well for KFT
    > (See http://elinux.org/Kernel_Function_Trace). I'm not sure if the
    > function prologue and epilogue modifications done by -mcount are
    > different than -finstrument-functions, but I thought I remember
    something
    > about Steven testing -finstrument-functions in an early version of
    ftrace.
    >
    > By the way, I'm really excited to see this "function_cost" stuff being
    > worked on. It has proven to be extremely useful for analyzing early
    boot
    > latencies at Sony.
    >

    No prob Tim. I need to make a standard template to explain the reason not
    to use -finstrument-functions. (/me goes look for a previous post...)

    Here it is:

    (here's the original post: http://lkml.org/lkml/2008/10/30/372 that
    was posted at the beginning of Frederic's work)

    ========================================================
    Lets take a simple C file called traceme.c:


    ---
    static int x;

    void trace_me(void)
    {
    x++;
    }
    ---

    Normal compiling of:

    gcc -c traceme.c

    produces:

    00000000 <trace_me>:
    0: 55 push %ebp
    1: 89 e5 mov %esp,%ebp
    3: a1 00 00 00 00 mov 0x0,%eax
    4: R_386_32 .bss
    8: 83 c0 01 add $0x1,%eax
    b: a3 00 00 00 00 mov %eax,0x0
    c: R_386_32 .bss
    10: 5d pop %ebp
    11: c3 ret


    With

    gcc -c -pg traceme.c

    00000000 <trace_me>:
    0: 55 push %ebp
    1: 89 e5 mov %esp,%ebp
    3: e8 fc ff ff ff call 4 <trace_me+0x4>
    4: R_386_PC32 mcount
    8: a1 00 00 00 00 mov 0x0,%eax
    9: R_386_32 .bss
    d: 83 c0 01 add $0x1,%eax
    10: a3 00 00 00 00 mov %eax,0x0
    11: R_386_32 .bss
    15: 5d pop %ebp
    16: c3 ret


    The only difference between the two is an added "call mcount".
    5 byte op to replace with dynamic ftrace.

    But now lets look at:

    gcc -c -finstrument-functions traceme.c

    00000000 <trace_me>:
    0: 55 push %ebp
    1: 89 e5 mov %esp,%ebp
    3: 83 ec 18 sub $0x18,%esp
    6: 8b 45 04 mov 0x4(%ebp),%eax
    9: 89 44 24 04 mov %eax,0x4(%esp)
    d: c7 04 24 00 00 00 00 movl $0x0,(%esp)
    10: R_386_32 trace_me
    14: e8 fc ff ff ff call 15 <trace_me+0x15>
    15: R_386_PC32 __cyg_profile_func_enter
    19: a1 00 00 00 00 mov 0x0,%eax
    1a: R_386_32 .bss
    1e: 83 c0 01 add $0x1,%eax
    21: a3 00 00 00 00 mov %eax,0x0
    22: R_386_32 .bss
    26: 8b 45 04 mov 0x4(%ebp),%eax
    29: 89 44 24 04 mov %eax,0x4(%esp)
    2d: c7 04 24 00 00 00 00 movl $0x0,(%esp)
    30: R_386_32 trace_me
    34: e8 fc ff ff ff call 35 <trace_me+0x35>
    35: R_386_PC32 __cyg_profile_func_exit
    39: c9 leave
    3a: c3 ret

    Here we see that

    mov %eax, 0x4(%esp)
    movl $trace_me,(%esp)
    call _cyg_profile_func_enter

    is added at the beginning and

    mov %eax,0x4(%esp)
    mov $trace_me,(%esp)
    call __cyg_profile_func_exit

    is added at the end.

    This is not 5 extra bytes but 27 extra bytes for a total of 32 bytes
    at every function.

    ========================================================

    The overhead of -finstrument-functions is way too big. Remember, with
    using mcount, we can also patch away the callers. It's 5 bytes on both
    x86_64 and i386 and 4 bytes on most other archs. To patch away the
    -finstrument-functions would be too large, not to mention, you could not
    do it with nops. You whould have to have a jump, since patching more than
    one op code would lead to race conditions with a task being preempted in
    the middle of those nops.

    I need to file this information away to give the next person that asks
    this question ;-)

    > Sorry again I didn't catch this and previous related threads
    > earlier. I have some post-processing tools which might be useful here.
    > Also, I've found it very handy to have the capability to filter by
    minimum
    > function duration. Is there any work to do that with the
    > current system. If not, maybe I could take a look at that and see if
    > I can add something.
    >

    Actually, I probably should have Cc'd you anyway. I know you did similar
    work. You may be able to add that filtering to the dynamic ftrace so that
    the tracer will filter them out as well. If you want to work on this,
    feel free. There's already been a lot of good ideas (and code) coming from
    other developers :-)

    -- Steve



    \
     
     \ /
      Last update: 2008-11-26 20:25    [W:0.378 / U:2.072 seconds]
    ©2003-2016 Jasper Spaans. hosted at Digital OceanAdvertise on this site