From acf220910bace257eef1d6466ec81a5915257208 Mon Sep 17 00:00:00 2001 From: Derek Bruening <bruening@google.com> Date: Tue, 4 May 2021 15:15:52 -0400 Subject: [PATCH 1/2] i#4893: Delay function tracing with address tracing In drcachesim, the -trace_after_instrs delayed-tracing feature fails to delay function tracing. We fix that here by leaving the function wrapping in place from the start and simply ignoring i/o until the trigger point. Delaying the function wrapping is complicated by being unable to hold locks during the whole module load event. Locks are needed to delay that event, as we need to enable it and then iterate existing modules. This is why we instead opt to not delay function wrapping. Adds documentation to drwrap_wrap* that event-blocking locks cannot be held. Adds a new test that delays all tracing and ensures there are zero function markers. Fixes #4893 --- .../tests/offline-delay-func.templatex | 20 +++++++++++++++++++ clients/drcachesim/tracer/func_trace.cpp | 5 ++++- clients/drcachesim/tracer/func_trace.h | 2 +- clients/drcachesim/tracer/tracer.cpp | 13 +++++++++--- ext/drwrap/drwrap.h | 8 ++++++++ suite/tests/CMakeLists.txt | 9 ++++++++- 6 files changed, 51 insertions(+), 6 deletions(-) create mode 100644 clients/drcachesim/tests/offline-delay-func.templatex diff --git a/clients/drcachesim/tests/offline-delay-func.templatex b/clients/drcachesim/tests/offline-delay-func.templatex new file mode 100644 index 000000000..7c4f10d7c --- /dev/null +++ b/clients/drcachesim/tests/offline-delay-func.templatex @@ -0,0 +1,20 @@ +Hello, world! +Basic counts tool results: +Total counts: + 0 total \(fetched\) instructions + 0 total unique \(fetched\) instructions + 0 total non-fetched instructions + 0 total prefetches + 0 total data loads + 0 total data stores + 0 total icache flushes + 0 total dcache flushes + 1 total threads + 2 total scheduling markers + 0 total transfer markers + 0 total function id markers + 0 total function return address markers + 0 total function argument markers + 0 total function return value markers + 2 total other markers +.* \ No newline at end of file diff --git a/clients/drcachesim/tracer/func_trace.cpp b/clients/drcachesim/tracer/func_trace.cpp index 5333047db..aa5337e6c 100644 --- a/clients/drcachesim/tracer/func_trace.cpp +++ b/clients/drcachesim/tracer/func_trace.cpp @@ -1,5 +1,5 @@ /* ********************************************************** - * Copyright (c) 2016-2020 Google, Inc. All rights reserved. + * Copyright (c) 2016-2021 Google, Inc. All rights reserved. * **********************************************************/ /* @@ -261,6 +261,9 @@ instru_funcs_module_load(void *drcontext, const module_data_t *mod, bool loaded) if (!hashtable_add(&pc2idplus1, (void *)f_pc, (void *)(ptr_int_t)(id + 1))) DR_ASSERT(false && "Failed to maintain pc2idplus1 internal hashtable"); } + // With the lock restrictions for calling drwrap_wrap_ex(), we can't hold a + // a lock across this entire callback. We release our lock during our + // drwrap_wrap_ex() call. dr_mutex_unlock(funcs_wrapped_lock); if (existing_id != 0) { continue; diff --git a/clients/drcachesim/tracer/func_trace.h b/clients/drcachesim/tracer/func_trace.h index 65825c473..247b06913 100644 --- a/clients/drcachesim/tracer/func_trace.h +++ b/clients/drcachesim/tracer/func_trace.h @@ -1,5 +1,5 @@ /* ********************************************************** - * Copyright (c) 2016-2020 Google, Inc. All rights reserved. + * Copyright (c) 2016-2021 Google, Inc. All rights reserved. * **********************************************************/ /* diff --git a/clients/drcachesim/tracer/tracer.cpp b/clients/drcachesim/tracer/tracer.cpp index ed4f86911..b7919bb5a 100644 --- a/clients/drcachesim/tracer/tracer.cpp +++ b/clients/drcachesim/tracer/tracer.cpp @@ -568,12 +568,20 @@ clean_call(void) * Tracing instrumentation. */ +static int tracing_enabled; + static void append_marker_seg_base(void *drcontext, func_trace_entry_vector_t *vec) { per_thread_t *data = (per_thread_t *)drmgr_get_tls_field(drcontext, tls_idx); if (BUF_PTR(data->seg_base) == NULL) return; /* This thread was filtered out. */ + // i#4893: While it would be lower overhead to delay function tracing's drwrap + // calls rather than solely skipping i/o, the lock restrictions around drwrap + // make it difficult to delay func_trace's module load event. This is the + // simplest way to delay function tracing output. + if (dr_atomic_load32(&tracing_enabled) == 0) + return; // Delayed tracing has not triggered yet. for (int i = 0; i < vec->size; i++) { BUF_PTR(data->seg_base) += instru->append_marker(BUF_PTR(data->seg_base), vec->entries[i].marker_type, @@ -1371,7 +1379,6 @@ event_kernel_xfer(void *drcontext, const dr_kernel_xfer_info_t *info) */ static uint64 instr_count; -static bool tracing_enabled; static volatile bool tracing_scheduled; static void *schedule_tracing_lock; @@ -1436,7 +1443,7 @@ enable_tracing_instrumentation() event_bb_instru2instru, &memtrace_pri)) DR_ASSERT(false); dr_register_filter_syscall_event(event_filter_syscall); - tracing_enabled = true; + dr_atomic_add32_return_sum(&tracing_enabled, 1); } static void @@ -1833,7 +1840,7 @@ event_exit(void) drvector_delete(&scratch_reserve_vec); - if (tracing_enabled) { + if (dr_atomic_load32(&tracing_enabled) > 0) { dr_unregister_filter_syscall_event(event_filter_syscall); if (!drmgr_unregister_pre_syscall_event(event_pre_syscall) || !drmgr_unregister_kernel_xfer_event(event_kernel_xfer) || diff --git a/ext/drwrap/drwrap.h b/ext/drwrap/drwrap.h index 4b80e371d..fad91495d 100644 --- a/ext/drwrap/drwrap.h +++ b/ext/drwrap/drwrap.h @@ -312,6 +312,10 @@ DR_EXPORT * DRWRAP_UNWIND_ON_EXCEPTION flag to drwrap_wrap_ex() to ensure that * all post-call callbacks will be called on an exception. * + * This routine may call dr_unlink_flush_region(), which means that it + * cannot be called while any locks are held that could block a thread + * processing a registered event callback or cache callout. + * * \note The priority of the app2app pass used here is * DRMGR_PRIORITY_INSERT_DRWRAP and its name is * DRMGR_PRIORITY_NAME_DRWRAP. @@ -431,6 +435,10 @@ DR_EXPORT * value, or will access a register or stack slot that does not contain * any argument value. If no calling convention is specified, defaults * to DRWRAP_CALLCONV_DEFAULT. + * + * This routine may call dr_unlink_flush_region(), which means that it + * cannot be called while any locks are held that could block a thread + * processing a registered event callback or cache callout. */ bool drwrap_wrap_ex(app_pc func, void (*pre_func_cb)(void *wrapcxt, INOUT void **user_data), diff --git a/suite/tests/CMakeLists.txt b/suite/tests/CMakeLists.txt index bca58ece2..3b2d5dba5 100644 --- a/suite/tests/CMakeLists.txt +++ b/suite/tests/CMakeLists.txt @@ -3459,9 +3459,16 @@ if (BUILD_CLIENTS) # As for the online test, we check that only 1 thread is in the final trace. torunonly_drcacheoff(max-global client.annotation-concurrency - "-trace_after_instrs 20K -max_global_trace_refs 10K" + # Include function tracing to sanity test combining with delay and max. + "-trace_after_instrs 20K -max_global_trace_refs 10K -record_heap" "@-simulator_type@basic_counts" "${annotation_test_args_shorter}") + torunonly_drcacheoff(delay-func ${ci_shared_app} + # Delay enough that zero data should be logged to test that function + # tracing is delayed (i#4893). + "-trace_after_instrs 200M -record_heap" + "@-simulator_type@basic_counts" "") + # __builtin_prefetch used in the test is not defined on MSVC. if (NOT MSVC) torunonly_drcacheoff(builtin-prefetch-basic-counts builtin_prefetch "" "@-simulator_type@basic_counts" "") -- GitLab From e51f4a57c4b762df848ca53da24ce688ce5bfbda Mon Sep 17 00:00:00 2001 From: Derek Bruening <bruening@google.com> Date: Wed, 12 May 2021 21:30:51 -0400 Subject: [PATCH 2/2] Switch to dr_atomic_store32 --- clients/drcachesim/tracer/tracer.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/clients/drcachesim/tracer/tracer.cpp b/clients/drcachesim/tracer/tracer.cpp index b7919bb5a..3fabf8071 100644 --- a/clients/drcachesim/tracer/tracer.cpp +++ b/clients/drcachesim/tracer/tracer.cpp @@ -1443,7 +1443,7 @@ enable_tracing_instrumentation() event_bb_instru2instru, &memtrace_pri)) DR_ASSERT(false); dr_register_filter_syscall_event(event_filter_syscall); - dr_atomic_add32_return_sum(&tracing_enabled, 1); + dr_atomic_store32(&tracing_enabled, 1); } static void -- GitLab