summaryrefslogtreecommitdiff
path: root/kernel-devel
diff options
context:
space:
mode:
authorManuel Traut <manut@mecka.net>2011-02-09 22:55:03 +0100
committerManuel Traut <manut@mecka.net>2011-02-09 22:55:03 +0100
commitd48f8197d689bc71d3d4ccfc0a12df7cbc9467ab (patch)
treee4ab9909f3d823b2ab6abcce9399a18240b87b11 /kernel-devel
parenta67b9e7e770e921a021e22deec3d1f6c24b0c6df (diff)
parent5c90abcf73cccc9247e935c83807f2293ebb8fb7 (diff)
Merge branch 'lx'
Diffstat (limited to 'kernel-devel')
-rw-r--r--kernel-devel/kernel-tracing/Makefile9
-rw-r--r--kernel-devel/kernel-tracing/pres_kernel-tracing_en.tex300
2 files changed, 309 insertions, 0 deletions
diff --git a/kernel-devel/kernel-tracing/Makefile b/kernel-devel/kernel-tracing/Makefile
new file mode 100644
index 0000000..d641258
--- /dev/null
+++ b/kernel-devel/kernel-tracing/Makefile
@@ -0,0 +1,9 @@
+all:
+ for pdf in `ls -1 *.tex` ; do \
+ TEXINPUTS=`pwd`/../..:.:..:$(TEXINPUTS) pdflatex $$pdf; \
+ TEXINPUTS=`pwd`/../..:.:..:$(TEXINPUTS) pdflatex $$pdf; \
+ done
+
+clean:
+ rm -f *.aux *.log *.pdf *.log *.snm *.toc *.vrb *.nav *.out
+
diff --git a/kernel-devel/kernel-tracing/pres_kernel-tracing_en.tex b/kernel-devel/kernel-tracing/pres_kernel-tracing_en.tex
new file mode 100644
index 0000000..11c2f5f
--- /dev/null
+++ b/kernel-devel/kernel-tracing/pres_kernel-tracing_en.tex
@@ -0,0 +1,300 @@
+\input{configpres}
+
+\title{Kernel-Tracing}
+\section{FTRACE}
+\maketitle
+\begin{frame}[fragile]
+\frametitle{Kerneltracing: Overview}
+\begin{itemize}
+\item DebugFS interface
+\item Different tracers: function, function\_graph, sched\_switch, ...
+\item Custom trace events
+\item Graphical frontend (kernelshark)
+\end{itemize}
+\end{frame}
+
+\begin{frame}[fragile]
+\frametitle{Kernel-Tracing: DebugFS}
+\begin{verbatim}
+$ mount -t debugfs debugfs /sys/kernel/debug
+$ cd /sys/kernel/debug/tracing
+$ cat available_tracers
+blk function_graph mmiotrace wakeup_rt wakeup
+\end{verbatim}
+\end{frame}
+
+
+\begin{frame}[fragile]
+\frametitle{Kerneltracing: Trivial example}
+\begin{verbatim}
+$ echo function_graph > current_tracer
+$ echo 1 > tracing_enabled
+$ sleep 1
+$ echo 0 > tracing_enabled
+$ less trace
+# tracer: function_graph
+# CPU DURATION FUNCTION CALLS
+# | | | | | | |
+ 1) | enqueue_entity() {
+ 1) | update_curr() {
+ 1) 0.336 us | task_of();
+ 1) 1.524 us | }
+ 1) 0.420 us | place_entity();
+\end{verbatim}
+\end{frame}
+
+\begin{frame}[fragile]
+\frametitle{Tracer: function}
+\begin{verbatim}
+# tracer: function
+#
+# TASK-PID CPU# TIMESTAMP FUNCTION
+# | | | | |
+wnck-2022 [003] 5766.659915: skb_release
+wnck-2022 [003] 5766.659916: sock_wfree
+wnck-2022 [003] 5766.659917: unix_write_free
+wnck-2022 [003] 5766.659917: skb_releasee_skb
+wnck-2022 [003] 5766.659918: kfree <-skb
+\end{verbatim}
+\end{frame}
+
+\begin{frame}[fragile]
+\frametitle{Tracer: function / latency\_format}
+\begin{verbatim}
+$ echo 1 > options/latency_format
+$ less trace
+# _------=> CPU#
+# / _-----=> irqs-off
+# | / _----=> need-resched
+# || / _---=> hardirq/softirq
+# ||| / _--=> preempt-depth
+# |||| /_--=> lock-depth
+# |||||/ delay
+# cmd pid |||||| time | caller
+# \ / |||||| \ | /
+wnck-app-2022 3..... 1237702us : skb_relea
+wnck-app-2022 3..... 1237703us : sock_wfre
+\end{verbatim}
+\end{frame}
+
+\begin{frame}[fragile]
+\frametitle{Tracer: function (custom tracepoint)}
+\begin{verbatim}
+$ echo 1 > tracing_enabled
+$ echo "MARK" > trace_marker
+$ echo 0 > tracing_enabled
+$ less trace
+...
+ bash-4328 [003] 5603.687935: get_slab
+ bash-4328 [003] 5603.687935: _cond_re
+ bash-4328 [003] 5603.687936: _cond_re
+ bash-4328 [003] 5603.687939: 0: MARK
+ bash-4328 [003] 5603.687939: kfree <-
+...
+\end{verbatim}
+\end{frame}
+
+\begin{frame}[fragile]
+\frametitle{Tracer: sched\_switch}
+\tiny
+\begin{verbatim}
+# tracer: sched_switch
+#
+# TASK-PID CPU# TIMESTAMP FUNCTION
+# | | | | |
+ bash-4328 [003] 78.553966: 4328:120:S + [003] 4328:120:S bash
+ bash-4328 [003] 78.553979: 4328:120:S ==> [003] 0:120:R <idle>
+<idle>-0 [003] 78.553986: 0:120:R + [003] 13:120:R ksoftirqd/3
+<idle>-0 [003] 78.553988: 0:120:R ==> [003] 13:120:R ksoftirqd/3
+
+\end{verbatim}
+\end{frame}
+
+\begin{frame}[fragile]
+\frametitle{Tracer: wakeup\_rt}
+\tiny
+\begin{verbatim}
+# tracer: wakeup_rt
+#
+# wakeup_rt latency trace v1.1.5 on 2.6.35-22-generic
+# --------------------------------------------------------------------
+# latency: 11 us, #20/20, CPU#3 | (M:desktop VP:0, KP:0, SP:0 HP:0 #P:4)
+...
+# cmd pid time | caller
+# \ / \ | /
+ls-4579 3d.... 1us+: 4579:120:R + [003] 12: 0:R migration/3
+ls-4579 3d.... 4us : wake_up_process <-cpu_stop_queue_work
+ls-4579 3d.... 4us : check_preempt_wakeup <-try_to_wake_up
+ls-4579 3d.... 4us : resched_task <-check_preempt_wakeup
+ls-4579 3dN... 5us : task_woken_rt <-try_to_wake_up
+ls-4579 3dN... 5us : _raw_spin_unlock_irqrestore <-try_to_wake_up
+\end{verbatim}
+\end{frame}
+
+\section{trace-cmd}
+
+\begin{frame}
+\frametitle{trace-cmd}
+\begin{alertblock}{What is trace-cmd?}
+trace-cmd is a commandline utility for controlling and analysing kernel traces.
+\end{alertblock}
+\end{frame}
+
+\begin{frame}[fragile]
+\frametitle{trace-cmd: Installation}
+\begin{verbatim}
+$ git clone git://git.kernel.org/pub/scm/linux/\
+ kernel/git/rostedt/trace-cmd.git
+$ cd trace-cmd
+# On Debian system
+$ apt-get install libgtk2.0-dev libxml2-dev
+$ make && make gui
+$ make install && make install_gui
+\end{verbatim}
+\end{frame}
+
+\begin{frame}[fragile]
+\small
+\frametitle{trace-cmd: Usage}
+\begin{verbatim}
+$ trace-cmd
+[...]
+record - record a trace into a trace.dat file
+start - start tracing without recording into a file
+extract - extract a trace from the kernel
+stop - stop the kernel from recording trace data
+reset - disable all kernel tracing / clear trace buffers
+report - read out the trace stored in a trace.dat file
+split - parse a trace.dat file into smaller file(s)
+listen - listen on a network socket for trace clients
+list - list the available events, plugins or options
+restore - restore a crashed record
+stack - output, enable or disable kernel stack tracing
+\end{verbatim}
+\end{frame}
+
+\begin{frame}[fragile]
+\frametitle{trace-cmd: Usage}
+\begin{verbatim}
+# Recording a sched_switch trace
+$ trace-cmd -p sched_switch
+ plugin sched_switch
+Hit Ctrl^C to stop recording
+Hit Ctrl^C to stop recording
+offset=ae000
+[...]
+
+CPU: 0
+entries: 0
+overrun: 0
+commit overrun: 0
+\end{verbatim}
+\end{frame}
+
+\begin{frame}[fragile]
+\frametitle{trace-cmd: Usage}
+\begin{verbatim}
+# Analysing a trace
+$ trace-cmd report
+version = 6
+cpus=1
+trace-cmd-29057 [000] 6901.652365: wakeup:
+29057:120:1 ==+ 29057:120:1 [000]
+trace-cmd-29057 [000] 6901.652388: wakeup:
+29057:120:0 ==+ 323:120:0 [000]
+trace-cmd-29057 [000] 6901.652393: context_switch:
+29057:120:0 ==> 323:120:0 [000]
+kworker/0:1-323 [000] 6901.652397: wakeup:
+323:120:0 ==+ 28355:120:0 [000]
+\end{verbatim}
+\end{frame}
+
+\begin{frame}
+\frametitle{trace-cmd: Usage}
+\begin{itemize}
+\item trace-cmd record generates a file called trace.dat. This can be overridden by
+the -o option
+\item trace-cmd report uses the -i option for specifying an input file
+\end{itemize}
+\end{frame}
+
+\begin{frame}[fragile]
+\frametitle{trace-cmd: Record specific events}
+\begin{verbatim}
+trace-cmd record -e sched
+# or a specific scheduler event
+trace-cmd record -e sched_wait_task
+# List availabe events and options
+trace-cmd report --events
+\end{verbatim}
+\begin{verbatim}
+
+\end{verbatim}
+\end{frame}
+
+\begin{frame}[fragile]
+\frametitle{trace-cmd: Filters}
+Based on the options from ''trace-cmd report --events'':
+\begin{verbatim}
+trace-cmd record -e context_switch \
+ -f 'next_pid == 323'
+\end{verbatim}
+\end{frame}
+
+\begin{frame}[fragile]
+\frametitle{trace-cmd: Tracing a specific command}
+Enable tracing while a specific command is being executed:
+\begin{verbatim}
+$ trace-cmd record -p function ls
+\end{verbatim}
+\end{frame}
+
+\begin{frame}[fragile]
+\frametitle{trace-cmd: Recording traces via network}
+On the host:
+\begin{verbatim}
+trace-cmd listen -p 1234 -o trace_remote
+\end{verbatim}
+On the target:
+\begin{verbatim}
+trace-cmd record -p sched_switch \
+ -N 192.168.0.182:1234 /bin/ls
+\end{verbatim}
+\end{frame}
+
+\section{Kernelshark}
+\begin{frame}[fragile]
+\frametitle{Kernelshark: A graphical front-end}
+\begin{verbatim}
+$ kernelshark
+# or
+$ kernelshark -i mytrace.dat
+\end{verbatim}
+\end{frame}
+
+\begin{frame}
+\frametitle{Kernelshark}
+\begin{figure}[h]
+\centering
+\includegraphics[width=10cm]{images/kernelshark.png}
+\end{figure}
+\end{frame}
+
+\begin{frame}
+\frametitle{Kernelshark}
+\begin{figure}[h]
+\centering
+\includegraphics[width=10cm]{images/kernelshark_zoom.png}
+\end{figure}
+\end{frame}
+\begin{frame}
+
+\section{sources}
+\frametitle{sources}
+\begin{thebibliography}{1}
+\bibitem{trace1} http://lwn.net/Articles/365835/
+\bibitem{trace2} http://lwn.net/Articles/366796/
+\end{thebibliography}
+\end{frame}
+
+\input{tailpres}