Skip to content

Commit

Permalink
Merge branch 'script-update'
Browse files Browse the repository at this point in the history
Enhance python scripting support

 * pass argument/return value info to script: "args", "retval"
 * allow to set filter in a script file: "UFTRACE_FUNCS"
 * allow to set record option in script: "# uftrace-option:"

Closes #144.

Signed-off-by: Namhyung Kim <namhyung@gmail.com>
  • Loading branch information
namhyung committed Sep 9, 2017
2 parents 827f38d + 00f38d0 commit 66d5e54
Show file tree
Hide file tree
Showing 21 changed files with 876 additions and 141 deletions.
2 changes: 1 addition & 1 deletion Makefile
Original file line number Diff line number Diff line change
Expand Up @@ -94,7 +94,7 @@ UFTRACE_OBJS := $(patsubst $(srcdir)/%.c,$(objdir)/%.o,$(UFTRACE_SRCS))
UFTRACE_ARCH_OBJS := $(objdir)/arch/$(ARCH)/uftrace.o

UFTRACE_HDRS := $(filter-out $(srcdir)/version.h,$(wildcard $(srcdir)/*.h $(srcdir)/utils/*.h))
UFTRACE_HDRS += $(srcdir)/libmcount/mcount.h
UFTRACE_HDRS += $(srcdir)/libmcount/mcount.h $(wildcard $(srcdir)/arch/$(ARCH)/*.h)

LIBMCOUNT_SRCS := $(filter-out %-nop.c,$(wildcard $(srcdir)/libmcount/*.c))
LIBMCOUNT_OBJS := $(patsubst $(srcdir)/%.c,$(objdir)/%.op,$(LIBMCOUNT_SRCS))
Expand Down
3 changes: 3 additions & 0 deletions arch/aarch64/mcount-arch.h
Original file line number Diff line number Diff line change
Expand Up @@ -61,6 +61,9 @@ enum arm_reg_index {
AARCH64_REG_D7,
};

struct mcount_arch_context {
};

#define ARCH_PLT0_SIZE 32

#endif /* __MCOUNT_ARCH_H__ */
3 changes: 3 additions & 0 deletions arch/arm/mcount-arch.h
Original file line number Diff line number Diff line change
Expand Up @@ -57,6 +57,9 @@ enum arm_reg_index {
ARM_REG_D7,
};

struct mcount_arch_context {
};

struct symtabs;

#define FIX_PARENT_LOC
Expand Down
5 changes: 5 additions & 0 deletions arch/x86_64/mcount-arch.h
Original file line number Diff line number Diff line change
Expand Up @@ -44,6 +44,11 @@ enum x86_reg_index {
X86_REG_XMM7,
};

#define HAVE_MCOUNT_ARCH_CONTEXT
struct mcount_arch_context {
double xmm[ARCH_MAX_FLOAT_REGS];
};

#define ARCH_PLT0_SIZE 16
#define ARCH_PLTHOOK_ADDR_OFFSET 6

Expand Down
24 changes: 24 additions & 0 deletions arch/x86_64/mcount-support.c
Original file line number Diff line number Diff line change
Expand Up @@ -129,6 +129,30 @@ void mcount_arch_get_retval(struct mcount_arg_context *ctx,
asm volatile ("movsd %%xmm0, %0\n" : "=m" (ctx->val.v));
}

void mcount_save_arch_context(struct mcount_arch_context *ctx)
{
asm volatile ("movsd %%xmm0, %0\n" : "=m" (ctx->xmm[0]));
asm volatile ("movsd %%xmm1, %0\n" : "=m" (ctx->xmm[1]));
asm volatile ("movsd %%xmm2, %0\n" : "=m" (ctx->xmm[2]));
asm volatile ("movsd %%xmm3, %0\n" : "=m" (ctx->xmm[3]));
asm volatile ("movsd %%xmm4, %0\n" : "=m" (ctx->xmm[4]));
asm volatile ("movsd %%xmm5, %0\n" : "=m" (ctx->xmm[5]));
asm volatile ("movsd %%xmm6, %0\n" : "=m" (ctx->xmm[6]));
asm volatile ("movsd %%xmm7, %0\n" : "=m" (ctx->xmm[7]));
}

void mcount_restore_arch_context(struct mcount_arch_context *ctx)
{
asm volatile ("movsd %0, %%xmm0\n" :: "m" (ctx->xmm[0]));
asm volatile ("movsd %0, %%xmm1\n" :: "m" (ctx->xmm[1]));
asm volatile ("movsd %0, %%xmm2\n" :: "m" (ctx->xmm[2]));
asm volatile ("movsd %0, %%xmm3\n" :: "m" (ctx->xmm[3]));
asm volatile ("movsd %0, %%xmm4\n" :: "m" (ctx->xmm[4]));
asm volatile ("movsd %0, %%xmm5\n" :: "m" (ctx->xmm[5]));
asm volatile ("movsd %0, %%xmm6\n" :: "m" (ctx->xmm[6]));
asm volatile ("movsd %0, %%xmm7\n" :: "m" (ctx->xmm[7]));
}

#define R_OFFSET_POS 2
#define PUSH_IDX_POS 1
#define JMP_OFS_POS 7
Expand Down
4 changes: 4 additions & 0 deletions cmd-record.c
Original file line number Diff line number Diff line change
Expand Up @@ -1845,6 +1845,10 @@ int command_record(int argc, char *argv[], struct opts *opts)

check_binary(opts);

/* apply script-provided options */
if (opts->script_file)
parse_script_opt(opts);

has_perf_event = check_linux_perf_event(opts->event);

fflush(stdout);
Expand Down
62 changes: 42 additions & 20 deletions cmd-script.c
Original file line number Diff line number Diff line change
Expand Up @@ -53,17 +53,26 @@ static int run_script_for_rstack(struct ftrace_file_handle *handle,
fstack = &task->func_stack[task->stack_count - 1];
fstack_update(UFTRACE_ENTRY, task, fstack);

/* setup arguments for script execution */
struct script_args sc_args = {
.tid = task->tid,
.depth = depth, /* display depth */
if (!script_match_filter(symname))
goto out;

/* setup context for script execution */
struct script_context sc_ctx = {
.tid = task->tid,
.depth = depth, /* display depth */
.timestamp = rstack->time,
.address = rstack->addr,
.symname = symname,
.address = rstack->addr,
.name = symname,
};

if (tr.flags & TRIGGER_FL_ARGUMENT) {
sc_ctx.argbuf = task->args.data;
sc_ctx.arglen = task->args.len;
sc_ctx.argspec = task->args.args;
}

/* script hooking for function entry */
script_uftrace_entry(&sc_args);
script_uftrace_entry(&sc_ctx);
}
else if (rstack->type == UFTRACE_EXIT) {
struct fstack *fstack;
Expand All @@ -74,24 +83,35 @@ static int run_script_for_rstack(struct ftrace_file_handle *handle,
if (!(fstack->flags & FSTACK_FL_NORECORD) && fstack_enabled) {
int depth = fstack_update(UFTRACE_EXIT, task, fstack);

if (!script_match_filter(symname)) {
fstack_exit(task);
goto out;
}

/* display depth is set before passing rstack */
rstack->depth = depth;

/* setup context for script execution */
struct script_context sc_ctx = {
.tid = task->tid,
.depth = rstack->depth,
.timestamp = rstack->time,
.duration = fstack->total_time,
.address = rstack->addr,
.name = symname,
};

if (rstack->more) {
sc_ctx.argbuf = task->args.data;
sc_ctx.arglen = task->args.len;
sc_ctx.argspec = task->args.args;
}

/* script hooking for function exit */
script_uftrace_exit(&sc_ctx);
}

fstack_exit(task);

/* setup arguments for script execution */
struct script_args sc_args = {
.tid = task->tid,
.depth = rstack->depth,
.timestamp = rstack->time,
.duration = fstack->total_time,
.address = rstack->addr,
.symname = symname,
};

/* script hooking for function exit */
script_uftrace_exit(&sc_args);
}
else if (rstack->type == UFTRACE_LOST) {
/* Do nothing as of now */
Expand Down Expand Up @@ -158,6 +178,8 @@ int command_script(int argc, char *argv[], struct opts *opts)
/* dtor for script support */
script_uftrace_end();

script_finish();

close_data_file(opts, &handle);

return ret;
Expand Down
66 changes: 50 additions & 16 deletions doc/uftrace-script.md
Original file line number Diff line number Diff line change
Expand Up @@ -54,27 +54,29 @@ The user can write four functions. 'uftrace_entry' and 'uftrace_exit' are execut
def uftrace_begin():
print("program begins...")

def uftrace_entry(args):
_symname = args["symname"]
print("entry : " + _symname + "()")
def uftrace_entry(ctx):
func = ctx["name"]
print("entry : " + func + "()")

def uftrace_exit(args):
_symname = args["symname"]
print("exit : " + _symname + "()")
def uftrace_exit(ctx):
func = ctx["name"]
print("exit : " + func + "()")

def uftrace_end():
print("program is finished")

The 'args' variable is a dictionary type that contains the below information.

/* argument information passed to script */
struct script_args {
int tid;
int depth;
uint64_t timestamp;
uint64_t duration; /* exit only */
unsigned long address;
char *symname;
The 'ctx' variable is a dictionary type that contains the below information.

/* context information passed to script */
script_context = {
int tid;
int depth;
long timestamp;
long duration; # exit only
long address;
string name;
list args; # entry only (if available)
value retval; # exit only (if available)
};

The above script can be executed while reading the recorded data. The usage is as follows:
Expand Down Expand Up @@ -112,6 +114,38 @@ The below is another example that shows the different output compared to previou

The python script above can be modified to do more output customization.

The python script can have an optional "UFTRACE_FUNCS" list which can have name (or regex pattern) of functions to run the script. If it exists, only matched functions will run the script. For example, if you add following lines to the script, it will run only for functions with a single letter name.

$ echo 'UFTRACE_FUNCS = [ "^.$" ]' >> replay.py
$ uftrace script -S replay.py
# DURATION TID FUNCTION
[25794] | a() {
[25794] | b() {
[25794] | c() {
44.752 us [25794] | } /* c */
70.924 us [25794] | } /* b */
98.191 us [25794] | } /* a */

Also script can have options for record if it requires some form of data (i.e. function argument or return value). A comment line started with "uftrace-option:" will provide (a part of) such options when recording.

$ cat arg.py
#
# uftrace-option: -A a@arg1 -R b@retval
#
def uftrace_entry(ctx):
if "args" in ctx:
print(ctx["name"] + " has args")
def uftrace_exit(ctx):
if "retval" in ctx:
print(ctx["name"] + " has retval")

$ uftrace record -S arg.py abc
a has args
b has retval
$ uftrace script -S arg.py
a has args
b has retval


SEE ALSO
========
Expand Down
81 changes: 63 additions & 18 deletions libmcount/mcount.c
Original file line number Diff line number Diff line change
Expand Up @@ -400,6 +400,8 @@ bool mcount_check_rstack(struct mcount_thread_data *mtdp)
}

#ifndef DISABLE_MCOUNT_FILTER
extern void * get_argbuf(struct mcount_thread_data *, struct mcount_ret_stack *);

/* update filter state from trigger result */
enum filter_result mcount_entry_filter_check(struct mcount_thread_data *mtdp,
unsigned long child,
Expand Down Expand Up @@ -543,14 +545,35 @@ void mcount_entry_filter_record(struct mcount_thread_data *mtdp,
unsigned long entry_addr = rstack->child_ip;
struct sym *sym = find_symtabs(&symtabs, entry_addr);
char *symname = symbol_getname(sym, entry_addr);
struct script_args sc_args = {
.tid = gettid(mtdp),
.depth = rstack->depth,
.timestamp = rstack->start_time,
.address = entry_addr,
.symname = symname,
};
script_uftrace_entry(&sc_args);
struct script_context sc_ctx;

if (!script_match_filter(symname))
goto skip;

sc_ctx.tid = gettid(mtdp);
sc_ctx.depth = rstack->depth;
sc_ctx.timestamp = rstack->start_time;
sc_ctx.address = entry_addr;
sc_ctx.name = symname;

if (tr->flags & TRIGGER_FL_ARGUMENT) {
unsigned *argbuf = get_argbuf(mtdp, rstack);

sc_ctx.arglen = argbuf[0];
sc_ctx.argbuf = &argbuf[1];
sc_ctx.argspec = tr->pargs;
}
else {
/* prevent access to arguments */
sc_ctx.arglen = 0;
}

/* accessing argument in script might change arch-context */
mcount_save_arch_context(&mtdp->arch);
script_uftrace_entry(&sc_ctx);
mcount_restore_arch_context(&mtdp->arch);

skip:
symbol_putname(sym, symname);
}

Expand Down Expand Up @@ -615,19 +638,39 @@ void mcount_exit_filter_record(struct mcount_thread_data *mtdp,

/* script hooking for function exit */
if (SCRIPT_ENABLED && script_str) {
uint64_t duration = rstack->end_time - rstack->start_time;
unsigned long entry_addr = rstack->child_ip;
struct sym *sym = find_symtabs(&symtabs, entry_addr);
char *symname = symbol_getname(sym, entry_addr);
struct script_args sc_args = {
.tid = gettid(mtdp),
.depth = rstack->depth,
.timestamp = rstack->end_time,
.duration = duration,
.address = entry_addr,
.symname = symname,
};
script_uftrace_exit(&sc_args);
struct script_context sc_ctx;

if (!script_match_filter(symname))
goto skip;

sc_ctx.tid = gettid(mtdp);
sc_ctx.depth = rstack->depth;
sc_ctx.timestamp = rstack->start_time;
sc_ctx.duration = rstack->end_time - rstack->start_time;
sc_ctx.address = entry_addr;
sc_ctx.name = symname;

if (rstack->flags & MCOUNT_FL_RETVAL) {
unsigned *argbuf = get_argbuf(mtdp, rstack);

sc_ctx.arglen = argbuf[0];
sc_ctx.argbuf = &argbuf[1];
sc_ctx.argspec = rstack->pargs;
}
else {
/* prevent access to retval*/
sc_ctx.arglen = 0;
}

/* accessing argument in script might change arch-context */
mcount_save_arch_context(&mtdp->arch);
script_uftrace_exit(&sc_ctx);
mcount_restore_arch_context(&mtdp->arch);

skip:
symbol_putname(sym, symname);
}
}
Expand Down Expand Up @@ -1294,6 +1337,8 @@ static void mcount_cleanup(void)
#ifndef DISABLE_MCOUNT_FILTER
ftrace_cleanup_filter(&mcount_triggers);
#endif
if (SCRIPT_ENABLED && script_str)
script_finish();

unload_symtabs(&symtabs);
}
Expand Down
Loading

0 comments on commit 66d5e54

Please sign in to comment.