From 9fc97fc681200293ceaf32aee92666f27b1f9a67 Mon Sep 17 00:00:00 2001 From: Andrey Pangin Date: Tue, 11 Feb 2020 03:26:19 +0300 Subject: [PATCH] #279, #287, #296: Wall clock profiler improvements: - stable interval - thread states (runnable vs. sleeping) - Java API to update set of monitored threads --- src/arch.h | 3 + src/arguments.cpp | 15 ++- src/arguments.h | 10 +- src/engine.h | 4 +- src/flightRecorder.cpp | 15 +-- src/flightRecorder.h | 3 +- src/java/one/profiler/AsyncProfiler.java | 31 +++++- src/javaApi.cpp | 24 ++++ src/os.h | 20 +++- src/os_linux.cpp | 74 ++++++++++-- src/os_macos.cpp | 65 ++++++++--- src/perfEvents.h | 9 +- src/perfEvents_linux.cpp | 21 +--- src/perfEvents_macos.cpp | 6 - src/profiler.cpp | 29 +++-- src/profiler.h | 25 +++-- src/stackFrame.h | 5 +- src/stackFrame_aarch64.cpp | 10 +- src/stackFrame_arm.cpp | 10 +- src/stackFrame_i386.cpp | 10 +- src/stackFrame_x64.cpp | 36 +++++- src/threadFilter.cpp | 79 +++++++++++++ src/threadFilter.h | 69 ++++++++++++ src/wallClock.cpp | 136 ++++++++++++++++------- src/wallClock.h | 8 +- 25 files changed, 570 insertions(+), 147 deletions(-) create mode 100644 src/threadFilter.cpp create mode 100644 src/threadFilter.h diff --git a/src/arch.h b/src/arch.h index a02325ca..756b14da 100644 --- a/src/arch.h +++ b/src/arch.h @@ -36,6 +36,7 @@ static inline int atomicInc(volatile int& var, int increment = 1) { typedef unsigned char instruction_t; const instruction_t BREAKPOINT = 0xcc; +const int SYSCALL_SIZE = 2; #define spinPause() asm volatile("pause") #define rmb() asm volatile("lfence" : : : "memory") @@ -45,6 +46,7 @@ const instruction_t BREAKPOINT = 0xcc; typedef unsigned int instruction_t; const instruction_t BREAKPOINT = 0xe7f001f0; +const int SYSCALL_SIZE = sizeof(instruction_t); #define spinPause() asm volatile("yield") #define rmb() asm volatile("dmb ish" : : : "memory") @@ -54,6 +56,7 @@ const instruction_t BREAKPOINT = 0xe7f001f0; typedef unsigned int instruction_t; const instruction_t BREAKPOINT = 0xd4200000; +const int SYSCALL_SIZE = sizeof(instruction_t); #define spinPause() asm volatile("yield") #define rmb() asm volatile("dmb ish" : : : "memory") diff --git a/src/arguments.cpp b/src/arguments.cpp index e237cd7b..77b75f7b 100644 --- a/src/arguments.cpp +++ b/src/arguments.cpp @@ -53,6 +53,8 @@ const size_t EXTRA_BUF_SIZE = 512; // interval=N - sampling interval in ns (default: 10'000'000, i.e. 10 ms) // jstackdepth=N - maximum Java stack depth (default: 2048) // framebuf=N - size of the buffer for stack frames (default: 1'000'000) +// file=FILENAME - output file name for dumping +// filter=FILTER - thread filter // threads - profile different threads separately // cstack - collect C stack when profiling Java-level events // allkernel - include only kernel-mode events @@ -66,7 +68,6 @@ const size_t EXTRA_BUF_SIZE = 512; // height=PX - FlameGraph frame height // minwidth=PX - FlameGraph minimum frame width // reverse - generate stack-reversed FlameGraph / Call tree -// file=FILENAME - output file name for dumping // // It is possible to specify multiple dump options at the same time @@ -135,6 +136,13 @@ Error Arguments::parse(const char* args) { if (value == NULL || (_framebuf = atoi(value)) <= 0) { return Error("framebuf must be > 0"); } + } else if (strcmp(arg, "file") == 0) { + if (value == NULL || value[0] == 0) { + return Error("file must not be empty"); + } + _file = value; + } else if (strcmp(arg, "filter") == 0) { + _filter = value == NULL ? "" : value; } else if (strcmp(arg, "threads") == 0) { _threads = true; } else if (strcmp(arg, "cstack") == 0) { @@ -161,11 +169,6 @@ Error Arguments::parse(const char* args) { _minwidth = atof(value); } else if (strcmp(arg, "reverse") == 0) { _reverse = true; - } else if (strcmp(arg, "file") == 0) { - if (value == NULL || value[0] == 0) { - return Error("file must not be empty"); - } - _file = value; } } diff --git a/src/arguments.h b/src/arguments.h index 97f1fb46..e4417ad3 100644 --- a/src/arguments.h +++ b/src/arguments.h @@ -105,10 +105,11 @@ class Arguments { long _interval; int _jstackdepth; int _framebuf; - bool _threads; - bool _cstack; - int _style; const char* _file; + const char* _filter; + bool _threads; + bool _cstack; // TODO + int _style; Output _output; int _dump_traces; int _dump_flat; @@ -128,10 +129,11 @@ class Arguments { _interval(0), _jstackdepth(DEFAULT_JSTACKDEPTH), _framebuf(DEFAULT_FRAMEBUF), + _file(NULL), + _filter(NULL), _threads(false), _cstack(false), _style(0), - _file(NULL), _output(OUTPUT_NONE), _dump_traces(0), _dump_flat(0), diff --git a/src/engine.h b/src/engine.h index 8c3bdf89..f192a573 100644 --- a/src/engine.h +++ b/src/engine.h @@ -29,8 +29,8 @@ class Engine { virtual Error start(Arguments& args) = 0; virtual void stop() = 0; - virtual void onThreadStart() {} - virtual void onThreadEnd() {} + virtual void onThreadStart(int tid) {} + virtual void onThreadEnd(int tid) {} virtual bool requireNativeTrace(); virtual int getNativeTrace(void* ucontext, int tid, const void** callchain, int max_depth, diff --git a/src/flightRecorder.cpp b/src/flightRecorder.cpp index 99f03528..8533ea2d 100644 --- a/src/flightRecorder.cpp +++ b/src/flightRecorder.cpp @@ -25,7 +25,6 @@ #include #include #include "flightRecorder.h" -#include "os.h" #include "profiler.h" #include "vmStructs.h" @@ -89,8 +88,9 @@ enum FrameTypeId { }; enum ThreadStateId { - STATE_RUNNABLE = 1, - STATE_TOTAL_COUNT = 1 + STATE_RUNNABLE = THREAD_RUNNING, + STATE_SLEEPING = THREAD_SLEEPING, + STATE_TOTAL_COUNT = 2 }; @@ -494,6 +494,7 @@ class Recording { buf->put32(CONTENT_STATE); buf->put32(STATE_TOTAL_COUNT); buf->put16(STATE_RUNNABLE); buf->putUtf8("STATE_RUNNABLE"); + buf->put16(STATE_SLEEPING); buf->putUtf8("STATE_SLEEPING"); } void writeStackTraces(Buffer* buf) { @@ -686,14 +687,14 @@ class Recording { buf->put32(metadata_start, buf->offset() - metadata_start); } - void recordExecutionSample(int lock_index, int tid, int call_trace_id) { + void recordExecutionSample(int lock_index, int tid, int call_trace_id, ThreadState thread_state) { Buffer* buf = &_buf[lock_index]; buf->put32(30); buf->put32(EVENT_EXECUTION_SAMPLE); buf->put64(OS::nanotime()); buf->put32(tid); buf->put64(call_trace_id); - buf->put16(STATE_RUNNABLE); + buf->put16(thread_state); flushIfNeeded(buf); } }; @@ -720,8 +721,8 @@ void FlightRecorder::stop() { } } -void FlightRecorder::recordExecutionSample(int lock_index, int tid, int call_trace_id) { +void FlightRecorder::recordExecutionSample(int lock_index, int tid, int call_trace_id, ThreadState thread_state) { if (_rec != NULL && call_trace_id != 0) { - _rec->recordExecutionSample(lock_index, tid, call_trace_id); + _rec->recordExecutionSample(lock_index, tid, call_trace_id, thread_state); } } diff --git a/src/flightRecorder.h b/src/flightRecorder.h index daf5a431..84b3da90 100644 --- a/src/flightRecorder.h +++ b/src/flightRecorder.h @@ -18,6 +18,7 @@ #define _FLIGHTRECORDER_H #include "arguments.h" +#include "os.h" class Recording; @@ -33,7 +34,7 @@ class FlightRecorder { Error start(const char* file); void stop(); - void recordExecutionSample(int lock_index, int tid, int call_trace_id); + void recordExecutionSample(int lock_index, int tid, int call_trace_id, ThreadState thread_state); }; #endif // _FLIGHTRECORDER_H diff --git a/src/java/one/profiler/AsyncProfiler.java b/src/java/one/profiler/AsyncProfiler.java index 65e5f0c6..4faefd74 100644 --- a/src/java/one/profiler/AsyncProfiler.java +++ b/src/java/one/profiler/AsyncProfiler.java @@ -16,6 +16,8 @@ package one.profiler; +import java.io.IOException; + /** * Java API for in-process profiling. Serves as a wrapper around * async-profiler native library. This class is a singleton. @@ -110,10 +112,10 @@ public class AsyncProfiler implements AsyncProfilerMXBean { * @param command Profiling command * @return The command result * @throws IllegalArgumentException If failed to parse the command - * @throws java.io.IOException If failed to create output file + * @throws IOException If failed to create output file */ @Override - public String execute(String command) throws IllegalArgumentException, java.io.IOException { + public String execute(String command) throws IllegalArgumentException, IOException { return execute0(command); } @@ -160,12 +162,35 @@ public class AsyncProfiler implements AsyncProfilerMXBean { return getNativeThreadId0(); } + /** + * Add or remove the given thread to the set of profiled threads + * + * @param thread A thread to add or remove; null means current thread + * @param enable true to enable profiling of the given thread, or + * false to disable profiling + * @throws IllegalStateException If thread has not yet started or has already finished + */ + public void filterThread(Thread thread, boolean enable) throws IllegalStateException { + if (thread == null) { + filterThread0(null, enable); + } else { + synchronized (thread) { + Thread.State state = thread.getState(); + if (state == Thread.State.NEW || state == Thread.State.TERMINATED) { + throw new IllegalStateException("Thread must be running"); + } + filterThread0(thread, enable); + } + } + } + private native void start0(String event, long interval, boolean reset) throws IllegalStateException; private native void stop0() throws IllegalStateException; - private native String execute0(String command) throws IllegalArgumentException, java.io.IOException; + private native String execute0(String command) throws IllegalArgumentException, IOException; private native String dumpCollapsed0(int counter); private native String dumpTraces0(int maxTraces); private native String dumpFlat0(int maxMethods); private native String version0(); private native long getNativeThreadId0(); + private native void filterThread0(Thread thread, boolean enable); } diff --git a/src/javaApi.cpp b/src/javaApi.cpp index 43279289..ce405415 100644 --- a/src/javaApi.cpp +++ b/src/javaApi.cpp @@ -21,6 +21,7 @@ #include "arguments.h" #include "os.h" #include "profiler.h" +#include "vmStructs.h" static void throw_new(JNIEnv* env, const char* exception_class, const char* message) { @@ -128,3 +129,26 @@ extern "C" JNIEXPORT jlong JNICALL Java_one_profiler_AsyncProfiler_getNativeThreadId0(JNIEnv* env, jobject unused) { return OS::threadId(); } + +extern "C" JNIEXPORT void JNICALL +Java_one_profiler_AsyncProfiler_filterThread0(JNIEnv* env, jobject unused, jthread thread, jboolean enable) { + int thread_id; + if (thread == NULL) { + thread_id = OS::threadId(); + } else if (VMThread::hasNativeId()) { + VMThread* vmThread = VMThread::fromJavaThread(env, thread); + if (vmThread == NULL) { + return; + } + thread_id = vmThread->osThreadId(); + } else { + return; + } + + ThreadFilter* thread_filter = Profiler::_instance.threadFilter(); + if (enable) { + thread_filter->add(thread_id); + } else { + thread_filter->remove(thread_id); + } +} diff --git a/src/os.h b/src/os.h index 625bb916..cd82e04e 100644 --- a/src/os.h +++ b/src/os.h @@ -21,25 +21,39 @@ #include "arch.h" +enum ThreadState { + THREAD_INVALID, + THREAD_RUNNING, + THREAD_SLEEPING +}; + + class ThreadList { public: virtual ~ThreadList() {} + virtual void rewind() = 0; virtual int next() = 0; + virtual int size() = 0; }; class OS { + private: + typedef void (*SigAction)(int, siginfo_t*, void*); + typedef void (*SigHandler)(int); + public: static u64 nanotime(); static u64 millis(); static u64 hton64(u64 x); static u64 ntoh64(u64 x); + static int getMaxThreadId(); static int threadId(); - static bool isThreadRunning(int thread_id); + static ThreadState threadState(int thread_id); static bool isSignalSafeTLS(); static bool isJavaLibraryVisible(); - static void installSignalHandler(int signo, void (*handler)(int, siginfo_t*, void*)); - static void sendSignalToThread(int thread_id, int signo); + static void installSignalHandler(int signo, SigAction action, SigHandler handler = NULL); + static bool sendSignalToThread(int thread_id, int signo); static ThreadList* listThreads(); }; diff --git a/src/os_linux.cpp b/src/os_linux.cpp index ad27ada5..efe3a0f0 100644 --- a/src/os_linux.cpp +++ b/src/os_linux.cpp @@ -35,10 +35,33 @@ class LinuxThreadList : public ThreadList { private: DIR* _dir; + int _thread_count; + + int getThreadCount() { + char buf[512]; + int fd = open("/proc/self/stat", O_RDONLY); + if (fd == -1) { + return 0; + } + + int thread_count = 0; + if (read(fd, buf, sizeof(buf)) > 0) { + char* s = strchr(buf, ')'); + if (s != NULL) { + // Read 18th integer field after the command name + for (int field = 0; *s != ' ' || ++field < 18; s++) ; + thread_count = atoi(s + 1); + } + } + + close(fd); + return thread_count; + } public: LinuxThreadList() { _dir = opendir("/proc/self/task"); + _thread_count = -1; } ~LinuxThreadList() { @@ -47,6 +70,13 @@ class LinuxThreadList : public ThreadList { } } + void rewind() { + if (_dir != NULL) { + rewinddir(_dir); + } + _thread_count = -1; + } + int next() { if (_dir != NULL) { struct dirent* entry; @@ -58,6 +88,13 @@ class LinuxThreadList : public ThreadList { } return -1; } + + int size() { + if (_thread_count < 0) { + _thread_count = getThreadCount(); + } + return _thread_count; + } }; @@ -81,26 +118,37 @@ u64 OS::ntoh64(u64 x) { return ntohl(1) == 1 ? x : bswap_64(x); } +int OS::getMaxThreadId() { + char buf[16] = "65536"; + int fd = open("/proc/sys/kernel/pid_max", O_RDONLY); + if (fd != -1) { + ssize_t r = read(fd, buf, sizeof(buf) - 1); + (void) r; + close(fd); + } + return atoi(buf); +} + int OS::threadId() { return syscall(__NR_gettid); } -bool OS::isThreadRunning(int thread_id) { +ThreadState OS::threadState(int thread_id) { char buf[512]; sprintf(buf, "/proc/self/task/%d/stat", thread_id); int fd = open(buf, O_RDONLY); if (fd == -1) { - return false; + return THREAD_INVALID; } - bool running = false; + ThreadState state = THREAD_INVALID; if (read(fd, buf, sizeof(buf)) > 0) { char* s = strchr(buf, ')'); - running = s != NULL && (s[2] == 'R' || s[2] == 'D'); + state = s != NULL && (s[2] == 'R' || s[2] == 'D') ? THREAD_RUNNING : THREAD_SLEEPING; } close(fd); - return running; + return state; } bool OS::isSignalSafeTLS() { @@ -111,19 +159,25 @@ bool OS::isJavaLibraryVisible() { return false; } -void OS::installSignalHandler(int signo, void (*handler)(int, siginfo_t*, void*)) { +void OS::installSignalHandler(int signo, SigAction action, SigHandler handler) { struct sigaction sa; sigemptyset(&sa.sa_mask); - sa.sa_sigaction = handler; - sa.sa_flags = SA_RESTART | SA_SIGINFO; + + if (handler != NULL) { + sa.sa_handler = handler; + sa.sa_flags = 0; + } else { + sa.sa_sigaction = action; + sa.sa_flags = SA_SIGINFO | SA_RESTART; + } sigaction(signo, &sa, NULL); } -void OS::sendSignalToThread(int thread_id, int signo) { +bool OS::sendSignalToThread(int thread_id, int signo) { static const int self_pid = getpid(); - syscall(__NR_tgkill, self_pid, thread_id, signo); + return syscall(__NR_tgkill, self_pid, thread_id, signo) == 0; } ThreadList* OS::listThreads() { diff --git a/src/os_macos.cpp b/src/os_macos.cpp index b7eca997..40edd643 100644 --- a/src/os_macos.cpp +++ b/src/os_macos.cpp @@ -25,29 +25,51 @@ class MacThreadList : public ThreadList { private: + task_t _task; thread_array_t _thread_array; unsigned int _thread_count; unsigned int _thread_index; + void ensureThreadArray() { + if (_thread_array == NULL) { + _thread_count = 0; + _thread_index = 0; + task_threads(_task, &_thread_array, &_thread_count); + } + } + public: - MacThreadList() : _thread_array(NULL), _thread_count(0), _thread_index(0) { - task_threads(mach_task_self(), &_thread_array, &_thread_count); + MacThreadList() { + _task = mach_task_self(); + _thread_array = NULL; } ~MacThreadList() { - task_t task = mach_task_self(); - for (int i = 0; i < _thread_count; i++) { - mach_port_deallocate(task, _thread_array[i]); + rewind(); + } + + void rewind() { + if (_thread_array != NULL) { + for (int i = 0; i < _thread_count; i++) { + mach_port_deallocate(_task, _thread_array[i]); + } + vm_deallocate(_task, (vm_address_t)_thread_array, sizeof(thread_t) * _thread_count); + _thread_array = NULL; } - vm_deallocate(task, (vm_address_t)_thread_array, sizeof(thread_t) * _thread_count); } int next() { + ensureThreadArray(); if (_thread_index < _thread_count) { return (int)_thread_array[_thread_index++]; } return -1; } + + int size() { + ensureThreadArray(); + return _thread_count; + } }; @@ -74,6 +96,10 @@ u64 OS::ntoh64(u64 x) { return OSSwapBigToHostInt64(x); } +int OS::getMaxThreadId() { + return 0x7fffffff; +} + int OS::threadId() { // Used to be pthread_mach_thread_np(pthread_self()), // but pthread_mach_thread_np is not async signal safe @@ -82,13 +108,13 @@ int OS::threadId() { return (int)port; } -bool OS::isThreadRunning(int thread_id) { +ThreadState OS::threadState(int thread_id) { struct thread_basic_info info; mach_msg_type_number_t size = sizeof(info); if (thread_info((thread_act_t)thread_id, THREAD_BASIC_INFO, (thread_info_t)&info, &size) != 0) { - return false; + return THREAD_INVALID; } - return info.run_state == TH_STATE_RUNNING; + return info.run_state == TH_STATE_RUNNING ? THREAD_RUNNING : THREAD_SLEEPING; } bool OS::isSignalSafeTLS() { @@ -99,17 +125,28 @@ bool OS::isJavaLibraryVisible() { return true; } -void OS::installSignalHandler(int signo, void (*handler)(int, siginfo_t*, void*)) { +void OS::installSignalHandler(int signo, SigAction action, SigHandler handler) { struct sigaction sa; sigemptyset(&sa.sa_mask); - sa.sa_sigaction = handler; - sa.sa_flags = SA_RESTART | SA_SIGINFO; + + if (handler != NULL) { + sa.sa_handler = handler; + sa.sa_flags = 0; + } else { + sa.sa_sigaction = action; + sa.sa_flags = SA_SIGINFO | SA_RESTART; + } sigaction(signo, &sa, NULL); } -void OS::sendSignalToThread(int thread_id, int signo) { - asm volatile("syscall" : : "a"(0x2000148), "D"(thread_id), "S"(signo)); +bool OS::sendSignalToThread(int thread_id, int signo) { + int result; + asm volatile("syscall" + : "=a" (result) + : "a" (0x2000148), "D" (thread_id), "S" (signo) + : "rcx", "r11", "memory"); + return result == 0; } ThreadList* OS::listThreads() { diff --git a/src/perfEvents.h b/src/perfEvents.h index 0e19c99a..b0c50908 100644 --- a/src/perfEvents.h +++ b/src/perfEvents.h @@ -47,8 +47,13 @@ class PerfEvents : public Engine { Error start(Arguments& args); void stop(); - void onThreadStart(); - void onThreadEnd(); + void onThreadStart(int tid) { + createForThread(tid); + } + + void onThreadEnd(int tid) { + destroyForThread(tid); + } int getNativeTrace(void* ucontext, int tid, const void** callchain, int max_depth, CodeCache* java_methods, CodeCache* runtime_stubs); diff --git a/src/perfEvents_linux.cpp b/src/perfEvents_linux.cpp index 00ec1c69..74e78ba9 100644 --- a/src/perfEvents_linux.cpp +++ b/src/perfEvents_linux.cpp @@ -61,17 +61,6 @@ enum { static const unsigned long PERF_PAGE_SIZE = sysconf(_SC_PAGESIZE); -static int getMaxPID() { - char buf[16] = "65536"; - int fd = open("/proc/sys/kernel/pid_max", O_RDONLY); - if (fd != -1) { - ssize_t r = read(fd, buf, sizeof(buf) - 1); - (void) r; - close(fd); - } - return atoi(buf); -} - // Get perf_event_attr.config numeric value of the given tracepoint name // by reading /sys/kernel/debug/tracing/events//id file static int findTracepointId(const char* name) { @@ -459,7 +448,7 @@ Error PerfEvents::start(Arguments& args) { } _print_extended_warning = _ring != RING_USER; - int max_events = getMaxPID(); + int max_events = OS::getMaxThreadId(); if (max_events != _max_events) { free(_events); _events = (PerfEvent*)calloc(max_events, sizeof(PerfEvent)); @@ -492,14 +481,6 @@ void PerfEvents::stop() { } } -void PerfEvents::onThreadStart() { - createForThread(OS::threadId()); -} - -void PerfEvents::onThreadEnd() { - destroyForThread(OS::threadId()); -} - int PerfEvents::getNativeTrace(void* ucontext, int tid, const void** callchain, int max_depth, CodeCache* java_methods, CodeCache* runtime_stubs) { PerfEvent* event = &_events[tid]; diff --git a/src/perfEvents_macos.cpp b/src/perfEvents_macos.cpp index a078f8db..2b65ca1b 100644 --- a/src/perfEvents_macos.cpp +++ b/src/perfEvents_macos.cpp @@ -42,12 +42,6 @@ Error PerfEvents::start(Arguments& args) { void PerfEvents::stop() { } -void PerfEvents::onThreadStart() { -} - -void PerfEvents::onThreadEnd() { -} - int PerfEvents::getNativeTrace(void* ucontext, int tid, const void** callchain, int max_depth, CodeCache* java_methods, CodeCache* runtime_stubs) { return 0; diff --git a/src/profiler.cpp b/src/profiler.cpp index d879c98e..e4441df6 100644 --- a/src/profiler.cpp +++ b/src/profiler.cpp @@ -167,6 +167,20 @@ void Profiler::addRuntimeStub(const void* address, int length, const char* name) _stubs_lock.unlock(); } +void Profiler::onThreadStart(jvmtiEnv* jvmti, JNIEnv* jni, jthread thread) { + int tid = OS::threadId(); + _thread_filter.remove(tid); + updateThreadName(jvmti, jni, thread); + _engine->onThreadStart(tid); +} + +void Profiler::onThreadEnd(jvmtiEnv* jvmti, JNIEnv* jni, jthread thread) { + int tid = OS::threadId(); + _thread_filter.remove(tid); + updateThreadName(jvmti, jni, thread); + _engine->onThreadEnd(tid); +} + const char* Profiler::asgctError(int code) { switch (code) { case ticks_no_Java_frame: @@ -432,7 +446,7 @@ bool Profiler::addressInCode(instruction_t* pc) { return false; } -void Profiler::recordSample(void* ucontext, u64 counter, jint event_type, jmethodID event) { +void Profiler::recordSample(void* ucontext, u64 counter, jint event_type, jmethodID event, ThreadState thread_state) { int tid = OS::threadId(); u64 lock_index = atomicInc(_total_samples) % CONCURRENCY_LEVEL; @@ -482,7 +496,7 @@ void Profiler::recordSample(void* ucontext, u64 counter, jint event_type, jmetho storeMethod(frames[0].method_id, frames[0].bci, counter); int call_trace_id = storeCallTrace(num_frames, frames, counter); - _jfr.recordExecutionSample(lock_index, tid, call_trace_id); + _jfr.recordExecutionSample(lock_index, tid, call_trace_id, thread_state); _locks[lock_index].unlock(); } @@ -667,6 +681,9 @@ Error Profiler::start(Arguments& args, bool reset) { _frame_buffer_index = 0; _frame_buffer_overflow = false; + // Reset thread filter bitmaps + _thread_filter.clear(); + // Reset thread names MutexLocker ml(_thread_names_lock); _thread_names.clear(); @@ -704,6 +721,7 @@ Error Profiler::start(Arguments& args, bool reset) { } _threads = args._threads && args._output != OUTPUT_JFR; + _thread_filter.init(args._filter); if (args._output == OUTPUT_JFR) { error = _jfr.start(args._file); @@ -721,11 +739,8 @@ Error Profiler::start(Arguments& args, bool reset) { return error; } - if (_threads) { - // Thread events might be already enabled by PerfEvents::start - switchThreadEvents(JVMTI_ENABLE); - } - + // Thread events might be already enabled by PerfEvents::start + switchThreadEvents(JVMTI_ENABLE); switchNativeMethodTraps(true); _state = RUNNING; diff --git a/src/profiler.h b/src/profiler.h index 6f5b591c..85784b85 100644 --- a/src/profiler.h +++ b/src/profiler.h @@ -22,17 +22,18 @@ #include #include "arch.h" #include "arguments.h" +#include "codeCache.h" #include "engine.h" #include "flightRecorder.h" #include "mutex.h" #include "spinLock.h" -#include "codeCache.h" +#include "threadFilter.h" #include "vmEntry.h" const char FULL_VERSION_STRING[] = "Async-profiler " PROFILER_VERSION " built on " __DATE__ "\n" - "Copyright 2019 Andrei Pangin\n"; + "Copyright 2016-2020 Andrei Pangin\n"; const int MAX_CALLTRACES = 65536; const int MAX_NATIVE_FRAMES = 128; @@ -98,6 +99,7 @@ class Profiler { State _state; Mutex _thread_names_lock; std::map _thread_names; + ThreadFilter _thread_filter; FlightRecorder _jfr; Engine* _engine; time_t _start_time; @@ -148,9 +150,10 @@ class Profiler { void removeJavaMethod(const void* address, jmethodID method); void addRuntimeStub(const void* address, int length, const char* name); + void onThreadStart(jvmtiEnv* jvmti, JNIEnv* jni, jthread thread); + void onThreadEnd(jvmtiEnv* jvmti, JNIEnv* jni, jthread thread); + const char* asgctError(int code); - NativeCodeCache* findNativeLibrary(const void* address); - const char* findNativeMethod(const void* address); int getNativeTrace(void* ucontext, ASGCT_CallFrame* frames, int tid, bool* stopped_at_java_frame); int getJavaTraceAsync(void* ucontext, ASGCT_CallFrame* frames, int max_depth); int getJavaTraceJvmti(jvmtiFrameInfo* jvmti_frames, ASGCT_CallFrame* frames, int max_depth); @@ -173,6 +176,7 @@ class Profiler { Profiler() : _state(IDLE), + _thread_filter(), _jfr(), _frame_buffer(NULL), _frame_buffer_size(0), @@ -196,6 +200,8 @@ class Profiler { u64 total_counter() { return _total_counter; } time_t uptime() { return time(NULL) - _start_time; } + ThreadFilter* threadFilter() { return &_thread_filter; } + NativeCodeCache* jvmLibrary() { return _libjvm; } void run(Arguments& args); @@ -209,8 +215,11 @@ class Profiler { void dumpFlameGraph(std::ostream& out, Arguments& args, bool tree); void dumpTraces(std::ostream& out, Arguments& args); void dumpFlat(std::ostream& out, Arguments& args); - void recordSample(void* ucontext, u64 counter, jint event_type, jmethodID event); + void recordSample(void* ucontext, u64 counter, jint event_type, jmethodID event, ThreadState thread_state = THREAD_RUNNING); + const void* findSymbol(const char* name); + NativeCodeCache* findNativeLibrary(const void* address); + const char* findNativeMethod(const void* address); // CompiledMethodLoad is also needed to enable DebugNonSafepoints info by default static void JNICALL CompiledMethodLoad(jvmtiEnv* jvmti, jmethodID method, @@ -231,13 +240,11 @@ class Profiler { } static void JNICALL ThreadStart(jvmtiEnv* jvmti, JNIEnv* jni, jthread thread) { - _instance.updateThreadName(jvmti, jni, thread); - _instance._engine->onThreadStart(); + _instance.onThreadStart(jvmti, jni, thread); } static void JNICALL ThreadEnd(jvmtiEnv* jvmti, JNIEnv* jni, jthread thread) { - _instance.updateThreadName(jvmti, jni, thread); - _instance._engine->onThreadEnd(); + _instance.onThreadEnd(jvmti, jni, thread); } friend class Recording; diff --git a/src/stackFrame.h b/src/stackFrame.h index aa2a9b09..0a6a8c8f 100644 --- a/src/stackFrame.h +++ b/src/stackFrame.h @@ -65,7 +65,7 @@ class StackFrame { bool pop(bool trust_frame_pointer); - void restartSyscall(); + bool checkInterruptedSyscall(); // Look that many stack slots for a return address candidate. // 0 = do not use stack snooping heuristics. @@ -74,6 +74,9 @@ class StackFrame { // Check if PC looks like a valid return address (i.e. the previous instruction is a CALL). // It's safe to return false to skip return address heuristics. static bool isReturnAddress(instruction_t* pc); + + // Check if PC points to a syscall instruction + static bool isSyscall(instruction_t* pc); }; #endif // _STACKFRAME_H diff --git a/src/stackFrame_aarch64.cpp b/src/stackFrame_aarch64.cpp index 9693d264..a43788ac 100644 --- a/src/stackFrame_aarch64.cpp +++ b/src/stackFrame_aarch64.cpp @@ -19,6 +19,7 @@ #if defined(__aarch64__) +#include #include "stackFrame.h" @@ -76,8 +77,8 @@ bool StackFrame::pop(bool trust_frame_pointer) { return true; } -void StackFrame::restartSyscall() { - // Not implemented on this arch +bool StackFrame::checkInterruptedSyscall() { + return retval() == (uintptr_t)-EINTR; } int StackFrame::callerLookupSlots() { @@ -88,4 +89,9 @@ bool StackFrame::isReturnAddress(instruction_t* pc) { return false; } +bool StackFrame::isSyscall(instruction_t* pc) { + // svc #0 + return *pc == 0xd4000001; +} + #endif // defined(__aarch64__) diff --git a/src/stackFrame_arm.cpp b/src/stackFrame_arm.cpp index 1eb3b801..351d357b 100644 --- a/src/stackFrame_arm.cpp +++ b/src/stackFrame_arm.cpp @@ -16,6 +16,7 @@ #if defined(__arm__) || defined(__thumb__) +#include #include "stackFrame.h" @@ -59,8 +60,8 @@ bool StackFrame::pop(bool trust_frame_pointer) { return false; } -void StackFrame::restartSyscall() { - // Not implemented on this arch +bool StackFrame::checkInterruptedSyscall() { + return retval() == (uintptr_t)-EINTR; } int StackFrame::callerLookupSlots() { @@ -71,4 +72,9 @@ bool StackFrame::isReturnAddress(instruction_t* pc) { return false; } +bool StackFrame::isSyscall(instruction_t* pc) { + // swi #0 + return *pc == 0xef000000; +} + #endif // defined(__arm__) || defined(__thumb__) diff --git a/src/stackFrame_i386.cpp b/src/stackFrame_i386.cpp index 5664f7f4..9134b12c 100644 --- a/src/stackFrame_i386.cpp +++ b/src/stackFrame_i386.cpp @@ -16,6 +16,7 @@ #ifdef __i386__ +#include #include "stackFrame.h" @@ -71,8 +72,8 @@ bool StackFrame::pop(bool trust_frame_pointer) { return false; } -void StackFrame::restartSyscall() { - // Not implemented on this arch +bool StackFrame::checkInterruptedSyscall() { + return retval() == (uintptr_t)-EINTR; } int StackFrame::callerLookupSlots() { @@ -90,4 +91,9 @@ bool StackFrame::isReturnAddress(instruction_t* pc) { return false; } +bool StackFrame::isSyscall(instruction_t* pc) { + // int 0x80 + return pc[0] == 0xcd && pc[1] == 0x80; +} + #endif // __i386__ diff --git a/src/stackFrame_x64.cpp b/src/stackFrame_x64.cpp index 5dab3d4a..5bca2196 100644 --- a/src/stackFrame_x64.cpp +++ b/src/stackFrame_x64.cpp @@ -16,6 +16,8 @@ #ifdef __x86_64__ +#include +#include #include "stackFrame.h" @@ -103,13 +105,31 @@ bool StackFrame::pop(bool trust_frame_pointer) { return false; } -void StackFrame::restartSyscall() { - uintptr_t pc = this->pc(); - if ((pc & 0xfff) >= 7 && *(unsigned short*)(pc - 2) == 0x50f && *(unsigned char*)(pc - 7) == 0xb8 && *(int*)(pc - 6) == 0x7) { - // mov eax, $0x7 - // syscall - this->pc() = pc - 7; +bool StackFrame::checkInterruptedSyscall() { +#ifdef __APPLE__ + // We are not interested in syscalls that do not check error code, e.g. semaphore_wait_trap + if (*(instruction_t*)pc() == 0xc3) { + return true; } + // If CF is set, the error code is in low byte of eax, + // some other syscalls (ulock_wait) do not set CF when interrupted + if (REG(REG_EFL, __rflags) & 1) { + return (retval() & 0xff) == EINTR || (retval() & 0xff) == ETIMEDOUT; + } else { + return retval() == (uintptr_t)-EINTR; + } +#else + if (retval() == (uintptr_t)-EINTR) { + // Workaround for JDK-8237858: restart the interrupted poll() manually. + // Check if the previous instruction is mov eax, SYS_poll + uintptr_t pc = this->pc(); + if ((pc & 0xfff) >= 7 && *(unsigned char*)(pc - 7) == 0xb8 && *(int*)(pc - 6) == SYS_poll) { + this->pc() = pc - 7; + } + return true; + } + return false; +#endif } int StackFrame::callerLookupSlots() { @@ -127,4 +147,8 @@ bool StackFrame::isReturnAddress(instruction_t* pc) { return false; } +bool StackFrame::isSyscall(instruction_t* pc) { + return pc[0] == 0x0f && pc[1] == 0x05; +} + #endif // __x86_64__ diff --git a/src/threadFilter.cpp b/src/threadFilter.cpp new file mode 100644 index 00000000..031f379a --- /dev/null +++ b/src/threadFilter.cpp @@ -0,0 +1,79 @@ +/* + * Copyright 2020 Andrei Pangin + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include +#include +#include "threadFilter.h" + + +ThreadFilter::ThreadFilter() { + memset(_bitmap, 0, sizeof(_bitmap)); + _enabled = false; + _size = 0; +} + +ThreadFilter::~ThreadFilter() { + for (int i = 0; i < MAX_BITMAPS; i++) { + free(_bitmap[i]); + } +} + +void ThreadFilter::init(const char* filter) { + _enabled = filter != NULL; +} + +void ThreadFilter::clear() { + for (int i = 0; i < MAX_BITMAPS; i++) { + if (_bitmap[i] != NULL) { + memset(_bitmap[i], 0, BITMAP_SIZE); + } + } + _size = 0; +} + +bool ThreadFilter::accept(int thread_id) { + u32* b = bitmap(thread_id); + return b != NULL && (word(b, thread_id) & (1 << (thread_id & 0x1f))); +} + +void ThreadFilter::add(int thread_id) { + u32* b = bitmap(thread_id); + if (b == NULL) { + MutexLocker ml(_lock); + b = bitmap(thread_id); + if (b == NULL) { + b = (u32*)calloc(1, BITMAP_SIZE); + _bitmap[(u32)thread_id / BITMAP_CAPACITY] = b; + } + } + + u32 bit = 1 << (thread_id & 0x1f); + if (!(__sync_fetch_and_or(&word(b, thread_id), bit) & bit)) { + atomicInc(_size); + } +} + +void ThreadFilter::remove(int thread_id) { + u32* b = bitmap(thread_id); + if (b == NULL) { + return; + } + + u32 bit = 1 << (thread_id & 0x1f); + if (__sync_fetch_and_and(&word(b, thread_id), ~bit) & bit) { + atomicInc(_size, -1); + } +} diff --git a/src/threadFilter.h b/src/threadFilter.h new file mode 100644 index 00000000..527293c2 --- /dev/null +++ b/src/threadFilter.h @@ -0,0 +1,69 @@ +/* + * Copyright 2020 Andrei Pangin + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#ifndef _THREADFILTER_H +#define _THREADFILTER_H + +#include "arch.h" +#include "mutex.h" + + +// The size of thread ID bitmap in bytes +const u32 BITMAP_SIZE = 65536; +// How many thread IDs one bitmap can hold +const u32 BITMAP_CAPACITY = BITMAP_SIZE * 8; +// Total number of bitmaps required to hold the entire range of thread IDs +const u32 MAX_BITMAPS = (1 << 31) / BITMAP_CAPACITY; + + +// ThreadFilter query operations must be lock-free and signal-safe; +// update operations are mostly lock-free, except rare bitmap allocations +class ThreadFilter { + private: + u32* _bitmap[MAX_BITMAPS]; + Mutex _lock; + bool _enabled; + volatile int _size; + + u32* bitmap(int thread_id) { + return _bitmap[(u32)thread_id / BITMAP_CAPACITY]; + } + + u32& word(u32* bitmap, int thread_id) { + return bitmap[((u32)thread_id % BITMAP_CAPACITY) >> 5]; + } + + public: + ThreadFilter(); + ~ThreadFilter(); + + bool enabled() { + return _enabled; + } + + int size() { + return _size; + } + + void init(const char* filter); + void clear(); + + bool accept(int thread_id); + void add(int thread_id); + void remove(int thread_id); +}; + +#endif // _THREADFILTER_H diff --git a/src/wallClock.cpp b/src/wallClock.cpp index 1b6e1ab7..c9acd77e 100644 --- a/src/wallClock.cpp +++ b/src/wallClock.cpp @@ -14,52 +14,94 @@ * limitations under the License. */ -#include -#include -#include #include -#include +#include +#include #include +#include #include "wallClock.h" -#include "os.h" #include "profiler.h" #include "stackFrame.h" +// Maximum number of threads sampled in one iteration. This limit serves as a throttle +// when generating profiling signals. Otherwise applications with too many threads may +// suffer from a big profiling overhead. Also, keeping this limit low enough helps +// to avoid contention on a spin lock inside Profiler::recordSample(). const int THREADS_PER_TICK = 8; +// Set the hard limit for thread walking interval to 100 microseconds. +// Smaller intervals are practically unusable due to large overhead. +const long MIN_INTERVAL = 100000; + +// Stop profiling thread with this signal. The same signal is used inside JDK to interrupt I/O operations. +const int WAKEUP_SIGNAL = SIGIO; + + long WallClock::_interval; bool WallClock::_sample_idle_threads; -void WallClock::signalHandler(int signo, siginfo_t* siginfo, void* ucontext) { -#ifdef __linux__ - // Workaround for JDK-8237858: restart the interrupted syscall manually. - // Currently this is implemented only for poll(). +ThreadState WallClock::getThreadState(void* ucontext) { StackFrame frame(ucontext); - if (frame.retval() == (uintptr_t)-EINTR) { - frame.restartSyscall(); - } -#endif // __linux__ + uintptr_t pc = frame.pc(); - Profiler::_instance.recordSample(ucontext, _interval, 0, NULL); + // Consider a thread sleeping, if it has been interrupted in the middle of syscall execution, + // either when PC points to the syscall instruction, or if syscall has just returned with EINTR + if (StackFrame::isSyscall((instruction_t*)pc)) { + return THREAD_SLEEPING; + } + + // Make sure the previous instruction address is readable + uintptr_t prev_pc = pc - SYSCALL_SIZE; + if ((pc & 0xfff) >= SYSCALL_SIZE || Profiler::_instance.findNativeLibrary((instruction_t*)prev_pc) != NULL) { + if (StackFrame::isSyscall((instruction_t*)prev_pc) && frame.checkInterruptedSyscall()) { + return THREAD_SLEEPING; + } + } + + return THREAD_RUNNING; +} + +void WallClock::signalHandler(int signo, siginfo_t* siginfo, void* ucontext) { + ThreadState thread_state = _sample_idle_threads ? getThreadState(ucontext) : THREAD_RUNNING; + Profiler::_instance.recordSample(ucontext, _interval, 0, NULL, thread_state); +} + +void WallClock::wakeupHandler(int signo) { + // Dummy handler for interrupting syscalls +} + +long WallClock::adjustInterval(long interval, int thread_count) { + if (thread_count > THREADS_PER_TICK) { + interval /= (thread_count + THREADS_PER_TICK - 1) / THREADS_PER_TICK; + } + return interval; +} + +void WallClock::sleep(long interval) { + struct timespec timeout; + timeout.tv_sec = interval / 1000000000; + timeout.tv_nsec = interval % 1000000000; + + nanosleep(&timeout, NULL); } Error WallClock::start(Arguments& args) { if (args._interval < 0) { return Error("interval must be positive"); } - _interval = args._interval ? args._interval : DEFAULT_INTERVAL; + _sample_idle_threads = strcmp(args._event, EVENT_WALL) == 0; - OS::installSignalHandler(SIGPROF, signalHandler); + // Increase default interval for wall clock mode due to larger number of sampled threads + _interval = args._interval ? args._interval : (_sample_idle_threads ? DEFAULT_INTERVAL * 5 : DEFAULT_INTERVAL); - if (pipe(_pipefd) != 0) { - return Error("Unable to create poll pipe"); - } + OS::installSignalHandler(SIGPROF, signalHandler); + OS::installSignalHandler(WAKEUP_SIGNAL, NULL, wakeupHandler); + + _running = true; if (pthread_create(&_thread, NULL, threadEntry, this) != 0) { - close(_pipefd[1]); - close(_pipefd[0]); return Error("Unable to create timer thread"); } @@ -67,39 +109,55 @@ Error WallClock::start(Arguments& args) { } void WallClock::stop() { - char val = 1; - ssize_t r = write(_pipefd[1], &val, sizeof(val)); - (void)r; - - close(_pipefd[1]); + _running = false; + pthread_kill(_thread, WAKEUP_SIGNAL); pthread_join(_thread, NULL); - close(_pipefd[0]); } void WallClock::timerLoop() { - ThreadList* thread_list = NULL; - int self = OS::threadId(); + ThreadFilter* thread_filter = Profiler::_instance.threadFilter(); + bool thread_filter_enabled = thread_filter->enabled(); bool sample_idle_threads = _sample_idle_threads; - struct pollfd fds = {_pipefd[0], POLLIN, 0}; - int timeout = _interval > 1000000 ? (int)(_interval / 1000000) : 1; - while (poll(&fds, 1, timeout) == 0) { - if (thread_list == NULL) { - thread_list = OS::listThreads(); + ThreadList* thread_list = OS::listThreads(); + long long next_cycle_time = OS::nanotime(); + + while (_running) { + if (sample_idle_threads) { + // Try to keep the wall clock interval stable, regardless of the number of profiled threads + int estimated_thread_count = thread_filter_enabled ? thread_filter->size() : thread_list->size(); + next_cycle_time += adjustInterval(_interval, estimated_thread_count); } for (int count = 0; count < THREADS_PER_TICK; ) { int thread_id = thread_list->next(); if (thread_id == -1) { - delete thread_list; - thread_list = NULL; + thread_list->rewind(); break; } - if (thread_id != self && (sample_idle_threads || OS::isThreadRunning(thread_id))) { - OS::sendSignalToThread(thread_id, SIGPROF); - count++; + + if (thread_id == self || (thread_filter_enabled && !thread_filter->accept(thread_id))) { + continue; } + + if (sample_idle_threads || OS::threadState(thread_id) == THREAD_RUNNING) { + if (OS::sendSignalToThread(thread_id, SIGPROF)) { + count++; + } + } + } + + if (sample_idle_threads) { + long long current_time = OS::nanotime(); + if (next_cycle_time - current_time > MIN_INTERVAL) { + sleep(next_cycle_time - current_time); + } else { + next_cycle_time = current_time + MIN_INTERVAL; + sleep(MIN_INTERVAL); + } + } else { + sleep(_interval); } } diff --git a/src/wallClock.h b/src/wallClock.h index 473b3a5a..1aeaac60 100644 --- a/src/wallClock.h +++ b/src/wallClock.h @@ -21,6 +21,7 @@ #include #include #include "engine.h" +#include "os.h" class WallClock : public Engine { @@ -28,7 +29,7 @@ class WallClock : public Engine { static long _interval; static bool _sample_idle_threads; - int _pipefd[2]; + volatile bool _running; pthread_t _thread; void timerLoop(); @@ -38,7 +39,12 @@ class WallClock : public Engine { return NULL; } + static ThreadState getThreadState(void* ucontext); static void signalHandler(int signo, siginfo_t* siginfo, void* ucontext); + static void wakeupHandler(int signo); + + static long adjustInterval(long interval, int thread_count); + static void sleep(long interval); public: const char* name() {