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.
