Transcript A Dynamic Aspect-oriented System for OS Kernels

A Dynamic Aspect-oriented
System for OS Kernels
Yoshisato Yanagisawa, Kenichi Kourai,
Shigeru Chiba, and Rei Ishikawa
Tokyo Institute of Technology.
1
Let’s insert profiling code
into a running kernel
For logging time stamps at arbitrary execution
points
– Performance tuning
– e.g. An elapse time from a packet arrival till it is
stored in a kernel buffer.
Other approaches
– Existing kernel profilers?
Time stamps are logged only at prefixed points.
– Modifying kernel source and reboot?
It’s annoying and error-prone.
2
Profiling code
Linux kernel code (fs/attr.c)
int inode_change_ok(…)
{
…
if ((ia_valid & ATTR_UID) && …
attr->ia_uid != inode->i_uid) …
goto error;
insert
if ((ia_valid & ATTR_GID) &&
…
}
Record a time stamp
at a specified source line
with values of variables.
No recompile or reboot!
Profiling code
struct timeval tv;
do_gettimeofday(&tv) ;
print_tv(tv);
printk(“%ld”, inode->i_uid);
3
Kerninst [Tamches et al. ’99]
An on-line kernel instrumentation tool.
– Assembly-level abstraction.
– Developers should manually calculate
the addresses of:
machine instructions,
and variables if their values are also logged.
Sample
code for Kerninst to
get a log.
kmgr.findModule(“kernel”,
&kmod);
kmod.findFuction(“inode_change_ok”,
&ifunc);{
void print_log()
ifunc.findEntryPoint(&entries); …
kmgr.findModule(“profiler”, &kmod);
__asm__ (“movl %%ebp, %0” : “=r”(ebp));
kmod.findFunction(“print_log”, &pf);
uid = ((struct inode*)ebp[11])->i_uid;
hook = kapi_call_expr(pf.getEntryAddr(),
/* ebp[11]args);
is inode */
…
kmgr.insertSnippet(hook, entries[0]);
4
KLASY
Kernel-level Aspect-Oriented System
– Source-level abstraction.
Thanks to Aspect-Oriented Programming (AOP)
– Our new implementation scheme
allows the users:
Specifying arbitrary execution points at source level
– Pointcuts
Writing profiling code in C
– Advice
– The code is executed at the specified points.
– It can access variables available at the execution points.
5
Logging
A killer application of AOP
– Logging (or profiling) code should be
separated into an independent module.
Why a new AOP system?
– Existing dynamic AOP systems for C
no context exposure: cannot access variables
no pointcut of struct-member accesses
– We cannot log a time stamp when inode->i_uid is updated.
This is crucial.
6
An example of a KLASY aspect
Aspect
Linux kernel code (fs/attr.c)
<aspect>
int inode_change_ok(…)
<import>linux/time.h</import>
pointcut {
<advice><pointcut>
…
access(inode.i_uid) AND
within_function(inode_change_ok) if ((ia_valid & ATTR_UID) && …
attr->ia_uid != inode->i_uid) …
AND target(inode_value)
goto error;
selected
</pointcut>
advice
<before>
if ((ia_valid & ATTR_GID) &&
struct inode *i = inode_value;
…
struct timeval tv;
}
do_gettimeofday(&amp;tv);
print(i-&gt;i_uid, tv.tv_sec, tv.tv_usec);
</before>
</advice>
</aspect>
7
An example of a KLASY aspect
Aspect
import
a header
file used
in
Linux
kernel code
(fs/attr.c)
advice bodies.
int inode_change_ok(…)
<aspect>
<import>linux/time.h</import>
pointcut {
<advice><pointcut>
…
access(inode.i_uid) AND
within_function(inode_change_ok) if ((ia_valid & ATTR_UID) && …
attr->ia_uid != inode->i_uid) …
AND target(inode_value)
goto error;
selected
</pointcut>
advice
<before>
if ((ia_valid & ATTR_GID) &&
struct inode *i = inode_value;
…
struct timeval tv;
}
do_gettimeofday(&amp;tv);
print(i-&gt;i_uid, tv.tv_sec, tv.tv_usec);
</before>
</advice>
</aspect>
8
An example of a KLASY aspect
Aspect
Linux kernel code (fs/attr.c)
<aspect>
int inode_change_ok(…)
<import>linux/time.h</import>
pointcut {
<advice><pointcut>
…
access(inode.i_uid) AND
within_function(inode_change_ok) if ((ia_valid & ATTR_UID) && …
attr->ia_uid != inode->i_uid) …
AND target(inode_value)
goto error;
selected
</pointcut>
advice
<before>
if ((ia_valid & ATTR_GID) &&
struct inode *i = inode_value;
…
struct timeval tv;
}
do_gettimeofday(&amp;tv);
print(i-&gt;i_uid, tv.tv_sec, tv.tv_usec);
</before>
</advice>
</aspect>
9
An example of a KLASY aspect
Aspect
Linux kernel code (fs/attr.c)
<aspect>
int inode_change_ok(…)
<import>linux/time.h</import>
pointcut {
<advice><pointcut>
…
access(inode.i_uid) AND
within_function(inode_change_ok) if ((ia_valid & ATTR_UID) && …
attr->ia_uid != inode->i_uid) …
AND target(inode_value)
goto error;
selected
</pointcut>
advice
<before>
if ((ia_valid & ATTR_GID) &&
struct inode *i = inode_value;
…
struct timeval tv;
}
do_gettimeofday(&amp;tv);
print(i-&gt;i_uid, tv.tv_sec, tv.tv_usec);
</before>
access(inode.i_uid) pointcut
</advice>
selects inode->i_uid
</aspect>
10
An example of a KLASY aspect
Aspect
Linux kernel code (fs/attr.c)
<aspect>
int inode_change_ok(…)
<import>linux/time.h</import>
pointcut {
<advice><pointcut>
…
access(inode.i_uid) AND
if ((ia_valid & ATTR_UID) && …
within_function(inode_change_ok)
attr->ia_uid != inode->i_uid) …
AND target(inode_value)
goto error;
selected
</pointcut>
advice
<before>
if ((ia_valid & ATTR_GID) &&
struct inode *i = inode_value;
…
struct timeval tv;
}
do_gettimeofday(&amp;tv);
within_function() limits the selection
print(i-&gt;i_uid, tv.tv_sec, tv.tv_usec);
to within inode_change_ok().
</before>
</advice>
</aspect>
11
An example of a KLASY aspect
Aspect
Linux kernel code (fs/attr.c)
<aspect>
int inode_change_ok(…)
<import>linux/time.h</import>
pointcut {
<advice><pointcut>
…
access(inode.i_uid) AND
within_function(inode_change_ok) if ((ia_valid & ATTR_UID) && …
attr->ia_uid != inode->i_uid) …
AND target(inode_value)
goto error;
selected
</pointcut>
advice
<before>
if ((ia_valid
& ATTR_GID)
&&
Context
exposure:
struct inode *i = inode_value;
…
set inode_value to the
struct timeval tv;
}
target structure inode.
do_gettimeofday(&amp;tv);
print(i-&gt;i_uid, tv.tv_sec, tv.tv_usec);
</before>
</advice>
</aspect>
12
An example of a KLASY aspect
Aspect
Linux kernel code (fs/attr.c)
<aspect>
int inode_change_ok(…)
<import>linux/time.h</import>
pointcut {
<advice><pointcut>
…
access(inode.i_uid) AND
within_function(inode_change_ok) if ((ia_valid & ATTR_UID) && …
attr->ia_uid != inode->i_uid) …
AND target(inode_value)
goto error;
selected
</pointcut>
advice
<before>
if ((ia_valid & ATTR_GID) &&
struct inode *i = inode_value;
…
struct timeval tv;
}
Get a time stamp
do_gettimeofday(&amp;tv);
and store it with the
print(i-&gt;i_uid, tv.tv_sec, tv.tv_usec);
</before>
value of i_uid
</advice>
</aspect>
13
Implementation of KLASY
Source-based binary-level dynamic weaving
– Modified GNU C compiler (gcc)
produces richer symbol information, which enables:
– Pointcut of accesses to struct-members
– Context exposure (the addresses of variables)
– Kerninst as a backend
to enable dynamic weaving.
– Advice is written in the C language.
surrounded by XML-like tags.
14
An overview of KLASY
Aspect
OS
source code
Aspect compiler
pointcut
Richer
symbol
information
Modified
gcc
insmod
OS kernel
Compiled advice
Dynamic Weaver
Core
Hook OS kernel
15
An overview of KLASY
Aspect
OS
source code
Aspect compiler
pointcut
Richer
symbol
information
Modified
gcc
insmod
OS kernel
Compiled advice
Dynamic Weaver
Core
Hook OS kernel
16
Our modified gcc compiler
It collects the following symbol information:
– The line number and the file name
in which a struct-member is accessed,
The parser of the compiler has been extended.
– The address of the first instruction of each line.
Debug option (-g) is used at compile-time.
This is also necessary to enable pointcut of structmember accesses.
17
An overview of KLASY
Aspect
OS
source code
Aspect compiler
pointcut
Richer
symbol
information
Modified
gcc
insmod
OS kernel
Compiled advice
Dynamic Weaver
Core
Hook OS kernel
18
Dynamic Weaver
Uses Kerninst to insert a hook
at an execution point selected by a pointcut.
– Hook
A code for calling an advice body
– The address at which a hook is inserted
An access to a struct-member
The line number and the file name
The address of the first instruction of that line.
Symbol
Information
19
Unweaving
KLASY can remove woven aspects from the
OS kernel at runtime
– This feature is important for profiling.
Users typically need to try various profiling aspects.
Users should be able to remove unnecessary aspects
to avoid probe effects.
– Users can associate a user-friendly name to an
aspect.
– KLASY also uses Kerninst to remove hooks
inserted by our weaver.
20
Some supported
Pointcuts and Advices
Pointcuts
– access
Selects access to a struct-member access.
– execution
Selects execution of a function.
Advices
– before
Profiling code will be executed before the selected point.
– after
Profiling code will be executed after a the selected point.
21
Context exposure in the aspect
Aspect
Linux kernel code (fs/attr.c)
<aspect>
int inode_change_ok(…)
<import>linux/time.h</import>
pointcut {
<advice><pointcut>
…
access(inode.i_uid) AND
within_function(inode_change_ok) if ((ia_valid & ATTR_UID) && …
attr->ia_uid != inode->i_uid) …
AND target(inode_value)
goto error;
selected
</pointcut>
Read a local variable and
advice
<before>
if ((ia_valid & ATTR_GID) &&
struct inode *i = inode_value;
…use it in an advice-body.
struct timeval tv;
}
do_gettimeofday(&amp;tv);
print(i-&gt;i_uid, tv.tv_sec, tv.tv_usec);
</before>
</advice>
</aspect>
22
Context Exposure
Pointcuts for context exposure
– target
Gets a reference to a value of the struct-member access
selected by access pointcut.
– local_var
Gets a reference to a local variable at the member access.
– argument
Gets a reference to a function argument of the function
selected by execution pointcut.
Implementation in weaver
– Requires special information from gcc’s debug option
– Strong coupling between weaver and KLASY’s gcc
23
Case study:
tracing packet-handling
Goal
– To find a performance bottleneck of the Linux network
I/O subsystem under heavy workload
We traced the accesses to struct sk_buff
– Sk_buff is used as a buffer in the network subsystem
of Linux
Tracing member accesses to sk_buff shows the
behavior of network processing
– We needed context exposure provided by KLASY
to identify each network packet
to ignore uninteresting packets
24
Aspect for tracing
Wid-card
<aspect><advice>
<pointcut>
access(sk_buff.%) AND target(arg0)
</pointcut>
<before>
struct sk_buff *skb = arg0;
skb->protocol
unsigned long timestamp;
if (skb-&gt;protocol != ETH_P_ARP) {
Store
STORE_DATA($pc$);
a program counter,
STORE_DATA(skb); Ignore ARP packets
a position of each
DO_RDTSC(timestamp);
sk_buf structure,
STORE_DATA(timestamp);
and a time stamp.
}
</before>
</advice></aspect>
25
Results of tracing
The results show that the performance
bottleneck is process scheduling
– skb_copy_datagram_iovec is executed during a
system call issued by a process
pa
cke
pa
cke
0.1
Time scale of packet arrival
Too much difference
t2
t1
1
10
Elapsed time
ip_rcv
netif_receive_skb
tcp_v4_rcv
1000_clean_rx_irq
ip_rcv_finish
100
1000
__kfree_skb
skb_copy_datagram_iovec
tcp_rcv_established
tcp_v4_do_rcv
26
Experiment
UnixBench benchmark
– Compare two Linux kernels:
Linux: compiled by normal gcc.
– With –fomit-frame-pointer optimization.
KLASY: compiled by our modified gcc.
– Cannot use -fomit-frame-pointer optimization
to enable context exposure.
– Measures the overhead of disabling –fomit-frame-pointer
optimization
– Environment
Fedora Core 2 (Linux™ 2.6.10),Kerninst 2.1.1
The GNU C Compiler 3.3.3,AMD Athlon™XP 2200+
1GB RAM,Intel PRO/1000 Ethernet card
27
Result of UnixBench
The performance of the kernel compiled
by our compiler is acceptable.
Linux
ex
ec
l
co
nt
ex
t
pi
pe
sy
sc
all
dhry2reg: drystone
syscall: system call
pipe: pipe system call
execl: execl system call
context: context-switch
y2
re
g
0 to 12 %
Average: 4.4 %
1000
800
600
400
200
0
dh
r
– Overhead:
KLASY
28
Related Works (1)
Dynamic aspect-oriented systems for C
– TOSKANA [Engel ’05], DAC++ [Almajali ’05],
TinyC2 [Zhang ’03],and Arachne [Douence ’05]
Dynamic code instrumentation.
Only a function call or an execution is a pointcut.
– They don’t use symbol information.
– TOSKANA-VM [Engel ’05]
Running an OS kernel on a virtual machine.
Not able to profile a kernel on native hardware.
29
Related Works (2)
Static aspect-oriented systems for C
– Not able to modify a running kernel.
– Need reboot to activate profiling codes.
e.g. AspectC [Coady ’01], AspectC++ [Spinczyk ’02]
Kernel Profilers
– LKST, DTrace [Cantrill ’04], SystemTAP [Prasad ’05],
and LTT [Yaghmour ’00]
Tools for producing log messages about events occurring
in the kernel.
The users can only select some of the pre-defined
execution point.
30
Concluding Remarks
KLASY: kernel-level aspect-oriented system
– source-based binary-level dynamic weaving
Pointcut of struct-member accesses
Context exposure
– KLASY was useful for profiling a network I/O
subsystem
We found that a performance bottleneck was process
scheduling
KLASY is distributed from http://www.csg.is.titech.ac.jp/~yanagisawa/KLASY/.
31