dynamic tracing without compiler support #281
Comments
ParkHanbum
changed the title
|
@ParkHanbum thanks for suggestion. I need more survey on existing dynamic instrumentation engines, but I'm also considering the second option. In our case, we don't need to do full CFG analysis since only a few of prologue instructions will be instrumented. |
|
@namhyung so, I feel needs about CFG... did you have approaches for it? |
namhyung
changed the title
|
A prologue is a sequence of instructions to setup necessary data at the beginning of a function. Please see the wikipedia page. |
|
@namhyung I know but as I say it does not made always. is it right? |
|
Well, uftrace only needs first few instructions to put a call instruction anyway. |
|
if we can assume that start point of function, maybe we can instrument at the correct position. but without compiler supporting, there is some variable. in my opinion, it is hard to find the start of function perfectly. because prologue of function is not necessary always, if so we can not assume the start point of function. and The situation I suppose is without any debugging symbol. it makes hard to assume that, too. for that reason, maybe pre/post call instruction is better point for instrumentation. |
Did you mean the binary doesn't have symbol table? I'll just give up then.
What is pre/post call instruction? |
|
@namhyung I think that is the better point to instrumentation when debugging symbols does not exist. |
|
I don't understand what you try to do. Why not adding calls to mcount at the function prologue? Adding instrumentation code in the middle of body would be difficult and unsafe IMO. |
|
@namhyung for now, I will try inject instrumentation point at prologue of function like as you say, first. if anyone have not try this now. |
|
What do you mean by debugging symbols - debug info? or symbol table? Anyway, it'd be really really great if we could trace binary without recompilation. I plan to try it but I have things to do before that. Please feel free to share your design and implementation as early as possible though. |
|
maybe this repository would helpful for this issue. I'll comment mechanism of ftrace, as soon as possible. |
|
At a glance, it seems to use |
|
@namhyung but if need that, maybe there is a way for reduce the part of ptrace. |
|
Sorry for late reply. I want to avoid ptrace for a performance reason and don't want to stop process execution as well. It could execute some more instructions but should not be stopped IMO. |
|
@namhyung I think this way is best. if you have a better idea or approach, please let me know. |
|
Ah right, for the injection, it needs ptrace. I meant that it should not use ptrace for tracing after the injection. |
|
I was success to inject libmcount module to running process at x86 64bit. just a prototype as proof a concept. still a long way to go. but for notice, I have left this comment. |
|
@ParkHanbum Cool!! |
|
@ParkHanbum Looks very cool! |
|
we had tried dynamic tracing without compiler support feature by using breakpoint and sighandler. to explain : that result is here : |
UPDATEI was make simple ppt to explain dynamic instrumation. CODElink : https://github.com/ParkHanbum/uftrace/commits/dynamic_trace_2 RESTRICTIONFor dynamic instrumentation, we need 6 bytes of space to patch from the function prologue. |
|
link is broken |
|
I revived the Hanbum's work (#588) and pushed to review/dynamic-trace-v1. I tried to keep original patches with small coding-style changes and added my changed on top. Notable change is using separate mmap area for saved (original) instructions. It works for the simplest cases on my machine and I'd like to improve it incrementally. But strangely, it sometimes runs very slow. Also I didn't test it much so please play with it together. :) |
|
With below change, it can trace more functions. Rational is to allow memory access unless it's PC-relative. diff --git a/arch/x86_64/mcount-dynamic.c b/arch/x86_64/mcount-dynamic.c
index baab770c..23219e22 100644
--- a/arch/x86_64/mcount-dynamic.c
+++ b/arch/x86_64/mcount-dynamic.c
@@ -484,25 +484,12 @@ static int check_instrumentable(csh ud, cs_insn *ins)
status = CODE_PATCH_OK;
break;
case X86_OP_MEM:
- // temporary till discover possibility of x86 instructions.
- status = CODE_PATCH_NO;
-
- if (op->mem.segment != X86_REG_INVALID)
- pr_dbg2("\t\t\toperands[%u].mem.segment: REG = %s\n",
- i, cs_reg_name(handle, op->mem.segment));
- if (op->mem.base != X86_REG_INVALID)
- pr_dbg2("\t\t\toperands[%u].mem.base: REG = %s\n",
- i, cs_reg_name(handle, op->mem.base));
- if (op->mem.index != X86_REG_INVALID)
- pr_dbg2("\t\t\toperands[%u].mem.index: REG = %s\n",
- i, cs_reg_name(handle, op->mem.index));
- if (op->mem.scale != 1)
- pr_dbg2("\t\t\toperands[%u].mem.scale: %u\n",
- i, op->mem.scale);
- if (op->mem.disp != 0)
- pr_dbg2("\t\t\toperands[%u].mem.disp: 0x%" PRIx64 "\n",
- i, op->mem.disp);
- return status;
+ if (op->mem.base == X86_REG_RIP ||
+ op->mem.index == X86_REG_RIP)
+ return CODE_PATCH_NO;
+
+ status = CODE_PATCH_OK;
+ break;
default:
break;
} |
|
Thank you for the work. I just tested it with uftrace itself, but it crashes as follows: |
|
The gdb example still crashes same as before: |
|
chrome still has the same problem. |
|
gdb is crashed even only with Here is more verbose message. 00000000040b780 <main>:
40b780: 48 83 ec 28 sub $0x28,%rsp
40b784: 48 c7 04 24 00 00 00 movq $0x0,(%rsp)
40b78b: 00
40b78c: 89 3c 24 mov %edi,(%rsp)
40b78f: 48 89 e7 mov %rsp,%rdi
40b792: 48 89 74 24 08 mov %rsi,0x8(%rsp)
40b797: 48 c7 44 24 10 a4 28 movq $0x7828a4,0x10(%rsp)
40b79e: 78 00
40b7a0: e8 bb 2c 17 00 callq 57e460 <gdb_main(captured_main_args*)>
40b7a5: 48 83 c4 28 add $0x28,%rsp
40b7a9: c3 retq
40b7aa: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1) |
|
It seems that almost every function makes the problem. 00000000005c6320 <make_command_stats_cleanup(int)>:
5c6320: 55 push %rbp
5c6321: 89 fd mov %edi,%ebp
5c6323: 53 push %rbx
5c6324: 48 83 ec 18 sub $0x18,%rsp
5c6328: 85 ff test %edi,%edi
5c632a: 0f 84 a8 00 00 00 je 5c63d8 <make_command_stats_cleanup(int)+0xb8>
5c6330: 44 8b 05 69 2d 69 00 mov 0x692d69(%rip),%r8d # c590a0 <per_command_time>
5c6337: 45 85 c0 test %r8d,%r8d
5c633a: 75 18 jne 5c6354 <make_command_stats_cleanup(int)+0x34>
5c633c: 8b 3d 5a 2d 69 00 mov 0x692d5a(%rip),%edi # c5909c <per_command_space>
5c6342: 85 ff test %edi,%edi
5c6344: 75 0e jne 5c6354 <make_command_stats_cleanup(int)+0x34>
5c6346: 8b 35 4c 2d 69 00 mov 0x692d4c(%rip),%esi # c59098 <per_command_symtab>
5c634c: 85 f6 test %esi,%esi
...Hmm.. the following case for 00000000057c5c0 <notice_open_fds()>:
57c5c0: bf 40 c5 57 00 mov $0x57c540,%edi
57c5c5: e9 26 fe ff ff jmpq 57c3f0 <fdwalk(int (*)(void*, int), void*) [clone .constprop.0]>
57c5ca: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1)
...
000000000057c3f0 <fdwalk(int (*)(void*, int), void*) [clone .constprop.0]>:
57c3f0: 41 56 push %r14
57c3f2: 49 89 fe mov %rdi,%r14
57c3f5: bf 54 d1 7f 00 mov $0x7fd154,%edi
57c3fa: 41 55 push %r13
57c3fc: 41 54 push %r12
57c3fe: 55 push %rbp
57c3ff: 53 push %rbx
57c400: 48 81 ec a0 00 00 00 sub $0xa0,%rsp
57c407: e8 34 cd e8 ff callq 409140 <opendir@plt>
57c40c: 48 85 c0 test %rax,%rax
57c40f: 49 89 c4 mov %rax,%r12
... |
|
I don't know why the following change is included in the commit for test.
diff --git a/arch/x86_64/mcount-insn.c b/arch/x86_64/mcount-insn.c
index c81c710..9558e3d 100644
--- a/arch/x86_64/mcount-insn.c
+++ b/arch/x86_64/mcount-insn.c
@@ -155,7 +155,7 @@ int disasm_check_insns(struct mcount_disasm_engine *disasm,
}
}
- while (i < count) {
+ while (++i < count) {
if (check_unsupported(disasm, &insn[i], addr, code_size) == CODE_PATCH_NO) {
ret = INSTRUMENT_FAILED;
break;It's better to be included in the previous commit. |
|
I would like to have the following change for better understanding the details. diff --git a/arch/x86_64/mcount-dynamic.c b/arch/x86_64/mcount-dynamic.c
index a40f3c2..bb1a462 100644
--- a/arch/x86_64/mcount-dynamic.c
+++ b/arch/x86_64/mcount-dynamic.c
@@ -423,8 +423,8 @@ static int patch_normal_func(struct mcount_dynamic_info *mdi, struct sym *sym,
if (instr_size < CALL_INSN_SIZE)
return instr_size;
- pr_dbg2("patch normal func: %s (patch size: %d)\n",
- sym->name, instr_size);
+ pr_dbg2("patch normal func \"%s\": %d bytes from %#x to %#x\n",
+ sym->name, instr_size, sym->addr, sym->addr + instr_size - 1);
/*
* stored origin instruction block:
diff --git a/libmcount/dynamic.c b/libmcount/dynamic.c
index 90a6dfb..c33ac45 100644
--- a/libmcount/dynamic.c
+++ b/libmcount/dynamic.c
@@ -288,6 +288,9 @@ static int do_dynamic_update(struct symtabs *symtabs, char *patch_funcs,
pr_out("uftrace: some functions cannot be patched dynamically (%d/%d)\n",
stats.total - (stats.failed + stats.skipped), stats.total);
}
+ else {
+ pr_out("uftrace: %d function(s) are dynamically patched\n", stats.total);
+ }
strv_free(&funcs);
return 0; |
|
Ah.. It's not a problem of dynamic tracing. It seems that gdb internally triggers some diff --git a/libmcount/mcount.c b/libmcount/mcount.c
index 3d2cd8e..fd47cf9 100644
--- a/libmcount/mcount.c
+++ b/libmcount/mcount.c
@@ -747,8 +747,8 @@ static void mcount_init_file(void)
SESSION_ID_LEN, mcount_session_name(), basename(mcount_exename));
sigemptyset(&sa.sa_mask);
- sigaction(SIGABRT, &sa, &old_sigact[0]);
- sigaction(SIGSEGV, &sa, &old_sigact[1]);
+// sigaction(SIGABRT, &sa, &old_sigact[0]);
+// sigaction(SIGSEGV, &sa, &old_sigact[1]);
}
struct mcount_thread_data * mcount_prepare(void)Then the problem is gone and works fine. |
|
In the previous crashed backtrace, it shows The problematic code in gdb is as follows: #ifdef HAVE_SIGACTION
static struct sigaction original_signal_actions[NSIG];
/* Note that we use sigprocmask without worrying about threads because
the save/restore functions are called either from main, or after a
fork. In both cases, we know the calling process is single
threaded. */
static sigset_t original_signal_mask;
#endif
void save_original_signals_state (void)
{
#ifdef HAVE_SIGACTION
int i;
int res;
res = sigprocmask (0, NULL, &original_signal_mask);
if (res == -1)
perror_with_name (("sigprocmask"));
for (i = 1; i < NSIG; i++)
{
struct sigaction *oldact = &original_signal_actions[i];
res = sigaction (i, NULL, oldact);
if (res == -1 && errno == EINVAL)
{
/* Some signal numbers in the range are invalid. */
continue;
}
else if (res == -1)
perror_with_name (("sigaction"));
/* If we find a custom signal handler already installed, then
this function was called too late. */
if (oldact->sa_handler != SIG_DFL && oldact->sa_handler != SIG_IGN)
internal_error (__FILE__, __LINE__, _("unexpected signal handler"));
}
#endif
}It seems to be a pair with void restore_original_signals_state (void)
{
#ifdef HAVE_SIGACTION
int i;
int res;
for (i = 1; i < NSIG; i++)
{
res = sigaction (i, &original_signal_actions[i], NULL);
if (res == -1 && errno == EINVAL)
{
/* Some signal numbers in the range are invalid. */
continue;
}
else if (res == -1)
perror_with_name (("sigaction"));
}
res = sigprocmask (SIG_SETMASK, &original_signal_mask, NULL);
if (res == -1)
perror_with_name (("sigprocmask"));
#endif
} |
Yes, that's my fault. Will move.
Thanks for the analysis! That's good to know. We may provide an option to suppress signal handling. Now it seems good to merge this series... |
|
I'm thinking of adding this code instead. Note that it's changed from diff --git a/libmcount/dynamic.c b/libmcount/dynamic.c
index 5c917a6..1656754 100644
--- a/libmcount/dynamic.c
+++ b/libmcount/dynamic.c
@@ -285,7 +285,8 @@ static int do_dynamic_update(struct symtabs *symtabs, char *patch_funcs,
}
if (stats.failed || stats.skipped || stats.nomatch) {
- pr_out("uftrace: some functions cannot be patched dynamically (%d/%d)\n",
+ pr_dbg("uftrace: failed to patch some functions in '%s' (%d/%d)\n",
+ basename(symtabs->filename),
stats.total - (stats.failed + stats.skipped), stats.total);
}
|
|
I think we better show the debug message without if condition check. Even if every function is patched, I may be curious how many functions are patched. |
I also agree. :) |
It’s not correct. As shown in the below code, gdb doesn’t allow custom signal handlers previously registered. for (i = 1; i < NSIG; i++)
{
struct sigaction *oldact = &original_signal_actions[i];
res = sigaction (i, NULL, oldact);
...
/* If we find a custom signal handler already installed, then
this function was called too late. */
if (oldact->sa_handler != SIG_DFL && oldact->sa_handler != SIG_IGN)
internal_error (__FILE__, __LINE__, _("unexpected signal handler"));
}I’m not sure if we can wrap the |
|
It may not be really needed but We must not dynamically patch some functions in |
it was finished when I use option to specific uftrace data path. maybe it occurred because it associated with stream channel |
|
@ParkHanbum Thanks. It works in my environment as well when |
|
Pushed review/dynamic-trace-v9 Changelog:
|
|
Thanks for the update! I found a very weird use case as follows: It seems that the tracing target uftrace received environmental variable passed by The uftrace record for uftrace record is fine anyway. |
|
The above is a different issue. I think it almost looks good and I agree to merge this into master. We may be able to enhance it in the next patches. I think we could somehow handle |
|
Here is the trace dump of Thanks for doing this great work @ParkHanbum and @namhyung! |
|
Please add the following change as well for easier installation. diff --git a/misc/install-deps.sh b/misc/install-deps.sh
index a1b01d96..62e084ac 100755
--- a/misc/install-deps.sh
+++ b/misc/install-deps.sh
@@ -13,12 +13,12 @@ distro=$(grep "^ID=" /etc/os-release | cut -d\= -f2 | sed -e 's/"//g')
case $distro in
"ubuntu" | "debian")
- apt-get $OPT install pandoc libdw-dev libpython2.7-dev libncursesw5-dev pkg-config ;;
+ apt-get $OPT install pandoc libdw-dev libpython2.7-dev libncursesw5-dev libcapstone-dev pkg-config ;;
"fedora")
- dnf install $OPT pandoc elfutils-devel python2-devel ncurses-devel pkgconf-pkg-config ;;
+ dnf install $OPT pandoc elfutils-devel python2-devel ncurses-devel capstone-devel pkgconf-pkg-config ;;
"rhel" | "centos")
rpm -ivh https://dl.fedoraproject.org/pub/epel/epel-release-latest-7.noarch.rpm
- yum install $OPT pandoc elfutils-devel python2-devel ncurses-devel pkgconfig ;;
+ yum install $OPT pandoc elfutils-devel python2-devel ncurses-devel capstone-devel pkgconfig ;;
*) # we can add more install command for each distros.
echo "\"$distro\" is not supported distro, so please install packages manually." ;;
esacConfirmed in Ubuntu and Fedora, but hope it to be correct in RHEL/CentOS. |
|
Good, can I add your signed-off? |
|
Sure. Please do that. Thanks. |
|
Thanks very much! We better update dynamic tracing section in the man page before making a release. |
currently uftrace use instrumentation feature that supported by compiler. but this dependency cause another dependency, for example a user who want use uftrace need knowledge of build system by reason of must rebuild binary with special compile option for using uftrace.
so, I think if we can support the instrumentation feature without any dependency, that is great useful.
in my opinion, there is two approach for that.
first, maybe we can use dynamic instrumentation engine like dynamoRIO. maybe you guys know about dynamic instrumentation already, so I'm summary this to 3 line.
second, build binary rewriting engine for inject instrumentation point(static or dynamic).
how do you think?
The text was updated successfully, but these errors were encountered: