310 likes | 385 Views
A Dynamic Aspect-oriented System for OS Kernels. Yoshisato Yanagisawa, Kenichi Kourai, Shigeru Chiba, and Rei Ishikawa Tokyo Institute of Technology. Let’s insert profiling code into a running kernel. For logging time stamps at arbitrary execution points Performance tuning
E N D
A Dynamic Aspect-oriented System for OS Kernels Yoshisato Yanagisawa, Kenichi Kourai, Shigeru Chiba, and Rei Ishikawa Tokyo Institute of Technology.
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.
Profiling code Record a time stamp at a specified source line with values of variables. No recompile or reboot! Linux kernel code (fs/attr.c) int inode_change_ok(…) { … if ((ia_valid & ATTR_UID) && … attr->ia_uid != inode->i_uid) … goto error; if ((ia_valid & ATTR_GID) && … } Profiling code struct timeval tv; do_gettimeofday(&tv) ; print_tv(tv); printk(“%ld”, inode->i_uid); insert
Kerninst [Tamches et al. ’99] • An on-line kernel instrumentation tool. • Assembly-level abstraction. • Developers should manually calculatethe 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); ifunc.findEntryPoint(&entries); kmgr.findModule(“profiler”, &kmod); kmod.findFunction(“print_log”, &pf); hook = kapi_call_expr(pf.getEntryAddr(), args); kmgr.insertSnippet(hook, entries[0]); void print_log() { … __asm__ (“movl %%ebp, %0” : “=r”(ebp)); uid = ((struct inode*)ebp[11])->i_uid; /* ebp[11] is inode */ …
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.
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.
An example of a KLASY aspect Aspect Linux kernel code (fs/attr.c) <aspect> <import>linux/time.h</import> <advice><pointcut> access(inode.i_uid)AND within_function(inode_change_ok) AND target(inode_value) </pointcut> <before> struct inode *i = inode_value; struct timeval tv; do_gettimeofday(&tv); print(i->i_uid, tv.tv_sec, tv.tv_usec); </before> </advice> </aspect> int inode_change_ok(…) { … if ((ia_valid & ATTR_UID) && … attr->ia_uid != inode->i_uid) … goto error; if ((ia_valid & ATTR_GID) && … } pointcut selected advice
An example of a KLASY aspect Aspect import a header file used in advice bodies. Linux kernel code (fs/attr.c) <aspect> <import>linux/time.h</import> <advice><pointcut> access(inode.i_uid)AND within_function(inode_change_ok) AND target(inode_value) </pointcut> <before> struct inode *i = inode_value; struct timeval tv; do_gettimeofday(&tv); print(i->i_uid, tv.tv_sec, tv.tv_usec); </before> </advice> </aspect> int inode_change_ok(…) { … if ((ia_valid & ATTR_UID) && … attr->ia_uid != inode->i_uid) … goto error; if ((ia_valid & ATTR_GID) && … } pointcut selected advice
An example of a KLASY aspect Aspect Linux kernel code (fs/attr.c) <aspect> <import>linux/time.h</import> <advice><pointcut> access(inode.i_uid)AND within_function(inode_change_ok) AND target(inode_value) </pointcut> <before> struct inode *i = inode_value; struct timeval tv; do_gettimeofday(&tv); print(i->i_uid, tv.tv_sec, tv.tv_usec); </before> </advice> </aspect> int inode_change_ok(…) { … if ((ia_valid & ATTR_UID) && … attr->ia_uid != inode->i_uid) … goto error; if ((ia_valid & ATTR_GID) && … } pointcut selected advice
An example of a KLASY aspect Aspect Linux kernel code (fs/attr.c) <aspect> <import>linux/time.h</import> <advice><pointcut> access(inode.i_uid)AND within_function(inode_change_ok) AND target(inode_value) </pointcut> <before> struct inode *i = inode_value; struct timeval tv; do_gettimeofday(&tv); print(i->i_uid, tv.tv_sec, tv.tv_usec); </before> </advice> </aspect> int inode_change_ok(…) { … if ((ia_valid & ATTR_UID) && … attr->ia_uid != inode->i_uid) … goto error; if ((ia_valid & ATTR_GID) && … } pointcut selected advice access(inode.i_uid) pointcut selects inode->i_uid
An example of a KLASY aspect Aspect Linux kernel code (fs/attr.c) <aspect> <import>linux/time.h</import> <advice><pointcut> access(inode.i_uid)AND within_function(inode_change_ok) AND target(inode_value) </pointcut> <before> struct inode *i = inode_value; struct timeval tv; do_gettimeofday(&tv); print(i->i_uid, tv.tv_sec, tv.tv_usec); </before> </advice> </aspect> int inode_change_ok(…) { … if ((ia_valid & ATTR_UID) && … attr->ia_uid != inode->i_uid) … goto error; if ((ia_valid & ATTR_GID) && … } pointcut selected advice within_function() limits the selection to within inode_change_ok().
An example of a KLASY aspect Aspect Linux kernel code (fs/attr.c) <aspect> <import>linux/time.h</import> <advice><pointcut> access(inode.i_uid)AND within_function(inode_change_ok) AND target(inode_value) </pointcut> <before> struct inode *i = inode_value; struct timeval tv; do_gettimeofday(&tv); print(i->i_uid, tv.tv_sec, tv.tv_usec); </before> </advice> </aspect> int inode_change_ok(…) { … if ((ia_valid & ATTR_UID) && … attr->ia_uid != inode->i_uid) … goto error; if ((ia_valid & ATTR_GID) && … } pointcut selected advice Context exposure:set inode_value to the target structure inode.
An example of a KLASY aspect Aspect Linux kernel code (fs/attr.c) <aspect> <import>linux/time.h</import> <advice><pointcut> access(inode.i_uid)AND within_function(inode_change_ok) AND target(inode_value) </pointcut> <before> struct inode *i = inode_value; struct timeval tv; do_gettimeofday(&tv); print(i->i_uid, tv.tv_sec, tv.tv_usec); </before> </advice> </aspect> int inode_change_ok(…) { … if ((ia_valid & ATTR_UID) && … attr->ia_uid != inode->i_uid) … goto error; if ((ia_valid & ATTR_GID) && … } pointcut selected advice Get a time stamp and store it with the value of i_uid
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.
An overview of KLASY OS source code Aspect Richer symbol information Modified gcc Aspect compiler pointcut insmod Dynamic Weaver OS kernel Compiled advice Core OS kernel Hook
An overview of KLASY OS source code Aspect Richer symbol information Modified gcc Aspect compiler pointcut insmod Dynamic Weaver OS kernel Compiled advice Core OS kernel Hook
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 struct-member accesses.
An overview of KLASY OS source code Aspect Richer symbol information Modified gcc Aspect compiler pointcut insmod Dynamic Weaver OS kernel Compiled advice Core OS kernel Hook
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
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.
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.
Context exposure in the aspect Aspect Linux kernel code (fs/attr.c) <aspect> <import>linux/time.h</import> <advice><pointcut> access(inode.i_uid)AND within_function(inode_change_ok) AND target(inode_value) </pointcut> <before> struct inode *i = inode_value; struct timeval tv; do_gettimeofday(&tv); print(i->i_uid, tv.tv_sec, tv.tv_usec); </before> </advice> </aspect> int inode_change_ok(…) { … if ((ia_valid & ATTR_UID) && … attr->ia_uid != inode->i_uid) … goto error; if ((ia_valid & ATTR_GID) && … } pointcut selected Read a local variable and use it in an advice-body. advice
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
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
Aspect for tracing Wid-card <aspect><advice> <pointcut> access(sk_buff.%) AND target(arg0) </pointcut> <before> struct sk_buff *skb = arg0; unsigned long timestamp; if (skb->protocol != ETH_P_ARP) { STORE_DATA($pc$); STORE_DATA(skb); DO_RDTSC(timestamp); STORE_DATA(timestamp); } </before> </advice></aspect> skb->protocol Store a program counter,a position of each sk_buf structure, and a time stamp. Ignore ARP packets
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 Too much difference __kfree_skb ip_rcv skb_copy_datagram_iovec netif_receive_skb tcp_v4_rcv tcp_rcv_established 1000_clean_rx_irq ip_rcv_finish tcp_v4_do_rcv
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
Result of UnixBench • The performance of the kernel compiled by our compiler is acceptable. • Overhead: • 0 to 12 % • Average: 4.4 % dhry2reg: drystone syscall: system call pipe: pipe system call execl: execl system call context: context-switch
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.
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.
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/.