diff --git a/src/jit_internal.h b/src/jit_internal.h index 0c28b6d..86991dd 100644 --- a/src/jit_internal.h +++ b/src/jit_internal.h @@ -49,6 +49,7 @@ namespace redmagic { class Manager { public: Manager(); + ~Manager(); void* begin_trace(void *id, void *ret_addr); void* end_trace(void *id, void *ret_addr); @@ -80,6 +81,8 @@ namespace redmagic { uint32_t tracer_stack_size(); tracer_stack_state* get_tracer_head(); + void print_info(); + private: bool should_trace_method(void *ptr); @@ -91,6 +94,7 @@ namespace redmagic { bool disabled = false; int64_t traced_instruction_count = 0; int sub_branches = 0; + int finish_traces = 0; // number of branched traces that reached the end (not merged blocked back) uint64_t *trace_loop_counter = nullptr; }; diff --git a/src/manager.cc b/src/manager.cc index afca605..a7bfb2c 100644 --- a/src/manager.cc +++ b/src/manager.cc @@ -4,6 +4,8 @@ #include #include +#include + using namespace redmagic; using namespace std; @@ -206,6 +208,10 @@ Manager::Manager() { get_tracer_head(); } +Manager::~Manager() { + red_printf("Manager::~Manager\n"); +} + void Manager::do_not_trace_method(void *addr) { no_trace_methods.insert(addr); } @@ -236,7 +242,7 @@ void* Manager::begin_trace(void *id, void *ret_addr) { } else { assert(old_head->resume_addr == nullptr); old_head->tracer->JumpToNestedLoop(id); - trace_pc = (void*)old_head->tracer->get_origional_pc(); + trace_pc = (void*)old_head->tracer->get_pc(); assert(old_head->resume_addr != nullptr); } } @@ -244,6 +250,7 @@ void* Manager::begin_trace(void *id, void *ret_addr) { //assert(tracer == nullptr); assert(info->tracer == nullptr || info->tracer->did_abort); + assert(info->starting_point == nullptr); //auto buff = make_shared(4 * 1024 * 1024); auto buff = CodeBuffer::CreateBuffer(1024 * 1024); @@ -261,6 +268,7 @@ void* Manager::begin_trace(void *id, void *ret_addr) { new_head->trace_id = id; ret = l->Start(trace_pc); new_head->is_traced = true; + assert(info->trace_loop_counter == nullptr); info->starting_point = l->get_start_location(); info->trace_loop_counter = l->get_loop_counter(); } @@ -316,6 +324,7 @@ void* Manager::backwards_branch(void *id, void *ret_addr) { //return NULL; auto head = get_tracer_head(); if(head->is_traced) { + assert(head->tracer); if(id == head->trace_id) { auto info = &branches[id]; #ifdef CONF_GLOBAL_ABORT @@ -351,6 +360,16 @@ void* Manager::backwards_branch(void *id, void *ret_addr) { return ret; } else { // then we should make a new tracer and jump to that + auto info = &branches[id]; + if(info->starting_point) { + assert(!info->tracer); // that we are done with this + head->tracer->JumpToNestedLoop(id); + auto new_head = push_tracer_stack(); + new_head->is_compiled = true; + new_head->is_traced = true; + new_head->trace_id = id; + return info->starting_point; + } return begin_trace(id, ret_addr); } } else { @@ -368,7 +387,9 @@ void* Manager::backwards_branch(void *id, void *ret_addr) { // TODO: if this aborted, then need to make this have written the resume block at the bottom and if(info->tracer->did_abort) { +#ifdef CONF_VERBOSE red_printf("previous attempt aborted %x\n", id); +#endif #ifdef CONF_GLOBAL_ABORT auto head = push_tracer_stack(); head->is_compiled = true; @@ -387,7 +408,9 @@ void* Manager::backwards_branch(void *id, void *ret_addr) { head->is_compiled = true; head->is_traced = true; head->trace_id = id; +#ifdef CONF_VERBOSE red_printf("entering trace %x\n", id); +#endif return info->starting_point; } // don't care about atomic since we are just trying to get an estimate, so if we lose some counts it is fine @@ -477,7 +500,7 @@ void* Manager::temp_enable(void *resume_pc) { void* Manager::begin_merge_block() { auto head = get_tracer_head(); - if(head->tracer) { + if(head->tracer && !head->tracer->did_abort) { return head->tracer->BeginMergeBlock(); } return NULL; @@ -485,7 +508,7 @@ void* Manager::begin_merge_block() { void* Manager::end_merge_block() { auto head = get_tracer_head(); - if(head->tracer) { + if(head->tracer && !head->tracer->did_abort) { return head->tracer->EndMergeBlock(); } return NULL; @@ -548,6 +571,10 @@ namespace { red_printf("failed to get dlinfo for self"); } } + ~_noname() { + if(manager) + manager->print_info(); + } } _noinst; } @@ -568,3 +595,68 @@ bool Manager::should_trace_method(void *id) { return true; } + + +void Manager::print_info() { + UnprotectMalloc upm; + vector> bi; + bi.reserve(branches.size()); + // for(auto b : branches) { + // bi.push_back(&b); + // } + for(auto it = branches.begin(); it != branches.end(); it++) { + bi.push_back(make_pair(it->first, &it->second)); + } + std::sort(bi.begin(), bi.begin() + bi.size(), [](auto a, auto b) -> bool { + //return a < b; + + + if(a.second->trace_loop_counter != nullptr && b.second->trace_loop_counter != nullptr) { + if(a.second->traced_instruction_count * (*a.second->trace_loop_counter) > b.second->traced_instruction_count * (*b.second->trace_loop_counter)) + return true; + else + return false; + } + if(a.second->trace_loop_counter == nullptr && b.second->trace_loop_counter != nullptr) + return false; + if(b.second->trace_loop_counter == nullptr && a.second->trace_loop_counter != nullptr) + return true; + + return a.second->count > b.second->count; + + }); + + int cnt = 0; + for(auto b : bi) { + if(cnt % 30 == 0) { + red_printf("%3s|%16s|%16s|%10s|%10s|%12s|%10s\n", "#", "trace id", "trace location", "loop count", "icount", "sub branches", "finish traces"); + red_printf("===============================================================================================\n"); + } + cnt++; + if(cnt > 200) break; + red_printf("%3i|%#016lx|%#016lx|%10lu|%10lu|%12i|%10i\n", + cnt, + b.first, + b.second->starting_point, + (b.second->trace_loop_counter ? *b.second->trace_loop_counter : 0), + b.second->traced_instruction_count, + b.second->sub_branches, + b.second->finish_traces); + } + + red_printf("thread tracers\n"); + red_printf("%3s|E|C|%16s|%16s|%16s|%16s|%16s\n", "#", "trace id", "tracing from", "tracing pc", "generated pc", "trace icount"); + red_printf("======================================================================================\n"); + for(int i = threadl_tracer_stack.size() - 1; i >= 0; i--) { + auto info = &threadl_tracer_stack[i]; + red_printf("%3i|%1i|%1i|%#016lx|%#016lx|%#016lx|%#016lx|%10lu\n", + i, + (info->tracer && !info->is_temp_disabled), + info->is_compiled, + info->trace_id, + info->tracer ? (mem_loc_t)info->tracer->tracing_from : 0, + info->tracer ? info->tracer->get_pc() : 0, + info->tracer ? info->tracer->generated_pc() : 0, + info->tracer ? info->tracer->get_icount() : 0); + } +} diff --git a/src/tracer.cc b/src/tracer.cc index f8db230..6345992 100644 --- a/src/tracer.cc +++ b/src/tracer.cc @@ -77,6 +77,8 @@ Tracer::Tracer(CodeBuffer* buffer) { merge_block_stack.reserve(100); merge_block_stack.push_back(0); + tracing_from = 0; + // mem_loc_t stack_ptr = (mem_loc_t)malloc(12*1024 + TRACE_STACK_SIZE); // stack = stack_ptr; // stack_ptr += 4*1024; @@ -132,6 +134,7 @@ extern "C" void red_resume_trace(mem_loc_t target_rip, mem_loc_t write_jump_addr auto head = manager->get_tracer_head(); assert(head->trace_id != nullptr); + assert(manager->branches.find(head->trace_id) != manager->branches.end()); auto info = &manager->branches[head->trace_id]; #ifdef CONF_GLOBAL_ABORT @@ -149,7 +152,11 @@ extern "C" void red_resume_trace(mem_loc_t target_rip, mem_loc_t write_jump_addr if(l == nullptr) { // we did not get a tracer, there must not have been one // TODO: allocate a new tracer - assert(0); + assert(protected_malloc); + protected_malloc = false; + l = new Tracer(CodeBuffer::CreateBuffer(1024 * 1024)); + protected_malloc = true; + //assert(0); } mem_loc_t old_tracing_from = l->tracing_from.exchange(target_rip); assert(old_tracing_from == 0); @@ -184,7 +191,9 @@ extern "C" void red_resume_trace(mem_loc_t target_rip, mem_loc_t write_jump_addr assert(ret != NULL); +#ifdef CONF_VERBOSE red_printf("======================\nresume trace: %#016lx %x\n", target_rip, head->trace_id); +#endif //protected_malloc = true; @@ -221,20 +230,22 @@ extern "C" void* red_end_trace(mem_loc_t normal_end_address) { new_head->resume_addr = nullptr; } else { #ifdef CONF_GLOBAL_ABORT - assert(global_abort()); + assert(!global_abort()); #endif } } else { //protected_malloc = false; } +#ifdef CONF_VERBOSE red_printf("exiting trace %x\n", head.trace_id); +#endif return ret; } extern "C" void* red_branch_to_sub_trace(void *resume_addr, void *sub_trace_id, void* target_rip) { auto head = manager->get_tracer_head(); assert(head->is_traced); - assert(head->tracer == nullptr); + assert(head->tracer == nullptr || head->tracer->did_abort); assert(head->resume_addr == nullptr); head->resume_addr = resume_addr; assert(sub_trace_id != head->trace_id); @@ -309,6 +320,10 @@ void* Tracer::Start(void *start_addr) { } icount = 0; + last_local_jump = 0; + last_call_instruction = -1; + local_jump_min_addr = 0; + #if defined(NDEBUG) && defined(CONF_GLOBAL_ABORT) if(global_abort()) { @@ -413,6 +428,8 @@ void Tracer::Run(struct user_regs_struct *other_stack) { processes_instructions: while(ud_disassemble(&disassm)) { + assert(merge_block_stack.size()); + ++icount; ++global_icount; @@ -527,13 +544,18 @@ void Tracer::Run(struct user_regs_struct *other_stack) { extern "C" void red_asm_end_trace(); void* Tracer::EndTraceFallthrough() { + assert(current_not_traced_call_addr == (mem_loc_t)&redmagic_fellthrough_branch || + current_not_traced_call_addr == (mem_loc_t)&redmagic_force_end_trace); + current_not_traced_call_addr = 0; assert(icount - last_call_instruction < 2); +#ifdef CONF_VERBOSE red_printf("tracer end fallthrough\n"); +#endif auto head = manager->get_tracer_head(); auto info = &manager->branches[head->trace_id]; info->traced_instruction_count += icount; - + info->finish_traces++; buffer->setOffset(last_call_generated_op); SimpleCompiler compiler(buffer); @@ -558,14 +580,19 @@ void* Tracer::EndTraceFallthrough() { void* Tracer::EndTraceLoop() { // assert that we recently performed a call // this should be to ourselves to end the trace + assert(current_not_traced_call_addr == (mem_loc_t)&redmagic_backwards_branch); + current_not_traced_call_addr = 0; assert(icount - last_call_instruction < 2); +#ifdef CONF_VERBOSE red_printf("tracer end loop back\n"); +#endif auto head = manager->get_tracer_head(); auto info = &manager->branches[head->trace_id]; mem_loc_t loop_location = (mem_loc_t)info->starting_point; assert(loop_location); info->traced_instruction_count += icount; + info->finish_traces++; buffer->setOffset(last_call_generated_op); SimpleCompiler compiler(buffer); @@ -587,6 +614,7 @@ void* Tracer::EndTraceLoop() { } void* Tracer::TempDisableTrace() { + assert(current_not_traced_call_addr == (mem_loc_t)&redmagic_temp_disable); assert(icount - last_call_instruction < 2); buffer->setOffset(last_call_generated_op); SimpleCompiler compiler(buffer); @@ -644,6 +672,7 @@ void Tracer::JumpToNestedLoop(void *nested_trace_id) { } void* Tracer::ReplaceIsTracedCall() { + assert(current_not_traced_call_addr == (mem_loc_t)&redmagic_is_traced); assert(icount - last_call_instruction < 2); buffer->setOffset(last_call_generated_op); SimpleCompiler compiler(buffer); @@ -657,7 +686,13 @@ void* Tracer::ReplaceIsTracedCall() { } void* Tracer::BeginMergeBlock() { + // if this method is called from some context where it wasn't inlined in the code + // then that means that it must have been some other non inlined method which means that we do not + // want to perform any actions + if(current_not_traced_call_addr != (mem_loc_t)&redmagic_begin_merge_block) + return NULL; assert(icount - last_call_instruction < 2); + //assert(current_not_traced_call_addr == (mem_loc_t)&redmagic_begin_merge_block); buffer->setOffset(last_call_generated_op); mem_loc_t ret = buffer->getRawBuffer() + buffer->getOffset(); // there are no instructions to generate for this @@ -667,6 +702,8 @@ void* Tracer::BeginMergeBlock() { } void* Tracer::EndMergeBlock() { + if(current_not_traced_call_addr != (mem_loc_t)&redmagic_end_merge_block) + return NULL; // see above assert(icount - last_call_instruction < 2); buffer->setOffset(last_call_generated_op); if(merge_block_stack.size() == 1) { @@ -751,7 +788,9 @@ void Tracer::finish_patch() { extern "C" void* red_asm_resume_eval_block(void*, void*); void Tracer::continue_program(mem_loc_t resume_loc) { +#ifdef CONF_VERBOSE red_printf("==> %#016lx\n", resume_loc); +#endif assert(regs_struct->rsp - TRACE_STACK_OFFSET == (register_t)regs_struct); regs_struct->rsp += move_stack_by; move_stack_by = 0; @@ -1320,6 +1359,7 @@ void Tracer::evaluate_instruction() { assert(jump_dest != 0); if(last_call_instruction + 1 == icount) { // we are jumping to a method eg dynamically loaded, so change what we think the methods address is + assert(!method_address_stack.empty()); method_address_stack.back() = jump_dest; } if(!manager->should_trace_method((void*)jump_dest)) { @@ -1340,14 +1380,21 @@ void Tracer::evaluate_instruction() { register_t return_pc = peek_stack(); set_pc(return_pc); SimpleCompiler compiler(buffer); + auto call_i = compiler.newLabel(); // pop the previous return address off the stack compiler.add(asmjit::x86::rsp, asmjit::imm(8)); + compiler.bind(call_i); compiler.call(asmjit::imm_ptr(jump_dest)); + size_t call_io = compiler.getLabelOffset(call_i); + last_call_generated_op = buffer->getOffset() + call_io; + last_call_instruction = icount; auto written = compiler.finalize(); write_interrupt_block(); cont_addr = written.getRawBuffer(); } + current_not_traced_call_addr = jump_dest; continue_program(cont_addr); + current_not_traced_call_addr = 0; return; } @@ -1465,7 +1512,9 @@ void Tracer::evaluate_instruction() { write_interrupt_block(); cont_addr = cb.getRawBuffer(); } + current_not_traced_call_addr = call_pc; continue_program(cont_addr); + current_not_traced_call_addr = 0; } else { // inline this method, so push the return address and continue diff --git a/src/tracer.h b/src/tracer.h index 95a43d8..d440c43 100644 --- a/src/tracer.h +++ b/src/tracer.h @@ -61,7 +61,7 @@ namespace redmagic { finish_patch_addr = addr; } - inline mem_loc_t get_origional_pc() { return udis_loc; } + inline mem_loc_t get_pc() { return udis_loc; } inline uint64_t* get_loop_counter() { return trace_loop_counter; } @@ -135,9 +135,11 @@ namespace redmagic { std::atomic tracing_from; uint32_t owning_thread; - bool did_abort = false; + // used for printing + inline mem_loc_t generated_pc() { return generated_location; } + inline int64_t get_icount() { return icount; } private: @@ -177,9 +179,10 @@ namespace redmagic { int64_t last_call_instruction = -1; size_t last_call_generated_op; // where we have the corresponding gened ops (eg push ret addr) mem_loc_t last_call_ret_addr; + mem_loc_t current_not_traced_call_addr = 0; // address of the call that is currently being execuited if we aren't tracing mem_loc_t trace_start_location; // where this current trace begins - mem_loc_t loop_start_location; // where it should branch the loop back to + //mem_loc_t loop_start_location; // where it should branch the loop back to int32_t *finish_patch_addr = nullptr; diff --git a/tools/gdb-helper.py b/tools/gdb-helper.py index 92a36cd..7debb4c 100644 --- a/tools/gdb-helper.py +++ b/tools/gdb-helper.py @@ -93,7 +93,7 @@ def get_breakpoint(): return r try: - while current_high - current_low > 2 + while current_high - current_low > 2: try: # kernel kill so that we don't deal with random cleanup code gdb.execute('signal 9')