Messages in this thread | | | From | Jeff Xie <> | Date | Tue, 18 Oct 2022 15:01:57 +0800 | Subject | Re: [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
| |