lkml.org 
[lkml]   [2022]   [Oct]   [18]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    From
    Date
    SubjectRe: [PATCH v15 0/4] trace: Introduce objtrace trigger to trace the kernel object
    On Tue, Oct 18, 2022 at 3:40 AM Steven Rostedt <rostedt@goodmis.org> wrote:
    >
    > On Fri, 19 Aug 2022 11:27:02 +0800
    > Jeff Xie <xiehuan09@gmail.com> wrote:
    >
    > So on my way home from London, I tried to update it to use the fetch
    > instruction logic of kprobes (which will work), but I also ended up pretty
    > much rewriting most of it, which then I realized, I'm going much further
    > than I wanted to.

    Very excited to hear it will work. Thank you for your hard work.

    > But know I have a much better idea of how this should work, and I'll try to
    > go through what I learned here and throughout the patches.
    >
    >
    > > Introduce a method based on function tracer to trace any object and get
    > > the value of the object dynamically. the object can be obtained from the
    > > dynamic event (kprobe_event/uprobe_event) or the static event(tracepoint).
    >
    > Note, I can see the value of tracing only the value of the object, but that
    > to me would be "objfollow" not "objtrace". That is, to find out what
    > functions are calling the object. I guess that may have been your original
    > objective, but it was articulated more about knowing how the value changed

    Yes, It actually was my original objective -;) and I also really love
    your idea of getting its value.

    > and not where the value is going (and the code was written more like that).
    > Having a objfollow may be nice, but reading the arguments of a function is
    > really a "best attempt" at most, and you can't really trust the arguments
    > are what you are tracing.

    It's true, you spoke to my heart ;-)

    >I would hold off on that until we have a good BTF
    > tracing infrastructure in the function tracer.
    >
    > So I'm going to continue with "objtrace" which is about tracing the
    > object's value throughout time.

    Thanks.

    >
    > >
    > > Usage:
    > > When using the kprobe event, only need to set the objtrace(a new trigger),
    > > we can get the value of the object. The object is from the setting of the
    > > kprobe event.
    > >
    > > For example:
    > > For the function bio_add_page():
    > >
    > > int bio_add_page(struct bio *bio, struct page *page,
    > > unsigned int len, unsigned int offset)
    > >
    > > Firstly, we can set the base of the object, thus the first string "arg1"
    > > stands for the value of the first parameter of this function bio_add_gage(),
    > >
    > > # echo 'p bio_add_page arg1=$arg1' > ./kprobe_events
    > >
    > > Secondly, we can get the value dynamically based on above object.
    > >
    > > find the offset of the bi_size in struct bio:
    > > $ gdb vmlinux
    > > (gdb) p &(((struct bio *)0)->bi_iter.bi_size)
    > > $1 = (unsigned int *) 0x28
    > >
    > > # echo 'objtrace:add:arg1,0x28:u32:1 if comm == "cat"' > ./events/kprobes/ \
    > > p_bio_add_page_0/trigger
    > >
    > > # cd /sys/kernel/debug/tracing/
    > > # echo 'p bio_add_page arg1=$arg1' > ./kprobe_events
    > > # echo 'objtrace:add:arg1,0x28:u32:1 if comm == "cat"' > ./events/kprobes/p_bio_add_page_0/trigger
    >
    > So I was working to change the above to:
    >
    > echo 'objtrace:add:+0x28($arg1):u32:1 if comm == "cat"'

    It seems easier to use, I like it.

    >
    >
    > >
    > > # du -sh /test.txt
    > > 12.0K /test.txt
    > >
    > > # cat /test.txt > /dev/null
    > > # cat ./trace
    > > # tracer: nop
    > > #
    > > # entries-in-buffer/entries-written: 128/128 #P:4
    > > #
    > > # _-----=> irqs-off/BH-disabled
    > > # / _----=> need-resched
    > > # | / _---=> hardirq/softirq
    > > # || / _--=> preempt-depth
    > > # ||| / _-=> migrate-disable
    > > # |||| / delay
    > > # TASK-PID CPU# ||||| TIMESTAMP FUNCTION
    > > # | | | ||||| | |
    > > cat-117 [002] ...1. 1.602243: __bio_try_merge_page <-bio_add_page object:0xffff88811bee4000 value:0x0
    > > cat-117 [002] ...1. 1.602244: __bio_add_page <-bio_add_page object:0xffff88811bee4000 value:0x0
    > > cat-117 [002] ...2. 1.602244: bio_add_page <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x1000
    > > cat-117 [002] ...1. 1.602245: __bio_try_merge_page <-bio_add_page object:0xffff88811bee4000 value:0x1000
    > > cat-117 [002] ...1. 1.602245: __bio_add_page <-bio_add_page object:0xffff88811bee4000 value:0x1000
    >
    > Now instead of searching the function arguments for "obj", we should just
    > read the obj value at every function and report when it changed, as well as
    > the last function it was still the same. The report will be like the
    > "func_repeats" entry. And instead we can print when the object changes,
    > something like this:
    >
    > cat-117 [002] ...2. 1.602245: bio_add_page <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x2000 (last value:0x1000 at [002] __bio_add_page <-bio_add_page ts: 1.602245)

    This output is better than I expected.

    >
    > This will tell us when a value changed.
    >
    > It would need to store the CPU, ip and pip and timestamp of the last time
    > it was the same. And when it changes, it would then report it.
    >
    > -- Steve

    --
    Thanks,
    JeffXie

    \
     
     \ /
      Last update: 2022-10-18 09:02    [W:2.898 / U:0.068 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site