From 64e70c8a53b3f3c152d31d40c3bd347af5c18f72 Mon Sep 17 00:00:00 2001 From: Matthew Francis-Landau Date: Tue, 23 Aug 2016 20:57:47 -0400 Subject: [PATCH] fix issue with the merging happening at the wrong stack frame by checking the rsp pointer still exists issue with some pointer getting currupted --- make | 8 ++ src/config.h | 2 +- src/jit_internal.h | 62 +++++++----- src/manager.cc | 21 ++-- src/tracer.cc | 68 +++++++++++-- src/tracer.h | 3 + tools/biset.py | 2 +- tools/gdb-helper.py | 230 ++++++++++++++++++++++++++------------------ 8 files changed, 258 insertions(+), 138 deletions(-) diff --git a/make b/make index 0ccf0b0..b3b780e 100755 --- a/make +++ b/make @@ -22,6 +22,7 @@ C_FLAGS = ( '-I ./deps/ ' '-I ./deps/udis86 ' '-I ./deps/asmjit/src ' + '-I ./build/ ' ) CXX_FLAGS = ( '-std=c++14 ' @@ -95,6 +96,13 @@ def link(): after() def compile(): + with open('build/build_version.h', 'w+') as f: + f.write(''' +#ifndef RED_BUILD_VERSION +#define RED_BUILD_VERSION "{}" +#endif + '''.format(GIT_VERSION)) + for f in glob.glob('src/*.cc'): Run('{CXX} {} -c {} -o {}'.format( C_FLAGS + CXX_FLAGS, diff --git a/src/config.h b/src/config.h index a8381df..d61bb48 100644 --- a/src/config.h +++ b/src/config.h @@ -43,7 +43,7 @@ // unable to determine where it should actually be performing this, so we are just makeing the end of the branchable frame // close out any traces that were created in this frame // ^^^ this might have been a bug with the intergration, but now it is using this auto closing as a "feature" -#define CONF_ALLOW_UNCLOSED_TRACES +//#define CONF_ALLOW_UNCLOSED_TRACES // using timers in addition to number of times it loops to determine what to trace diff --git a/src/jit_internal.h b/src/jit_internal.h index 7fcc035..053afc8 100644 --- a/src/jit_internal.h +++ b/src/jit_internal.h @@ -52,6 +52,13 @@ namespace redmagic { struct tracer_stack_state; + template + using RealMallocMap = std::unordered_map, std::equal_to, RealMallocAllocator>>; + + template + using RealMallocSet = std::unordered_set, std::equal_to, RealMallocAllocator>; + + class Manager { public: Manager(); @@ -119,31 +126,34 @@ namespace redmagic { #endif }; - std::unordered_map< - void*, - branch_info, - // should be the same as normal - std::hash, - std::equal_to, - RealMallocAllocator> - > branches; + // std::unordered_map< + // void*, + // branch_info, + // // should be the same as normal + // std::hash, + // std::equal_to, + // RealMallocAllocator> + // > + RealMallocMap branches; #ifdef CONF_CHECK_MERGE_RIP - std::unordered_map< - mem_loc_t, - mem_loc_t, - std::hash, - std::equal_to, - RealMallocAllocator> - > merge_rip; + // std::unordered_map< + // mem_loc_t, + // mem_loc_t, + // std::hash, + // std::equal_to, + // RealMallocAllocator> + // > + RealMallocMap > merge_rip; #endif private: - std::unordered_set< - void*, - std::hash, - std::equal_to, - RealMallocAllocator - > no_trace_methods; + // std::unordered_set< + // void*, + // std::hash, + // std::equal_to, + // RealMallocAllocator + // > + RealMallocSet no_trace_methods; std::atomic thread_id_counter; @@ -179,6 +189,10 @@ namespace redmagic { mem_loc_t method_address; mem_loc_t return_stack_pointer; +#ifdef CONF_MERGE_BACK_ON_RET + int corresponding_merge_block = 0; +#endif + tracer_method_stack_s(mem_loc_t a=0, mem_loc_t b=0): method_address(a), return_stack_pointer(b) {} }; @@ -186,11 +200,6 @@ namespace redmagic { struct tracer_merge_block_stack_s { mem_loc_t merge_head = 0; // head of linked list for this merge point -#ifdef CONF_CHECK_MERGE_RIP - mem_loc_t merge_rip_head = 0; -#endif - - tracer_merge_block_stack_s() {} }; @@ -307,6 +316,7 @@ namespace redmagic { location++; } assert(did_find == 1); + assert(*ret == from); return ret; } diff --git a/src/manager.cc b/src/manager.cc index aa06793..f9d731a 100644 --- a/src/manager.cc +++ b/src/manager.cc @@ -6,6 +6,8 @@ #include +#include "build_version.h" + using namespace redmagic; using namespace std; @@ -141,7 +143,7 @@ extern "C" void *__real_malloc(size_t); extern "C" void redmagic_start() { UnprotectMalloc upm; - red_printf("Using redmagic jit by Matthew Francis-Landau \n"); + red_printf("Using redmagic jit by Matthew Francis-Landau version: " RED_BUILD_VERSION "\n"); if(manager != nullptr) { red_printf("redmagic_start called twice"); abort(); @@ -531,7 +533,7 @@ void* Manager::backwards_branch(void *id, void *ret_addr) { new_head = head; #ifdef CONF_ESTIMATE_INSTRUCTIONS head->num_backwards_loops++; - if(head->num_backwards_loops > (info->count / 8)) { + if(head->num_backwards_loops > (info->count / 8) || (head->num_backwards_loops > 2 && info->avg_observed_instructions == 0)) { uint64_t icnt = instruction_cnt(); info->avg_observed_instructions = (icnt - head->instruction_cnt_at_start - head->sub_frame_num_instructions) / head->num_backwards_loops; } @@ -565,10 +567,10 @@ void* Manager::backwards_branch(void *id, void *ret_addr) { #ifndef NDEBUG if(info->tracer->owning_thread == get_thread_id()) { // this is a recursive frame - for(auto t : threadl_tracer_stack) { - if(t.trace_id == id) { + for(int i = threadl_tracer_stack.size() - 2; i >= 0; i--) { + if(threadl_tracer_stack[i].trace_id == id) { // we found this that was tracing from - assert(t.frame_id != branchable_frame_id); + assert(threadl_tracer_stack[i].frame_id != branchable_frame_id); return start_addr; } } @@ -875,10 +877,17 @@ void* Manager::end_branchable_frame(void *ret_addr, void **stack_ptr) { // this method will get call again with this current frame poped return ret; } else { + if(head->trace_id != nullptr) { + auto info = &branches[head->trace_id]; + info->count_fellthrough++; + } pop_tracer_stack(); head = get_tracer_head(); if(head->resume_addr) { + // assert that this is a call instruction + assert(((uint8_t*)ret_addr)[-5] == 0xE8); + if(head->tracer) { head->tracer->JumpFromNestedLoop((uint8_t*)ret_addr - 5); // backup the pc to the call instruction } @@ -944,7 +953,7 @@ tracer_stack_state *Manager::get_tracer_head() { // tracer_stack_state e; // threadl_tracer_stack.push_back(e); push_tracer_stack(); - stack_head = &threadl_tracer_stack[0]; + // stack_head = &threadl_tracer_stack[0]; } return stack_head; } diff --git a/src/tracer.cc b/src/tracer.cc index 6e912d2..16975d3 100644 --- a/src/tracer.cc +++ b/src/tracer.cc @@ -47,6 +47,11 @@ namespace redmagic { return false; } #endif + +#ifndef NDEBUG + // using a conditional break point is much slower then having the check internally + long global_debugger_int = -1; +#endif } @@ -160,6 +165,8 @@ extern "C" void red_resume_trace(mem_loc_t target_rip, mem_loc_t write_jump_addr head->is_compiled = false; l->owning_thread = manager->get_thread_id(); + // vvv this might be "wrong" since the frame id might have changed within a given trace + // but this field is write only atm so might not be a problem l->owning_frame_id = branchable_frame_id; // calling Start will invalidate the previous stack @@ -190,6 +197,8 @@ extern "C" void* red_end_trace(mem_loc_t normal_end_address) { auto head = manager->pop_tracer_stack(); auto new_head = manager->get_tracer_head(); assert(head.is_traced); + auto info = &manager->branches[head.trace_id]; + info->count_fellthrough++; void *ret = (void*)normal_end_address; if(new_head->is_traced) { if(new_head->tracer) { @@ -280,6 +289,9 @@ void* Tracer::Start(void *start_addr) { local_jump_min_addr = 0; #endif + current_not_traced_call_addr = 0; + current_not_traced_call_ret_loc = nullptr; + #ifdef CONF_GLOBAL_ABORT #ifdef NDEBUG @@ -340,6 +352,11 @@ void Tracer::Run(struct user_regs_struct *other_stack) { red_printf("----->start %i\n", ++loop_n); #endif + assert(method_stack.size() == 1); + assert(method_stack.back().return_stack_pointer == -1); + + run_starting_stack_pointer = regs_struct->rsp; + while(true) { assert(before_stack == 0xdeadbeef); assert(after_stack == 0xdeadbeef); @@ -361,6 +378,7 @@ void Tracer::Run(struct user_regs_struct *other_stack) { assert(method_stack.back().return_stack_pointer >= regs_struct->rsp + move_stack_by); #ifdef CONF_MERGE_BACK_ON_RET assert(merge_block_stack.size() >= method_stack.size()); + assert(merge_block_stack.size() >= method_stack.back().corresponding_merge_block); #endif // if we somehow have less then 1kb free then we might have overwritten something @@ -412,6 +430,12 @@ void Tracer::Run(struct user_regs_struct *other_stack) { red_printf("[%10lu %8i %#016lx] \t%-38s %-20s lib=%s\n", global_icount, icount, ins_loc, ud_insn_asm(&disassm), ud_insn_hex(&disassm), dlinfo.dli_fname); #endif +#ifndef NDEBUG + if(global_debugger_int != -1 && global_debugger_int == global_icount) { + __asm__("int3\n"); + } +#endif + jmp_info = decode_instruction(); if(jmp_info.is_jump) { if(jmp_info.is_local_jump) { @@ -800,6 +824,15 @@ void* Tracer::EndMergeBlock() { } mem_loc_t Tracer::merge_close_core() { +#ifdef CONF_CHECK_MERGE_RIP + mem_loc_t check_rip; + if(current_not_traced_call_ret_loc != nullptr) { + check_rip = last_call_pc; + } else { + check_rip = udis_loc; + } +#endif + if(merge_block_stack.size() == 1) { assert(merge_resume != 0); mem_loc_t resume_a = merge_resume; @@ -817,8 +850,11 @@ mem_loc_t Tracer::merge_close_core() { write_addr = next_addr; } #ifdef CONF_CHECK_MERGE_RIP - mem_loc_t merge_rip = manager->merge_rip[resume_a]; - assert(merge_rip == udis_loc); + auto merge_f = manager->merge_rip.find(resume_a); + assert(merge_f != manager->merge_rip.end()); + assert(merge_f->second.find(check_rip) != merge_f->second.end()); + // mem_loc_t merge_rip = merge_f->second; + // assert(merge_rip == check_rip); #endif // the ending of this tracer instructions @@ -853,7 +889,9 @@ mem_loc_t Tracer::merge_close_core() { Tracer *expected = nullptr; if(!free_tracer_list.compare_exchange_strong(expected, this)) { // gaaaa + protected_malloc = false; delete this; + protected_malloc = true; } #ifdef CONF_VERBOSE @@ -864,15 +902,23 @@ mem_loc_t Tracer::merge_close_core() { } else { mem_loc_t merge_addr = buffer->getRawBuffer() + buffer->getOffset(); mem_loc_t write_addr = merge_block_stack.back().merge_head; + +#ifdef CONF_CHECK_MERGE_RIP + // if(manager->merge_rip.find(merge_addr) == manager->merge_rip.end() || current_not_traced_call_ret_loc != nullptr) + // manager->merge_rip[merge_addr] = check_rip; + if(write_addr != 0) { + auto merge_set = &manager->merge_rip[merge_addr]; + merge_set->insert(check_rip); + assert(merge_set->size() < 3); // just trying to avoid filling the set with a lot of items since this is suppose to catch bugs + } +#endif + merge_block_stack.pop_back(); while(write_addr != 0) { mem_loc_t next_addr = *(mem_loc_t*)write_addr; *(mem_loc_t*)write_addr = merge_addr; write_addr = next_addr; } -#ifdef CONF_CHECK_MERGE_RIP - manager->merge_rip[merge_addr] = udis_loc; -#endif return 0; } assert(0); @@ -912,7 +958,9 @@ void Tracer::continue_program(mem_loc_t resume_loc) { regs_struct->rsp += move_stack_by; move_stack_by = 0; *((register_t*)(regs_struct->rsp - TRACE_RESUME_ADDRESS_OFFSET)) = resume_loc; + // assert((regs_struct->rax & ~0xff) != 0xfbfbfbfbfbfbfb00); regs_struct = (struct user_regs_struct*)red_asm_resume_eval_block(&resume_struct, regs_struct); + // assert((regs_struct->rax & ~0xff) != 0xfbfbfbfbfbfbfb00); } @@ -1559,6 +1607,7 @@ void Tracer::evaluate_instruction() { if(merge_close) // this might have an issue with the tracer getting free and then using it when it trys to continue the program continue_program(merge_close); } + assert(merge_block_stack.size() < method_stack.back().corresponding_merge_block || method_stack.back().corresponding_merge_block == 0); #endif if(method_stack.back().return_stack_pointer == regs_struct->rsp + move_stack_by - sizeof(register_t)) { assert(!method_stack.empty()); @@ -1708,6 +1757,7 @@ void Tracer::evaluate_instruction() { method_stack.push_back(tracer_method_stack_s(call_pc, regs_struct->rsp + move_stack_by)); #ifdef CONF_MERGE_BACK_ON_RET merge_block_stack.push_back(tracer_merge_block_stack_s()); + method_stack.back().corresponding_merge_block = merge_block_stack.size(); #endif } @@ -1732,20 +1782,18 @@ void Tracer::evaluate_instruction() { // assert(disassm.pfx_repne == UD_NONE); mem_loc_t ret_addr = pop_stack(); set_pc(ret_addr); -// #ifdef CONF_CHECK_RET_ADDRESS - -// #else buffer->writeToEnd(cb_asm_pop_stack); - //#endif assert(method_stack.back().return_stack_pointer >= regs_struct->rsp + move_stack_by - sizeof(register_t)); #ifdef CONF_MERGE_BACK_ON_RET - if(method_stack.back().return_stack_pointer == -1 || + assert(merge_block_stack.size() >= method_stack.back().corresponding_merge_block); + if((method_stack.back().return_stack_pointer == -1 && regs_struct->rsp + move_stack_by - sizeof(register_t) >= run_starting_stack_pointer) || method_stack.back().return_stack_pointer == regs_struct->rsp + move_stack_by - sizeof(register_t)) { mem_loc_t merge_close = merge_close_core(); if(merge_close) // this might have an issue with the tracer getting free and then using it when it trys to continue the program continue_program(merge_close); } + //assert(merge_block_stack.size() >= method_stack.back().corresponding_merge_block);// || method_stack.back().corresponding_merge_block == 0); #endif if(method_stack.back().return_stack_pointer == regs_struct->rsp + move_stack_by - sizeof(register_t)) { assert(!method_stack.empty()); diff --git a/src/tracer.h b/src/tracer.h index ae4d15a..b27fd61 100644 --- a/src/tracer.h +++ b/src/tracer.h @@ -215,8 +215,11 @@ namespace redmagic { std::vector > method_stack; std::vector > merge_block_stack; + mem_loc_t run_starting_stack_pointer = 0; + mem_loc_t merge_resume = 0; + uint64_t *trace_loop_counter = nullptr; // mem_loc_t stack; diff --git a/tools/biset.py b/tools/biset.py index 155f900..6dda757 100644 --- a/tools/biset.py +++ b/tools/biset.py @@ -46,7 +46,7 @@ def main(): error_search = ['IndexError', 'Assertion', 'SIGSEGV', 'Traceback'] #process = '/home/matthew/developer/cpython/python -m IPython -c exit()'.split() # run under gdb since the program seems to change behavor depending on how it is run - process = ['gdb', '/home/matthew/developer/cpython/python', '--eval-command=run -m IPython -c "exit()"', '--eval-command=quit'] + process = ['gdb', '/home/matthew/developer/cpython/python', '--eval-command=run -m IPython -c "exit()"', '--eval-command=quit', '-batch'] try: while max_i - min_i > 2: diff --git a/tools/gdb-helper.py b/tools/gdb-helper.py index 674af64..aa0ef17 100644 --- a/tools/gdb-helper.py +++ b/tools/gdb-helper.py @@ -57,101 +57,143 @@ def get_rip(): TraceJumps() -class BisectTrace(gdb.Command): - # NOTE: this doesn't fully work, gdb will produce strange results some times +class LocateFirstValue(gdb.Command): def __init__(self): - super().__init__("trace-bisect", gdb.COMMAND_USER) + super().__init__("local-first-value", gdb.COMMAND_USER) def invoke(self, args, from_tty): - argv = args.split() - - success_break = int(argv[0]) - failure_break = int(argv[1]) - - # current_max_instruction = int(argv[2]) // 2 - # current_instruction_change_size = current_max_instruction // 2 - current_high = int(argv[2]) - current_low = 0 - - last_break_point_info = {} - - def get_breakpoint(): - # determine which breakpoint we hit - nonlocal last_break_point_info - bp_cnts = {} - info = gdb.execute('info break', to_string=True).split('\n') - print(info) - i = 0 - while i < len(info): - try: - bi = int(info[i].split()[0]) - if 'already hit' in info[i + 1]: - cnt = int(info[i+1].split()[3]) - else: - cnt = 0 - bp_cnts[bi] = cnt - except (ValueError, IndexError): - pass - i += 1 - r = None - for bi, v in bp_cnts.items(): - if last_break_point_info.get(bi) != v: - r = bi - last_break_point_info = bp_cnts - print(bp_cnts) - return r - - try: - while current_high - current_low > 2: - try: - # kernel kill so that we don't deal with random cleanup code - gdb.execute('signal 9') - #gdb.execute('kill') - except gdb.error as e: - pass - get_breakpoint() - stop_i = (current_high + current_low) // 2 - print('\n='*15) - print('current instruction at {}'.format(stop_i)) - print('\n='*15) - time.sleep(5) - set_count = True - try: - gdb.execute('run') # will use the run arguments from the previous time - while True: - # del bp - # try: - # bp = int(gdb.parse_and_eval('$bpnum')) - # except gdb.error: - # print('failed to get breakpoint num') - # break - bp = get_breakpoint() - print('at breakpoint number {}'.format(bp)) - time.sleep(2) - if bp == success_break: - # we were successful - current_low = stop_i - print('successful run') - break - elif bp == failure_break: - current_high = stop_i - print('failure run') - break - else: - if set_count: - gdb.execute('set redmagic::global_icount_abort = {}'.format(stop_i)) - set_count = False - gdb.execute('c') - except gdb.error: - time.sleep(2) - pass - except Exception as e: - print(e) - traceback.print_exc(10) - finally: - gdb.write('error instruction: {} {}'.format(current_high, current_low)) - print('current instruction at {} {}'.format(current_high, current_low)) - - -BisectTrace() + argv = gdb.string_to_argv(args) + + redmagic_info = gdb.execute('info shared redmagic', to_string=True).split('\n')[-2].split() + redmagic_start = int(redmagic_info[0], 16) + redmagic_end = int(redmagic_info[1], 16) + + search = argv[0] + + verbose = False + + gdb.execute('break red_asm_resume_eval_block') + + while True: + rip = int(gdb.parse_and_eval('$rip')) + if redmagic_start < rip < redmagic_end: + li = gdb.execute('x/i {}'.format(rip), to_string=True) + if 'red_asm_resume_eval_block' in li: + gdb.execute('si', to_string=True) + else: + gdb.execute('n', to_string=True) + else: + regs_info = gdb.execute('info all-registers', to_string=True) + if search in regs_info: + stack = gdb.execute('bt', to_string=True) + # filter out methods that are called from the tracer such as memcpy etc + if 'red_asm_begin_block' not in stack: + sr = '\n\t'.join([r for r in regs_info.split('\n') if search in r]) + gdb.write('search pattern found in: \n\t{}'.format(sr)) + return + gdb.execute('si', to_string=True) + + +LocateFirstValue() + + + +# class BisectTrace(gdb.Command): +# # NOTE: this doesn't fully work, gdb will produce strange results some times + +# def __init__(self): +# super().__init__("trace-bisect", gdb.COMMAND_USER) + +# def invoke(self, args, from_tty): +# argv = args.split() + +# success_break = int(argv[0]) +# failure_break = int(argv[1]) + +# # current_max_instruction = int(argv[2]) // 2 +# # current_instruction_change_size = current_max_instruction // 2 +# current_high = int(argv[2]) +# current_low = 0 + +# last_break_point_info = {} + +# def get_breakpoint(): +# # determine which breakpoint we hit +# nonlocal last_break_point_info +# bp_cnts = {} +# info = gdb.execute('info break', to_string=True).split('\n') +# print(info) +# i = 0 +# while i < len(info): +# try: +# bi = int(info[i].split()[0]) +# if 'already hit' in info[i + 1]: +# cnt = int(info[i+1].split()[3]) +# else: +# cnt = 0 +# bp_cnts[bi] = cnt +# except (ValueError, IndexError): +# pass +# i += 1 +# r = None +# for bi, v in bp_cnts.items(): +# if last_break_point_info.get(bi) != v: +# r = bi +# last_break_point_info = bp_cnts +# print(bp_cnts) +# return r + +# try: +# while current_high - current_low > 2: +# try: +# # kernel kill so that we don't deal with random cleanup code +# gdb.execute('signal 9') +# #gdb.execute('kill') +# except gdb.error as e: +# pass +# get_breakpoint() +# stop_i = (current_high + current_low) // 2 +# print('\n='*15) +# print('current instruction at {}'.format(stop_i)) +# print('\n='*15) +# time.sleep(5) +# set_count = True +# try: +# gdb.execute('run') # will use the run arguments from the previous time +# while True: +# # del bp +# # try: +# # bp = int(gdb.parse_and_eval('$bpnum')) +# # except gdb.error: +# # print('failed to get breakpoint num') +# # break +# bp = get_breakpoint() +# print('at breakpoint number {}'.format(bp)) +# time.sleep(2) +# if bp == success_break: +# # we were successful +# current_low = stop_i +# print('successful run') +# break +# elif bp == failure_break: +# current_high = stop_i +# print('failure run') +# break +# else: +# if set_count: +# gdb.execute('set redmagic::global_icount_abort = {}'.format(stop_i)) +# set_count = False +# gdb.execute('c') +# except gdb.error: +# time.sleep(2) +# pass +# except Exception as e: +# print(e) +# traceback.print_exc(10) +# finally: +# gdb.write('error instruction: {} {}'.format(current_high, current_low)) +# print('current instruction at {} {}'.format(current_high, current_low)) + + +# BisectTrace()