Re: [PATCH v13 4/4] Documentation: trace/objtrace: Add documentation for objtrace

On Sun, Jun 26, 2022 at 10:56:04AM +0800, Jeff Xie wrote:

Added documentation explaining how to use objtrace trigger to get the value of the object.

Write "Add documentation..." instead.

+- objtrace

• This command provides a way to get the value of any object, The object
• can be obtained from the dynamic event(kprobe_event/uprobe_event) or the
• static event(tracepoint).
• 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.

Did you mean "the object value can be obtained by only needing to set the objtrace?"

• 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

Did you mean "the first parameter (arg1) is the parameter value of function that is passed to kprobe_event, in this case the object base"?

• 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
• # 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
  

•           cat-117     [002] ...2.     1.602245: bio_add_page <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x2000
  

•           cat-117     [002] ...1.     1.602245: __bio_try_merge_page <-bio_add_page object:0xffff88811bee4000 value:0x2000
  

•           cat-117     [002] ...1.     1.602245: __bio_add_page <-bio_add_page object:0xffff88811bee4000 value:0x2000
  

•           cat-117     [002] ...1.     1.602245: submit_bio <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x3000
  

•           cat-117     [002] ...1.     1.602245: submit_bio_noacct <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x3000
  

•           cat-117     [002] ...1.     1.602246: __submit_bio <-submit_bio_noacct object:0xffff88811bee4000 value:0x3000
  

•           cat-117     [002] ...1.     1.602246: submit_bio_checks <-__submit_bio object:0xffff88811bee4000 value:0x3000
  

•           cat-117     [002] ...1.     1.602246: __cond_resched <-submit_bio_checks object:0xffff88811bee4000 value:0x3000
  

•           cat-117     [002] ...1.     1.602246: should_fail_bio <-submit_bio_checks object:0xffff88811bee4000 value:0x3000
  

•           cat-117     [002] ...1.     1.602246: blk_mq_submit_bio <-submit_bio_noacct object:0xffff88811bee4000 value:0x3000
  

•           cat-117     [002] ...1.     1.602246: blk_attempt_plug_merge <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000
  

•           cat-117     [002] ...1.     1.602246: blk_mq_sched_bio_merge <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000
  

•           cat-117     [002] ...1.     1.602247: __rcu_read_lock <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000
  

•           cat-117     [002] ...1.     1.602247: __rcu_read_unlock <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000
  

•           cat-117     [002] ...1.     1.602247: __blk_mq_alloc_requests <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000
  

•        <idle>-0       [002] d..3.     1.602298: bio_endio <-blk_update_request object:0xffff88811bee4000 value:0x0
  

•        <idle>-0       [002] d..3.     1.602298: mpage_end_io <-blk_update_request object:0xffff88811bee4000 value:0x0
  

•        <idle>-0       [002] d..3.     1.602298: __read_end_io <-blk_update_request object:0xffff88811bee4000 value:0x0
  

•        <idle>-0       [002] d..3.     1.602300: bio_put <-blk_update_request object:0xffff88811bee4000 value:0x0
  

•        <idle>-0       [002] d..3.     1.602300: bio_free <-blk_update_request object:0xffff88811bee4000 value:0x0
  

•        <idle>-0       [002] d..3.     1.602300: mempool_free <-blk_update_request object:0xffff88811bee4000 value:0x0
  

•        <idle>-0       [002] d..3.     1.602300: mempool_free_slab <-blk_update_request object:0xffff88811bee4000 value:0x0
  

•        <idle>-0       [002] d..3.     1.602300: kmem_cache_free <-blk_update_request object:0xffff88811bee4000 value:0x0
  

•         ...
  

The output is messy, because for code example and output, literal code blocks aren't used, hence trigger new warnings:

Documentation/trace/events.rst:564: WARNING: Inline emphasis start-string without end-string. Documentation/trace/events.rst:564: WARNING: Inline emphasis start-string without end-string. Documentation/trace/events.rst:573: WARNING: Inline emphasis start-string without end-string. Documentation/trace/events.rst:573: WARNING: Inline emphasis start-string without end-string. Documentation/trace/events.rst:602: WARNING: Unexpected indentation. Documentation/trace/events.rst:622: WARNING: Block quote ends without a blank line; unexpected unindent. Documentation/trace/events.rst:630: WARNING: Unexpected indentation.

I had to apply the following fixup (with rewording):

---- >8 ----

diff --git a/Documentation/trace/events.rst b/Documentation/trace/events.rst index 0dc47516013331..c15f1d25d4a071 100644 --- a/Documentation/trace/events.rst +++ b/Documentation/trace/events.rst @@ -549,85 +549,89 @@ The following commands are supported: - objtrace

This command provides a way to get the value of any object, The object - can be obtained from the dynamic event(kprobe_event/uprobe_event) or the - static event(tracepoint). + can be obtained from the dynamic event (kprobe_event/uprobe_event) or the + static event (tracepoint).

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. + When using the kprobe event, by only need to set the objtrace (a new + trigger), we can get the value of object that is set by kprobe event.

- For example: - For the function bio_add_page(): + For example, for the function bio_add_page():

- int bio_add_page(struct bio *bio, struct page *page, - unsigned int len, unsigned int offset) + .. code-block:: c

- 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(), + int bio_add_page(struct bio *bio, struct page *page, + unsigned int len, unsigned int offset)

- # echo 'p bio_add_page arg1=$arg1' > ./kprobe_events + Firstly, we can set the base of the object as first parameter (arg1) to + to the function:

- Secondly, we can get the value dynamically based on above object. + .. code-block::

- 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 '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 + Secondly, we can get the value dynamically based on the object:

- # 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 + .. code-block::

- # du -sh /test.txt - 12.0K /test.txt + 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

- # 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 - cat-117 [002] ...2. 1.602245: bio_add_page <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x2000 - cat-117 [002] ...1. 1.602245: __bio_try_merge_page <-bio_add_page object:0xffff88811bee4000 value:0x2000 - cat-117 [002] ...1. 1.602245: __bio_add_page <-bio_add_page object:0xffff88811bee4000 value:0x2000 - cat-117 [002] ...1. 1.602245: submit_bio <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x3000 - cat-117 [002] ...1. 1.602245: submit_bio_noacct <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x3000 - cat-117 [002] ...1. 1.602246: __submit_bio <-submit_bio_noacct object:0xffff88811bee4000 value:0x3000 - cat-117 [002] ...1. 1.602246: submit_bio_checks <-__submit_bio object:0xffff88811bee4000 value:0x3000 - cat-117 [002] ...1. 1.602246: __cond_resched <-submit_bio_checks object:0xffff88811bee4000 value:0x3000 - cat-117 [002] ...1. 1.602246: should_fail_bio <-submit_bio_checks object:0xffff88811bee4000 value:0x3000 - cat-117 [002] ...1. 1.602246: blk_mq_submit_bio <-submit_bio_noacct object:0xffff88811bee4000 value:0x3000 - cat-117 [002] ...1. 1.602246: blk_attempt_plug_merge <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000 - cat-117 [002] ...1. 1.602246: blk_mq_sched_bio_merge <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000 - cat-117 [002] ...1. 1.602247: __rcu_read_lock <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000 - cat-117 [002] ...1. 1.602247: __rcu_read_unlock <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000 - cat-117 [002] ...1. 1.602247: __blk_mq_alloc_requests <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000 - <idle>-0 [002] d..3. 1.602298: bio_endio <-blk_update_request object:0xffff88811bee4000 value:0x0 - <idle>-0 [002] d..3. 1.602298: mpage_end_io <-blk_update_request object:0xffff88811bee4000 value:0x0 - <idle>-0 [002] d..3. 1.602298: __read_end_io <-blk_update_request object:0xffff88811bee4000 value:0x0 - <idle>-0 [002] d..3. 1.602300: bio_put <-blk_update_request object:0xffff88811bee4000 value:0x0 - <idle>-0 [002] d..3. 1.602300: bio_free <-blk_update_request object:0xffff88811bee4000 value:0x0 - <idle>-0 [002] d..3. 1.602300: mempool_free <-blk_update_request object:0xffff88811bee4000 value:0x0 - <idle>-0 [002] d..3. 1.602300: mempool_free_slab <-blk_update_request object:0xffff88811bee4000 value:0x0 - <idle>-0 [002] d..3. 1.602300: kmem_cache_free <-blk_update_request object:0xffff88811bee4000 value:0x0 - ... + # 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 + + # 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 + cat-117 [002] ...2. 1.602245: bio_add_page <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x2000 + cat-117 [002] ...1. 1.602245: __bio_try_merge_page <-bio_add_page object:0xffff88811bee4000 value:0x2000 + cat-117 [002] ...1. 1.602245: __bio_add_page <-bio_add_page object:0xffff88811bee4000 value:0x2000 + cat-117 [002] ...1. 1.602245: submit_bio <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x3000 + cat-117 [002] ...1. 1.602245: submit_bio_noacct <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x3000 + cat-117 [002] ...1. 1.602246: __submit_bio <-submit_bio_noacct object:0xffff88811bee4000 value:0x3000 + cat-117 [002] ...1. 1.602246: submit_bio_checks <-__submit_bio object:0xffff88811bee4000 value:0x3000 + cat-117 [002] ...1. 1.602246: __cond_resched <-submit_bio_checks object:0xffff88811bee4000 value:0x3000 + cat-117 [002] ...1. 1.602246: should_fail_bio <-submit_bio_checks object:0xffff88811bee4000 value:0x3000 + cat-117 [002] ...1. 1.602246: blk_mq_submit_bio <-submit_bio_noacct object:0xffff88811bee4000 value:0x3000 + cat-117 [002] ...1. 1.602246: blk_attempt_plug_merge <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000 + cat-117 [002] ...1. 1.602246: blk_mq_sched_bio_merge <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000 + cat-117 [002] ...1. 1.602247: __rcu_read_lock <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000 + cat-117 [002] ...1. 1.602247: __rcu_read_unlock <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000 + cat-117 [002] ...1. 1.602247: __blk_mq_alloc_requests <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000 + <idle>-0 [002] d..3. 1.602298: bio_endio <-blk_update_request object:0xffff88811bee4000 value:0x0 + <idle>-0 [002] d..3. 1.602298: mpage_end_io <-blk_update_request object:0xffff88811bee4000 value:0x0 + <idle>-0 [002] d..3. 1.602298: __read_end_io <-blk_update_request object:0xffff88811bee4000 value:0x0 + <idle>-0 [002] d..3. 1.602300: bio_put <-blk_update_request object:0xffff88811bee4000 value:0x0 + <idle>-0 [002] d..3. 1.602300: bio_free <-blk_update_request object:0xffff88811bee4000 value:0x0 + <idle>-0 [002] d..3. 1.602300: mempool_free <-blk_update_request object:0xffff88811bee4000 value:0x0 + <idle>-0 [002] d..3. 1.602300: mempool_free_slab <-blk_update_request object:0xffff88811bee4000 value:0x0 + <idle>-0 [002] d..3. 1.602300: kmem_cache_free <-blk_update_request object:0xffff88811bee4000 value:0x0 + ...

7. In-kernel trace event API ============================

Thanks.