diff options
| author | Manuel Traut <manut@mecka.net> | 2011-02-09 22:55:03 +0100 |
|---|---|---|
| committer | Manuel Traut <manut@mecka.net> | 2011-02-09 22:55:03 +0100 |
| commit | d48f8197d689bc71d3d4ccfc0a12df7cbc9467ab (patch) | |
| tree | e4ab9909f3d823b2ab6abcce9399a18240b87b11 /kernel-devel/kernel-tracing | |
| parent | a67b9e7e770e921a021e22deec3d1f6c24b0c6df (diff) | |
| parent | 5c90abcf73cccc9247e935c83807f2293ebb8fb7 (diff) | |
Merge branch 'lx'
Diffstat (limited to 'kernel-devel/kernel-tracing')
| -rw-r--r-- | kernel-devel/kernel-tracing/Makefile | 9 | ||||
| -rw-r--r-- | kernel-devel/kernel-tracing/pres_kernel-tracing_en.tex | 300 |
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} |
