From e6745a4da964f5f49b21cbcce5125456984ddc6b Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" <rostedt@goodmis.org> Date: Mon, 19 Dec 2022 13:31:07 -0500 Subject: tracing: Add a way to filter function addresses to function names There's been several times where an event records a function address in its field and I needed to filter on that address for a specific function name. It required looking up the function in kallsyms, finding its size, and doing a compare of "field >= function_start && field < function_end". But this would change from boot to boot and is unreliable in scripts. Also, it is useful to have this at boot up, where the addresses will not be known. For example, on the boot command line: trace_trigger="initcall_finish.traceoff if func.function == acpi_init" To implement this, add a ".function" prefix, that will check that the field is of size long, and the only operations allowed (so far) are "==" and "!=". Link: https://lkml.kernel.org/r/20221219183213.916833763@goodmis.org Cc: Masami Hiramatsu <mhiramat@kernel.org> Cc: Andrew Morton <akpm@linux-foundation.org> Cc: Tom Zanussi <zanussi@kernel.org> Cc: Zheng Yejian <zhengyejian1@huawei.com> Reviewed-by: Ross Zwisler <zwisler@google.com> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> --- Documentation/trace/events.rst | 12 ++++++++++++ 1 file changed, 12 insertions(+) (limited to 'Documentation/trace') diff --git a/Documentation/trace/events.rst b/Documentation/trace/events.rst index c47f381d0c00..d0fd5c7220b7 100644 --- a/Documentation/trace/events.rst +++ b/Documentation/trace/events.rst @@ -207,6 +207,18 @@ field name:: As the kernel will have to know how to retrieve the memory that the pointer is at from user space. +You can convert any long type to a function address and search by function name:: + + call_site.function == security_prepare_creds + +The above will filter when the field "call_site" falls on the address within +"security_prepare_creds". That is, it will compare the value of "call_site" and +the filter will return true if it is greater than or equal to the start of +the function "security_prepare_creds" and less than the end of that function. + +The ".function" postfix can only be attached to values of size long, and can only +be compared with "==" or "!=". + 5.2 Setting filters ------------------- -- cgit v1.2.3 From 88238513bb26713ef6d4418bdf1af062fe608bcb Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Google)" <rostedt@goodmis.org> Date: Tue, 17 Jan 2023 10:21:30 -0500 Subject: tracing/histogram: Document variable stacktrace Add a little documentation (and a useful example) of how a stacktrace can be used within a histogram variable and synthetic event. Link: https://lkml.kernel.org/r/20230117152236.320181354@goodmis.org Cc: Masami Hiramatsu <mhiramat@kernel.org> Cc: Andrew Morton <akpm@linux-foundation.org> Cc: Tom Zanussi <zanussi@kernel.org> Cc: Ross Zwisler <zwisler@google.com> Cc: Ching-lin Yu <chinglinyu@google.com> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> --- Documentation/trace/histogram.rst | 129 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 129 insertions(+) (limited to 'Documentation/trace') diff --git a/Documentation/trace/histogram.rst b/Documentation/trace/histogram.rst index f95459aa984f..5c391328b9bb 100644 --- a/Documentation/trace/histogram.rst +++ b/Documentation/trace/histogram.rst @@ -81,6 +81,7 @@ Documentation written by Tom Zanussi .usecs display a common_timestamp in microseconds .percent display a number of percentage value .graph display a bar-graph of a value + .stacktrace display as a stacktrace (must by a long[] type) ============= ================================================= Note that in general the semantics of a given field aren't @@ -1786,6 +1787,8 @@ or assigned to a variable and referenced in a subsequent expression:: # echo 'hist:keys=next_pid:us_per_sec=1000000 ...' >> event/trigger # echo 'hist:keys=next_pid:timestamp_secs=common_timestamp/$us_per_sec ...' >> event/trigger +Variables can even hold stacktraces, which are useful with synthetic events. + 2.2.2 Synthetic Events ---------------------- @@ -1940,6 +1943,132 @@ the ".buckets" modifier and specify a size (in this case groups of 10). Entries: 16 Dropped: 0 +To save stacktraces, create a synthetic event with a field of type "unsigned long[]" +or even just "long[]". For example, to see how long a task is blocked in an +uninterruptible state: + + # cd /sys/kernel/tracing + # echo 's:block_lat pid_t pid; u64 delta; unsigned long[] stack;' > dynamic_events + # echo 'hist:keys=next_pid:ts=common_timestamp.usecs,st=stacktrace if prev_state == 2' >> events/sched/sched_switch/trigger + # echo 'hist:keys=prev_pid:delta=common_timestamp.usecs-$ts,s=$st:onmax($delta).trace(block_lat,prev_pid,$delta,$s)' >> events/sched/sched_switch/trigger + # echo 1 > events/synthetic/block_lat/enable + # cat trace + + # tracer: nop + # + # entries-in-buffer/entries-written: 2/2 #P:8 + # + # _-----=> irqs-off/BH-disabled + # / _----=> need-resched + # | / _---=> hardirq/softirq + # || / _--=> preempt-depth + # ||| / _-=> migrate-disable + # |||| / delay + # TASK-PID CPU# ||||| TIMESTAMP FUNCTION + # | | | ||||| | | + <idle>-0 [005] d..4. 521.164922: block_lat: pid=0 delta=8322 stack=STACK: + => __schedule+0x448/0x7b0 + => schedule+0x5a/0xb0 + => io_schedule+0x42/0x70 + => bit_wait_io+0xd/0x60 + => __wait_on_bit+0x4b/0x140 + => out_of_line_wait_on_bit+0x91/0xb0 + => jbd2_journal_commit_transaction+0x1679/0x1a70 + => kjournald2+0xa9/0x280 + => kthread+0xe9/0x110 + => ret_from_fork+0x2c/0x50 + + <...>-2 [004] d..4. 525.184257: block_lat: pid=2 delta=76 stack=STACK: + => __schedule+0x448/0x7b0 + => schedule+0x5a/0xb0 + => schedule_timeout+0x11a/0x150 + => wait_for_completion_killable+0x144/0x1f0 + => __kthread_create_on_node+0xe7/0x1e0 + => kthread_create_on_node+0x51/0x70 + => create_worker+0xcc/0x1a0 + => worker_thread+0x2ad/0x380 + => kthread+0xe9/0x110 + => ret_from_fork+0x2c/0x50 + +A synthetic event that has a stacktrace field may use it as a key in histogram: + + # echo 'hist:delta.buckets=100,stack.stacktrace:sort=delta' > events/synthetic/block_lat/trigger + # cat events/synthetic/block_lat/hist + + # event histogram + # + # trigger info: hist:keys=delta.buckets=100,stacktrace:vals=hitcount:sort=delta.buckets=100:size=2048 [active] + # + + { delta: ~ 0-99, stacktrace: + event_hist_trigger+0x464/0x480 + event_triggers_call+0x52/0xe0 + trace_event_buffer_commit+0x193/0x250 + trace_event_raw_event_sched_switch+0xfc/0x150 + __traceiter_sched_switch+0x41/0x60 + __schedule+0x448/0x7b0 + schedule_idle+0x26/0x40 + cpu_startup_entry+0x19/0x20 + start_secondary+0xed/0xf0 + secondary_startup_64_no_verify+0xe0/0xeb + } hitcount: 6 + { delta: ~ 0-99, stacktrace: + event_hist_trigger+0x464/0x480 + event_triggers_call+0x52/0xe0 + trace_event_buffer_commit+0x193/0x250 + trace_event_raw_event_sched_switch+0xfc/0x150 + __traceiter_sched_switch+0x41/0x60 + __schedule+0x448/0x7b0 + schedule_idle+0x26/0x40 + cpu_startup_entry+0x19/0x20 + __pfx_kernel_init+0x0/0x10 + arch_call_rest_init+0xa/0x24 + start_kernel+0x964/0x98d + secondary_startup_64_no_verify+0xe0/0xeb + } hitcount: 3 + { delta: ~ 0-99, stacktrace: + event_hist_trigger+0x464/0x480 + event_triggers_call+0x52/0xe0 + trace_event_buffer_commit+0x193/0x250 + trace_event_raw_event_sched_switch+0xfc/0x150 + __traceiter_sched_switch+0x41/0x60 + __schedule+0x448/0x7b0 + schedule+0x5a/0xb0 + worker_thread+0xaf/0x380 + kthread+0xe9/0x110 + ret_from_fork+0x2c/0x50 + } hitcount: 1 + { delta: ~ 100-199, stacktrace: + event_hist_trigger+0x464/0x480 + event_triggers_call+0x52/0xe0 + trace_event_buffer_commit+0x193/0x250 + trace_event_raw_event_sched_switch+0xfc/0x150 + __traceiter_sched_switch+0x41/0x60 + __schedule+0x448/0x7b0 + schedule_idle+0x26/0x40 + cpu_startup_entry+0x19/0x20 + start_secondary+0xed/0xf0 + secondary_startup_64_no_verify+0xe0/0xeb + } hitcount: 15 + [..] + { delta: ~ 8500-8599, stacktrace: + event_hist_trigger+0x464/0x480 + event_triggers_call+0x52/0xe0 + trace_event_buffer_commit+0x193/0x250 + trace_event_raw_event_sched_switch+0xfc/0x150 + __traceiter_sched_switch+0x41/0x60 + __schedule+0x448/0x7b0 + schedule_idle+0x26/0x40 + cpu_startup_entry+0x19/0x20 + start_secondary+0xed/0xf0 + secondary_startup_64_no_verify+0xe0/0xeb + } hitcount: 1 + + Totals: + Hits: 89 + Entries: 11 + Dropped: 0 + 2.2.3 Hist trigger 'handlers' and 'actions' ------------------------------------------- -- cgit v1.2.3 From a2ff84a5d1e65c7d1178f24ecf39fc55283fbd14 Mon Sep 17 00:00:00 2001 From: Bagas Sanjaya <bagasdotme@gmail.com> Date: Sun, 29 Jan 2023 10:14:02 +0700 Subject: tracing/histogram: Wrap remaining shell snippets in code blocks Most shell command snippets (echo/cat) and their output are already in literal code blocks. However a few still isn't wrapped, in which the htmldocs output is ugly. Wrap the remaining unwrapped snippets, while also fix recent kernel test robot warnings. Link: https://lore.kernel.org/linux-trace-kernel/20230129031402.47420-1-bagasdotme@gmail.com Cc: Masami Hiramatsu <mhiramat@kernel.org> Cc: Jonathan Corbet <corbet@lwn.net> Link: https://lore.kernel.org/linux-doc/202301290253.LU5yIxcJ-lkp@intel.com/ Fixes: 88238513bb2671 ("tracing/histogram: Document variable stacktrace") Reported-by: kernel test robot <lkp@intel.com> Signed-off-by: Bagas Sanjaya <bagasdotme@gmail.com> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> --- Documentation/trace/histogram.rst | 93 ++++++++++++++++++++------------------- 1 file changed, 47 insertions(+), 46 deletions(-) (limited to 'Documentation/trace') diff --git a/Documentation/trace/histogram.rst b/Documentation/trace/histogram.rst index 5c391328b9bb..8e95295e39b6 100644 --- a/Documentation/trace/histogram.rst +++ b/Documentation/trace/histogram.rst @@ -1864,7 +1864,7 @@ A histogram can now be defined for the new synthetic event:: The above shows the latency "lat" in a power of 2 grouping. Like any other event, once a histogram is enabled for the event, the -output can be displayed by reading the event's 'hist' file. +output can be displayed by reading the event's 'hist' file:: # cat /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/hist @@ -1911,7 +1911,7 @@ output can be displayed by reading the event's 'hist' file. The latency values can also be grouped linearly by a given size with -the ".buckets" modifier and specify a size (in this case groups of 10). +the ".buckets" modifier and specify a size (in this case groups of 10):: # echo 'hist:keys=pid,prio,lat.buckets=10:sort=lat' >> \ /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/trigger @@ -1945,7 +1945,7 @@ the ".buckets" modifier and specify a size (in this case groups of 10). To save stacktraces, create a synthetic event with a field of type "unsigned long[]" or even just "long[]". For example, to see how long a task is blocked in an -uninterruptible state: +uninterruptible state:: # cd /sys/kernel/tracing # echo 's:block_lat pid_t pid; u64 delta; unsigned long[] stack;' > dynamic_events @@ -1990,7 +1990,8 @@ uninterruptible state: => kthread+0xe9/0x110 => ret_from_fork+0x2c/0x50 -A synthetic event that has a stacktrace field may use it as a key in histogram: +A synthetic event that has a stacktrace field may use it as a key in +histogram:: # echo 'hist:delta.buckets=100,stack.stacktrace:sort=delta' > events/synthetic/block_lat/trigger # cat events/synthetic/block_lat/hist @@ -2183,11 +2184,11 @@ The following commonly-used handler.action pairs are available: wakeup_new_test($testpid) if comm=="cyclictest"' >> \ /sys/kernel/debug/tracing/events/sched/sched_wakeup_new/trigger - Or, equivalently, using the 'trace' keyword syntax: + Or, equivalently, using the 'trace' keyword syntax:: - # echo 'hist:keys=$testpid:testpid=pid:onmatch(sched.sched_wakeup_new).\ - trace(wakeup_new_test,$testpid) if comm=="cyclictest"' >> \ - /sys/kernel/debug/tracing/events/sched/sched_wakeup_new/trigger + # echo 'hist:keys=$testpid:testpid=pid:onmatch(sched.sched_wakeup_new).\ + trace(wakeup_new_test,$testpid) if comm=="cyclictest"' >> \ + /sys/kernel/debug/tracing/events/sched/sched_wakeup_new/trigger Creating and displaying a histogram based on those events is now just a matter of using the fields and new synthetic event in the @@ -2320,48 +2321,48 @@ The following commonly-used handler.action pairs are available: resulting latency, stored in wakeup_lat, exceeds the current maximum latency, a snapshot is taken. As part of the setup, all the scheduler events are also enabled, which are the events that - will show up in the snapshot when it is taken at some point: + will show up in the snapshot when it is taken at some point:: - # echo 1 > /sys/kernel/debug/tracing/events/sched/enable + # echo 1 > /sys/kernel/debug/tracing/events/sched/enable - # echo 'hist:keys=pid:ts0=common_timestamp.usecs \ - if comm=="cyclictest"' >> \ - /sys/kernel/debug/tracing/events/sched/sched_waking/trigger + # echo 'hist:keys=pid:ts0=common_timestamp.usecs \ + if comm=="cyclictest"' >> \ + /sys/kernel/debug/tracing/events/sched/sched_waking/trigger - # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \ - onmax($wakeup_lat).save(next_prio,next_comm,prev_pid,prev_prio, \ - prev_comm):onmax($wakeup_lat).snapshot() \ - if next_comm=="cyclictest"' >> \ - /sys/kernel/debug/tracing/events/sched/sched_switch/trigger + # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \ + onmax($wakeup_lat).save(next_prio,next_comm,prev_pid,prev_prio, \ + prev_comm):onmax($wakeup_lat).snapshot() \ + if next_comm=="cyclictest"' >> \ + /sys/kernel/debug/tracing/events/sched/sched_switch/trigger When the histogram is displayed, for each bucket the max value and the saved values corresponding to the max are displayed following the rest of the fields. If a snapshot was taken, there is also a message indicating that, - along with the value and event that triggered the global maximum: + along with the value and event that triggered the global maximum:: - # cat /sys/kernel/debug/tracing/events/sched/sched_switch/hist - { next_pid: 2101 } hitcount: 200 - max: 52 next_prio: 120 next_comm: cyclictest \ - prev_pid: 0 prev_prio: 120 prev_comm: swapper/6 + # cat /sys/kernel/debug/tracing/events/sched/sched_switch/hist + { next_pid: 2101 } hitcount: 200 + max: 52 next_prio: 120 next_comm: cyclictest \ + prev_pid: 0 prev_prio: 120 prev_comm: swapper/6 - { next_pid: 2103 } hitcount: 1326 - max: 572 next_prio: 19 next_comm: cyclictest \ - prev_pid: 0 prev_prio: 120 prev_comm: swapper/1 + { next_pid: 2103 } hitcount: 1326 + max: 572 next_prio: 19 next_comm: cyclictest \ + prev_pid: 0 prev_prio: 120 prev_comm: swapper/1 - { next_pid: 2102 } hitcount: 1982 \ - max: 74 next_prio: 19 next_comm: cyclictest \ - prev_pid: 0 prev_prio: 120 prev_comm: swapper/5 + { next_pid: 2102 } hitcount: 1982 \ + max: 74 next_prio: 19 next_comm: cyclictest \ + prev_pid: 0 prev_prio: 120 prev_comm: swapper/5 - Snapshot taken (see tracing/snapshot). Details: - triggering value { onmax($wakeup_lat) }: 572 \ - triggered by event with key: { next_pid: 2103 } + Snapshot taken (see tracing/snapshot). Details: + triggering value { onmax($wakeup_lat) }: 572 \ + triggered by event with key: { next_pid: 2103 } - Totals: - Hits: 3508 - Entries: 3 - Dropped: 0 + Totals: + Hits: 3508 + Entries: 3 + Dropped: 0 In the above case, the event that triggered the global maximum has the key with next_pid == 2103. If you look at the bucket that has @@ -2439,15 +2440,15 @@ The following commonly-used handler.action pairs are available: $cwnd variable. If the value has changed, a snapshot is taken. As part of the setup, all the scheduler and tcp events are also enabled, which are the events that will show up in the snapshot - when it is taken at some point: + when it is taken at some point:: - # echo 1 > /sys/kernel/debug/tracing/events/sched/enable - # echo 1 > /sys/kernel/debug/tracing/events/tcp/enable + # echo 1 > /sys/kernel/debug/tracing/events/sched/enable + # echo 1 > /sys/kernel/debug/tracing/events/tcp/enable - # echo 'hist:keys=dport:cwnd=snd_cwnd: \ - onchange($cwnd).save(snd_wnd,srtt,rcv_wnd): \ - onchange($cwnd).snapshot()' >> \ - /sys/kernel/debug/tracing/events/tcp/tcp_probe/trigger + # echo 'hist:keys=dport:cwnd=snd_cwnd: \ + onchange($cwnd).save(snd_wnd,srtt,rcv_wnd): \ + onchange($cwnd).snapshot()' >> \ + /sys/kernel/debug/tracing/events/tcp/tcp_probe/trigger When the histogram is displayed, for each bucket the tracked value and the saved values corresponding to that value are displayed @@ -2470,10 +2471,10 @@ The following commonly-used handler.action pairs are available: { dport: 443 } hitcount: 211 changed: 10 snd_wnd: 26960 srtt: 17379 rcv_wnd: 28800 - Snapshot taken (see tracing/snapshot). Details:: + Snapshot taken (see tracing/snapshot). Details: - triggering value { onchange($cwnd) }: 10 - triggered by event with key: { dport: 80 } + triggering value { onchange($cwnd) }: 10 + triggered by event with key: { dport: 80 } Totals: Hits: 414 -- cgit v1.2.3 From d8f0ae3ebed416728077fe94698983c30d409241 Mon Sep 17 00:00:00 2001 From: Tom Zanussi <zanussi@kernel.org> Date: Fri, 10 Feb 2023 15:33:06 -0600 Subject: tracing/histogram: Fix stacktrace histogram Documententation Fix a small problem with the histogram specification in the Documentation, and change the example to show output using a stacktrace field rather than the global stacktrace. Link: https://lkml.kernel.org/r/f75f807dd4998249e513515f703a2ff7407605f4.1676063532.git.zanussi@kernel.org Signed-off-by: Tom Zanussi <zanussi@kernel.org> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> --- Documentation/trace/histogram.rst | 156 ++++++++++++++++++++++---------------- 1 file changed, 90 insertions(+), 66 deletions(-) (limited to 'Documentation/trace') diff --git a/Documentation/trace/histogram.rst b/Documentation/trace/histogram.rst index 8e95295e39b6..c5cfc6e7baea 100644 --- a/Documentation/trace/histogram.rst +++ b/Documentation/trace/histogram.rst @@ -1993,82 +1993,106 @@ uninterruptible state:: A synthetic event that has a stacktrace field may use it as a key in histogram:: - # echo 'hist:delta.buckets=100,stack.stacktrace:sort=delta' > events/synthetic/block_lat/trigger + # echo 'hist:keys=delta.buckets=100,stack.stacktrace:sort=delta' > events/synthetic/block_lat/trigger # cat events/synthetic/block_lat/hist # event histogram # - # trigger info: hist:keys=delta.buckets=100,stacktrace:vals=hitcount:sort=delta.buckets=100:size=2048 [active] + # trigger info: hist:keys=delta.buckets=100,stack.stacktrace:vals=hitcount:sort=delta.buckets=100:size=2048 [active] # - - { delta: ~ 0-99, stacktrace: - event_hist_trigger+0x464/0x480 - event_triggers_call+0x52/0xe0 - trace_event_buffer_commit+0x193/0x250 - trace_event_raw_event_sched_switch+0xfc/0x150 - __traceiter_sched_switch+0x41/0x60 - __schedule+0x448/0x7b0 - schedule_idle+0x26/0x40 - cpu_startup_entry+0x19/0x20 - start_secondary+0xed/0xf0 - secondary_startup_64_no_verify+0xe0/0xeb - } hitcount: 6 - { delta: ~ 0-99, stacktrace: - event_hist_trigger+0x464/0x480 - event_triggers_call+0x52/0xe0 - trace_event_buffer_commit+0x193/0x250 - trace_event_raw_event_sched_switch+0xfc/0x150 - __traceiter_sched_switch+0x41/0x60 - __schedule+0x448/0x7b0 - schedule_idle+0x26/0x40 - cpu_startup_entry+0x19/0x20 - __pfx_kernel_init+0x0/0x10 - arch_call_rest_init+0xa/0x24 - start_kernel+0x964/0x98d - secondary_startup_64_no_verify+0xe0/0xeb + { delta: ~ 0-99, stack.stacktrace __schedule+0xa19/0x1520 + schedule+0x6b/0x110 + io_schedule+0x46/0x80 + bit_wait_io+0x11/0x80 + __wait_on_bit+0x4e/0x120 + out_of_line_wait_on_bit+0x8d/0xb0 + __wait_on_buffer+0x33/0x40 + jbd2_journal_commit_transaction+0x155a/0x19b0 + kjournald2+0xab/0x270 + kthread+0xfa/0x130 + ret_from_fork+0x29/0x50 + } hitcount: 1 + { delta: ~ 0-99, stack.stacktrace __schedule+0xa19/0x1520 + schedule+0x6b/0x110 + io_schedule+0x46/0x80 + rq_qos_wait+0xd0/0x170 + wbt_wait+0x9e/0xf0 + __rq_qos_throttle+0x25/0x40 + blk_mq_submit_bio+0x2c3/0x5b0 + __submit_bio+0xff/0x190 + submit_bio_noacct_nocheck+0x25b/0x2b0 + submit_bio_noacct+0x20b/0x600 + submit_bio+0x28/0x90 + ext4_bio_write_page+0x1e0/0x8c0 + mpage_submit_page+0x60/0x80 + mpage_process_page_bufs+0x16c/0x180 + mpage_prepare_extent_to_map+0x23f/0x530 + } hitcount: 1 + { delta: ~ 0-99, stack.stacktrace __schedule+0xa19/0x1520 + schedule+0x6b/0x110 + schedule_hrtimeout_range_clock+0x97/0x110 + schedule_hrtimeout_range+0x13/0x20 + usleep_range_state+0x65/0x90 + __intel_wait_for_register+0x1c1/0x230 [i915] + intel_psr_wait_for_idle_locked+0x171/0x2a0 [i915] + intel_pipe_update_start+0x169/0x360 [i915] + intel_update_crtc+0x112/0x490 [i915] + skl_commit_modeset_enables+0x199/0x600 [i915] + intel_atomic_commit_tail+0x7c4/0x1080 [i915] + intel_atomic_commit_work+0x12/0x20 [i915] + process_one_work+0x21c/0x3f0 + worker_thread+0x50/0x3e0 + kthread+0xfa/0x130 } hitcount: 3 - { delta: ~ 0-99, stacktrace: - event_hist_trigger+0x464/0x480 - event_triggers_call+0x52/0xe0 - trace_event_buffer_commit+0x193/0x250 - trace_event_raw_event_sched_switch+0xfc/0x150 - __traceiter_sched_switch+0x41/0x60 - __schedule+0x448/0x7b0 - schedule+0x5a/0xb0 - worker_thread+0xaf/0x380 - kthread+0xe9/0x110 - ret_from_fork+0x2c/0x50 + { delta: ~ 0-99, stack.stacktrace __schedule+0xa19/0x1520 + schedule+0x6b/0x110 + schedule_timeout+0x11e/0x160 + __wait_for_common+0x8f/0x190 + wait_for_completion+0x24/0x30 + __flush_work.isra.0+0x1cc/0x360 + flush_work+0xe/0x20 + drm_mode_rmfb+0x18b/0x1d0 [drm] + drm_mode_rmfb_ioctl+0x10/0x20 [drm] + drm_ioctl_kernel+0xb8/0x150 [drm] + drm_ioctl+0x243/0x560 [drm] + __x64_sys_ioctl+0x92/0xd0 + do_syscall_64+0x59/0x90 + entry_SYSCALL_64_after_hwframe+0x72/0xdc } hitcount: 1 - { delta: ~ 100-199, stacktrace: - event_hist_trigger+0x464/0x480 - event_triggers_call+0x52/0xe0 - trace_event_buffer_commit+0x193/0x250 - trace_event_raw_event_sched_switch+0xfc/0x150 - __traceiter_sched_switch+0x41/0x60 - __schedule+0x448/0x7b0 - schedule_idle+0x26/0x40 - cpu_startup_entry+0x19/0x20 - start_secondary+0xed/0xf0 - secondary_startup_64_no_verify+0xe0/0xeb - } hitcount: 15 - [..] - { delta: ~ 8500-8599, stacktrace: - event_hist_trigger+0x464/0x480 - event_triggers_call+0x52/0xe0 - trace_event_buffer_commit+0x193/0x250 - trace_event_raw_event_sched_switch+0xfc/0x150 - __traceiter_sched_switch+0x41/0x60 - __schedule+0x448/0x7b0 - schedule_idle+0x26/0x40 - cpu_startup_entry+0x19/0x20 - start_secondary+0xed/0xf0 - secondary_startup_64_no_verify+0xe0/0xeb + { delta: ~ 0-99, stack.stacktrace __schedule+0xa19/0x1520 + schedule+0x6b/0x110 + schedule_timeout+0x87/0x160 + __wait_for_common+0x8f/0x190 + wait_for_completion_timeout+0x1d/0x30 + drm_atomic_helper_wait_for_flip_done+0x57/0x90 [drm_kms_helper] + intel_atomic_commit_tail+0x8ce/0x1080 [i915] + intel_atomic_commit_work+0x12/0x20 [i915] + process_one_work+0x21c/0x3f0 + worker_thread+0x50/0x3e0 + kthread+0xfa/0x130 + ret_from_fork+0x29/0x50 + } hitcount: 1 + { delta: ~ 100-199, stack.stacktrace __schedule+0xa19/0x1520 + schedule+0x6b/0x110 + schedule_hrtimeout_range_clock+0x97/0x110 + schedule_hrtimeout_range+0x13/0x20 + usleep_range_state+0x65/0x90 + pci_set_low_power_state+0x17f/0x1f0 + pci_set_power_state+0x49/0x250 + pci_finish_runtime_suspend+0x4a/0x90 + pci_pm_runtime_suspend+0xcb/0x1b0 + __rpm_callback+0x48/0x120 + rpm_callback+0x67/0x70 + rpm_suspend+0x167/0x780 + rpm_idle+0x25a/0x380 + pm_runtime_work+0x93/0xc0 + process_one_work+0x21c/0x3f0 } hitcount: 1 Totals: - Hits: 89 - Entries: 11 - Dropped: 0 + Hits: 10 + Entries: 7 + Dropped: 0 2.2.3 Hist trigger 'handlers' and 'actions' ------------------------------------------- -- cgit v1.2.3