From 31c509b171e425806d8e1cce6fbf45ec238569e7 Mon Sep 17 00:00:00 2001 From: Steffen Schulz Date: Sun, 20 Nov 2022 13:33:56 -0800 Subject: [PATCH] replace most fprintf with nyx_error/warn/debug/abort - printf that looks like debug/status info or disabled by macro/comments mostly turned to corresponding nyx_debug() - printf followed by exit/abort/assert turned to nyx_error(), or nyx_abort() if the error is unlikely to need backtrace/gdb - non-fatal error/warning messages turned to nyx_warn() - few hardcoded printf remain, e.g. hexdump and debug helpers --- nyx/khash.h | 6 +- nyx/memory_access.c | 36 ++++------- nyx/page_cache.c | 9 ++- nyx/redqueen_trace.c | 3 +- nyx/snapshot/block/block_cow.c | 77 +++++++++++----------- nyx/snapshot/devices/state_reallocation.c | 79 ++++++++++++----------- nyx/snapshot/memory/backend/nyx_debug.c | 6 +- nyx/snapshot/memory/block_list.c | 2 +- nyx/state/snapshot_state.c | 2 +- nyx/state/state.c | 7 +- nyx/synchronization.c | 58 ++++++++--------- 11 files changed, 138 insertions(+), 147 deletions(-) diff --git a/nyx/khash.h b/nyx/khash.h index fdabc18a73..40783f99ea 100644 --- a/nyx/khash.h +++ b/nyx/khash.h @@ -130,6 +130,8 @@ int main() { #include #include +#include "debug.h" + /* compiler specific configuration */ #if UINT_MAX == 0xffffffffu @@ -358,7 +360,7 @@ static const double __ac_HASH_UPPER = 0.77; SCOPE void kh_write_##name(kh_##name##_t *map, const char *path) { \ FILE *fp = fopen(path, "wb"); \ if(fp == NULL) { \ - fprintf(stderr, "[%s] Could not open file %s.\n", __func__, path);\ + nyx_error("[%s] Could not open file %s.\n", __func__, path);\ assert(0); \ /*exit(EXIT_FAILURE);*/ \ } \ @@ -674,4 +676,4 @@ typedef const char *kh_cstr_t; #define KHASH_MAP_INIT_STR(name, khval_t) \ KHASH_INIT(name, kh_cstr_t, khval_t, 1, kh_str_hash_func, kh_str_hash_equal) -#endif /* __AC_KHASH_H */ \ No newline at end of file +#endif /* __AC_KHASH_H */ diff --git a/nyx/memory_access.c b/nyx/memory_access.c index 3caf2cce2d..1106fed9ad 100644 --- a/nyx/memory_access.c +++ b/nyx/memory_access.c @@ -88,23 +88,20 @@ uint64_t get_paging_phys_addr(CPUState *cpu, uint64_t cr3, uint64_t addr) case mm_32_protected: return addr & 0xFFFFFFFFULL; case mm_32_paging: - fprintf(stderr, "mem_mode: mm_32_paging not implemented!\n"); - abort(); + nyx_abort("mem_mode: mm_32_paging not implemented!\n"); case mm_32_pae: - fprintf(stderr, "mem_mode: mm_32_pae not implemented!\n"); - abort(); + nyx_abort("mem_mode: mm_32_pae not implemented!\n"); case mm_64_l4_paging: return get_48_paging_phys_addr(cr3, addr, false); case mm_64_l5_paging: - fprintf(stderr, "mem_mode: mm_64_l5_paging not implemented!\n"); - abort(); + nyx_abort("mem_mode: mm_64_l5_paging not implemented!\n"); case mm_unkown: - fprintf(stderr, "mem_mode: unkown!\n"); - abort(); + nyx_abort("mem_mode: unkown!\n"); } return 0; } +// FIXME: seems like a duplicate of get_paging_phys_addr()? static uint64_t get_paging_phys_addr_snapshot(CPUState *cpu, uint64_t cr3, uint64_t addr) { if (GET_GLOBAL_STATE()->mem_mode == mm_unkown) { @@ -115,19 +112,15 @@ static uint64_t get_paging_phys_addr_snapshot(CPUState *cpu, uint64_t cr3, uint6 case mm_32_protected: return addr & 0xFFFFFFFFULL; case mm_32_paging: - fprintf(stderr, "mem_mode: mm_32_paging not implemented!\n"); - abort(); + nyx_abort("mem_mode: mm_32_paging not implemented!\n"); case mm_32_pae: - fprintf(stderr, "mem_mode: mm_32_pae not implemented!\n"); - abort(); + nyx_abort("mem_mode: mm_32_pae not implemented!\n"); case mm_64_l4_paging: return get_48_paging_phys_addr(cr3, addr, true); case mm_64_l5_paging: - fprintf(stderr, "mem_mode: mm_64_l5_paging not implemented!\n"); - abort(); + nyx_abort("mem_mode: mm_64_l5_paging not implemented!\n"); case mm_unkown: - fprintf(stderr, "mem_mode: unkown!\n"); - abort(); + nyx_abort("mem_mode: unkown!\n"); } return 0; } @@ -208,10 +201,9 @@ bool remap_slot(uint64_t addr, phys_addr = get_paging_phys_addr(cpu, cr3, (addr & x86_64_PAGE_MASK)); if (phys_addr == INVALID_ADDRESS) { - fprintf(stderr, "[QEMU-Nyx] Error: failed to translate v_addr (0x%lx) to p_addr!\n", - addr); - fprintf(stderr, "[QEMU-Nyx] Check if the buffer is present in the " - "guest's memory...\n"); + nyx_error("Failed to translate v_addr (0x%lx) to p_addr!\n" + "Check if the buffer is present in the guest's memory...\n", + addr); exit(1); } } @@ -444,7 +436,7 @@ static int redqueen_insert_sw_breakpoint(CPUState *cs, struct kvm_sw_breakpoint address_space_rw(cpu_get_address_space(cs, asidx), phys_addr, MEMTXATTRS_UNSPECIFIED, (uint8_t *)&int3, 1, 1)) { - // fprintf(stderr, "%s WRITTE AT %lx %lx failed!\n", __func__, bp->pc, phys_addr); + // nyx_debug("%s WRITE AT %lx %lx failed!\n", __func__, bp->pc, phys_addr); return -EINVAL; } @@ -465,7 +457,7 @@ static int redqueen_remove_sw_breakpoint(CPUState *cs, struct kvm_sw_breakpoint address_space_rw(cpu_get_address_space(cs, asidx), phys_addr, MEMTXATTRS_UNSPECIFIED, (uint8_t *)&bp->saved_insn, 1, 1)) { - // fprintf(stderr, "%s failed\n", __func__); + // nyx_debug("%s failed\n", __func__); return -EINVAL; } diff --git a/nyx/page_cache.c b/nyx/page_cache.c index 5f1b0eb67a..ed8d6785c2 100644 --- a/nyx/page_cache.c +++ b/nyx/page_cache.c @@ -42,15 +42,14 @@ static bool reload_addresses(page_cache_t *self) k = kh_get(PC_CACHE, self->lookup, addr); if (k == kh_end(self->lookup)) { if (value & 0xFFF) { - fprintf(stderr, "Load page: %lx (UNMAPPED)\n", addr); + nyx_warn("Load page: %lx (UNMAPPED)\n", addr); } else { k = kh_put(PC_CACHE, self->lookup, addr, &ret); kh_value(self->lookup, k) = (offset - 1) * PAGE_SIZE; } } else { /* likely a bug / race condition in page_cache itself! */ - fprintf(stderr, - "----------> Page duplicate found ...skipping! %lx\n", addr); + nyx_warn("----> Page duplicate found ...skipping! %lx\n", addr); // abort(); } } @@ -119,7 +118,7 @@ static void page_cache_lock(page_cache_t *self) return; } else if (ret == EINTR) { /* try again if acquiring this lock has failed */ - fprintf(stderr, "%s: interrupted by signal...\n", __func__); + nyx_debug("%s: interrupted by signal...\n", __func__); } else { assert(false); } @@ -135,7 +134,7 @@ static void page_cache_unlock(page_cache_t *self) return; } else if (ret == EINTR) { /* try again if releasing this lock has failed */ - fprintf(stderr, "%s: interrupted by signal...\n", __func__); + nyx_debug("%s: interrupted by signal...\n", __func__); } else { assert(false); } diff --git a/nyx/redqueen_trace.c b/nyx/redqueen_trace.c index 06619ebf99..b4c224d037 100644 --- a/nyx/redqueen_trace.c +++ b/nyx/redqueen_trace.c @@ -56,7 +56,6 @@ static void alt_bitmap_add(uint64_t from, uint64_t to) } } - static int reset_trace_fd(void) { if (trace_fd) @@ -64,7 +63,7 @@ static int reset_trace_fd(void) trace_fd = open(redqueen_workdir.pt_trace_results, O_WRONLY | O_CREAT | O_TRUNC, 0644); if (trace_fd < 0) { - fprintf(stderr, "Failed to initiate trace output: %s\n", strerror(errno)); + nyx_error("Failed to initiate trace output: %s\n", strerror(errno)); assert(0); } return trace_fd; diff --git a/nyx/snapshot/block/block_cow.c b/nyx/snapshot/block/block_cow.c index 18ea59d63e..b3e078e192 100644 --- a/nyx/snapshot/block/block_cow.c +++ b/nyx/snapshot/block/block_cow.c @@ -62,10 +62,9 @@ cow_cache_t *cow_cache_new(const char *filename) self->offset_secondary_tmp = 0; if (getenv("NYX_DISABLE_BLOCK_COW")) { - fprintf(stderr, - "WARNING: Nyx block COW layer disabled for %s (** write operations " - "are not cached **)\n", - filename); + nyx_warn("Nyx block COW layer disabled for %s " + "(write operations are not cached!)\n", + filename); self->enabled = false; } else { self->enabled = true; @@ -122,11 +121,10 @@ void read_primary_buffer(cow_cache_t *self, const char *filename_prefix, bool sw assert(stat(tmp2, &buffer) == 0); if (buffer.st_size > get_global_cow_cache_primary_size()) { - fprintf(stderr, - "ERROR: in-memory CoW buffer is too small compared to snapshot file " - "(buffer: 0x%lx / file: 0x%lx)\n", - get_global_cow_cache_primary_size(), buffer.st_size); - exit(1); + nyx_error("in-memory CoW buffer is smaller than snapshot file " + "(0x%lx < 0x%lx)\n", + get_global_cow_cache_primary_size(), buffer.st_size); + assert(false); } if (buffer.st_size) { @@ -189,7 +187,7 @@ void dump_primary_buffer(cow_cache_t *self, const char *filename_prefix) FILE *fp = fopen(tmp2, "wb"); if (fp == NULL) { - fprintf(stderr, "[%s] Could not open file %s.\n", __func__, tmp2); + nyx_error("%s: Could not open file %s\n", __func__, tmp2); assert(false); } @@ -212,10 +210,10 @@ void cow_cache_reset(cow_cache_t *self) if (self->enabled_fuzz) { #ifdef DEBUG_COW_LAYER - printf("%s: read_calls =>\t%ld\n", __func__, self->read_calls); - printf("%s: write_calls =>\t%ld\n", __func__, self->write_calls); - printf("%s: read_calls_tmp =>\t%ld\n", __func__, self->read_calls_tmp); - printf("%s: write_calls_tmp =>\t%ld\n", __func__, self->write_calls_tmp); + nyx_debug("%s: read_calls =>\t%ld\n", __func__, self->read_calls); + nyx_debug("%s: write_calls =>\t%ld\n", __func__, self->write_calls); + nyx_debug("%s: read_calls_tmp =>\t%ld\n", __func__, self->read_calls_tmp); + nyx_debug("%s: write_calls_tmp =>\t%ld\n", __func__, self->write_calls_tmp); #endif if (!self->enabled_fuzz_tmp) { @@ -231,7 +229,7 @@ void cow_cache_reset(cow_cache_t *self) kh_clear(COW_CACHE, self->lookup_secondary_tmp); #ifdef DEBUG_COW_LAYER - printf("CLEAR lookup_secondary_tmp\n"); + nyx_debug("CLEAR lookup_secondary_tmp\n"); self->read_calls_tmp = 0; self->write_calls_tmp = 0; #endif @@ -301,9 +299,9 @@ static inline void read_from_primary_buffer(cow_cache_t *self, k = kh_get(COW_CACHE, self->lookup_primary, offset_addr); if (k != kh_end(self->lookup_primary)) { #ifdef COW_CACHE_DEBUG - printf("[PRE ] READ DIRTY COW PAGE: ADDR: %lx IOVEC OFFSET: %lx DATA " - "OFFSET: %lx\n", - offset_addr, iov_offset, self->offset_primary); + nyx_debug("[PRE ] READ DIRTY COW PAGE: ADDR: %lx IOVEC OFFSET: %lx DATA " + "OFFSET: %lx\n", + offset_addr, iov_offset, self->offset_primary); #endif qemu_iovec_from_buf(qiov, iov_offset, self->data_primary + kh_value(self->lookup_primary, k), @@ -329,9 +327,9 @@ static inline void read_from_secondary_buffer(cow_cache_t *self, k = kh_get(COW_CACHE, self->lookup_secondary_tmp, offset_addr); if (k != kh_end(self->lookup_secondary_tmp)) { #ifdef COW_CACHE_DEBUG - printf("[FTMP] READ DIRTY COW PAGE: ADDR: %lx IOVEC OFFSET: %lx DATA " - "OFFSET: %lx\n", - offset_addr, iov_offset, self->offset_secondary); + nyx_debug("[FTMP] READ DIRTY COW PAGE: ADDR: %lx IOVEC OFFSET: %lx DATA " + "OFFSET: %lx\n", + offset_addr, iov_offset, self->offset_secondary); #endif qemu_iovec_from_buf(qiov, iov_offset, self->data_secondary_tmp + @@ -345,9 +343,9 @@ static inline void read_from_secondary_buffer(cow_cache_t *self, k = kh_get(COW_CACHE, self->lookup_secondary, offset_addr); if (k != kh_end(self->lookup_secondary)) { #ifdef COW_CACHE_DEBUG - printf("[FUZZ] READ DIRTY COW PAGE: ADDR: %lx IOVEC OFFSET: %lx DATA " - "OFFSET: %lx\n", - offset_addr, iov_offset, self->offset_secondary); + nyx_debug("[FUZZ] READ DIRTY COW PAGE: ADDR: %lx IOVEC OFFSET: %lx DATA " + "OFFSET: %lx\n", + offset_addr, iov_offset, self->offset_secondary); #endif qemu_iovec_from_buf(qiov, iov_offset, self->data_secondary + kh_value(self->lookup_secondary, k), @@ -359,9 +357,9 @@ static inline void read_from_secondary_buffer(cow_cache_t *self, k = kh_get(COW_CACHE, self->lookup_primary, offset_addr); if (k != kh_end(self->lookup_primary)) { #ifdef COW_CACHE_DEBUG - printf("[PRE ] READ DIRTY COW PAGE: ADDR: %lx IOVEC OFFSET: %lx DATA " - "OFFSET: %lx\n", - offset_addr, iov_offset, self->offset_primary); + nyx_debug("[PRE ] READ DIRTY COW PAGE: ADDR: %lx IOVEC OFFSET: %lx DATA " + "OFFSET: %lx\n", + offset_addr, iov_offset, self->offset_primary); #endif qemu_iovec_from_buf(qiov, iov_offset, self->data_primary + kh_value(self->lookup_primary, k), @@ -390,7 +388,7 @@ static int cow_cache_read(cow_cache_t *self, if ((qiov->size % CHUNK_SIZE)) { #ifdef COW_CACHE_DEBUG - fprintf(stderr, "%s: FAILED %lx!\n", __func__, qiov->size); + nyx_debug("%s: FAILED %lx!\n", __func__, qiov->size); #endif return 0; } @@ -433,8 +431,8 @@ static inline void write_to_primary_buffer(cow_cache_t *self, /* create page */ k = kh_put(COW_CACHE, self->lookup_primary, offset_addr, &ret); #ifdef COW_CACHE_DEBUG - printf("ADD NEW COW PAGE: ADDR: %lx IOVEC OFFSET: %lx DATA OFFSET: %lx\n", - offset_addr, iov_offset, self->offset_primary); + nyx_debug("ADD NEW COW PAGE: ADDR: %lx IOVEC OFFSET: %lx DATA OFFSET: %lx\n", + offset_addr, iov_offset, self->offset_primary); #endif @@ -443,9 +441,9 @@ static inline void write_to_primary_buffer(cow_cache_t *self, self->offset_primary += CHUNK_SIZE; #ifdef COW_CACHE_VERBOSE - printf("COW CACHE IS 0x%lx BYTES (KB: %ld / MB: %ld / GB: %ld) IN SIZE!\n", - self->offset, self->offset >> 10, self->offset >> 20, - self->offset >> 30); + nyx_debug( + "COW CACHE IS 0x%lx BYTES (KB: %ld / MB: %ld / GB: %ld) IN SIZE!\n", + self->offset, self->offset >> 10, self->offset >> 20, self->offset >> 30); #endif /* IN CASE THE BUFFER IS FULL -> ABORT! */ @@ -453,8 +451,9 @@ static inline void write_to_primary_buffer(cow_cache_t *self, } #ifdef COW_CACHE_DEBUG - printf("LOAD COW PAGE: ADDR: %lx IOVEC OFFSET: %lx DATA OFFSET: %lx (%s)\n", - offset_addr, iov_offset, kh_value(self->lookup_primary, k), self->filename); + nyx_debug("LOAD COW PAGE: ADDR: %lx IOVEC OFFSET: %lx DATA OFFSET: %lx (%s)\n", + offset_addr, iov_offset, kh_value(self->lookup_primary, k), + self->filename); #endif /* write to cached page */ @@ -545,13 +544,13 @@ static int cow_cache_write(cow_cache_t *self, if ((qiov->size % CHUNK_SIZE)) { #ifdef COW_CACHE_DEBUG - fprintf(stderr, "%s: FAILED %lx!\n", __func__, qiov->size); + nyx_debug("%s: FAILED %lx!\n", __func__, qiov->size); #endif return 0; } if ((qiov->size % CHUNK_SIZE) && GET_GLOBAL_STATE()->in_fuzzing_mode) { GET_GLOBAL_STATE()->cow_cache_full = true; - fprintf(stderr, "WARNING: %s write in %lx CHUNKSIZE\n", __func__, qiov->size); + nyx_warn("%s write in %lx CHUNKSIZE\n", __func__, qiov->size); return 0; } else { assert(!(qiov->size % CHUNK_SIZE)); @@ -588,7 +587,7 @@ void cow_cache_read_entry(void *opaque) BlkRwCo *rwco = &acb->rwco; #ifdef COW_CACHE_DEBUG - printf("%s %lx %lx\n", __func__, rwco->offset, acb->bytes); + nyx_debug("%s %lx %lx\n", __func__, rwco->offset, acb->bytes); #endif rwco->ret = cow_cache_read(*((cow_cache_t **)(rwco->blk)), rwco->blk, @@ -604,7 +603,7 @@ void cow_cache_write_entry(void *opaque) BlkRwCo *rwco = &acb->rwco; #ifdef COW_CACHE_DEBUG - printf("%s\n", __func__); + nyx_debug("%s\n", __func__); #endif rwco->ret = cow_cache_write(*((cow_cache_t **)(rwco->blk)), rwco->blk, diff --git a/nyx/snapshot/devices/state_reallocation.c b/nyx/snapshot/devices/state_reallocation.c index c8bf2aa7b3..19a437e081 100644 --- a/nyx/snapshot/devices/state_reallocation.c +++ b/nyx/snapshot/devices/state_reallocation.c @@ -257,7 +257,7 @@ static void add_post_fptr(state_reallocation_t *self, --> globalstate */ - // fprintf(stderr, "--> %s\n", name); + // printf("--> %s\n", name); self->fptr[self->fast_state_fptr_pos] = fptr; self->opaque[self->fast_state_fptr_pos] = opaque; @@ -358,7 +358,7 @@ static void add_get(state_reallocation_t *self, data = malloc(sizeof(uint8_t) * size); qemu_get_buffer(f, (uint8_t *)data, size); } else { - fprintf(stderr, "WARNING: NOT IMPLEMENTED FAST GET ROUTINE for %s\n", name); + nyx_warn("NOT IMPLEMENTED FAST GET ROUTINE for %s\n", name); abort(); return; } @@ -433,7 +433,9 @@ static inline int get_handler(state_reallocation_t *self, char *vmsd_name) { int ret; - // printf("%s\n", vmsd_name); +#ifdef VERBOSE_DEBUG + nyx_debug("%s: %s\n", __func__, vmsd_name); +#endif ret = field->info->get(f, curr_elem, size, field); @@ -537,9 +539,8 @@ static inline int get_handler(state_reallocation_t *self, add_get(self, (void *)field->info->get, curr_elem, size, (void *)field, f, field->info->name); } else { - fprintf(stderr, - "[QEMU-PT] %s: WARNING no handler for %s, type %s, size %lx!\n", - __func__, vmsd_name, field->info->name, size); + nyx_error("%s: no handler for %s, type %s, size %lx!\n", __func__, vmsd_name, + field->info->name, size); assert(0); } return ret; @@ -554,7 +555,9 @@ static int fdl_vmstate_load_state(state_reallocation_t *self, uintptr_t *opaque_ptr) { #ifdef VERBOSE_DEBUG - printf("---------------------------------\nVMSD: %p\t%s\n", opaque, vmsd->name); + nyx_debug("---------------------------------\n" + "VMSD: %p\t%s\n", + opaque, vmsd->name); #endif VMStateField *field = (VMStateField *)vmsd->fields; @@ -567,11 +570,11 @@ static int fdl_vmstate_load_state(state_reallocation_t *self, } if (version_id < vmsd->minimum_version_id) { #ifdef VERBOSE_DEBUG - printf("OLD LOAD\n"); + nyx_debug("OLD LOAD\n"); #endif if (vmsd->load_state_old && version_id >= vmsd->minimum_version_id_old) { - fprintf(stderr, "OLDSTATE\n"); + nyx_debug("OLDSTATE\n"); assert(0); ret = vmsd->load_state_old(f, opaque, version_id); return ret; @@ -580,16 +583,16 @@ static int fdl_vmstate_load_state(state_reallocation_t *self, } if (vmsd->pre_load) { #ifdef VERBOSE_DEBUG - printf("\tPRELOAD Function\n"); + nyx_debug("\tPRELOAD Function\n"); #endif /* TODO ADD PRE FPTR FOR SERIAL */ - // fprintf(stderr, "PRELOAD RUN: %s\n", vmsd->name); + // nyx_debug("PRELOAD RUN: %s\n", vmsd->name); // add_pre_fptr(self, vmsd->pre_load, opaque, vmsd->name); add_post_fptr(self, vmsd->pre_load, 1337, opaque, vmsd->name); } while (field->name) { #ifdef VERBOSE_DEBUG - printf("Field: %s %s %s\n", __func__, vmsd->name, field->name); + nyx_debug("Field: %s %s %s\n", __func__, vmsd->name, field->name); #endif if ((field->field_exists && field->field_exists(opaque, version_id)) || (!field->field_exists && field->version_id <= version_id)) @@ -599,15 +602,16 @@ static int fdl_vmstate_load_state(state_reallocation_t *self, int size = vmstate_size(opaque, field); #ifdef VERBOSE_DEBUG - printf("-----------------> vmstate_handle_alloc\n"); + nyx_debug("--> vmstate_handle_alloc\n"); #endif - // fprintf(stderr, "-----------------> vmstate_handle_alloc\n"); vmstate_handle_alloc(first_elem, field, opaque); if (field->flags & VMS_POINTER) { #ifdef VERBOSE_DEBUG - printf("FIX ME VMS_POINTER\n"); + nyx_debug("FIX ME VMS_POINTER\n"); #endif - // printf("Field-Offset 0x%lx-0x%lx\n", opaque+field->offset, opaque+field->offset+(size*n_elems)); + // nyx_debug("Field-Offset 0x%lx-0x%lx\n", + // opaque+field->offset, + // opaque+field->offset+(size*n_elems)); first_elem = *(void **)first_elem; assert(first_elem || !n_elems || !size); @@ -620,11 +624,11 @@ static int fdl_vmstate_load_state(state_reallocation_t *self, if (field->flags & VMS_ARRAY_OF_POINTER) { #ifdef VERBOSE_DEBUG - printf("Field-Offset 1 0x%lx-0x%lx\n", - (uint64_t)(field->offset + (opaque)), - (uint64_t)(field->offset + (size * n_elems) + (opaque))); - printf("=VMS_ARRAY_OF_POINTER 1= %lx %x\n", - *((uint64_t *)curr_elem), size); + nyx_debug("Field-Offset 1 0x%lx-0x%lx\n", + (uint64_t)(field->offset + (opaque)), + (uint64_t)(field->offset + (size * n_elems) + (opaque))); + nyx_debug("=VMS_ARRAY_OF_POINTER 1= %lx %x\n", + *((uint64_t *)curr_elem), size); // hexDump((void*)field->name, curr_elem, size); #endif @@ -641,11 +645,11 @@ static int fdl_vmstate_load_state(state_reallocation_t *self, // if null pointer check placeholder and do not follow assert(field->flags & VMS_ARRAY_OF_POINTER); #ifdef VERBOSE_DEBUG - printf("Field-Offset 2 0x%lx-0x%lx\n", - (uint64_t)(field->offset + (opaque)), - (uint64_t)(field->offset + (size * n_elems) + (opaque))); - printf("=VMS_ARRAY_OF_POINTER 2= %lx %x\n", - *((uint64_t *)curr_elem), size); + nyx_debug("Field-Offset 2 0x%lx-0x%lx\n", + (uint64_t)(field->offset + (opaque)), + (uint64_t)(field->offset + (size * n_elems) + (opaque))); + nyx_debug("=VMS_ARRAY_OF_POINTER 2= %lx %x\n", + *((uint64_t *)curr_elem), size); // hexDump((void*)field->name, curr_elem, size); #endif @@ -658,10 +662,11 @@ static int fdl_vmstate_load_state(state_reallocation_t *self, #endif } else if (field->flags & VMS_STRUCT) { - // printf("Field-Offset 0x%lx-0x%lx\n", field->offset + (opaque-base_opaque), + // nyx_debug("Field-Offset 0x%lx-0x%lx\n", + // field->offset + (opaque-base_opaque), // field->offset+(size*n_elems) + (opaque-base_opaque)); #ifdef VERBOSE_DEBUG - printf("=VMS_STRUCT= %lx %x\n", *((uint64_t *)curr_elem), size); + nyx_debug("=VMS_STRUCT= %lx %x\n", *((uint64_t *)curr_elem), size); // hexDump((void*)field->name, curr_elem, size); #endif /* FIXME */ @@ -688,7 +693,7 @@ static int fdl_vmstate_load_state(state_reallocation_t *self, nyx_debug("Input validation failed: %s/%s\n", vmsd->name, field->name); return -1; } else { - // printf("Field does not exist...\n"); + // nyx_debug("Field does not exist...\n"); } field++; } @@ -702,13 +707,13 @@ static int fdl_vmstate_load_state(state_reallocation_t *self, if (vmsd->post_load) { #ifdef VERBOSE_DEBUG - printf("\tPOSTLOAD Function\n"); + nyx_debug("\tPOSTLOAD Function\n"); #endif add_post_fptr(self, vmsd->post_load, version_id, opaque, vmsd->name); ret = vmsd->post_load(opaque, version_id); } #ifdef VERBOSE_DEBUG - printf("\tTotal Size:%ld\n", total_size); + nyx_debug("\tTotal Size:%ld\n", total_size); #endif return ret; } @@ -741,7 +746,7 @@ static int fdl_enumerate_section(state_reallocation_t *self, /* Read section start */ section_id = qemu_get_be32(f); if (!qemu_get_counted_string(f, idstr)) { - printf("Unable to read ID string for section %u", section_id); + nyx_error("Unable to read ID string for section %u", section_id); return -EINVAL; } instance_id = qemu_get_be32(f); @@ -750,14 +755,14 @@ static int fdl_enumerate_section(state_reallocation_t *self, /* Find savevm section */ se = fdl_find_se(idstr, instance_id); if (se == NULL) { - printf("Unknown savevm section or instance '%s' %d", idstr, instance_id); + nyx_error("Unknown savevm section or instance '%s' %d", idstr, instance_id); return -EINVAL; } /* Validate version */ if (version_id > se->version_id) { - printf("savevm: unsupported version %d for '%s' v%d", version_id, idstr, - se->version_id); + nyx_error("savevm: unsupported version %d for '%s' v%d", version_id, idstr, + se->version_id); return -EINVAL; } @@ -816,8 +821,8 @@ static int fdl_enumerate_section(state_reallocation_t *self, } if (ret < 0) { - printf("error while loading state for instance 0x%x of device '%s'", - instance_id, idstr); + nyx_error("failed to load state for instance 0x%x of device '%s'", + instance_id, idstr); return ret; } diff --git a/nyx/snapshot/memory/backend/nyx_debug.c b/nyx/snapshot/memory/backend/nyx_debug.c index 43e75bc459..fc3088efd8 100644 --- a/nyx/snapshot/memory/backend/nyx_debug.c +++ b/nyx/snapshot/memory/backend/nyx_debug.c @@ -61,7 +61,7 @@ uint32_t nyx_snapshot_debug_restore(shadow_memory_t *shadow_memory_sta if (snapshot_page_blocklist_check_phys_addr(blocklist, physical_addr) == false) { - // fprintf(stderr, "(2) DIRTY: 0x%lx (NUM: %d - OFFSET: 0x%lx)\n", physical_addr, i, addr); + // nyx_debug("(2) DIRTY: 0x%lx (NUM: %d - OFFSET: 0x%lx)\n", physical_addr, i, addr); if (verbose) { printf("%s -> (phys: 0x%lx) %p <-- %p [%d]\n", __func__, @@ -113,7 +113,7 @@ void nyx_snapshot_debug_save_root_pages(shadow_memory_t *shadow_memory_state, if (snapshot_page_blocklist_check_phys_addr(blocklist, physical_addr) == false) { - // fprintf(stderr, "(2) DIRTY: 0x%lx (NUM: %d - OFFSET: 0x%lx)\n", physical_addr, i, addr); + // nyx_debug("(2) DIRTY: 0x%lx (NUM: %d - OFFSET: 0x%lx)\n", physical_addr, i, addr); if (verbose && !shadow_memory_is_root_page_tracked(shadow_memory_state, @@ -136,4 +136,4 @@ void nyx_snapshot_debug_save_root_pages(shadow_memory_t *shadow_memory_state, void nyx_snapshot_debug_set(fast_reload_t *self) { /* TODO */ -} \ No newline at end of file +} diff --git a/nyx/snapshot/memory/block_list.c b/nyx/snapshot/memory/block_list.c index 9abfbb5e1f..d263d184fa 100644 --- a/nyx/snapshot/memory/block_list.c +++ b/nyx/snapshot/memory/block_list.c @@ -44,7 +44,7 @@ snapshot_page_blocklist_t *snapshot_page_blocklist_init(void) void snapshot_page_blocklist_add(snapshot_page_blocklist_t *self, uint64_t phys_addr) { if (phys_addr == -1) { - fprintf(stderr, "ERROR %s: phys_addr=%lx\n", __func__, phys_addr); + nyx_error("%s: phys_addr=%lx\n", __func__, phys_addr); return; } assert(self != NULL); diff --git a/nyx/state/snapshot_state.c b/nyx/state/snapshot_state.c index 14d7800f18..b7b62d2933 100644 --- a/nyx/state/snapshot_state.c +++ b/nyx/state/snapshot_state.c @@ -144,7 +144,7 @@ void deserialize_state(const char *filename_prefix) nyx_global_state->get_host_config_done = true; nyx_global_state->set_agent_config_done = true; } else { - fprintf(stderr, "[QEMU-Nyx]: this feature is currently missing\n"); + nyx_error("this feature is currently missing\n"); abort(); } diff --git a/nyx/state/state.c b/nyx/state/state.c index 4e2018b58c..f03de20702 100644 --- a/nyx/state/state.c +++ b/nyx/state/state.c @@ -33,8 +33,6 @@ along with QEMU-PT. If not, see . #include "nyx/sharedir.h" #include "nyx/state/state.h" -// #define STATE_VERBOSE - /* global singleton */ qemu_nyx_state_t global_state; @@ -42,9 +40,8 @@ qemu_nyx_state_t global_state; void state_init_global(void) { -#ifdef STATE_VERBOSE - fprintf(stderr, "--> %s <--\n", __func__); -#endif + nyx_trace(); + /* safety first */ assert(libxdc_get_release_version() == LIBXDC_RELEASE_VERSION_REQUIRED); diff --git a/nyx/synchronization.c b/nyx/synchronization.c index 77d222c56d..a7eafaa9c5 100644 --- a/nyx/synchronization.c +++ b/nyx/synchronization.c @@ -47,7 +47,7 @@ static void sigalarm_handler(int signum) /* ensure that SIGALARM is ALWAYS handled by kvm thread */ assert(GET_GLOBAL_STATE()->timeout_detector.kvm_tid == syscall(SYS_gettid)); #ifdef DEBUG_TIMEOUT_DETECTOR - fprintf(stderr, "Handled! %d %ld\n", signum, syscall(SYS_gettid)); + nyx_debug("Handled! %d %ld\n", signum, syscall(SYS_gettid)); #endif } @@ -55,18 +55,18 @@ void install_timeout_detector(timeout_detector_t *timer) { timer->kvm_tid = syscall(SYS_gettid); if (signal(SIGALRM, sigalarm_handler) == SIG_ERR) { - fprintf(stderr, "%s failed!\n", __func__); + nyx_debug("%s failed!\n", __func__); assert(false); } #ifdef DEBUG_TIMEOUT_DETECTOR - fprintf(stderr, "SIGALRM HANDLER INSTALLED! tid=%ld\n", syscall(SYS_gettid)); + nyx_debug("SIGALRM HANDLER INSTALLED! tid=%ld\n", syscall(SYS_gettid)); #endif } void reset_timeout_detector(timeout_detector_t *timer) { #ifdef DEBUG_TIMEOUT_DETECTOR - fprintf(stderr, "%s!\n", __func__); + nyx_debug("%s!\n", __func__); #endif if (timer->config.tv_sec || timer->config.tv_usec) { @@ -81,7 +81,7 @@ void reset_timeout_detector(timeout_detector_t *timer) void update_itimer(timeout_detector_t *timer, uint8_t sec, uint32_t usec) { #ifdef DEBUG_TIMEOUT_DETECTOR - // fprintf(stderr, "%s: %x %x\n", __func__, sec, usec); + nyx_debug("%s: %x %x\n", __func__, sec, usec); #endif if (sec || usec) { @@ -96,15 +96,14 @@ void update_itimer(timeout_detector_t *timer, uint8_t sec, uint32_t usec) void arm_sigprof_timer(timeout_detector_t *timer) { #ifdef DEBUG_TIMEOUT_DETECTOR - fprintf(stderr, "%s (%ld %ld)\n", __func__, timer->alarm.it_value.tv_sec, - timer->alarm.it_value.tv_usec); + nyx_debug("%s (%ld %ld)\n", __func__, timer->alarm.it_value.tv_sec, + timer->alarm.it_value.tv_usec); #endif if (timer->detection_enabled) { if (timer->alarm.it_value.tv_usec == 0 && timer->alarm.it_value.tv_sec == 0) { - fprintf(stderr, - "Attempting to re-arm an expired timer! => reset(%ld.%ld)\n", - timer->config.tv_sec, timer->config.tv_usec); + nyx_warn("Attempt to re-arm an expired timer! => reset(%ld.%ld)\n", + timer->config.tv_sec, timer->config.tv_usec); reset_timeout_detector(timer); } assert(setitimer(ITIMER_REAL, &timer->alarm, NULL) == 0); @@ -114,8 +113,8 @@ void arm_sigprof_timer(timeout_detector_t *timer) bool disarm_sigprof_timer(timeout_detector_t *timer) { #ifdef DEBUG_TIMEOUT_DETECTOR - fprintf(stderr, "%s (%ld %ld)\n", __func__, timer->alarm.it_value.tv_sec, - timer->alarm.it_value.tv_usec); + nyx_debug("%s (%ld %ld)\n", __func__, timer->alarm.it_value.tv_sec, + timer->alarm.it_value.tv_usec); #endif if (timer->detection_enabled) { @@ -140,7 +139,6 @@ void block_signals(void) sigaddset(&set, SIGABRT); sigaddset(&set, SIGSEGV); pthread_sigmask(SIG_BLOCK, &set, NULL); - // fprintf(stderr, "%s!\n", __func__); } void unblock_signals(void) @@ -163,7 +161,7 @@ static inline void handle_tmp_snapshot_state(void) qemu_mutex_lock_iothread(); fast_reload_discard_tmp_snapshot(get_fast_reload_snapshot()); /* bye bye */ qemu_mutex_unlock_iothread(); - // fprintf(stderr, "======= SNAPSHOT REMOVED! =======\n"); + // nyx_debug("======= SNAPSHOT REMOVED! =======\n"); } GET_GLOBAL_STATE()->discard_tmp_snapshot = false; set_tmp_snapshot_created(GET_GLOBAL_STATE()->auxilary_buffer, 0); @@ -197,7 +195,7 @@ static inline bool synchronization_check_page_not_found(void) void synchronization_unlock(void) { - // fprintf(stderr, "%s\n", __func__); + // nyx_debug("%s\n", __func__); pthread_mutex_lock(&synchronization_lock_mutex); pthread_cond_signal(&synchronization_lock_condition); @@ -231,7 +229,7 @@ void synchronization_lock(void) if (runtime_usec < 0) { if (runtime_sec < 1) { - fprintf(stderr, "Error: negative payload runtime?!\n"); + nyx_warn("negative payload runtime?!\n"); } runtime_sec -= 1; runtime_usec = timer.config.tv_usec - timer.alarm.it_value.tv_usec + 1000000; @@ -285,15 +283,15 @@ static void perform_reload(void) set_result_dirty_pages(GET_GLOBAL_STATE()->auxilary_buffer, get_dirty_page_num(get_fast_reload_snapshot())); } else { - fprintf(stderr, "WARNING: Root snapshot is not available yet!\n"); + nyx_warn("Root snapshot is not available yet!\n"); } } void synchronization_lock_crash_found(void) { if (!in_fuzzing_loop && GET_GLOBAL_STATE()->in_fuzzing_mode) { - fprintf(stderr, "<%d-%ld>\t%s [NOT IN FUZZING LOOP] at %lx\n", getpid(), - run_counter, __func__, get_rip(qemu_get_cpu(0))); + nyx_warn("<%d-%ld>\t%s [NOT IN FUZZING LOOP] at %lx\n", getpid(), + run_counter, __func__, get_rip(qemu_get_cpu(0))); // abort(); } @@ -311,8 +309,8 @@ void synchronization_lock_crash_found(void) void synchronization_lock_asan_found(void) { if (!in_fuzzing_loop) { - fprintf(stderr, "<%d-%ld>\t%s [NOT IN FUZZING LOOP]\n", getpid(), - run_counter, __func__); + nyx_warn("<%d-%ld>\t%s [NOT IN FUZZING LOOP]\n", getpid(), run_counter, + __func__); set_success_auxiliary_result_buffer(GET_GLOBAL_STATE()->auxilary_buffer, 0); } @@ -329,10 +327,10 @@ void synchronization_lock_asan_found(void) void synchronization_lock_timeout_found(void) { - // fprintf(stderr, "<%d>\t%s\n", getpid(), __func__); + // nyx_debug("<%d>\t%s\n", getpid(), __func__); if (!in_fuzzing_loop) { - // fprintf(stderr, "<%d-%ld>\t%s [NOT IN FUZZING LOOP]\n", getpid(), run_counter, __func__); + // nyx_warn("<%d-%ld>\t%s [NOT IN FUZZING LOOP]\n", getpid(), run_counter, __func__); set_success_auxiliary_result_buffer(GET_GLOBAL_STATE()->auxilary_buffer, 0); } @@ -350,8 +348,8 @@ void synchronization_lock_timeout_found(void) void synchronization_lock_shutdown_detected(void) { if (!in_fuzzing_loop) { - fprintf(stderr, "<%d-%ld>\t%s [NOT IN FUZZING LOOP]\n", getpid(), - run_counter, __func__); + nyx_warn("<%d-%ld>\t%s [NOT IN FUZZING LOOP]\n", getpid(), run_counter, + __func__); set_success_auxiliary_result_buffer(GET_GLOBAL_STATE()->auxilary_buffer, 0); } @@ -369,8 +367,8 @@ void synchronization_payload_buffer_write_detected(void) static char reason[1024]; if (!in_fuzzing_loop) { - fprintf(stderr, "<%d-%ld>\t%s [NOT IN FUZZING LOOP]\n", getpid(), - run_counter, __func__); + nyx_warn("<%d-%ld>\t%s [NOT IN FUZZING LOOP]\n", getpid(), run_counter, + __func__); } pt_disable(qemu_get_cpu(0), false); @@ -391,8 +389,8 @@ void synchronization_payload_buffer_write_detected(void) void synchronization_cow_full_detected(void) { if (!in_fuzzing_loop) { - fprintf(stderr, "<%d-%ld>\t%s [NOT IN FUZZING LOOP]\n", getpid(), - run_counter, __func__); + nyx_warn("<%d-%ld>\t%s [NOT IN FUZZING LOOP]\n", getpid(), run_counter, + __func__); } pt_disable(qemu_get_cpu(0), false); @@ -408,7 +406,7 @@ void synchronization_disable_pt(CPUState *cpu) { // nyx_trace(); if (!in_fuzzing_loop) { - // fprintf(stderr, "<%d-%ld>\t%s [NOT IN FUZZING LOOP]\n", getpid(), run_counter, __func__); + // nyx_warn("<%d-%ld>\t%s [NOT IN FUZZING LOOP]\n", getpid(), run_counter, __func__); set_success_auxiliary_result_buffer(GET_GLOBAL_STATE()->auxilary_buffer, 0); }