tutorial draft checked in

tutorial draft checked in

[Frank Ch. Eigler]

Hi -

I checked in a draft of the systemtap tutorial (/doc/tutorial).  It's
16 pages long at the moment, written in latex.  Let me know if you
have trouble formatting it into ps/pdf.  I'll put up a snapshot at
<http://web.elastic.org/~fche/systemtap.pdf> *temporarily*.

I welcome comments on organization, presentation, and content.

- FChE

Re: tutorial draft checked in

[Martin Hunt]

On Fri, 2006-03-03 at 12:56 -0500, Frank Ch. Eigler wrote:
> I checked in a draft of the systemtap tutorial (/doc/tutorial).  

Very Nice!

On first reading, I have only a few minor comments.

Section 3.5

>This operation is efficient (taking a shared lock) because the
>aggregate values are kept separately on each processor, and are only 
>aggregated across processors on request.

Surprised me. I checked and this accurately described the current
implementation, but the shared lock is unnecessary and should probably
not be mentioned.


>b[cpu(),execname()] <<< 1 # better than ++
[...]
>print(@hist_log(b[0,"zsh"])) print an "ascii art" 
>logarithmic histogram of the same data stream

Indexing by cpu() here complicates the example, especially after
discussing how aggregates store information per-cpu. And the histogram
example won't print anything like a histogram because the values are all
1. I suggest you change these to something clearer.

writes[execname()] <<< count 

print(@hist_log(writes["zsh"])) print an "ascii art" logarithmic
histogram of the same data stream

Section 3.6

What about running out of memory? Need to mention that arrays are
preallocated, fixed in size, can overflow, and what happens when they
do. That may change in the future.

Section 4.3

>Since systemtap cannot examine the C code to infer these 
>types, an optional type annotation syntax is available 
>for explicitly declaring them.

If it is optional, what happens if the types are not declared?
Is there a default? 

4.4

The ideas here are fine. 

Maybe it needs to be clearer that people shouldn't prefix their tapset
functions with "TAPSET_" but with the unique tapset name followed by
underscore.

Martin

Re: tutorial draft checked in

[William Cohen]

Thanks for the tutorial.

The counters used by get_cycles() ?  are not synced between processors
this is likely to give wrong results on smp machines, particularly now
with variable clockspeeds. So the examples at the bottom of page 7 are
misleading.

-Will

Re: tutorial draft checked in

[Jim Keniston]

[-- Attachment #1: Type: text/plain, Size: 1404 bytes --]

On Fri, 2006-03-03 at 09:56, Frank Ch. Eigler wrote:
> Hi -
> 
> I checked in a draft of the systemtap tutorial (/doc/tutorial).  It's
> 16 pages long at the moment, written in latex.  Let me know if you
> have trouble formatting it into ps/pdf.  I'll put up a snapshot at
> <http://web.elastic.org/~fche/systemtap.pdf> *temporarily*.
> 
> I welcome comments on organization, presentation, and content.
> 
> - FChE

Nice job.  It was fun to read, and should be a huge help to new users. 
Post it to the web site pronto.

Attached is a patch with suggested fixes and clarifications.

Other comments not reflected in that patch:

I didn't like the use of caps (rather than the usual italics) for
generic terms like STATEMENT.  I was especially confused by the use of
TAPSET in "Naming conventions."

I'd like to see one or more examples of probes set mid-function (i.e.,
specified by line number).  (Exercise for reader: Adjust the line number
to match your kernel version.)

Item #4 at the end of section 4.3: "Block" is a synonym for "sleep." 
"Spin" is the term you want.  And I'm not sure I agree that trylock/fail
is necessary when you fully understand the dangers of deadlock.

I edited out the use of "per-version."  An interesting word, but
distracting. :-)

I'm with Richard.  "Probepoint" is the spelling established by dprobes
and kprobes documents.  And it's consistent with "breakpoint."

Jim

[-- Attachment #2: tutedit.patch --]
[-- Type: text/plain, Size: 12985 bytes --]

--- oldtu/analysis.tex	2006-03-03 09:46:57.000000000 -0800
+++ tutorial/analysis.tex	2006-03-06 16:15:21.000000000 -0800
@@ -14,9 +14,19 @@
 
 Most systemtap scripts include conditionals, to limit tracing or other
 logic to those processes or users or {\em whatever} of interest.  The
-syntax is simple: \verb+if(EXPR) STATEMENT [else STATEMENT]+.
-Similarly, scripts can loop: \verb+while(EXPR) STATEMENT+ or
-\verb+for(A;B;C) STATEMENT+, and \verb+break+/\verb+continue+ as in C.
+syntax is simple:
+\begin{verbatim}
+if(EXPR) STATEMENT [else STATEMENT]
+\end{verbatim}
+Similarly, scripts can loop:
+\begin{verbatim}
+while(EXPR) STATEMENT
+\end{verbatim}
+or
+\begin{verbatim}
+for(A;B;C) STATEMENT
+\end{verbatim}
+and \verb+break+/\verb+continue+ as in C.
 Probe handlers can return early using \verb+next+ as in \verb+awk+.
 Blocks of statements are enclosed in \verb+{+ and \verb+}+.  In
 systemtap, the semicolon (\verb+;+) is accepted as a null statement
@@ -27,7 +37,7 @@
 C++-style (\verb+//+) comments are all accepted.
 
 Expressions look like C or \verb+awk+, and support the usual
-operators, precedences, and numeric literals.  String are treated as
+operators, precedences, and numeric literals.  Strings are treated as
 atomic values rather than arrays of characters.  String concatenation
 is done with the dot (\verb+"a" . "b"+).  Some examples:
 
@@ -42,7 +52,7 @@
 use it in expressions.  They are automatically initialized and
 declared.  The type of each identifier -- string vs. number -- is
 automatically inferred by systemtap from the kinds of operators and
-literals used on it.  Any inconsistencies will signal an error.
+literals used on it.  Any inconsistencies will be reported as errors.
 Conversion between string and number types is done through explicit
 function calls.
 
@@ -51,7 +61,7 @@
 or number.}  \nomenclature{string}{A \verb+\0+-terminated character
 string of up to a fixed limit in length.}  \nomenclature{number}{A
 64-bit signed integer.}  \nomenclature{type inference}{The automatic
-computation of the type of each variable, function parameter, array
+determination of the type of each variable, function parameter, array
 value and index, based on their use.}
 
 \begin{tabular}{rl}
@@ -67,9 +77,9 @@
 anywhere in the script.  Because of possible concurrency (multiple
 probe handlers running on different CPUs), each global variable used
 by a probe is automatically read- or write-locked while the handler is
-running.  \nomenclature{global variable}{A scalar or array that was
+running.  \nomenclature{global variable}{A scalar, array, or aggregate that was
 named in a \verb+global+ declaration, sharing that object amongst all
-probe handlers executed during a systemtap session.}
+probe handlers and functions executed during a systemtap session.}
 \nomenclature{locking}{An automated facility used by systemtap to
 protect global variables against concurrent modification and/or
 access.}
@@ -102,7 +112,7 @@
 A class of special ``target variables'' allow access to the probe
 point context.  \nomenclature{target variable}{A value that may be
 extracted from the kernel context of the probe point, such as a
-parameter or local variable within an probed function.}  In a symbolic
+parameter or local variable within a probed function.}  In a symbolic
 debugger, when you're stopped at a breakpoint, you can print values
 from the program's context.  In systemtap scripts, for those probe
 points that match with specific executable point (rather than an
@@ -118,7 +128,7 @@
 \verb+vfs_write+.  Each takes a \verb+struct file *+ argument, inside
 which there is a \verb+struct dentry *+, a \verb+struct inode *+, and
 so on.  Systemtap allows limited dereferencing of such pointer chains.
-Two functions \verb+user_string+ and \verb+kernel_string+ can copy
+Two functions, \verb+user_string+ and \verb+kernel_string+, can copy
 \verb+char *+ target variables into systemtap strings.
 Figure~\ref{fig:inode-watch} demonstrates one way to monitor a
 particular file (identifed by device number and inode number).  This
@@ -212,8 +222,9 @@
 is fixed at startup.  Because they are too large to be created
 dynamically for inidividual probes handler runs, they must be declared
 as global.  \nomenclature{array}{A global
-$k_1,k_2,\ldots,k_n\rightarrow value$ lookup table, with a string,
-number, or statistics type for each index and value.}
+\verb+[+$k_1,k_2,\ldots,k_n\verb+]+\rightarrow value$ lookup table, with a string,
+number, or statistics type for each index and value.
+Systemtap arrays are associative arrays.}
 
 The basic operations for arrays are setting and looking up elements.
 These are expressed in \verb+awk+ syntax: the array name followed by
@@ -250,12 +261,12 @@
 value by adding an extra \verb|+| or \verb|-| code.
 
 \begin{tabular}{rl}
-\verb|foreach ([a,b] in foo) { foo[a,b] }| & simple loop in arbitrary sequence \\
+\verb|foreach ([a,b] in foo) { fuss_with(foo[a,b]) }| & simple loop in arbitrary sequence \\
 \verb|foreach ([a,b] in foo+) { }| & loop in increasing sequence of value \\
 \verb|foreach ([a-,b] in foo) { }| & loop in decreasing sequence of first key \\
 \end{tabular}
 
-The \verb+break+ and \verb+continue+ statements work inside too.
+The \verb+break+ and \verb+continue+ statements work inside \verb+foreach+ loops, too.
 Since arrays can be large but probe handlers must not run for long,
 it is a good idea to exit iteration early if possible.\footnote{We
 anticipate an iteration-count-limited extension to {\tt foreach}
@@ -266,13 +277,13 @@
 
 When we said above that values can only be strings or numbers, we lied
 a little.  There is a third type: statistics aggregates, or aggregates
-for short.  Instaces of this type are used to collect statistics on
+for short.  Instances of this type are used to collect statistics on
 numerical values, where it is important to accumulate new data quickly
 ({\em without} exclusive locks) and in large volume (storing only
 aggregated stream statistics).  This type only makes sense for global
 variables, and may be stored individually or as elements of an array.
 \nomenclature{aggregate}{A special data type used to efficiently store
-aggregated values of a potentially huge data stream.}
+aggregated values (such as statistics) of a potentially huge data stream.}
 
 To add a value to a statistics aggregate, systemtap uses the special
 operator \verb+<<<+.  Think of it like C++'s \verb+<<+ output
@@ -297,7 +308,7 @@
 \verb+@hist_linear+.  These evaluate to a special sort of array that
 may at present\footnote{We anticipate support for indexing and looping
 using {\tt foreach} shortly.} only be printed.
-\nomenclature{extractor}{A function-like expression in script that
+\nomenclature{extractor}{A function-like expression in a script that
 computes a single statistic for a given aggregate.}
 
 \begin{tabular}{rl}
@@ -357,6 +368,7 @@
 of writing.  Putting probes indiscriminately into unusually sensitive
 parts of the kernel (low level context switching, interrupt
 dispatching) has reportedly caused crashes in the past.  We are
+fixing these bugs as they are found, and
 constructing a probe point ``blacklist'', but it is not complete.
 \nomenclature{blacklist}{A list of probe point patterns encoded into
 the translator or the kernel, where probing is prohibited for safety
--- oldtu/fini.tex	2006-03-03 09:46:57.000000000 -0800
+++ tutorial/fini.tex	2006-03-06 16:04:48.000000000 -0800
@@ -18,9 +18,9 @@
 than their documentation, they are the most reliable way to see what's
 inside all the tapsets.  Use the \verb+-v+ (verbose) command line
 option, several times if you like, to show inner workings.
-\nomenclature{free softare}{Software licensed under terms such as the
+\nomenclature{free software}{Software licensed under terms such as the
 GNU GPL, which aims to enforce certain specified user freedoms such
-as study, modification, sharing.}
+as study, modification, and sharing.}
 
 Finally, there is the project web site
 (\verb+http://sources.redhat.com/systemtap/+) with several articles,
--- oldtu/intro.tex	2006-03-03 09:46:57.000000000 -0800
+++ tutorial/intro.tex	2006-03-06 16:04:48.000000000 -0800
@@ -2,7 +2,7 @@
 
 Systemtap is a tool that allows developers and administrators to write
 and reuse simple scripts to deeply examine the activities of a live
-linux system.  Data may be extracted, filtered, and summarized quickly
+Linux system.  Data may be extracted, filtered, and summarized quickly
 and safely, to enable diagnoses of complex performance or functional
 problems.
 
@@ -10,7 +10,7 @@
 
 The essential idea behind a systemtap script is to name {\em events},
 and to give them {\em handlers}.  Whenever a specified event occurs,
-the linux kernel runs the handler as if it were a quick subroutine,
+the Linux kernel runs the handler as if it were a quick subroutine,
 then resumes.  There are several kind of events, such as entering or
 exiting a function, a timer expiring, or the entire systemtap session
 starting or stopping.  A handler is a series of script language
@@ -31,8 +31,8 @@
 loaded, it activates all the probed events by hooking into the kernel.
 Then, as events occur on any processor, the compiled handlers run.
 Eventually, the session stops, the hooks are disconnected, and the
-module removed.  This entire process is driven from a single command
-line program \verb+stap+.
+module removed.  This entire process is driven from a single
+command-line program, \verb+stap+.
 
 \begin{figure}[h!]
 \begin{boxedminipage}{4.5in}
--- oldtu/tapsets.tex	2006-03-03 10:13:06.000000000 -0800
+++ tutorial/tapsets.tex	2006-03-06 16:04:48.000000000 -0800
@@ -23,8 +23,8 @@
 larger kernel families.  Naturally, the search is ordered from
 specific to general, as shown in Figure~\ref{fig:tapset-search}.
 \nomenclature{tapset search path}{A list of subdirectories searched by
-systemtap for tapset scripts, allowing per-version or
-per-architectural specialization.}
+systemtap for tapset scripts, allowing specialization by version
+or architecture.}
 
 \begin{figure}[h!]
 \begin{boxedminipage}{6in}
@@ -181,7 +181,7 @@
 
 Sometimes, a tapset needs provide data values from the kernel that
 cannot be extracted using ordinary target variables (\verb+$var+).  %$
-This may be becuase the values are in complicated data structures, may
+This may be because the values are in complicated data structures, may
 require lock awareness, or are defined by layers of macros.  Systemtap
 provides an ``escape hatch'' to go beyond what the language can safely
 offer.  In certain contexts, you may embed plain raw C in tapsets,
--- oldtu/tracing.tex	2006-03-03 09:46:57.000000000 -0800
+++ tutorial/tracing.tex	2006-03-06 16:04:48.000000000 -0800
@@ -18,10 +18,11 @@
 the \verb+stapprobes+ man page for details.  \nomenclature{tapset}{A
 reusable script forming part of the automatically searched tapset
 library.}  All these events are named using a unified syntax that
-looks like dot-separated parametrized identifiers:
+looks like dot-separated parameterized identifiers:
 
 \begin{tabular}{rl}
 \verb+begin+ & The startup of the systemtap session. \\
+\verb+end+ & The end of the systemtap session. \\
 \verb+kernel.function("sys_open")+ & The entry to the function named
 \verb+sys_open+ in the kernel. \\
 \verb+syscall.close.return+ & The return from the \verb+close+ system
@@ -60,7 +61,7 @@
 \end{verbatim}
 You can run this script as is, though with empty handlers there will
 be no output.  Put the two lines into a new file.  Run
-\verb+stap -v FILE+.  Interrupt it any time with \verb+^C+.  (The
+\verb+stap -v FILE+.  Terminate it any time with \verb+^C+.  (The
 \verb+-v+ option tells systemtap to print more verbose messages during
 its processing.  Try the \verb+-h+ option to see more options.)
 
@@ -82,12 +83,13 @@
 
 \begin{tabular}{rl}
 \verb+tid()+ & The id of the current thread. \\
+\verb+pid()+ & The process (task group) id of the current thread. \\
 \verb+uid()+ & The id of the current user. \\
 \verb+execname()+ & The name of the current process. \\
 \verb+cpu()+ & The current cpu number. \\
 \verb+gettimeofday_s()+ & Number of seconds since epoch. \\
 \verb+get_cycles()+ & Snapshot of hardware cycle counter. \\
-\verb+pp()+ & The probe point being currently handled. \\
+\verb+pp()+ & A string describing the probe point being currently handled. \\
 \verb+probefunc()+ & If known, the name of the function in which
                      this probe was placed. \\
 \end{tabular}
@@ -108,7 +110,7 @@
 process name and the thread id itself.  It therefore gives an idea not
 only about what functions were called, but who called them, and how
 long they took.  Figure~\ref{fig:socket-trace} shows the finished
-script.  It lacks an call to the \verb+exit()+ function, so you need to
+script.  It lacks a call to the \verb+exit()+ function, so you need to
 interrupt it with \verb+^C+ when you want the tracing to stop.
 
 \begin{figure}[h!]

Re: tutorial draft checked in

[Frank Ch. Eigler]

Hi -

hunt wrote:

> >This operation is efficient (taking a shared lock) because the
> >aggregate values are kept separately on each processor, and are only 
> >aggregated across processors on request.
> 
> Surprised me. I checked and this accurately described the current
> implementation, but the shared lock is unnecessary and should probably
> not be mentioned.
> [...]

This is the subject of bug #2224.  The runtime is taking locks, and
the translator is also emitting locks.  In my opinion, the runtime
should leave the maximum possible locking discretion to the
translator, since e.g. only the latter knows how to enforce locking
timeouts over contentious data.

There happens to be a small potential advantage to one technique the
runtime uses for pmap locking.  Instead of a single rwlock (which
concurrent <<< thread would all take in shared mode), it uses per-cpu
spinlocks (which each <<< thread can take without sharing with other
<<< users).  (On the flip side, a @op thread has to lock all spinlocks
in a loop, instead of just taking the rwlock in exclusive mode,
risking a little incoherence if this is done in the wrong order.)

Anyway, if the advantage of having unshared per-cpu locks for the <<<
case was large, the translator could adopt the technique just as
easily.

- FChE

Re: tutorial draft checked in

[Martin Hunt]

On Thu, 2006-03-09 at 19:51 -0500, Frank Ch. Eigler wrote:
> Hi -
> 
> hunt wrote:
> 
> > >This operation is efficient (taking a shared lock) because the
> > >aggregate values are kept separately on each processor, and are only 
> > >aggregated across processors on request.
> > 
> > Surprised me. I checked and this accurately described the current
> > implementation, but the shared lock is unnecessary and should probably
> > not be mentioned.
> > [...]
> 
> This is the subject of bug #2224.  The runtime is taking locks, and
> the translator is also emitting locks.  In my opinion, the runtime
> should leave the maximum possible locking discretion to the
> translator, since e.g. only the latter knows how to enforce locking
> timeouts over contentious data.

We have argued this again and again. I see no reason why you want the
translator to be more complicated and slower.  Surely we have better
things to work on.

For the specific case of pmaps I am sure I spent more time arguing about
it than writing it. The disadvantages of what you want to do are
1. Reader locks are slow. They don't scale as well as per-cpu spinlocks.
2. The translator holds the lock during the whole probe vs the runtime
which holds the lock as short a time as possible.
3. Having the translator handle low-level locking eliminates the
possibility of switching the runtime to a more efficient lockless
solution later. 

> Anyway, if the advantage of having unshared per-cpu locks for the <<<
> case was large, the translator could adopt the technique just as
> easily.

Obviously not true. It is already done and works in the runtime pmap
implementation. 

I ran a few benchmarks to demonstrate pmaps scalability and measure the
additional overhead from the translator reader-writer locks.

Regular maps
probe TEST {
        syscalls[probefunc()]++
}
Pmaps
probe TEST {
        syscalls[probefunc()] <<< 1
}

Running on a dual-processor hyperthreaded machine.
I ran threads that were making syscalls as fast as possible.
Results are Kprobes/sec

           1 thread        4 threads
Regular     340              500
Pmaps       340              940
Pmaps*      380             1040

Pmaps* is pmaps with the redundant reader-writer locks removed.
Measured overhead of those locks is approximately 10% of the cpu time
for this test case.



              

Re: tutorial draft checked in

[Frank Ch. Eigler]

Hi -

hunt wrote:

> [...]
> We have argued this again and again. I see no reason why you want the
> translator to be more complicated and slower.  [...]

You misjudge my intention.

> For the specific case of pmaps I am sure I spent more time arguing about
> it than writing it. The disadvantages of what you want to do are
>
> 1. Reader locks are slow. They don't scale as well as per-cpu spinlocks.

At least this is a quantifiable concern.

> 2. The translator holds the lock during the whole probe vs the runtime
> which holds the lock as short a time as possible.

Among other things, this guarantees ACID-style properties for probe
handlers, and prevents various race conditions.

> 3. Having the translator handle low-level locking eliminates the
> possibility of switching the runtime to a more efficient lockless
> solution later.

By removing locks from the runtime that the translator makes
redundant, we still have a "lockless" solution.  If locks can be done
away with entirely, the translator can be taught not to emit them.
It's probably one line of code change.

> > Anyway, if the advantage of having unshared per-cpu locks for the <<<
> > case was large, the translator could adopt the technique just as
> > easily.
> 
> Obviously not true.

WHAT can you possibly mean by that?  The translator could emit per-cpu
spinlocks for pmaps.  Its programmer would not even break a sweat.

> It is already done and works in the runtime pmap implementation. 

Yes, but the question is where better to put the locking.

> I ran a few benchmarks to demonstrate pmaps scalability and measure the
> additional overhead from the translator reader-writer locks. [...]

Good.

> I ran threads that were making syscalls as fast as possible.
> Results are Kprobes/sec
>            1 thread        4 threads
> Regular     340              500
> Pmaps       340              940
> Pmaps*      380             1040
> 
> Pmaps* is pmaps with the redundant reader-writer locks removed.

How about a result with the redundant spinlocks removed?

> Measured overhead of those locks is approximately 10% of the cpu
> time for this test case.

It sounds a bit high, considering all the other overhead involved.
An oprofile count of SMP type events would be interesting.

- FChE

Re: tutorial draft checked in

[Frank Ch. Eigler]

Hi -

> [...]
> Post it to the web site pronto.

Done - on the documentation page.

> Attached is a patch with suggested fixes and clarifications.

Thanks, applied.

> [...]  I'm with Richard.  "Probepoint" is the spelling established
> by dprobes and kprobes documents.  And it's consistent with
> "breakpoint."

Yeah, ok (but I can't find the oomph within me to rename this everywhere).

- FChE