Messages in this thread | | | Date | Sun, 27 Sep 2015 15:25:41 +0200 | Subject | Tracing IRQ-flags | From | Sedat Dilek <> |
| |
Hi Ingo, Hi Steven,
I am still fighting with a llvmlinux problem in the area...
workqueue | hid | irq-flags (hardirqs/sofirqs disabled) | whatever?!
...(see [0]).
[ 24.705463] BUG: sleeping function called from invalid context at kernel/workqueue.c:2680 [ 24.705576] in_atomic(): 0, irqs_disabled(): 1, pid: 1447, name: acpid
Several people had ideas where to look at - Thanks.
Finally, Jiri encouraged me to try with a ftrace graph trace (see [1]).
I remembered TraceFS entered Linux v4.1 and wanted to play with it. One result is the attached doc.
Can I do a ftrace graph trace with TraceFS? And how do I do that?
Steven, is it possible to place your tracing mini-HOWTO (file: /sys/kernel/tracing/README) into docs-dir? Existing Documentation/trace? Documentation/tracefs (new)? Documentation/tracing (new)? First, I was confused how and where to mount tracefs :-(. Thanks.
Ingo, the kernel-configs in irqflags-tracing.txt doc are a bit outdated. Which are very important for irqflags-tracing (hardirq | softirq)? Are the lockdeps settings important? Is irqsoff setting important?
$ egrep -i 'lockdep|tracing|irqsoff|irqflags' /boot/config-$(uname -r) | sort CONFIG_DEBUG_LOCKDEP=y CONFIG_EVENT_TRACING=y CONFIG_IRQSOFF_TRACER=y CONFIG_IWLWIFI_DEVICE_TRACING=y CONFIG_LOCKDEP_SUPPORT=y CONFIG_LOCKDEP=y # CONFIG_MAC80211_MESSAGE_TRACING is not set CONFIG_TRACE_IRQFLAGS_SUPPORT=y CONFIG_TRACE_IRQFLAGS=y CONFIG_TRACING_SUPPORT=y CONFIG_TRACING=y
What about a new tracing-dir in Documentation/ and place all tracing docs there?
Thanks.
Regards, - Sedat -
[0] http://marc.info/?t=144179442100006&r=1&w=2 [1] http://marc.info/?l=linux-kernel&m=144318685710847&w=2 [2] https://lwn.net/Articles/631798/ [3] http://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/Documentation/irqflags-tracing.txt ***** TRACEFS-TRACING-IRQFLAGS.txt *****
[ HELP ]
[1] tracing mini-HOWTO: See /sys/kernel/tracing/README file [2] http://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/Documentation/irqflags-tracing.txt [3] http://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/Documentation/trace
[ KERNEL-CONFIG SETTINGS ]
[ TRACEFS ] CONFIG_TRACING_SUPPORT=y CONFIG_TRACING=y
[ IRQFLAGS-TRACING AND IRQSOFF LATENCY TRACER ] CONFIG_TRACE_IRQFLAGS_SUPPORT=y CONFIG_TRACE_IRQFLAGS=y CONFIG_IRQSOFF_TRACER=y
[ MOUNT AND CHECK TRACEFS ]
root# mount -t tracefs none /sys/kernel/tracing
root# mount | grep tracefs none on /sys/kernel/tracing type tracefs (rw,relatime)
[ ENTER TRACEFS-DIR ]
root# cd /sys/kernel/tracing/
[ DOCUMENTATION: TRACING MINI-HOWTO ]
root# cat README
[ CHECK TRACING SETTINGS ]
root# cat tracing_on 1
[ DISABLE TRACING AND EMPTY TRACE FILE ]
root# echo 0 > tracing_on root# cat tracing_on 0
root# echo > trace root# cat trace # tracer: nop # # entries-in-buffer/entries-written: 0/0 #P:4 # # _-----=> irqs-off # / _----=> need-resched # | / _---=> hardirq/softirq # || / _--=> preempt-depth # ||| / delay # TASK-PID CPU# |||| TIMESTAMP FUNCTION # | | | |||| | |
[ CHECK AVAILABLE TRACERS AND EVENTS (HERE: IRQSOFF) ]
root# cat /sys/kernel/tracing/available_tracers blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup irqsoff function nop <--- XXX: IRQSOFF
root# cat /sys/kernel/tracing/available_events | grep irq: irq:irq_handler_entry irq:irq_handler_exit irq:softirq_entry irq:softirq_exit irq:softirq_raise
root# cat events/irq/enable 1
root# cat events/irq/filter ### global filter ### # Use this to set filters for multiple events. # Only events with the given fields will be affected. # If no events are modified, an error message will be displayed here
[ ENABLE IRQ_HANDLER AND SOFTIRQ SETTINGS ]
root# echo 1 > events/irq/irq_handler_entry/enable root# echo 1 > events/irq/irq_handler_exit/enable root# cat events/irq/irq_handler_entry/enable events/irq/irq_handler_exit/enable 1 1
root# echo 1 > events/irq/softirq_entry/enable root# echo 1 > events/irq/softirq_exit/enable root# echo 1 > events/irq/softirq_raise/enable root# cat events/irq/softirq_entry/enable events/irq/softirq_exit/enable events/irq/softirq_raise/enable 1 1 1
root# cat trace # tracer: nop # # entries-in-buffer/entries-written: 0/0 #P:4 # # _-----=> irqs-off # / _----=> need-resched # | / _---=> hardirq/softirq # || / _--=> preempt-depth # ||| / delay # TASK-PID CPU# |||| TIMESTAMP FUNCTION # | | | |||| | |
[ START TRACING ]
root# echo 1 > tracing_on
[ CHECK TRACE FILE ]
root# cat trace
-dileks // 27-SEP-2015 tracing mini-HOWTO:
# echo 0 > tracing_on : quick way to disable tracing # echo 1 > tracing_on : quick way to re-enable tracing
Important files: trace - The static contents of the buffer To clear the buffer write into this file: echo > trace trace_pipe - A consuming read to see the contents of the buffer current_tracer - function and latency tracers available_tracers - list of configured tracers for current_tracer buffer_size_kb - view and modify size of per cpu buffer buffer_total_size_kb - view total size of all cpu buffers
trace_clock -change the clock used to order events local: Per cpu clock but may not be synced across CPUs global: Synced across CPUs but slows tracing down. counter: Not a clock, but just an increment uptime: Jiffy counter from time of boot perf: Same clock that perf events use x86-tsc: TSC cycle counter
trace_marker - Writes into this file writes into the kernel buffer tracing_cpumask - Limit which CPUs to trace instances - Make sub-buffers with: mkdir instances/foo Remove sub-buffer with rmdir trace_options - Set format or modify how tracing happens Disable an option by adding a suffix 'no' to the option name saved_cmdlines_size - echo command number in here to store comm-pid list
available_filter_functions - list of functions that can be filtered on set_ftrace_filter - echo function name in here to only trace these functions accepts: func_full_name, *func_end, func_begin*, *func_middle* modules: Can select a group via module Format: :mod:<module-name> example: echo :mod:ext3 > set_ftrace_filter triggers: a command to perform when function is hit Format: <function>:<trigger>[:count] trigger: traceon, traceoff enable_event:<system>:<event> disable_event:<system>:<event> stacktrace snapshot dump cpudump example: echo do_fault:traceoff > set_ftrace_filter echo do_trap:traceoff:3 > set_ftrace_filter The first one will disable tracing every time do_fault is hit The second will disable tracing at most 3 times when do_trap is hit The first time do trap is hit and it disables tracing, the counter will decrement to 2. If tracing is already disabled, the counter will not decrement. It only decrements when the trigger did work To remove trigger without count: echo '!<function>:<trigger> > set_ftrace_filter To remove trigger with a count: echo '!<function>:<trigger>:0 > set_ftrace_filter set_ftrace_notrace - echo function name in here to never trace. accepts: func_full_name, *func_end, func_begin*, *func_middle* modules: Can select a group via module command :mod: Does not accept triggers set_ftrace_pid - Write pid(s) to only function trace those pids (function) set_graph_function - Trace the nested calls of a function (function_graph) set_graph_notrace - Do not trace the nested calls of a function (function_graph) max_graph_depth - Trace a limited depth of nested calls (0 is unlimited)
snapshot - Like 'trace' but shows the content of the static snapshot buffer. Read the contents for more information stack_trace - Shows the max stack trace when active stack_max_size - Shows current max stack size that was traced Write into this file to reset the max size (trigger a new trace) stack_trace_filter - Like set_ftrace_filter but limits what stack_trace traces events/ - Directory containing all trace event subsystems: enable - Write 0/1 to enable/disable tracing of all events events/<system>/ - Directory containing all trace events for <system>: enable - Write 0/1 to enable/disable tracing of all <system> events filter - If set, only events passing filter are traced events/<system>/<event>/ - Directory containing control files for <event>: enable - Write 0/1 to enable/disable tracing of <event> filter - If set, only events passing filter are traced trigger - If set, a command to perform when event is hit Format: <trigger>[:count][if <filter>] trigger: traceon, traceoff enable_event:<system>:<event> disable_event:<system>:<event> stacktrace snapshot example: echo traceoff > events/block/block_unplug/trigger echo traceoff:3 > events/block/block_unplug/trigger echo 'enable_event:kmem:kmalloc:3 if nr_rq > 1' > \ events/block/block_unplug/trigger The first disables tracing every time block_unplug is hit. The second disables tracing the first 3 times block_unplug is hit. The third enables the kmalloc event the first 3 times block_unplug is hit and has value of greater than 1 for the 'nr_rq' event field. Like function triggers, the counter is only decremented if it enabled or disabled tracing. To remove a trigger without a count: echo '!<trigger> > <system>/<event>/trigger To remove a trigger with a count: echo '!<trigger>:0 > <system>/<event>/trigger Filters can be ignored when removing a trigger.
| |