Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Profile: Fix checks of remaining backtrace buffer #36006

Merged
merged 1 commit into from
Nov 6, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 8 additions & 1 deletion src/signal-handling.c
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,8 @@ extern "C" {

#include <threading.h>

// 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;
Expand Down Expand Up @@ -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
6 changes: 5 additions & 1 deletion src/signals-mach.c
Original file line number Diff line number Diff line change
@@ -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 <mach/clock.h>
#include <mach/clock_types.h>
#include <mach/clock_reply.h>
Expand Down Expand Up @@ -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);
Expand Down
14 changes: 8 additions & 6 deletions src/signals-unix.c
Original file line number Diff line number Diff line change
@@ -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 <signal.h>
#include <sys/types.h>
#include <sys/stat.h>
Expand Down Expand Up @@ -223,7 +225,7 @@ static void sigdie_handler(int sig, siginfo_t *info, void *context)
}

#if defined(HAVE_MACH)
#include <signals-mach.c>
#include "signals-mach.c"
#else

static int is_addr_on_sigstack(jl_ptls_t ptls, void *ptr)
Expand Down Expand Up @@ -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();
Expand All @@ -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
Expand Down
85 changes: 48 additions & 37 deletions src/signals-win.c
Original file line number Diff line number Diff line change
@@ -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

Expand Down Expand Up @@ -324,78 +325,79 @@ 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
profile_bt, // thread function name
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 {
Expand All @@ -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;
}

Expand Down
2 changes: 1 addition & 1 deletion src/stackwalk.c
Original file line number Diff line number Diff line change
Expand Up @@ -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]`.
//
Expand Down
4 changes: 3 additions & 1 deletion stdlib/Profile/src/Profile.jl
Original file line number Diff line number Diff line change
Expand Up @@ -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, ()))
Expand All @@ -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."""
Expand Down
7 changes: 7 additions & 0 deletions stdlib/Profile/test/runtests.jl
Original file line number Diff line number Diff line change
Expand Up @@ -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()...)
Expand Down