diff --git a/drltrace_src/CMakeLists.txt b/drltrace_src/CMakeLists.txt index 7ee46e0..327dc33 100644 --- a/drltrace_src/CMakeLists.txt +++ b/drltrace_src/CMakeLists.txt @@ -294,7 +294,8 @@ set(srcs drltrace.cpp drltrace_libcalls.cpp drltrace_options.cpp - drltrace_utils.cpp) + drltrace_utils.cpp + drltrace_retval_cache.cpp) set(DynamoRIO_USE_LIBC OFF) diff --git a/drltrace_src/drltrace.cpp b/drltrace_src/drltrace.cpp index d8959c0..366f265 100644 --- a/drltrace_src/drltrace.cpp +++ b/drltrace_src/drltrace.cpp @@ -39,8 +39,10 @@ */ #include #include +#include #include "drltrace.h" #include "drltrace_utils.h" +#include "drltrace_retval_cache.h" /* Where to write the trace */ static file_t outf; @@ -74,77 +76,92 @@ static std::vector filter_module_whitelist; static std::vector filter_module_blacklist; - /**************************************************************************** * Arguments printing */ static void -print_simple_value(drltrace_arg_t *arg, bool leading_zeroes) +get_simple_value(char *out, size_t out_size, drltrace_arg_t *arg, bool leading_zeroes) { bool pointer = !TEST(DRSYS_PARAM_INLINED, arg->mode); - dr_fprintf(outf, pointer ? PFX : (leading_zeroes ? PFX : PIFX), arg->value); + char temp[256]; + snprintf(temp, sizeof(temp) - 1, pointer ? PFX : (leading_zeroes ? PFX : PIFX), arg->value); + strncat(out, temp, out_size - 1); if (pointer && ((arg->pre && TEST(DRSYS_PARAM_IN, arg->mode)) || (!arg->pre && TEST(DRSYS_PARAM_OUT, arg->mode)))) { ptr_uint_t deref = 0; ASSERT(arg->size <= sizeof(deref), "too-big simple type"); /* We assume little-endian */ - if (dr_safe_read((void *)arg->value, arg->size, &deref, NULL)) - dr_fprintf(outf, (leading_zeroes ? " => " PFX : " => " PIFX), deref); + if (dr_safe_read((void *)arg->value, arg->size, &deref, NULL)) { + snprintf(temp, sizeof(temp) - 1, (leading_zeroes ? " => " PFX : " => " PIFX), deref); + strncat(out, temp, out_size - 1); + } } } static void -print_string(void *drcontext, void *pointer_str, bool is_wide) +get_string(char *out, size_t out_size, void *drcontext, void *pointer_str, bool is_wide) { if (pointer_str == NULL) - dr_fprintf(outf, ""); + strncat(out, "", out_size - 1); else { DR_TRY_EXCEPT(drcontext, { - dr_fprintf(outf, is_wide ? "%S" : "%s", pointer_str); + char temp[256]; + if (is_wide) + snprintf(temp, sizeof(temp) - 1, "0x%"PRIxPTR":\"%S\"", (uintptr_t)pointer_str, (wchar_t *)pointer_str); + else + snprintf(temp, sizeof(temp) - 1, "0x%"PRIxPTR":\"%s\"", (uintptr_t)pointer_str, (char *)pointer_str); + + strncat(out, temp, out_size - 1); }, { - dr_fprintf(outf, ""); + strncat(out, "", out_size - 1); }); } } static void -print_arg(void *drcontext, drltrace_arg_t *arg) +get_arg(char *out, size_t out_size, void *drcontext, drltrace_arg_t *arg) { if (arg->pre && (TEST(DRSYS_PARAM_OUT, arg->mode) && !TEST(DRSYS_PARAM_IN, arg->mode))) return; - dr_fprintf(outf, "%s%d: ", (op_grepable.get_value() ? " {" : "\n arg "), arg->ordinal); + + char temp[384]; + snprintf(temp, sizeof(temp) - 1, "%s%d: ", (op_grepable.get_value() ? " {" : "\n arg "), arg->ordinal); + strncat(out, temp, out_size - 1); + switch (arg->type) { - case DRSYS_TYPE_VOID: print_simple_value(arg, true); break; - case DRSYS_TYPE_POINTER: print_simple_value(arg, true); break; - case DRSYS_TYPE_BOOL: print_simple_value(arg, false); break; - case DRSYS_TYPE_INT: print_simple_value(arg, false); break; - case DRSYS_TYPE_SIGNED_INT: print_simple_value(arg, false); break; - case DRSYS_TYPE_UNSIGNED_INT: print_simple_value(arg, false); break; - case DRSYS_TYPE_HANDLE: print_simple_value(arg, false); break; - case DRSYS_TYPE_NTSTATUS: print_simple_value(arg, false); break; - case DRSYS_TYPE_ATOM: print_simple_value(arg, false); break; + case DRSYS_TYPE_VOID: get_simple_value(out, out_size, arg, true); break; + case DRSYS_TYPE_POINTER: get_simple_value(out, out_size, arg, true); break; + case DRSYS_TYPE_BOOL: get_simple_value(out, out_size, arg, false); break; + case DRSYS_TYPE_INT: get_simple_value(out, out_size, arg, false); break; + case DRSYS_TYPE_SIGNED_INT: get_simple_value(out, out_size, arg, false); break; + case DRSYS_TYPE_UNSIGNED_INT: get_simple_value(out, out_size, arg, false); break; + case DRSYS_TYPE_HANDLE: get_simple_value(out, out_size, arg, false); break; + case DRSYS_TYPE_NTSTATUS: get_simple_value(out, out_size, arg, false); break; + case DRSYS_TYPE_ATOM: get_simple_value(out, out_size, arg, false); break; #ifdef WINDOWS - case DRSYS_TYPE_LCID: print_simple_value(arg, false); break; - case DRSYS_TYPE_LPARAM: print_simple_value(arg, false); break; - case DRSYS_TYPE_SIZE_T: print_simple_value(arg, false); break; - case DRSYS_TYPE_HMODULE: print_simple_value(arg, false); break; + case DRSYS_TYPE_LCID: get_simple_value(out, out_size, arg, false); break; + case DRSYS_TYPE_LPARAM: get_simple_value(out, out_size, arg, false); break; + case DRSYS_TYPE_SIZE_T: get_simple_value(out, out_size, arg, false); break; + case DRSYS_TYPE_HMODULE: get_simple_value(out, out_size, arg, false); break; #endif case DRSYS_TYPE_CSTRING: - print_string(drcontext, (void *)arg->value, false); + get_string(out, out_size, drcontext, (void *)arg->value, false); break; case DRSYS_TYPE_CWSTRING: - print_string(drcontext, (void *)arg->value, true); + get_string(out, out_size, drcontext, (void *)arg->value, true); break; default: { if (arg->value == 0) - dr_fprintf(outf, ""); - else - dr_fprintf(outf, PFX, arg->value); + strncat(out, "", out_size - 1); + else { + snprintf(temp, sizeof(temp), PFX, arg->value); + strncat(out, temp, out_size - 1); + } } } - dr_fprintf(outf, " (%s%s%stype=%s%s, size=" PIFX ")", + snprintf(temp, sizeof(temp) - 1, " (%s%s%stype=%s%s, size=" PIFX ")", (arg->arg_name == NULL) ? "" : "name=", (arg->arg_name == NULL) ? "" : arg->arg_name, (arg->arg_name == NULL) ? "" : ", ", @@ -152,13 +169,14 @@ print_arg(void *drcontext, drltrace_arg_t *arg) (arg->type_name == NULL || TESTANY(DRSYS_PARAM_INLINED|DRSYS_PARAM_RETVAL, arg->mode)) ? "" : "*", arg->size); + strncat(out, temp, out_size - 1); if (op_grepable.get_value()) - dr_fprintf(outf, "}"); + strncat(out, "}", out_size - 1); } static bool -drlib_iter_arg_cb(drltrace_arg_t *arg, void *wrapcxt) +drlib_iter_arg_cb(char *out, size_t out_size, drltrace_arg_t *arg, void *wrapcxt) { if (arg->ordinal == -1) return true; @@ -167,52 +185,56 @@ drlib_iter_arg_cb(drltrace_arg_t *arg, void *wrapcxt) arg->value = (ptr_uint_t)drwrap_get_arg(wrapcxt, arg->ordinal); - print_arg(drwrap_get_drcontext(wrapcxt), arg); + get_arg(out, out_size, drwrap_get_drcontext(wrapcxt), arg); return true; /* keep going */ } static void -print_args_unknown_call(app_pc func, void *wrapcxt) +get_args_unknown_call(char *out, size_t out_size, app_pc func, void *wrapcxt) { uint i; void *drcontext = drwrap_get_drcontext(wrapcxt); - char *prefix = "\n arg "; - char *suffix = ""; + const char *prefix = "\n arg "; + const char *suffix = ""; if (op_grepable.get_value()) { prefix = " {"; suffix = "}"; } DR_TRY_EXCEPT(drcontext, { for (i = 0; i < op_unknown_args.get_value(); i++) { - dr_fprintf(outf, "%s%d: " PFX, prefix, i, - drwrap_get_arg(wrapcxt, i)); - if (*suffix != '\0') - dr_fprintf(outf, suffix); + char temp[256]; + snprintf(temp, sizeof(temp) - 1, "%s%d: " PFX, prefix, i, (long unsigned int)drwrap_get_arg(wrapcxt, i)); + strncat(out, temp, out_size - 1); + if (*suffix != '\0') + strncat(out, suffix, out_size - 1); } }, { - dr_fprintf(outf, ""); + strncat(out, "", out_size - 1); /* Just keep going */ }); /* all args have been sucessfully printed */ - dr_fprintf(outf, op_print_ret_addr.get_value() ? "\n ": ""); + if (op_print_ret_addr.get_value()) + strncat(out, "\n ", out_size - 1); } static bool -print_libcall_args(std::vector *args_vec, void *wrapcxt) +get_libcall_args(char *out, size_t out_size, drsys_param_type_t *retval_type, std::vector *args_vec, void *wrapcxt) { if (args_vec == NULL || args_vec->size() <= 0) return false; std::vector::iterator it; for (it = args_vec->begin(); it != args_vec->end(); ++it) { - if (!drlib_iter_arg_cb(*it, wrapcxt)) - break; + if (it == args_vec->begin()) + *retval_type = (*it)->type; + else if (!drlib_iter_arg_cb(out, out_size, *it, wrapcxt)) + break; } return true; } static void -print_symbolic_args(const char *name, void *wrapcxt, app_pc func) +get_symbolic_args(char *out, size_t out_size, drsys_param_type_t *retval_type, const char *name, void *wrapcxt, app_pc func) { std::vector *args_vec; @@ -222,14 +244,58 @@ print_symbolic_args(const char *name, void *wrapcxt, app_pc func) if (op_use_config.get_value()) { /* looking for libcall in libcalls hashtable */ args_vec = libcalls_search(name); - if (print_libcall_args(args_vec, wrapcxt)) { - dr_fprintf(outf, op_print_ret_addr.get_value() ? "\n " : ""); - return; /* we found libcall and sucessfully printed all arguments */ + if (get_libcall_args(out, out_size, retval_type, args_vec, wrapcxt)) { + if (op_print_ret_addr.get_value()) { + strncat(out, "\n ", out_size - 1); + } + return; /* we found libcall and sucessfully printed all arguments */ } } /* use standard type-blind scheme */ if (op_unknown_args.get_value() > 0) - print_args_unknown_call(func, wrapcxt); + get_args_unknown_call(out, out_size, func, wrapcxt); +} + +/* Puts "module_name!function_name" into the module_and_function_name output buffer. + * Returns the number of characters written. */ +inline int +get_module_and_function_name(char *module_and_function_name, \ + size_t module_and_function_name_len, \ + const char *function_name, \ + void *wrapcxt) { + int ret; + const char *modname = NULL; + /* XXX: it may be better to heap-allocate the "module!func" string and + * pass in, to avoid this lookup. + */ + module_data_t *mod = dr_lookup_module(drwrap_get_func(wrapcxt)); + if (mod != NULL) + modname = dr_module_preferred_name(mod); + if (modname == NULL) + modname = ""; + + ret = snprintf(module_and_function_name, \ + module_and_function_name_len - 1, "%s%s%s", \ + modname == NULL ? "" : modname, modname == NULL ? "" : "!", function_name); + + if (mod != NULL) + dr_free_module_data(mod); + + return ret; +} + +/* Places the thread ID tag into the buffer, then returns its length. */ +inline unsigned int +get_thread_id_tag(char *out, size_t out_size, void *drcontext) { + thread_id_t tid = INVALID_THREAD_ID; + if (drcontext != NULL) + tid = dr_get_thread_id(drcontext); + if (tid != INVALID_THREAD_ID) + return (unsigned int)snprintf(out, out_size - 1, "~~%d~~ ", tid); + else { + strncpy(out, "~~Dr.L~~ ", out_size - 1); + return 9; + } } /**************************************************************************** @@ -239,16 +305,14 @@ print_symbolic_args(const char *name, void *wrapcxt, app_pc func) static void lib_entry(void *wrapcxt, INOUT void **user_data) { - const char *name = (const char *) *user_data; + const char *function_name = (const char *) *user_data; + + skip_unstable_functions(function_name); + const char *modname = NULL; app_pc func = drwrap_get_func(wrapcxt); - module_data_t *mod; - thread_id_t tid; - uint mod_id; - app_pc mod_start, ret_addr; - drcovlib_status_t res; - void *drcontext = drwrap_get_drcontext(wrapcxt); + thread_id_t tid = dr_get_thread_id(drcontext); if (op_only_from_app.get_value()) { /* For just this option, the modxfer approach might be better */ @@ -259,7 +323,7 @@ lib_entry(void *wrapcxt, INOUT void **user_data) retaddr = NULL; }); if (retaddr != NULL) { - mod = dr_lookup_module(retaddr); + module_data_t *mod = dr_lookup_module(retaddr); if (mod != NULL) { bool from_exe = (mod->start == exe_start); dr_free_module_data(mod); @@ -275,26 +339,13 @@ lib_entry(void *wrapcxt, INOUT void **user_data) return; } } - /* XXX: it may be better to heap-allocate the "module!func" string and - * pass in, to avoid this lookup. - */ - mod = dr_lookup_module(func); - if (mod != NULL) - modname = dr_module_preferred_name(mod); /* Build the module & function string, then compare to the white/black * list. */ - char module_name[256]; - memset(module_name, 0, sizeof(module_name)); - - /* Temporary workaround for VC2013, which doesn't have snprintf(). - * apparently, this was added in later releases... */ -#ifdef WINDOWS -#define snprintf _snprintf -#endif - unsigned int module_name_len = (unsigned int)snprintf(module_name, \ - sizeof(module_name) - 1, "%s%s%s", modname == NULL ? "" : modname, \ - modname == NULL ? "" : "!", name); + char module_and_function_name[256]; + size_t module_and_function_name_len = \ + get_module_and_function_name(module_and_function_name, \ + sizeof(module_and_function_name), function_name, wrapcxt); /* Check if this module & function is in the whitelist. */ bool allowed = false; @@ -304,14 +355,14 @@ lib_entry(void *wrapcxt, INOUT void **user_data) /* If the whitelist entry contains a wildcard, then compare only the shortest * part of either string. */ - unsigned int module_name_len_compare; + unsigned int len_compare; if (filter_function_whitelist[i].is_wildcard) - module_name_len_compare = MIN(module_name_len, \ + len_compare = MIN(module_and_function_name_len, \ filter_function_whitelist[i].func_name_len); else - module_name_len_compare = module_name_len; + len_compare = module_and_function_name_len; - if (fast_strcmp(module_name, module_name_len_compare, \ + if (fast_strcmp(module_and_function_name, len_compare, \ filter_function_whitelist[i].func_name, \ filter_function_whitelist[i].func_name_len) == 0) { allowed = true; @@ -326,14 +377,14 @@ lib_entry(void *wrapcxt, INOUT void **user_data) /* If the blacklist entry contains a wildcard, then compare only the shortest * part of either string. */ - unsigned int module_name_len_compare; + unsigned int len_compare; if (filter_function_blacklist[i].is_wildcard) - module_name_len_compare = MIN(module_name_len, \ + len_compare = MIN(module_and_function_name_len, \ filter_function_blacklist[i].func_name_len); else - module_name_len_compare = module_name_len; + len_compare = module_and_function_name_len; - if (fast_strcmp(module_name, module_name_len_compare, \ + if (fast_strcmp(module_and_function_name, len_compare, \ filter_function_blacklist[i].func_name, \ filter_function_blacklist[i].func_name_len) == 0) { allowed = false; @@ -346,34 +397,80 @@ lib_entry(void *wrapcxt, INOUT void **user_data) if (tested && !allowed) return; - tid = dr_get_thread_id(drcontext); - if (tid != INVALID_THREAD_ID) - dr_fprintf(outf, "~~%d~~ ", tid); - else - dr_fprintf(outf, "~~Dr.L~~ "); - dr_fprintf(outf, module_name); + /* Buffer to hold function call and arguments for caching. */ + char out[1024]; + out[ sizeof(out) - 1 ] = '\0'; /* Ensure it remains null-terminated. */ + + unsigned int thread_id_tag_len = get_thread_id_tag(out, sizeof(out) - 1, drcontext); + strncat(out, module_and_function_name, sizeof(out) - 1); /* XXX: We employ two schemes of arguments printing. We are looking for prototypes * in config file specified by user to get symbolic representation of arguments * for known library calls. For the rest of library calls. If there is no info * we employ type-blindprinting and use -num_unknown_args to get a count of arguments - * to print. + * to print. */ - print_symbolic_args(name, wrapcxt, func); + drsys_param_type_t retval_arg = DRSYS_TYPE_UNKNOWN; + get_symbolic_args(out, sizeof(out) - 1, &retval_arg, function_name, wrapcxt, func); + uint mod_id; + app_pc mod_start, ret_addr; + drcovlib_status_t res; if (op_print_ret_addr.get_value()) { - ret_addr = drwrap_get_retaddr(wrapcxt); - res = drmodtrack_lookup(drcontext, ret_addr, &mod_id, &mod_start); - if (res == DRCOVLIB_SUCCESS) { - dr_fprintf(outf, - op_print_ret_addr.get_value() ? - " and return to module id:%d, offset:" PIFX : "", - mod_id, ret_addr - mod_start); - } + ret_addr = drwrap_get_retaddr(wrapcxt); + res = drmodtrack_lookup(drcontext, ret_addr, &mod_id, &mod_start); + if (res == DRCOVLIB_SUCCESS) { + char temp[128]; + snprintf(temp, sizeof(temp) - 1, + op_print_ret_addr.get_value() ? + " and return to module id:%d, offset:" PIFX : "", + mod_id, ret_addr - mod_start); + + strncat(out, temp, sizeof(out) - 1); + } + } + + /* If return value caching is disabled, just print the function out now. */ + if (op_no_retval.get_value()) { + dr_fprintf(outf, "%s", out); + dr_fprintf(outf, "\n"); + + /* Otherwise, cache this function call until the return value is obtained later. */ + } else { + retval_cache_append(drcontext, (unsigned int)tid, retval_arg, \ + module_and_function_name, module_and_function_name_len, out, strlen(out)); } - dr_fprintf(outf, "\n"); - if (mod != NULL) - dr_free_module_data(mod); +} + +/**************************************************************************** + * Library exit wrapping + */ + +static void +lib_exit(void *wrapcxt, void *user_data) +{ + const char *function_name = (const char *)user_data; + void *drcontext = NULL; + unsigned int tid = 0; + void *retval = NULL; + + skip_unstable_functions(function_name); + + if (wrapcxt != NULL) { + drcontext = drwrap_get_drcontext(wrapcxt); + retval = drwrap_get_retval(wrapcxt); + if (drcontext != NULL) + tid = (unsigned int)dr_get_thread_id(drcontext); + } + + char module_and_function_name[256]; + + unsigned int thread_id_tag_len = get_thread_id_tag(module_and_function_name, sizeof(module_and_function_name), drcontext); + + /*size_t module_and_function_name_len =*/ get_module_and_function_name(module_and_function_name + thread_id_tag_len, sizeof(module_and_function_name) - thread_id_tag_len, function_name, wrapcxt); + + /* Set the return value in the cache for this function call. */ + retval_cache_set_return_value(drcontext, tid, module_and_function_name, strlen(module_and_function_name), retval); } static void @@ -405,13 +502,13 @@ iterate_exports(const module_data_t *info, bool add) if (func != NULL) { if (add) { IF_DEBUG(bool ok =) - drwrap_wrap_ex(func, lib_entry, NULL, (void *) sym->name, 0); + drwrap_wrap_ex(func, lib_entry, op_no_retval.get_value() ? NULL : lib_exit, (void *) sym->name, 0); ASSERT(ok, "wrap request failed"); VNOTIFY(2, "wrapping export %s!%s @" PFX NL, dr_module_preferred_name(info), sym->name, func); } else { IF_DEBUG(bool ok =) - drwrap_unwrap(func, lib_entry, NULL); + drwrap_unwrap(func, lib_entry, op_no_retval.get_value() ? NULL : lib_exit); ASSERT(ok, "unwrap request failed"); } } @@ -665,6 +762,10 @@ event_exit(void) if (op_use_config.get_value()) libcalls_hashtable_delete(); + /* Flush any remaining entries in the return value cache. */ + if (!op_no_retval.get_value()) + retval_cache_dump_all(NULL); + if (outf != STDERR) { if (op_print_ret_addr.get_value()) drmodtrack_dump(outf); @@ -674,6 +775,9 @@ event_exit(void) free_wblist_array(&filter_function_whitelist, filter_function_whitelist_len); free_wblist_array(&filter_function_blacklist, filter_function_blacklist_len); + if (!op_no_retval.get_value()) + retval_cache_free(); + drx_exit(); drwrap_exit(); drmgr_exit(); @@ -736,4 +840,8 @@ dr_client_main(client_id_t id, int argc, const char *argv[]) open_log_file(); parse_filter_file(); + + /* Initialize the return value cache system, unless it was disabled by the user. */ + if (!op_no_retval.get_value()) + retval_cache_init(outf, op_retval_max_cache.get_value(), op_grepable.get_value()); } diff --git a/drltrace_src/drltrace.h b/drltrace_src/drltrace.h index 33f1344..d5afbbd 100644 --- a/drltrace_src/drltrace.h +++ b/drltrace_src/drltrace.h @@ -30,6 +30,9 @@ * DAMAGE. */ +#ifndef _DRLTRACE_H +#define _DRLTRACE_H + #include "dr_api.h" #include "drltrace_options.h" #include "drmgr.h" @@ -40,6 +43,37 @@ #include #include + +/* Temporary workaround for VC2013, which doesn't have snprintf(). + * apparently, this was added in later releases... */ +#ifdef WINDOWS +#define snprintf _snprintf +#endif + +/* Some function on Windows aren't stable to process (i.e.: we can't + * reliably or safely get the thread ID and/or the return value). */ +#ifdef WINDOWS +#define skip_unstable_functions(_function_name) \ + { size_t function_name_len = strlen(_function_name); \ + if ((fast_strcmp(_function_name, function_name_len, \ + "ZwCallbackReturn", 16) == 0) || \ + (fast_strcmp(_function_name, function_name_len, \ + "KiUserCallbackDispatcher", 24) == 0) || \ + (fast_strcmp(_function_name, function_name_len, \ + "ExpInterlockedPopEntrySListResume", 33) == 0) || \ + (fast_strcmp(_function_name, function_name_len, \ + "_dll_crt0", 9) == 0) || \ + (fast_strcmp(_function_name, function_name_len, \ + "BaseThreadInitThunk", 19) == 0) || \ + (fast_strcmp(_function_name, function_name_len, \ + "RtlUserThreadStart", 18) == 0) \ + ) { \ + return; \ + }} +#else +#define skip_unstable_functions(_unused) {} +#endif + typedef enum { DRSYS_PARAM_IN = 0x01, /**< Input parameter. */ DRSYS_PARAM_OUT = 0x02, /**< Output parameter. */ @@ -184,7 +218,8 @@ typedef struct _drltrace_arg_t { uint64 value64; } drltrace_arg_t; - void parse_config(void); std::vector *libcalls_search(const char *name); void libcalls_hashtable_delete(); + +#endif /* _DRLTRACE_H */ diff --git a/drltrace_src/drltrace_libcalls.cpp b/drltrace_src/drltrace_libcalls.cpp index a4349e0..9373483 100644 --- a/drltrace_src/drltrace_libcalls.cpp +++ b/drltrace_src/drltrace_libcalls.cpp @@ -260,15 +260,15 @@ parse_line(const char *line, int line_num) std::vector *args_vector = new std::vector(); std::vector::iterator it; for (it = tokens.begin(); it != tokens.end(); ++it) { - /* FIXME DrMemory i#1948: Currently, we don't support ret value printing and - * skipping it here. - */ if (elem_index >= 2) { tmp_arg = config_parse_type(*it, elem_index - 2); args_vector->push_back(tmp_arg); } else if (elem_index == 1) func_name = it->c_str(); - + else { + tmp_arg = config_parse_type(*it, 0); + args_vector->push_back(tmp_arg); + } elem_index++; } diff --git a/drltrace_src/drltrace_options.cpp b/drltrace_src/drltrace_options.cpp index 1999319..a944b64 100644 --- a/drltrace_src/drltrace_options.cpp +++ b/drltrace_src/drltrace_options.cpp @@ -107,3 +107,14 @@ droption_t op_ltracelib_ops droption_t op_grepable (DROPTION_SCOPE_CLIENT, "grepable", false, "Grepable output", "Outputs function names and arguments entirely on one line to enable easy log grepping."); + +droption_t op_no_retval +(DROPTION_SCOPE_CLIENT, "no-retval", false, "Disable return value parsing", + "Disable return value caching & parsing."); + +droption_t op_retval_max_cache +(DROPTION_SCOPE_CLIENT, "retval-max-cache", 0, + "Maximum number of cached function calls", "The maximum number of function calls that " + "should be cached while waiting for return values. When reached, the cache will be " + "emptied immediately and return values discarded; new function calls will be cached " + "normally. Only use this option if memory exhaustion occurs."); diff --git a/drltrace_src/drltrace_options.h b/drltrace_src/drltrace_options.h index 619052f..05a481b 100644 --- a/drltrace_src/drltrace_options.h +++ b/drltrace_src/drltrace_options.h @@ -49,3 +49,5 @@ extern droption_t op_verbose; extern droption_t op_use_config; extern droption_t op_ltracelib_ops; extern droption_t op_grepable; +extern droption_t op_no_retval; +extern droption_t op_retval_max_cache; diff --git a/drltrace_src/drltrace_retval_cache.cpp b/drltrace_src/drltrace_retval_cache.cpp new file mode 100644 index 0000000..bcb2bad --- /dev/null +++ b/drltrace_src/drltrace_retval_cache.cpp @@ -0,0 +1,327 @@ +/* + * Copyright 2020 Joe Testa + * + * Redistribution and use in source and binary forms, with or without modification, + * are permitted provided that the following conditions are met: + * + * 1. Redistributions of source code must retain the above copyright notice, this + * list of conditions and the following disclaimer. + * + * 2. Redistributions in binary form must reproduce the above copyright notice, this + * list of conditions and the following disclaimer in the documentation and/or other + * materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS" AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED + * WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE + * DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE LIABLE FOR + * ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES + * (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS + * OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY + * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING + * NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, + * EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. + */ + +#include +#include +#include +#include "drltrace_retval_cache.h" + + +#ifdef UNIT_TESTS /* Re-define a few things when doing unit tests. */ + + #define RETVAL_CACHE_SIZE 8 + #define dr_fprintf fprintf + +#else /* Production values. */ + + #include "drltrace_utils.h" + + /* There are 128K entries in the cache. Each entry is 16 bytes, so the cache takes + * up 2MB memory at minimum (not counting the function strings stored). */ + #define RETVAL_CACHE_SIZE (128 * 1024) + +#endif + +/* The output stream for dr_fprintf() calls. */ +file_t out_stream; + +/* True when the user wants grepable output (see '-grepable' option in the frontend). */ +bool grepable_output = false; + +/* The array of cached_function_call structs which make up the return value cache. */ +static cached_function_call *retval_cache = NULL; + +/* The current size of the cache. */ +static unsigned int cache_size = 0; + +/* The user-defined maximum size of the cache. When non-zero, if this size is reached, + * all entries are immediately dumped out to prevent memory exhaustion; caching then + * continues normally. */ +static unsigned int max_cache_size = 0; + +/* If at any point the cache was dumped out (due to max_cache_size being reached, or + * the cache limit being reached), this is set to 1 so that subsequent mismatched + * return values do not trigger error messages. */ +static unsigned int cache_dump_triggered = 0; + + +/* Outputs and clears as many entries with return values from the cache matching + * the thread_id as possible (which may be zero). If 'clear_all' is set, then all + * entries are outputted & cleared. */ +void +retval_cache_output(void *drcontext, unsigned int thread_id, bool clear_all) { + + /* If the caller wants to dump the cache, set this flag so that later return value + * calls don't print error messages when the entry can't be found. */ + unsigned int i = 0; + int first_slot = -1; + if (clear_all) + cache_dump_triggered = 1; + else { + + /* Find the first index matching this thread ID. */ + for (; (i < cache_size); i++) + if (retval_cache[i].thread_id == thread_id) { + + /* If the first matching index doesn't have its return value set, there's + * nothing to do. */ + if (!retval_cache[i].retval_set) + return; + else + break; + } + + /* If no matching thread ID was found after reaching the end, there's nothing to + * do. */ + if (i == cache_size) + return; + } + + first_slot = i; + for (; (i < cache_size); i++) { + if ((thread_id == retval_cache[i].thread_id) || clear_all) { + + /* Print the function and return value. */ + dr_fprintf(out_stream, "%s", retval_cache[i].function_call); + dr_fprintf(out_stream, grepable_output ? " = " : "\n ret: "); + unsigned int retval_set = retval_cache[i].retval_set; + void *retval = retval_cache[i].retval; + + if (retval_set) { + + switch (retval_cache[i].retval_type) { + /* Unfortunately, the type for VOID and VOID * are lumped together. So we'll + * just have to skip this case and let the default case print it in hex. */ + /* + case DRSYS_TYPE_VOID: + dr_fprintf(out_stream, "\n"); + break; + */ + case DRSYS_TYPE_SIGNED_INT: + dr_fprintf(out_stream, "%d\n", retval); + break; + case DRSYS_TYPE_UNSIGNED_INT: + dr_fprintf(out_stream, "%u\n", retval); + break; + case DRSYS_TYPE_SIZE_T: + dr_fprintf(out_stream, "%zu\n", (size_t)retval); + break; + case DRSYS_TYPE_CSTRING: + if (retval == NULL) + dr_fprintf(out_stream, "\n"); + else if (drcontext == NULL) + dr_fprintf(out_stream, "0x%" PRIxPTR "\n", (uintptr_t)retval); + else { + DR_TRY_EXCEPT(drcontext, { + dr_fprintf(out_stream, "0x%" PRIxPTR ":\"%s\"\n", \ + (uintptr_t)retval, (char *)retval); + }, { + dr_fprintf(out_stream, ""); + }); + } + break; + case DRSYS_TYPE_CWSTRING: + if (retval == NULL) + dr_fprintf(out_stream, "\n"); + else if (drcontext == NULL) + dr_fprintf(out_stream, "0x%" PRIxPTR "\n", (uintptr_t)retval); + else { + DR_TRY_EXCEPT(drcontext, { + dr_fprintf(out_stream, "0x%" PRIxPTR ":\"%S\"\n", \ + (uintptr_t)retval, (char *)retval); + }, { + dr_fprintf(out_stream, ""); + }); + } + break; + default: /* Print hex value. */ + dr_fprintf(out_stream, "0x%" PRIxPTR "\n", (uintptr_t)retval); + break; + } + } else + dr_fprintf(out_stream, grepable_output ? "?\n" : "?"); + + free(retval_cache[i].function_call); + } + } + + if (clear_all) + cache_size = 0; + else { + int free_slot = first_slot; + + /* There may be remaining entries in the cache belonging to other thread IDs. + * De-fragment the entries to eliminate gaps in the array. */ + for (i = first_slot + 1; i < cache_size; i++) { + if (thread_id != retval_cache[i].thread_id) { + memcpy(&(retval_cache[free_slot]), &(retval_cache[i]), sizeof(cached_function_call)); + free_slot++; + } + } + + cache_size = free_slot; + } + + return; +} + +/* Append a function call to the return value cache. */ +void +retval_cache_append(void *drcontext, \ + unsigned int thread_id, \ + drsys_param_type_t retval_type, \ + const char *module_and_function_name, \ + size_t module_and_function_name_len, \ + const char *function_call, \ + size_t function_call_len) { + + /* If the cache size hits the user-defined limit, immediately dump it all as-is into + * the log, then we'll continue. */ + if ((max_cache_size > 0) && (cache_size >= max_cache_size)) + retval_cache_dump_all(drcontext); + +#ifdef UNIX + /* The post-function callback for these functions are never called. So instead of + * letting them clog up the cache, we'll just dump them out immediately. */ + if ((fast_strcmp(module_and_function_name, module_and_function_name_len, \ + "libc.so.6!__libc_start_main", 27) == 0) || \ + (fast_strcmp(module_and_function_name, module_and_function_name_len, \ + "libc.so.6!exit", 14) == 0)) { + + dr_fprintf(out_stream, "%s", function_call); + if (grepable_output) + dr_fprintf(out_stream, " = ??\n"); + else + dr_fprintf(out_stream, "\n ret: ??\n"); + + return; + } +#endif + + retval_cache[cache_size].thread_id = thread_id; + retval_cache[cache_size].function_call = strdup(function_call); + retval_cache[cache_size].function_call_len = function_call_len; + retval_cache[cache_size].retval_type = retval_type; + retval_cache[cache_size].retval_set = 0; + cache_size++; + + /* If we reached the end of the cache, dump it all out then continue normally. */ + if (cache_size == RETVAL_CACHE_SIZE) + retval_cache_dump_all(drcontext); +} + +/* Set the return value of an entry in the cache. */ +void +retval_cache_set_return_value(void *drcontext, \ + unsigned int thread_id, \ + const char *module_name_and_function, \ + size_t module_name_and_function_len, \ + void *retval) { + bool found_entry = false; + unsigned int min_len; + int i = cache_size - 1; + + for (; (i >= 0) && (found_entry == false); i--) { + /* If the return value is already set on this entry, or it does not belong to + * the same thread ID, skip it. */ + if (retval_cache[i].retval_set || (retval_cache[i].thread_id != thread_id)) + continue; + + /* Only compare the shortest prefix of the two strings. */ + min_len = MIN(module_name_and_function_len, retval_cache[i].function_call_len); + if (fast_strcmp(module_name_and_function, min_len, \ + retval_cache[i].function_call, min_len) == 0) { + + retval_cache[i].retval = retval; + retval_cache[i].retval_set = 1; + found_entry = true; + } + } + + /* If we found and set the entry, then check if its time to output the call stack. */ + if (found_entry) + retval_cache_output(drcontext, thread_id, false); + + /* If the entry was not found, print an error. However, if the cache was dumped + * previously, this might be a valid call to an entry that was cleared. */ + else if (!found_entry && !cache_dump_triggered) + dr_fprintf(out_stream, "ERROR: failed to find cache entry for [%s] (return value: 0x%" PRIx64 ")\n", module_name_and_function, retval); + + return; +} + +/* Initialize the return value caching system. The 'retval_cache_free()' function + * must be called to clean up when done. */ +void +retval_cache_init(file_t _out_stream, unsigned int _max_cache_size, \ + bool _grepable_output) { + + out_stream = _out_stream; + max_cache_size = _max_cache_size; + grepable_output = _grepable_output; + + retval_cache = (cached_function_call *)calloc(RETVAL_CACHE_SIZE, \ + sizeof(cached_function_call)); + if (retval_cache == NULL) { + fprintf(stderr, "Failed to create retval_cache array.\n"); + exit(-1); + } +} + +/* Frees and cleans up the return value caching system. The caller must call + * 'retval_cache_dump_all()' before this function to prevent memory leackage. Returns + * true if the cache was empty. */ +bool +retval_cache_free() { + bool ret = true; + + if (retval_cache == NULL) + return false; + + if (cache_size != 0) { + ret = false; + fprintf(stderr, "WARNING: freeing return value cache even though it is not " \ + "empty!: %u\n", cache_size); + } + + free(retval_cache); retval_cache = NULL; + return ret; +} + +/* Functions only used during unit testing. */ +#ifdef UNIT_TESTS +unsigned int +is_cache_empty() { + if (cache_size == 0) + return 1; + else + return 0; +} + +unsigned int +get_cache_size() { + return cache_size; +} +#endif diff --git a/drltrace_src/drltrace_retval_cache.h b/drltrace_src/drltrace_retval_cache.h new file mode 100644 index 0000000..ecb652b --- /dev/null +++ b/drltrace_src/drltrace_retval_cache.h @@ -0,0 +1,99 @@ +/* + * Copyright 2020 Joe Testa + * + * Redistribution and use in source and binary forms, with or without modification, + * are permitted provided that the following conditions are met: + * + * 1. Redistributions of source code must retain the above copyright notice, this + * list of conditions and the following disclaimer. + * + * 2. Redistributions in binary form must reproduce the above copyright notice, this + * list of conditions and the following disclaimer in the documentation and/or other + * materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS" AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED + * WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE + * DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE LIABLE FOR + * ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES + * (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS + * OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY + * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING + * NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, + * EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. + */ + +#ifndef _DRLTRACE_RETVAL_CACHE_H +#define _DRLTRACE_RETVAL_CACHE_H + +#ifdef UNIT_TESTS + + #include + #define file_t FILE* + #define drsys_param_type_t unsigned int + + #define DRSYS_TYPE_UNSIGNED_INT 1 + #define DRSYS_TYPE_SIGNED_INT 2 + #define DRSYS_TYPE_SIZE_T 3 + #define DRSYS_TYPE_CSTRING 4 + #define DRSYS_TYPE_CWSTRING 5 + + #define MIN(x,y) (((x) > (y)) ? (y) : (x)) + #define DR_TRY_EXCEPT(_drcontext, _code, _altcode) #_code + + inline int fast_strcmp(const char *s1, size_t s1_len, const char *s2, size_t s2_len) { + if (s1_len != s2_len) + return -1; + + #ifdef WINDOWS + return memcmp(s1, s2, s1_len); /* VC2013 doesn't have bcmp(), sadly. */ + #else + return bcmp(s1, s2, s1_len); /* Fastest option. */ + #endif + } + +#else + #include "dr_api.h" + #include "drltrace.h" +#endif + +/* The return value cache is an array of these structs. */ +struct _cached_function_call { + unsigned int thread_id; /* The thread ID that this call belongs to. */ + char *function_call; /* Contains the module name, function name, and arguments. */ + unsigned int function_call_len; /* Length of the function_call string. */ + drsys_param_type_t retval_type; /* The type of return value. */ + unsigned int retval_set; /* Set to 1 when retval is set, otherwise 0. */ + void *retval; /* The return value of the function. */ +}; +typedef struct _cached_function_call cached_function_call; + + +#define retval_cache_dump_all(__drcontext) retval_cache_output((__drcontext), 0, true) + +void +retval_cache_output(void *drcontext, unsigned int thread_id, bool clear_all); + +void +retval_cache_append(void *drcontext, unsigned int thread_id, drsys_param_type_t retval_type, const char *module_and_function_name, size_t module_and_function_name_len, const char *function_call, size_t function_call_len); + +void +retval_cache_set_return_value(void *drcontext, unsigned int thread_id, const char *function_call, size_t function_call_len, void *retval); + +void +retval_cache_init(file_t _out_stream, unsigned int _max_cache_size, bool grepable_output); + +bool +retval_cache_free(); + + +/* Functions only used during unit testing of the retval cache system. */ +#ifdef UNIT_TESTS +unsigned int +is_cache_empty(); + +unsigned int +get_cache_size(); +#endif + +#endif /* _DRLTRACE_RETVAL_CACHE_H */ diff --git a/drltrace_src/drltrace_utils.h b/drltrace_src/drltrace_utils.h index aaa0de3..c97d424 100644 --- a/drltrace_src/drltrace_utils.h +++ b/drltrace_src/drltrace_utils.h @@ -33,6 +33,12 @@ #ifndef _DRLTRACE_UTILS_H #define _DRLTRACE_UTILS_H +#ifdef WINDOWS +#include +#else +#include +#endif + #include "dr_api.h" /* XXX: some data types were taken from drsyscall.h and utils.h (DrMemory) */ @@ -43,7 +49,7 @@ void print_prefix_to_console(void); * comparison we don't need (we just need an equality test). Returns * 0 when strings are equal, otherwise returns non-zero. */ inline int -fast_strcmp(char *s1, size_t s1_len, char *s2, size_t s2_len) { +fast_strcmp(const char *s1, size_t s1_len, const char *s2, size_t s2_len) { if (s1_len != s2_len) return -1;