From 6f94af79aecc78d2236567f756fe93cf618bd2f4 Mon Sep 17 00:00:00 2001 From: kimikage Date: Thu, 21 May 2020 22:08:17 +0900 Subject: [PATCH] Fix checks of remaining backtrace buffer --- src/signal-handling.c | 9 +++- src/signals-mach.c | 6 ++- src/signals-unix.c | 14 +++--- src/signals-win.c | 85 +++++++++++++++++++-------------- src/stackwalk.c | 2 +- stdlib/Profile/src/Profile.jl | 4 +- stdlib/Profile/test/runtests.jl | 7 +++ 7 files changed, 80 insertions(+), 47 deletions(-) diff --git a/src/signal-handling.c b/src/signal-handling.c index 1f809354361d1..edd59631efbde 100644 --- a/src/signal-handling.c +++ b/src/signal-handling.c @@ -17,7 +17,8 @@ extern "C" { #include -// Profiler control variables // +// Profiler control variables +// Note: these "static" variables are also used in "signals-*.c" static volatile jl_bt_element_t *bt_data_prof = NULL; static volatile size_t bt_size_max = 0; static volatile size_t bt_size_cur = 0; @@ -292,6 +293,12 @@ JL_DLLEXPORT int jl_profile_is_running(void) return running; } +JL_DLLEXPORT int jl_profile_is_buffer_full(void) +{ + // the latter `+ 1` is for the block terminator `0`. + return bt_size_cur + (JL_BT_MAX_ENTRY_SIZE + 1) + 1 > bt_size_max; +} + #ifdef __cplusplus } #endif diff --git a/src/signals-mach.c b/src/signals-mach.c index 3b37ef5fe43a1..3737bab1002cd 100644 --- a/src/signals-mach.c +++ b/src/signals-mach.c @@ -1,5 +1,7 @@ // This file is a part of Julia. License is MIT: https://julialang.org/license +// Note that this file is `#include`d by "signals-unix.c" + #include #include #include @@ -491,8 +493,10 @@ void *mach_profile_listener(void *arg) int keymgr_locked = _keymgr_get_and_lock_processwide_ptr_2(KEYMGR_GCC3_DW2_OBJ_LIST, &unused) == 0; for (i = jl_n_threads; i-- > 0; ) { // if there is no space left, break early - if (bt_size_cur >= bt_size_max - 1) + if (jl_profile_is_buffer_full()) { + jl_profile_stop_timer(); break; + } unw_context_t *uc; jl_thread_suspend_and_get_state(i, &uc); diff --git a/src/signals-unix.c b/src/signals-unix.c index d5a9798b9812f..795000532bbd5 100644 --- a/src/signals-unix.c +++ b/src/signals-unix.c @@ -1,5 +1,7 @@ // This file is a part of Julia. License is MIT: https://julialang.org/license +// Note that this file is `#include`d by "signal-handling.c" + #include #include #include @@ -223,7 +225,7 @@ static void sigdie_handler(int sig, siginfo_t *info, void *context) } #if defined(HAVE_MACH) -#include +#include "signals-mach.c" #else static int is_addr_on_sigstack(jl_ptls_t ptls, void *ptr) @@ -690,7 +692,11 @@ static void *signal_listener(void *arg) // do backtrace for profiler if (profile && running) { - if (bt_size_cur < bt_size_max - 1) { + if (jl_profile_is_buffer_full()) { + // Buffer full: Delete the timer + jl_profile_stop_timer(); + } + else { // unwinding can fail, so keep track of the current state // and restore from the SEGV handler if anything happens. jl_ptls_t ptls = jl_get_ptls_states(); @@ -710,10 +716,6 @@ static void *signal_listener(void *arg) // Mark the end of this block with 0 bt_data_prof[bt_size_cur++].uintptr = 0; } - if (bt_size_cur >= bt_size_max - 1) { - // Buffer full: Delete the timer - jl_profile_stop_timer(); - } } // notify thread to resume diff --git a/src/signals-win.c b/src/signals-win.c index f7fa16bf8b05a..c871c59aa1316 100644 --- a/src/signals-win.c +++ b/src/signals-win.c @@ -1,6 +1,7 @@ // This file is a part of Julia. License is MIT: https://julialang.org/license // Windows +// Note that this file is `#include`d by "signal-handling.c" #define sig_stack_size 131072 // 128k reserved for SEGV handling @@ -324,71 +325,70 @@ JL_DLLEXPORT void jl_install_sigint_handler(void) SetConsoleCtrlHandler((PHANDLER_ROUTINE)sigint_handler,1); } -volatile HANDLE hBtThread = 0; +static volatile HANDLE hBtThread = 0; + static DWORD WINAPI profile_bt( LPVOID lparam ) { - // Note: illegal to use jl_* functions from this thread - - TIMECAPS tc; - if (MMSYSERR_NOERROR != timeGetDevCaps(&tc, sizeof(tc))) { - fputs("failed to get timer resolution", stderr); - hBtThread = 0; - return 0; - } - timeBeginPeriod(tc.wPeriodMin); + // Note: illegal to use jl_* functions from this thread except for profiling-specific functions while (1) { DWORD timeout_ms = nsecprof / (GIGA / 1000); Sleep(timeout_ms > 0 ? timeout_ms : 1); - if (bt_size_cur < bt_size_max && running) { - JL_LOCK_NOGC(&jl_in_stackwalk); - jl_lock_profile(); - if ((DWORD)-1 == SuspendThread(hMainThread)) { - fputs("failed to suspend main thread. aborting profiling.", stderr); - break; + if (running) { + if (jl_profile_is_buffer_full()) { + jl_profile_stop_timer(); // does not change the thread state + SuspendThread(GetCurrentThread()); + continue; } - if (running) { + else { + JL_LOCK_NOGC(&jl_in_stackwalk); + jl_lock_profile(); + if ((DWORD)-1 == SuspendThread(hMainThread)) { + fputs("failed to suspend main thread. aborting profiling.", stderr); + break; + } CONTEXT ctxThread; memset(&ctxThread, 0, sizeof(CONTEXT)); ctxThread.ContextFlags = CONTEXT_CONTROL | CONTEXT_INTEGER; if (!GetThreadContext(hMainThread, &ctxThread)) { fputs("failed to get context from main thread. aborting profiling.", stderr); - running = 0; + jl_profile_stop_timer(); } else { // Get backtrace data bt_size_cur += rec_backtrace_ctx((jl_bt_element_t*)bt_data_prof + bt_size_cur, bt_size_max - bt_size_cur - 1, &ctxThread, NULL); // Mark the end of this block with 0 - if (bt_size_cur < bt_size_max) - bt_data_prof[bt_size_cur++].uintptr = 0; + bt_data_prof[bt_size_cur++].uintptr = 0; + } + jl_unlock_profile(); + JL_UNLOCK_NOGC(&jl_in_stackwalk); + if ((DWORD)-1 == ResumeThread(hMainThread)) { + jl_profile_stop_timer(); + fputs("failed to resume main thread! aborting.", stderr); + gc_debug_critical_error(); + abort(); } } - jl_unlock_profile(); - JL_UNLOCK_NOGC(&jl_in_stackwalk); - if ((DWORD)-1 == ResumeThread(hMainThread)) { - timeEndPeriod(tc.wPeriodMin); - fputs("failed to resume main thread! aborting.", stderr); - gc_debug_critical_error(); - abort(); - } - } - else { - timeEndPeriod(tc.wPeriodMin); - SuspendThread(GetCurrentThread()); - timeBeginPeriod(tc.wPeriodMin); } } jl_unlock_profile(); JL_UNLOCK_NOGC(&jl_in_stackwalk); - timeEndPeriod(tc.wPeriodMin); + jl_profile_stop_timer(); hBtThread = 0; return 0; } +static volatile TIMECAPS timecaps; + JL_DLLEXPORT int jl_profile_start_timer(void) { - running = 1; - if (hBtThread == 0) { + if (hBtThread == NULL) { + + if (MMSYSERR_NOERROR != timeGetDevCaps(&timecaps, sizeof(timecaps))) { + fputs("failed to get timer resolution", stderr); + return -2; + } + hBtThread = CreateThread( NULL, // default security attributes 0, // use default stack size @@ -396,6 +396,8 @@ JL_DLLEXPORT int jl_profile_start_timer(void) 0, // argument to thread function 0, // use default creation flags 0); // returns the thread identifier + if (hBtThread == NULL) + return -1; (void)SetThreadPriority(hBtThread, THREAD_PRIORITY_ABOVE_NORMAL); } else { @@ -404,10 +406,19 @@ JL_DLLEXPORT int jl_profile_start_timer(void) return -2; } } - return (hBtThread != NULL ? 0 : -1); + if (running == 0) { + // Failure to change the timer resolution is not fatal. However, it is important to + // ensure that the timeBeginPeriod/timeEndPeriod is paired. + if (TIMERR_NOERROR != timeBeginPeriod(timecaps.wPeriodMin)) + timecaps.wPeriodMin = 0; + } + running = 1; // set `running` finally + return 0; } JL_DLLEXPORT void jl_profile_stop_timer(void) { + if (running && timecaps.wPeriodMin) + timeEndPeriod(timecaps.wPeriodMin); running = 0; } diff --git a/src/stackwalk.c b/src/stackwalk.c index a70788aacaebb..db10cca2d6a29 100644 --- a/src/stackwalk.c +++ b/src/stackwalk.c @@ -54,7 +54,7 @@ static jl_gcframe_t *is_enter_interpreter_frame(jl_gcframe_t **ppgcstack, uintpt // the call instruction. The first `skip` frames are not included in `bt_data`. // // `maxsize` is the size of the buffer `bt_data` (and `sp` if non-NULL). It -// must be at least JL_BT_MAX_ENTRY_SIZE to accommodate extended backtrace +// must be at least `JL_BT_MAX_ENTRY_SIZE + 1` to accommodate extended backtrace // entries. If `sp != NULL`, the stack pointer corresponding `bt_data[i]` is // stored in `sp[i]`. // diff --git a/stdlib/Profile/src/Profile.jl b/stdlib/Profile/src/Profile.jl index ecc8f99e1ae61..f297ad12f80a1 100644 --- a/stdlib/Profile/src/Profile.jl +++ b/stdlib/Profile/src/Profile.jl @@ -353,6 +353,8 @@ stop_timer() = ccall(:jl_profile_stop_timer, Cvoid, ()) is_running() = ccall(:jl_profile_is_running, Cint, ())!=0 +is_buffer_full() = ccall(:jl_profile_is_buffer_full, Cint, ())!=0 + get_data_pointer() = convert(Ptr{UInt}, ccall(:jl_profile_get_data, Ptr{UInt8}, ())) len_data() = convert(Int, ccall(:jl_profile_len_data, Csize_t, ())) @@ -377,7 +379,7 @@ internal use; [`retrieve`](@ref) may be a better choice for most users. function fetch() maxlen = maxlen_data() len = len_data() - if (len == maxlen) + if is_buffer_full() @warn """The profile data buffer is full; profiling probably terminated before your program finished. To profile for longer runs, call `Profile.init()` with a larger buffer and/or larger delay.""" diff --git a/stdlib/Profile/test/runtests.jl b/stdlib/Profile/test/runtests.jl index 83167870abf18..76f8a3a1b8ca8 100644 --- a/stdlib/Profile/test/runtests.jl +++ b/stdlib/Profile/test/runtests.jl @@ -95,6 +95,13 @@ end Profile.init(n=def_n, delay=def_delay) end +@testset "warning for buffer full" begin + n_, delay_ = Profile.init() + Profile.init(n=17) + @test_logs (:warn, r"The profile data buffer is full") Profile.fetch() + Profile.init(n=n_, delay=delay_) +end + @testset "Line number correction" begin @profile busywait(1, 20) _, fdict0 = Profile.flatten(Profile.retrieve()...)