Skip to content

Commit

Permalink
#49: Ability to start profiler together with JVM and dump profile on …
Browse files Browse the repository at this point in the history 
…exit
  • Loading branch information
Andrei Pangin committed Nov 9, 2017
1 parent 5887145 commit 8b2fd87
Show file tree
Hide file tree
Showing 7 changed files with 93 additions and 84 deletions.
40 changes: 27 additions & 13 deletions profiler.sh
View file
Original file line number Diff line number Diff line change
Expand Up @@ -27,8 +27,25 @@ usage() {
exit 1
}

mirror_output() {
# Mirror output from temporary file to local terminal
if [[ $USE_TMP ]]; then
if [[ -f $FILE ]]; then
cat $FILE
rm $FILE
fi
fi
}

check_if_terminated() {
if ! kill -0 $PID 2> /dev/null; then
mirror_output
exit 0
fi
}

jattach() {
$JATTACH $PID load $PROFILER true $1 > /dev/null
$JATTACH $PID load "$PROFILER" true $1 > /dev/null
RET=$?

# Check if jattach failed
Expand All @@ -37,21 +54,15 @@ jattach() {
echo "Failed to inject profiler into $PID"
UNAME_S=$(uname -s)
if [ "$UNAME_S" == "Darwin" ]; then
otool -L $PROFILER
otool -L "$PROFILER"
else
ldd $PROFILER
ldd "$PROFILER"
fi
fi
exit $RET
fi

# Duplicate output from temporary file to local terminal
if [[ $USE_TMP ]]; then
if [[ -f $FILE ]]; then
cat $FILE
rm $FILE
fi
fi
mirror_output
}

function abspath() {
Expand Down Expand Up @@ -139,7 +150,7 @@ fi

case $ACTION in
start)
jattach start,event=$EVENT,file=$FILE$INTERVAL$FRAMEBUF$THREADS
jattach start,event=$EVENT,file=$FILE$INTERVAL$FRAMEBUF$THREADS,$OUTPUT
;;
stop)
jattach stop,file=$FILE,$OUTPUT
Expand All @@ -151,8 +162,11 @@ case $ACTION in
jattach list,file=$FILE
;;
collect)
jattach start,event=$EVENT,file=$FILE$INTERVAL$FRAMEBUF$THREADS
sleep $DURATION
jattach start,event=$EVENT,file=$FILE$INTERVAL$FRAMEBUF$THREADS,$OUTPUT
while (( DURATION-- > 0 )); do
check_if_terminated
sleep 1
done
jattach stop,file=$FILE,$OUTPUT
;;
esac
15 changes: 9 additions & 6 deletions src/arguments.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -46,10 +46,13 @@ const Error Error::OK(NULL);
//
// It is possible to specify multiple dump options at the same time

Error Arguments::parse(char* args) {
if (strlen(args) >= sizeof(_buf)) {
Error Arguments::parse(const char* args) {
if (args == NULL) {
return Error::OK;
} else if (strlen(args) >= sizeof(_buf)) {
return Error("Argument list too long");
}

strcpy(_buf, args);

for (char* arg = strtok(_buf, ","); arg != NULL; arg = strtok(NULL, ",")) {
Expand All @@ -70,17 +73,13 @@ Error Arguments::parse(char* args) {
}
_event = value;
} else if (strcmp(arg, "collapsed") == 0 || strcmp(arg, "folded") == 0) {
_action = ACTION_DUMP;
_dump_collapsed = true;
_counter = value == NULL || strcmp(value, "samples") == 0 ? COUNTER_SAMPLES : COUNTER_TOTAL;
} else if (strcmp(arg, "summary") == 0) {
_action = ACTION_DUMP;
_dump_summary = true;
} else if (strcmp(arg, "traces") == 0) {
_action = ACTION_DUMP;
_dump_traces = value == NULL ? INT_MAX : atoi(value);
} else if (strcmp(arg, "flat") == 0) {
_action = ACTION_DUMP;
_dump_flat = value == NULL ? INT_MAX : atoi(value);
} else if (strcmp(arg, "interval") == 0) {
if (value == NULL || (_interval = atol(value)) <= 0) {
Expand All @@ -100,5 +99,9 @@ Error Arguments::parse(char* args) {
}
}

if (dumpRequested() && (_action == ACTION_NONE || _action == ACTION_STOP)) {
_action = ACTION_DUMP;
}

return Error::OK;
}
15 changes: 5 additions & 10 deletions src/arguments.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -49,9 +49,6 @@ class Error {
public:
static const Error OK;

Error() {
}

explicit Error(const char* message) : _message(message) {
}

Expand All @@ -68,9 +65,6 @@ class Error {
class Arguments {
private:
char _buf[1024];
Error _error;

Error parse(char* args);

public:
Action _action;
Expand All @@ -85,7 +79,7 @@ class Arguments {
int _dump_traces;
int _dump_flat;

Arguments(char* args) :
Arguments() :
_action(ACTION_NONE),
_counter(COUNTER_SAMPLES),
_event(EVENT_CPU),
Expand All @@ -97,12 +91,13 @@ class Arguments {
_dump_summary(false),
_dump_traces(0),
_dump_flat(0) {
_error = parse(args);
}

Error error() {
return _error;
bool dumpRequested() {
return _dump_collapsed || _dump_summary || _dump_traces > 0 || _dump_flat > 0;
}

Error parse(const char* args);
};

#endif // _ARGUMENTS_H
49 changes: 23 additions & 26 deletions src/profiler.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -247,21 +247,6 @@ int Profiler::getJavaTraceAsync(void* ucontext, ASGCT_CallFrame* frames, int max
return 0;
}

int Profiler::getJavaTraceJVMTI(jvmtiFrameInfo* jvmti_frames, ASGCT_CallFrame* frames, int max_depth) {
jint num_frames;
if (VM::jvmti()->GetStackTrace(NULL, 0, max_depth, jvmti_frames, &num_frames) == 0 && num_frames > 0) {
// Profiler expects stack trace in AsyncGetCallTrace format; convert it now
for (int i = 0; i < num_frames; i++) {
frames[i].method_id = jvmti_frames[i].method;
frames[i].bci = 0;
}
return num_frames;
}

atomicInc(_failures[-ticks_no_Java_frame]);
return 0;
}

int Profiler::makeEventFrame(ASGCT_CallFrame* frames, jint event_type, jmethodID event) {
frames[0].bci = event_type;
frames[0].method_id = event;
Expand Down Expand Up @@ -298,19 +283,12 @@ void Profiler::recordSample(void* ucontext, u64 counter, jint event_type, jmetho

atomicInc(_total_counter, counter);

ASGCT_CallFrame* frames = _calltrace_buffer[lock_index]._asgct_frames;
int num_frames;
ASGCT_CallFrame* frames = _calltrace_buffer[lock_index];
int tid = PerfEvents::tid();

if (event == NULL) {
num_frames = getNativeTrace(tid, frames);
num_frames += getJavaTraceAsync(ucontext, frames + num_frames, MAX_STACK_FRAMES - 1 - num_frames);
} else {
// Events like object allocation happen at known places where it is safe to call JVM TI
jvmtiFrameInfo* jvmti_frames = _calltrace_buffer[lock_index]._jvmti_frames;
num_frames = makeEventFrame(frames, event_type, event);
num_frames += getJavaTraceJVMTI(jvmti_frames + num_frames, frames + num_frames, MAX_STACK_FRAMES - 1 - num_frames);
}
int num_frames = event != NULL ? makeEventFrame(frames, event_type, event) : 0;
num_frames += getNativeTrace(tid, frames);
num_frames += getJavaTraceAsync(ucontext, frames + num_frames, MAX_STACK_FRAMES - 1 - num_frames);

if (_threads) {
num_frames += makeEventFrame(frames + num_frames, BCI_THREAD_ID, (jmethodID)(uintptr_t)tid);
Expand All @@ -324,6 +302,13 @@ void Profiler::recordSample(void* ucontext, u64 counter, jint event_type, jmetho
_locks[lock_index].unlock();
}

void Profiler::initStateLock() {
pthread_mutexattr_t attr;
pthread_mutexattr_init(&attr);
pthread_mutexattr_settype(&attr, PTHREAD_MUTEX_RECURSIVE);
pthread_mutex_init(&_state_lock, &attr);
}

void Profiler::resetSymbols() {
for (int i = 0; i < _native_lib_count; i++) {
delete _native_libs[i];
Expand Down Expand Up @@ -585,3 +570,15 @@ void Profiler::run(Arguments& args) {
}
}
}

void Profiler::shutdown(Arguments& args) {
MutexLocker ml(_state_lock);

// The last chance to dump profile before VM terminates
if (_state == RUNNING && args.dumpRequested()) {
args._action = ACTION_DUMP;
run(args);
}

_state = TERMINATED;
}
18 changes: 4 additions & 14 deletions src/profiler.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -40,12 +40,6 @@ static inline int cmp64(u64 a, u64 b) {
}


union CallTraceBuffer {
ASGCT_CallFrame _asgct_frames[MAX_STACK_FRAMES];
jvmtiFrameInfo _jvmti_frames[MAX_STACK_FRAMES];
};


class CallTraceSample {
private:
u64 _samples;
Expand Down Expand Up @@ -130,7 +124,7 @@ class Profiler {
MethodSample _methods[MAX_CALLTRACES];

SpinLock _locks[CONCURRENCY_LEVEL];
CallTraceBuffer _calltrace_buffer[CONCURRENCY_LEVEL];
ASGCT_CallFrame _calltrace_buffer[CONCURRENCY_LEVEL][MAX_STACK_FRAMES];
ASGCT_CallFrame* _frame_buffer;
int _frame_buffer_size;
volatile int _frame_buffer_index;
Expand All @@ -153,14 +147,14 @@ class Profiler {
const char* findNativeMethod(const void* address);
int getNativeTrace(int tid, ASGCT_CallFrame* frames);
int getJavaTraceAsync(void* ucontext, ASGCT_CallFrame* frames, int max_depth);
int getJavaTraceJVMTI(jvmtiFrameInfo* jvmti_frames, ASGCT_CallFrame* frames, int max_depth);
int makeEventFrame(ASGCT_CallFrame* frames, jint event_type, jmethodID event);
bool fillTopFrame(const void* pc, ASGCT_CallFrame* frame);
u64 hashCallTrace(int num_frames, ASGCT_CallFrame* frames);
void storeCallTrace(int num_frames, ASGCT_CallFrame* frames, u64 counter);
void copyToFrameBuffer(int num_frames, ASGCT_CallFrame* frames, CallTraceSample* trace);
u64 hashMethod(jmethodID method);
void storeMethod(jmethodID method, jint bci, u64 counter);
void initStateLock();
void resetSymbols();
void setSignalHandler();
void runInternal(Arguments& args, std::ostream& out);
Expand All @@ -177,14 +171,15 @@ class Profiler {
_java_methods(),
_runtime_stubs("[stubs]"),
_native_lib_count(0) {
pthread_mutex_init(&_state_lock, NULL);
initStateLock();
}

u64 total_samples() { return _total_samples; }
u64 total_counter() { return _total_counter; }
time_t uptime() { return time(NULL) - _start_time; }

void run(Arguments& args);
void shutdown(Arguments& args);
Error start(const char* event, long interval, int frame_buffer_size, bool threads);
Error stop();
void dumpSummary(std::ostream& out);
Expand All @@ -194,11 +189,6 @@ class Profiler {
void recordSample(void* ucontext, u64 counter, jint event_type, jmethodID event);
NativeCodeCache* jvmLibrary();

static void JNICALL VMDeath(jvmtiEnv* jvmti, JNIEnv* jni) {
MutexLocker ml(_instance._state_lock);
_instance._state = TERMINATED;
}

// CompiledMethodLoad is also needed to enable DebugNonSafepoints info by default
static void JNICALL CompiledMethodLoad(jvmtiEnv* jvmti, jmethodID method,
jint code_size, const void* code_addr,
Expand Down
35 changes: 23 additions & 12 deletions src/vmEntry.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,8 @@
#include "lockTracer.h"


static Arguments _agent_args;

JavaVM* VM::_vm;
jvmtiEnv* VM::_jvmti = NULL;
AsyncGetCallTrace VM::_asyncGetCallTrace;
Expand All @@ -47,7 +49,7 @@ void VM::init(JavaVM* vm, bool attach) {

jvmtiEventCallbacks callbacks = {0};
callbacks.VMInit = VMInit;
callbacks.VMDeath = Profiler::VMDeath;
callbacks.VMDeath = VMDeath;
callbacks.ClassLoad = ClassLoad;
callbacks.ClassPrepare = ClassPrepare;
callbacks.CompiledMethodLoad = Profiler::CompiledMethodLoad;
Expand All @@ -71,13 +73,13 @@ void VM::init(JavaVM* vm, bool attach) {

_asyncGetCallTrace = (AsyncGetCallTrace)dlsym(RTLD_DEFAULT, "AsyncGetCallTrace");
if (_asyncGetCallTrace == NULL) {
// Unable to locate AsyncGetCallTrace, it is likely that JVM has been started
// by JNI_CreateJavaVM() via dynamically loaded libjvm.so from a C/C++ program
// Unable to locate AsyncGetCallTrace, it is likely that JVM has been started
// by JNI_CreateJavaVM() via dynamically loaded libjvm.so from a C/C++ program
void* libjvm_handle = dlopen("libjvm.so", RTLD_NOW);
if (!libjvm_handle) {
std::cerr << "Failed to load libjvm.so: " << dlerror() << std::endl;
}
// Try loading AGCT after opening libjvm.so
// Try loading AGCT after opening libjvm.so
_asyncGetCallTrace = (AsyncGetCallTrace)dlsym(libjvm_handle, "AsyncGetCallTrace");
}

Expand Down Expand Up @@ -107,32 +109,41 @@ void VM::loadAllMethodIDs(jvmtiEnv* jvmti) {
}
}

void JNICALL VM::VMInit(jvmtiEnv* jvmti, JNIEnv* jni, jthread thread) {
loadAllMethodIDs(jvmti);
// Delayed start of profiler if agent has been loaded at VM bootstrap
Profiler::_instance.run(_agent_args);
}

void JNICALL VM::VMDeath(jvmtiEnv* jvmti, JNIEnv* jni) {
Profiler::_instance.shutdown(_agent_args);
}


extern "C" JNIEXPORT jint JNICALL
Agent_OnLoad(JavaVM* vm, char* options, void* reserved) {
VM::init(vm, false);

Arguments args(options);
if (args.error()) {
std::cerr << args.error().message() << std::endl;
Error error = _agent_args.parse(options);
if (error) {
std::cerr << error.message() << std::endl;
return -1;
}

Profiler::_instance.run(args);
return 0;
}

extern "C" JNIEXPORT jint JNICALL
Agent_OnAttach(JavaVM* vm, char* options, void* reserved) {
VM::init(vm, true);

Arguments args(options);
if (args.error()) {
std::cerr << args.error().message() << std::endl;
Error error = _agent_args.parse(options);
if (error) {
std::cerr << error.message() << std::endl;
return -1;
}

Profiler::_instance.run(args);
Profiler::_instance.run(_agent_args);
return 0;
}

Expand Down
Loading

0 comments on commit 8b2fd87

Please sign in to comment.