Compare commits

...

28 Commits
jstack ... v2.0

Author SHA1 Message Date
Andrey Pangin
3ff315ea8f Release 2.0 2021-03-14 20:19:13 +03:00
Andrey Pangin
308074a9eb Print error if JVM does not support Tool Interface (e.g. minimal VM) 2021-03-14 16:49:11 +03:00
Andrey Pangin
685da8d84f Update native thread names on Zing 2021-03-14 16:29:26 +03:00
Andrey Pangin
bd7bf9726e Add [unknown_Java] frame in safe mode 2021-03-14 15:22:34 +03:00
Andrey Pangin
034677435d Fixed handling of some profiler.sh arguments 2021-03-14 14:49:17 +03:00
Andrey Pangin
89f7d34456 Added new safe mode for troubleshooting 2021-03-14 01:03:41 +03:00
Andrey Pangin
ec8a40431a An alias for time-to-safepoint profiling: --ttsp 2021-03-13 01:17:19 +03:00
Andrey Pangin
81bc1f2df2 Support appending JFR profiles on 'resume' command 2021-03-13 00:46:43 +03:00
Andrey Pangin
40ff09a14f Combine async-profiler recording with JDK Flight Recording 2021-03-13 00:14:52 +03:00
Andrey Pangin
d6de541799 Corrected README links 2021-03-04 00:44:33 +03:00
Andrey Pangin
b807987f1d 2.0 Release Candidate 2021-03-04 00:22:42 +03:00
Andrey Pangin
02875138f1 Updated README 2021-03-03 23:52:30 +03:00
Andrey Pangin
d1c19d1904 Updated CHANGELOG. New FlameGraph example 2021-03-03 04:14:51 +03:00
Andrey Pangin
cc2307b92c 'cstack' option now correctly works in multievent profiles 2021-03-03 00:39:47 +03:00
Andrey Pangin
b5d89fef29 --begin/--end compatibility with allocation profiling 2021-03-02 05:11:46 +03:00
Andrey Pangin
646a92e2a0 Improved CLI experience 2021-03-02 02:35:29 +03:00
Andrey Pangin
bcd2375f39 Merge branch 'master' into v2.0
# Conflicts:
#	CHANGELOG.md
#	Makefile
#	README.md
2021-03-01 04:49:53 +03:00
Andrey Pangin
3cbe6aec2f Multievent fixes; 'alloc=bytes' and 'lock=duration' options 2021-03-01 04:41:00 +03:00
Andrey Pangin
2d51c07b23 Output profile in text format: traces + flat 2021-02-28 19:51:24 +03:00
Andrey Pangin
32ead969c1 Graceful handling of storage overflow 2021-02-28 00:38:00 +03:00
Andrey Pangin
de55fadbba JFR writer fixes 2021-02-25 00:33:20 +03:00
Andrey Pangin
da0ac08c64 Correct PerfEvents stack traces when begin/end options are set 2021-02-24 08:02:13 +03:00
Andrey Pangin
5dd9e86a1d Release 1.8.4 2021-02-24 02:50:58 +03:00
Andrey Pangin
81583b9af3 Merge branch 'master' into v2.0
# Conflicts:
#	src/profiler.cpp
2021-02-24 02:34:48 +03:00
Andrey Pangin
7ec5c195e7 Better error handling 2021-02-24 02:31:48 +03:00
Andrey Pangin
cb0f1eb72d Fixed JDK 7 crash during wall-clock profiling 2021-02-20 03:41:37 +03:00
Andrey Pangin
051424890a Recover stack traces below C1 Runtime stubs 2021-02-03 02:08:59 +03:00
Andrey Pangin
34daf4f540 #386: Added a note about IntelliJ IDEA 2021-02-01 19:11:59 +03:00
50 changed files with 2652 additions and 2889 deletions

View File

@@ -1,21 +1,35 @@
# Changelog
## [2.0-b1] - Early access
## [2.0] - 2021-03-14
### Features
- Profile multiple events together (cpu + alloc + lock)
- HTML 5 Flame Graphs: faster rendering, smaller size
- JFR v2 output format, compatible with FlightRecorder API
- JFR to Flame Graph converter
- Automatically turn profiling on/off at `--begin`/`--end` functions
- Time-to-safepoint profiling
- Time-to-safepoint profiling: `--ttsp`
### Improvements
- Unlimited frame buffer. Removed `-b` option and 64K stack traces limit
- Record CPU load in JFR format
- Additional JFR events: OS, CPU, and JVM information; CPU load
- Record bytecode indices / line numbers
- Native stack traces for Java events
- Improved CLI experience
- Better error handling; an option to log warnings/errors to a dedicated stream
- Reduced the amount of unknown stack traces
### Changes
- Removed non-ASL code. No more CDDL license
## [1.8.4] - 2021-02-24
### Improvements
- Smaller and faster agent library
### Bug fixes
- Fixed JDK 7 crash during wall-clock profiling
## [1.8.3] - 2021-01-06
### Improvements

View File

@@ -1,5 +1,4 @@
PROFILER_VERSION=2.0-b1
JATTACH_VERSION=1.5
PROFILER_VERSION=2.0
JAVAC_RELEASE_VERSION=6
PACKAGE_NAME=async-profiler-$(PROFILER_VERSION)-$(OS_TAG)-$(ARCH_TAG)
@@ -21,6 +20,7 @@ JAR=$(JAVA_HOME)/bin/jar
SOURCES := $(wildcard src/*.cpp)
HEADERS := $(wildcard src/*.h)
JAVA_HEADERS := $(patsubst %.java,%.class.h,$(wildcard src/helper/one/profiler/*.java))
API_SOURCES := $(wildcard src/api/one/profiler/*.java)
CONVERTER_SOURCES := $(shell find src/converter -name '*.java')
@@ -83,11 +83,11 @@ $(PACKAGE_NAME).tar.gz: build/$(LIB_PROFILER) build/$(JATTACH) \
build:
mkdir -p build
build/$(LIB_PROFILER_SO): $(SOURCES) $(HEADERS)
build/$(LIB_PROFILER_SO): $(SOURCES) $(HEADERS) $(JAVA_HEADERS)
$(CXX) $(CXXFLAGS) -DPROFILER_VERSION=\"$(PROFILER_VERSION)\" $(INCLUDES) -fPIC -shared -o $@ $(SOURCES) $(LIBS)
build/$(JATTACH): src/jattach/jattach.c
$(CC) $(CFLAGS) -DJATTACH_VERSION=\"$(JATTACH_VERSION)\" -o $@ $^
$(CC) $(CFLAGS) -DJATTACH_VERSION=\"$(PROFILER_VERSION)-ap\" -o $@ $^
build/$(API_JAR): $(API_SOURCES)
mkdir -p build/api
@@ -101,6 +101,12 @@ build/$(CONVERTER_JAR): $(CONVERTER_SOURCES) src/converter/MANIFEST.MF
$(JAR) cvfm $@ src/converter/MANIFEST.MF -C build/converter .
$(RM) -r build/converter
%.class.h: %.class
hexdump -v -e '1/1 "%u,"' $^ > $@
%.class: %.java
$(JAVAC) -g:none -source $(JAVAC_RELEASE_VERSION) -target $(JAVAC_RELEASE_VERSION) $(*D)/*.java
test: all
test/smoke-test.sh
test/thread-smoke-test.sh

566
README.md
View File

@@ -1,7 +1,5 @@
# async-profiler
[![Build Status](https://travis-ci.org/jvm-profiling-tools/async-profiler.svg?branch=master)](https://travis-ci.org/jvm-profiling-tools/async-profiler)
This project is a low overhead sampling profiler for Java
that does not suffer from [Safepoint bias problem](http://psy-lob-saw.blogspot.ru/2016/02/why-most-sampling-java-profilers-are.html).
It features HotSpot-specific APIs to collect stack traces
@@ -13,41 +11,571 @@ async-profiler can trace the following kinds of events:
- Hardware and Software performance counters like cache misses, branch misses, page faults, context switches etc.
- Allocations in Java Heap
- Contented lock attempts, including both Java object monitors and ReentrantLocks
## Usage
See our [Wiki](https://github.com/jvm-profiling-tools/async-profiler/wiki) or [3 hours playlist](https://www.youtube.com/playlist?list=PLNCLTEx3B8h4Yo_WvKWdLvI9mj1XpTKBr) to learn about all set of features.
See our [Wiki](https://github.com/jvm-profiling-tools/async-profiler/wiki) or
[3 hours playlist](https://www.youtube.com/playlist?list=PLNCLTEx3B8h4Yo_WvKWdLvI9mj1XpTKBr)
to learn about all features.
## Download
Latest release (1.8.3):
Current release (2.0):
- Linux x64 (glibc): [async-profiler-1.8.3-linux-x64.tar.gz](https://github.com/jvm-profiling-tools/async-profiler/releases/download/v1.8.3/async-profiler-1.8.3-linux-x64.tar.gz)
- Linux x86 (glibc): [async-profiler-1.8.3-linux-x86.tar.gz](https://github.com/jvm-profiling-tools/async-profiler/releases/download/v1.8.3/async-profiler-1.8.3-linux-x86.tar.gz)
- Linux x64 (musl): [async-profiler-1.8.3-linux-musl-x64.tar.gz](https://github.com/jvm-profiling-tools/async-profiler/releases/download/v1.8.3/async-profiler-1.8.3-linux-musl-x64.tar.gz)
- Linux ARM: [async-profiler-1.8.3-linux-arm.tar.gz](https://github.com/jvm-profiling-tools/async-profiler/releases/download/v1.8.3/async-profiler-1.8.3-linux-arm.tar.gz)
- Linux AArch64: [async-profiler-1.8.3-linux-aarch64.tar.gz](https://github.com/jvm-profiling-tools/async-profiler/releases/download/v1.8.3/async-profiler-1.8.3-linux-aarch64.tar.gz)
- macOS x64: [async-profiler-1.8.3-macos-x64.tar.gz](https://github.com/jvm-profiling-tools/async-profiler/releases/download/v1.8.3/async-profiler-1.8.3-macos-x64.tar.gz)
[Early access](https://github.com/jvm-profiling-tools/async-profiler/releases/tag/v2.0-b1) (2.0-b1):
- Linux x64 (glibc): [async-profiler-2.0-b1-linux-x64.tar.gz](https://github.com/jvm-profiling-tools/async-profiler/releases/download/v2.0-b1/async-profiler-2.0-b1-linux-x64.tar.gz)
- macOS x64: [async-profiler-2.0-b1-macos-x64.tar.gz](https://github.com/jvm-profiling-tools/async-profiler/releases/download/v2.0-b1/async-profiler-2.0-b1-macos-x64.tar.gz)
- Linux x64 (glibc): [async-profiler-2.0-linux-x64.tar.gz](https://github.com/jvm-profiling-tools/async-profiler/releases/download/v2.0/async-profiler-2.0-linux-x64.tar.gz)
- Linux x86 (glibc): [async-profiler-2.0-linux-x86.tar.gz](https://github.com/jvm-profiling-tools/async-profiler/releases/download/v2.0/async-profiler-2.0-linux-x86.tar.gz)
- Linux x64 (musl): [async-profiler-2.0-linux-musl-x64.tar.gz](https://github.com/jvm-profiling-tools/async-profiler/releases/download/v2.0/async-profiler-2.0-linux-musl-x64.tar.gz)
- Linux ARM: [async-profiler-2.0-linux-arm.tar.gz](https://github.com/jvm-profiling-tools/async-profiler/releases/download/v2.0/async-profiler-2.0-linux-arm.tar.gz)
- Linux AArch64: [async-profiler-2.0-linux-aarch64.tar.gz](https://github.com/jvm-profiling-tools/async-profiler/releases/download/v2.0/async-profiler-2.0-linux-aarch64.tar.gz)
- macOS x64: [async-profiler-2.0-macos-x64.tar.gz](https://github.com/jvm-profiling-tools/async-profiler/releases/download/v2.0/async-profiler-2.0-macos-x64.tar.gz)
 
- Converters between profile formats: [converter.jar](https://github.com/jvm-profiling-tools/async-profiler/releases/download/v2.0/converter.jar)
(JFR to Flame Graph, JFR to FlameScope, collapsed stacks to Flame Graph)
[Previous releases](https://github.com/jvm-profiling-tools/async-profiler/releases)
Note: async-profiler also comes bundled with IntelliJ IDEA Ultimate 2018.3 and later.
For more information refer to [IntelliJ IDEA documentation](https://www.jetbrains.com/help/idea/cpu-profiler.html).
## Supported platforms
- **Linux** / x64 / x86 / ARM / AArch64
- **macOS** / x64
- **Linux** / x64 / x86 / ARM / AArch64
- **macOS** / x64
Note: macOS profiling is limited to user space code only.
## CPU profiling
In this mode profiler collects stack trace samples that include **Java** methods,
**native** calls, **JVM** code and **kernel** functions.
The general approach is receiving call stacks generated by `perf_events`
and matching them up with call stacks generated by `AsyncGetCallTrace`,
in order to produce an accurate profile of both Java and native code.
Additionally, async-profiler provides a workaround to recover stack traces
in some [corner cases](https://bugs.openjdk.java.net/browse/JDK-8178287)
where `AsyncGetCallTrace` fails.
This approach has the following advantages compared to using `perf_events`
directly with a Java agent that translates addresses to Java method names:
* Works on older Java versions because it doesn't require
`-XX:+PreserveFramePointer`, which is only available in JDK 8u60 and later.
* Does not introduce the performance overhead from `-XX:+PreserveFramePointer`,
which can in rare cases be as high as 10%.
* Does not require generating a map file to map Java code addresses to method
names.
* Works with interpreter frames.
* Does not require writing out a perf.data file for further processing in
user space scripts.
If you wish to resolve frames within `libjvm`, the [debug symbols](#installing-debug-symbols) are required.
## ALLOCATION profiling
Instead of detecting CPU-consuming code, the profiler can be configured
to collect call sites where the largest amount of heap memory is allocated.
async-profiler does not use intrusive techniques like bytecode instrumentation
or expensive DTrace probes which have significant performance impact.
It also does not affect Escape Analysis or prevent from JIT optimizations
like allocation elimination. Only actual heap allocations are measured.
The profiler features TLAB-driven sampling. It relies on HotSpot-specific
callbacks to receive two kinds of notifications:
- when an object is allocated in a newly created TLAB (aqua frames in a Flame Graph);
- when an object is allocated on a slow path outside TLAB (brown frames).
This means not each allocation is counted, but only allocations every _N_ kB,
where _N_ is the average size of TLAB. This makes heap sampling very cheap
and suitable for production. On the other hand, the collected data
may be incomplete, though in practice it will often reflect the top allocation
sources.
Sampling interval can be adjusted with `--alloc` option.
For example, `--alloc 500k` will take one sample after 500 KB of allocated
space on average. However, intervals less than TLAB size will not take effect.
The minimum supported JDK version is 7u40 where the TLAB callbacks appeared.
### Installing Debug Symbols
The allocation profiler requires HotSpot debug symbols. Oracle JDK already has them
embedded in `libjvm.so`, but in OpenJDK builds they are typically shipped
in a separate package. For example, to install OpenJDK debug symbols on
Debian / Ubuntu, run:
```
# apt install openjdk-8-dbg
```
or for OpenJDK 11:
```
# apt install openjdk-11-dbg
```
On CentOS, RHEL and some other RPM-based distributions, this could be done with
[debuginfo-install](http://man7.org/linux/man-pages/man1/debuginfo-install.1.html) utility:
```
# debuginfo-install java-1.8.0-openjdk
```
On Gentoo the `icedtea` OpenJDK package can be built with the per-package setting
`FEATURES="nostrip"` to retain symbols.
The `gdb` tool can be used to verify if the debug symbols are properly installed for the `libjvm` library.
For example on Linux:
```
$ gdb $JAVA_HOME/lib/server/libjvm.so -ex 'info address UseG1GC'
```
This command's output will either contain `Symbol "UseG1GC" is at 0xxxxx`
or `No symbol "UseG1GC" in current context`.
## Wall-clock profiling
`-e wall` option tells async-profiler to sample all threads equally every given
period of time regardless of thread status: Running, Sleeping or Blocked.
For instance, this can be helpful when profiling application start-up time.
Wall-clock profiler is most useful in per-thread mode: `-t`.
Example: `./profiler.sh -e wall -t -i 5ms -f result.html 8983`
## Java method profiling
`-e ClassName.methodName` option instruments the given Java method
in order to record all invocations of this method with the stack traces.
Example: `-e java.util.Properties.getProperty` will profile all places
where `getProperty` method is called from.
Only non-native Java methods are supported. To profile a native method,
use hardware breakpoint event instead, e.g. `-e Java_java_lang_Throwable_fillInStackTrace`
## Building
Build status: [![Build Status](https://travis-ci.org/jvm-profiling-tools/async-profiler.svg?branch=master)](https://travis-ci.org/jvm-profiling-tools/async-profiler)
Make sure the `JAVA_HOME` environment variable points to your JDK installation,
and then run `make`. GCC is required. After building, the profiler agent binary
will be in the `build` subdirectory. Additionally, a small application `jattach`
that can load the agent into the target process will also be compiled to the
`build` subdirectory.
## Basic Usage
As of Linux 4.6, capturing kernel call stacks using `perf_events` from a non-root
process requires setting two runtime variables. You can set them using
sysctl or as follows:
```
# sysctl kernel.perf_event_paranoid=1
# sysctl kernel.kptr_restrict=0
```
To run the agent and pass commands to it, the helper script `profiler.sh`
is provided. A typical workflow would be to launch your Java application,
attach the agent and start profiling, exercise your performance scenario, and
then stop profiling. The agent's output, including the profiling results, will
be displayed in the Java application's standard output.
Example:
```
$ jps
9234 Jps
8983 Computey
$ ./profiler.sh start 8983
$ ./profiler.sh stop 8983
```
The following may be used in lieu of the `pid` (8983):
- The keyword `jps`, which will use the most recently launched Java process.
- The application name as it appears in the `jps` output: e.g. `Computey`
Alternatively, you may specify `-d` (duration) argument to profile
the application for a fixed period of time with a single command.
```
$ ./profiler.sh -d 30 8983
```
By default, the profiling frequency is 100Hz (every 10ms of CPU time).
Here is a sample of the output printed to the Java application's terminal:
```
--- Execution profile ---
Total samples: 687
Unknown (native): 1 (0.15%)
--- 6790000000 (98.84%) ns, 679 samples
[ 0] Primes.isPrime
[ 1] Primes.primesThread
[ 2] Primes.access$000
[ 3] Primes$1.run
[ 4] java.lang.Thread.run
... a lot of output omitted for brevity ...
ns percent samples top
---------- ------- ------- ---
6790000000 98.84% 679 Primes.isPrime
40000000 0.58% 4 __do_softirq
... more output omitted ...
```
This indicates that the hottest method was `Primes.isPrime`, and the hottest
call stack leading to it comes from `Primes.primesThread`.
## Launching as an Agent
If you need to profile some code as soon as the JVM starts up, instead of using the `profiler.sh` script,
it is possible to attach async-profiler as an agent on the command line. For example:
```
$ java -agentpath:/path/to/libasyncProfiler.so=start,event=cpu,file=profile.html ...
```
Agent library is configured through the JVMTI argument interface.
The format of the arguments string is described
[in the source code](https://github.com/jvm-profiling-tools/async-profiler/blob/v2.0/src/arguments.cpp#L44).
The `profiler.sh` script actually converts command line arguments to that format.
For instance, `-e wall` is converted to `event=wall`, `-f profile.html`
is converted to `file=profile.html`, and so on. However, some arguments are processed
directly by `profiler.sh` script. E.g. `-d 5` results in 3 actions:
attaching profiler agent with start command, sleeping for 5 seconds,
and then attaching the agent again with stop command.
## Multiple events
It is possible to profile CPU, allocations, and locks at the same time.
Or, instead of CPU, you may choose any other execution event: wall-clock,
perf event, tracepoint, Java method, etc.
The only output format that supports multiple events together is JFR.
The recording will contain the following event types:
- `jdk.ExecutionSample`
- `jdk.ObjectAllocationInNewTLAB` (alloc)
- `jdk.ObjectAllocationOutsideTLAB` (alloc)
- `jdk.JavaMonitorEnter` (lock)
- `jdk.ThreadPark` (lock)
To start profiling cpu + allocations + locks together, specify
```
./profiler.sh -e cpu,alloc,lock -f profile.jfr ...
```
or use `--alloc` and `--lock` parameters with the desired threshold:
```
./profiler.sh -e cpu --alloc 2m --lock 10ms -f profile.jfr ...
```
The same, when starting profiler as an agent:
```
-agentpath:/path/to/libasyncProfiler.so=start,event=cpu,alloc=2m,lock=10ms,file=profile.jfr
```
## Flame Graph visualization
async-profiler provides out-of-the-box [Flame Graph](https://github.com/BrendanGregg/FlameGraph) support.
Specify `-o flamegraph` argument to dump profiling results as an interactive HTML Flame Graph.
Also, Flame Graph output format will be chosen automatically if the target filename ends with `.html`.
```
$ jps
9234 Jps
8983 Computey
$ ./profiler.sh -d 30 -f /tmp/flamegraph.html 8983
```
[![Example](https://github.com/jvm-profiling-tools/async-profiler/blob/master/demo/flamegraph.png)](https://htmlpreview.github.io/?https://github.com/jvm-profiling-tools/async-profiler/blob/master/demo/flamegraph.html)
## Profiler Options
The following is a complete list of the command-line options accepted by
`profiler.sh` script.
* `start` - starts profiling in semi-automatic mode, i.e. profiler will run
until `stop` command is explicitly called.
* `resume` - starts or resumes earlier profiling session that has been stopped.
All the collected data remains valid. The profiling options are not preserved
between sessions, and should be specified again.
* `stop` - stops profiling and prints the report.
* `check` - check if the specified profiling event is available.
* `status` - prints profiling status: whether profiler is active and
for how long.
* `list` - show the list of available profiling events. This option still
requires PID, since supported events may differ depending on JVM version.
* `-d N` - the profiling duration, in seconds. If no `start`, `resume`, `stop`
or `status` option is given, the profiler will run for the specified period
of time and then automatically stop.
Example: `./profiler.sh -d 30 8983`
* `-e event` - the profiling event: `cpu`, `alloc`, `lock`, `cache-misses` etc.
Use `list` to see the complete list of available events.
In allocation profiling mode the top frame of every call trace is the class
of the allocated object, and the counter is the heap pressure (the total size
of allocated TLABs or objects outside TLAB).
In lock profiling mode the top frame is the class of lock/monitor, and
the counter is number of nanoseconds it took to enter this lock/monitor.
Two special event types are supported on Linux: hardware breakpoints
and kernel tracepoints:
- `-e mem:<func>[:rwx]` sets read/write/exec breakpoint at function
`<func>`. The format of `mem` event is the same as in `perf-record`.
Execution breakpoints can be also specified by the function name,
e.g. `-e malloc` will trace all calls of native `malloc` function.
- `-e trace:<id>` sets a kernel tracepoint. It is possible to specify
tracepoint symbolic name, e.g. `-e syscalls:sys_enter_open` will trace
all `open` syscalls.
* `-i N` - sets the profiling interval in nanoseconds or in other units,
if N is followed by `ms` (for milliseconds), `us` (for microseconds),
or `s` (for seconds). Only CPU active time is counted. No samples
are collected while CPU is idle. The default is 10000000 (10ms).
Example: `./profiler.sh -i 500us 8983`
* `--alloc N` - allocation profiling interval in bytes or in other units,
if N is followed by `k` (kilobytes), `m` (megabytes), or `g` (gigabytes).
* `--lock N` - lock profiling threshold in nanoseconds (or other units).
In lock profiling mode, record contended locks that the JVM has waited for
longer than the specified duration.
* `-j N` - sets the Java stack profiling depth. This option will be ignored if N is greater
than default 2048.
Example: `./profiler.sh -j 30 8983`
* `-t` - profile threads separately. Each stack trace will end with a frame
that denotes a single thread.
Example: `./profiler.sh -t 8983`
* `-s` - print simple class names instead of FQN.
* `-g` - print method signatures.
* `-a` - annotate Java method names by adding `_[j]` suffix.
* `-o fmt` - specifies what information to dump when profiling ends.
`fmt` can be one of the following options:
- `traces[=N]` - dump call traces (at most N samples);
- `flat[=N]` - dump flat profile (top N hot methods);
can be combined with `traces`, e.g. `traces=200,flat=200`
- `jfr` - dump events in Java Flight Recorder format readable by Java Mission Control.
This *does not* require JDK commercial features to be enabled.
- `collapsed` - dump collapsed call traces in the format used by
[FlameGraph](https://github.com/brendangregg/FlameGraph) script. This is
a collection of call stacks, where each line is a semicolon separated list
of frames followed by a counter.
- `flamegraph` - produce Flame Graph in HTML format.
- `tree` - produce Call Tree in HTML format.
`--reverse` option will generate backtrace view.
* `--total` - count the total value of the collected metric instead of the number of samples,
e.g. total allocation size.
* `-I include`, `-X exclude` - filter stack traces by the given pattern(s).
`-I` defines the name pattern that *must* be present in the stack traces,
while `-X` is the pattern that *must not* occur in any of stack traces in the output.
`-I` and `-X` options can be specified multiple times. A pattern may begin or end with
a star `*` that denotes any (possibly empty) sequence of characters.
Example: `./profiler.sh -I 'Primes.*' -I 'java/*' -X '*Unsafe.park*' 8983`
* `--title TITLE`, `--minwidth PERCENT`, `--reverse` - FlameGraph parameters.
Example: `./profiler.sh -f profile.html --title "Sample CPU profile" --minwidth 0.5 8983`
* `-f FILENAME` - the file name to dump the profile information to.
`%p` in the file name is expanded to the PID of the target JVM;
`%t` - to the timestamp at the time of command invocation.
Example: `./profiler.sh -o collapsed -f /tmp/traces-%t.txt 8983`
* `--all-user` - include only user-mode events. This option is helpful when kernel profiling
is restricted by `perf_event_paranoid` settings.
* `--cstack MODE` - how to traverse native frames (C stack). Possible modes are
`fp` (Frame Pointer), `lbr` (Last Branch Record, available on Haswell since Linux 4.1),
and `no` (do not collect C stack).
By default, C stack is shown in cpu, itimer, wall-clock and perf-events profiles.
Java-level events like `alloc` and `lock` collect only Java stack.
* `--begin function`, `--end function` - automatically start/stop profiling
when the specified native function is executed.
* `--ttsp` - time-to-safepoint profiling. An alias for
`--begin SafepointSynchronize::begin --end RuntimeService::record_safepoint_synchronized`
It is not a separate event type, but rather a constraint. Whatever event type
you choose (e.g. `cpu` or `wall`), the profiler will work as usual, except that
only events between the safepoint request and the start of the VM operation
will be recorded.
* `-v`, `--version` - prints the version of profiler library. If PID is specified,
gets the version of the library loaded into the given process.
## Profiling Java in a container
It is possible to profile Java processes running in a Docker or LXC container
both from within a container and from the host system.
When profiling from the host, `pid` should be the Java process ID in the host
namespace. Use `ps aux | grep java` or `docker top <container>` to find
the process ID.
async-profiler should be run from the host by a privileged user - it will
automatically switch to the proper pid/mount namespace and change
user credentials to match the target process. Also make sure that
the target container can access `libasyncProfiler.so` by the same
absolute path as on the host.
By default, Docker container restricts the access to `perf_event_open`
syscall. So, in order to allow profiling inside a container, you'll need
to modify [seccomp profile](https://docs.docker.com/engine/security/seccomp/)
or disable it altogether with `--security-opt seccomp=unconfined` option. In
addition, `--cap-add SYS_ADMIN` may be required.
Alternatively, if changing Docker configuration is not possible,
you may fall back to `-e itimer` profiling mode, see [Troubleshooting](#troubleshooting).
## Restrictions/Limitations
* On most Linux systems, `perf_events` captures call stacks with a maximum depth
of 127 frames. On recent Linux kernels, this can be configured using
`sysctl kernel.perf_event_max_stack` or by writing to the
`/proc/sys/kernel/perf_event_max_stack` file.
* Profiler allocates 8kB perf_event buffer for each thread of the target process.
Make sure `/proc/sys/kernel/perf_event_mlock_kb` value is large enough
(more than `8 * threads`) when running under unprivileged user.
Otherwise the message _"perf_event mmap failed: Operation not permitted"_
will be printed, and no native stack traces will be collected.
* There is no bullet-proof guarantee that the `perf_events` overflow signal
is delivered to the Java thread in a way that guarantees no other code has run,
which means that in some rare cases, the captured Java stack might not match
the captured native (user+kernel) stack.
* You will not see the non-Java frames _preceding_ the Java frames on the
stack. For example, if `start_thread` called `JavaMain` and then your Java
code started running, you will not see the first two frames in the resulting
stack. On the other hand, you _will_ see non-Java frames (user and kernel)
invoked by your Java code.
* No Java stacks will be collected if `-XX:MaxJavaStackTraceDepth` is zero
or negative.
* Too short profiling interval may cause continuous interruption of heavy
system calls like `clone()`, so that it will never complete;
see [#97](https://github.com/jvm-profiling-tools/async-profiler/issues/97).
The workaround is simply to increase the interval.
* When agent is not loaded at JVM startup (by using -agentpath option) it is
highly recommended to use `-XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints` JVM flags.
Without those flags the profiler will still work correctly but results might be
less accurate. For example, without `-XX:+DebugNonSafepoints` there is a high chance
that simple inlined methods will not appear in the profile. When the agent is attached at runtime,
`CompiledMethodLoad` JVMTI event enables debug info, but only for methods compiled after attaching.
## Troubleshooting
```
Failed to change credentials to match the target process: Operation not permitted
```
Due to limitation of HotSpot Dynamic Attach mechanism, the profiler must be run
by exactly the same user (and group) as the owner of target JVM process.
If profiler is run by a different user, it will try to automatically change
current user and group. This will likely succeed for `root`, but not for
other users, resulting in the above error.
```
Could not start attach mechanism: No such file or directory
```
The profiler cannot establish communication with the target JVM through UNIX domain socket.
Usually this happens in one of the following cases:
1. Attach socket `/tmp/.java_pidNNN` has been deleted. It is a common
practice to clean `/tmp` automatically with some scheduled script.
Configure the cleanup software to exclude `.java_pid*` files from deletion.
How to check: run `lsof -p PID | grep java_pid`
If it lists a socket file, but the file does not exist, then this is exactly
the described problem.
2. JVM is started with `-XX:+DisableAttachMechanism` option.
3. `/tmp` directory of Java process is not physically the same directory
as `/tmp` of your shell, because Java is running in a container or in
`chroot` environment. `jattach` attempts to solve this automatically,
but it might lack the required permissions to do so.
Check `strace build/jattach PID properties`
4. JVM is busy and cannot reach a safepoint. For instance,
JVM is in the middle of long-running garbage collection.
How to check: run `kill -3 PID`. Healthy JVM process should print
a thread dump and heap info in its console.
```
Failed to inject profiler into <pid>
```
The connection with the target JVM has been established, but JVM is unable to load profiler shared library.
Make sure the user of JVM process has permissions to access `libasyncProfiler.so` by exactly the same absolute path.
For more information see [#78](https://github.com/jvm-profiling-tools/async-profiler/issues/78).
```
No access to perf events. Try --all-user option or 'sysctl kernel.perf_event_paranoid=1'
```
or
```
Perf events unavailable
```
`perf_event_open()` syscall has failed.
Typical reasons include:
1. `/proc/sys/kernel/perf_event_paranoid` is set to restricted mode (>=2).
2. seccomp disables perf_event_open API in a container.
3. OS runs under a hypervisor that does not virtualize performance counters.
4. perf_event_open API is not supported on this system, e.g. WSL.
If changing the configuration is not possible, you may fall back to
`-e itimer` profiling mode. It is similar to `cpu` mode, but does not
require perf_events support. As a drawback, there will be no kernel
stack traces.
```
No AllocTracer symbols found. Are JDK debug symbols installed?
```
The OpenJDK debug symbols are required for allocation profiling.
See [Installing Debug Symbols](#installing-debug-symbols) for more details.
If the error message persists after a successful installation of the debug symbols,
it is possible that the JDK was upgraded when installing the debug symbols.
In this case, profiling any Java process which had started prior to the installation
will continue to display this message, since the process had loaded
the older version of the JDK which lacked debug symbols.
Restarting the affected Java processes should resolve the issue.
```
VMStructs unavailable. Unsupported JVM?
```
JVM shared library does not export `gHotSpotVMStructs*` symbols -
apparently this is not a HotSpot JVM. Sometimes the same message
can be also caused by an incorrectly built JDK
(see [#218](https://github.com/jvm-profiling-tools/async-profiler/issues/218)).
In these cases installing JDK debug symbols may solve the problem.
```
Could not parse symbols from <libname.so>
```
Async-profiler was unable to parse non-Java function names because of
the corrupted contents in `/proc/[pid]/maps`. The problem is known to
occur in a container when running Ubuntu with Linux kernel 5.x.
This is the OS bug, see https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1843018.
```
Could not open output file
```
Output file is written by the target JVM process, not by the profiler script.
Make sure the path specified in `-f` option is correct and is accessible by the JVM.

File diff suppressed because it is too large Load Diff

Before

Width:  |  Height:  |  Size: 141 KiB

877
demo/flamegraph.html Normal file
View File

@@ -0,0 +1,877 @@
<!DOCTYPE html>
<html lang='en'>
<head>
<meta charset='utf-8'>
<style>
body {margin: 0; padding: 10px; background-color: #ffffff}
h1 {margin: 5px 0 0 0; font-size: 18px; font-weight: normal; text-align: center}
header {margin: -24px 0 5px 0; line-height: 24px}
button {font: 12px sans-serif; cursor: pointer}
p {margin: 5px 0 5px 0}
a {color: #0366d6}
#hl {position: absolute; display: none; overflow: hidden; white-space: nowrap; pointer-events: none; background-color: #ffffe0; outline: 1px solid #ffc000; height: 15px}
#hl span {padding: 0 3px 0 3px}
#status {overflow: hidden; white-space: nowrap}
#match {overflow: hidden; white-space: nowrap; display: none; float: right; text-align: right}
#reset {cursor: pointer}
</style>
</head>
<body style='font: 12px Verdana, sans-serif'>
<h1>Flame Graph</h1>
<header style='text-align: left'><button id='reverse' title='Reverse'>&#x1f53b;</button>&nbsp;&nbsp;<button id='search' title='Search'>&#x1f50d;</button></header>
<header style='text-align: right'>Produced by <a href='https://github.com/jvm-profiling-tools/async-profiler'>async-profiler</a></header>
<canvas id='canvas' style='width: 100%; height: 752px'></canvas>
<div id='hl'><span></span></div>
<p id='match'>Matched: <span id='matchval'></span> <span id='reset' title='Clear'>&#x274c;</span></p>
<p id='status'>&nbsp;</p>
<script>
// Copyright 2020 Andrei Pangin
// Licensed under the Apache License, Version 2.0.
'use strict';
var root, rootLevel, px, pattern;
var reverse = false;
const levels = Array(47);
for (let h = 0; h < levels.length; h++) {
levels[h] = [];
}
const canvas = document.getElementById('canvas');
const c = canvas.getContext('2d');
const hl = document.getElementById('hl');
const status = document.getElementById('status');
const canvasWidth = canvas.offsetWidth;
const canvasHeight = canvas.offsetHeight;
canvas.style.width = canvasWidth + 'px';
canvas.width = canvasWidth * (devicePixelRatio || 1);
canvas.height = canvasHeight * (devicePixelRatio || 1);
if (devicePixelRatio) c.scale(devicePixelRatio, devicePixelRatio);
c.font = document.body.style.font;
const palette = [
[0x50e150, 30, 30, 30],
[0x50bebe, 30, 30, 30],
[0xe17d00, 30, 30, 0],
[0xc8c83c, 30, 30, 10],
[0xe15a5a, 30, 40, 40],
];
function getColor(p) {
const v = Math.random();
return '#' + (p[0] + ((p[1] * v) << 16 | (p[2] * v) << 8 | (p[3] * v))).toString(16);
}
function f(level, left, width, type, title) {
levels[level].push({left: left, width: width, color: getColor(palette[type]), title: title});
}
function samples(n) {
return n === 1 ? '1 sample' : n.toString().replace(/\B(?=(\d{3})+(?!\d))/g, ',') + ' samples';
}
function pct(a, b) {
return a >= b ? '100' : (100 * a / b).toFixed(2);
}
function findFrame(frames, x) {
let left = 0;
let right = frames.length - 1;
while (left <= right) {
const mid = (left + right) >>> 1;
const f = frames[mid];
if (f.left > x) {
right = mid - 1;
} else if (f.left + f.width <= x) {
left = mid + 1;
} else {
return f;
}
}
if (frames[left] && (frames[left].left - x) * px < 0.5) return frames[left];
if (frames[right] && (x - (frames[right].left + frames[right].width)) * px < 0.5) return frames[right];
return null;
}
function search(r) {
if (r && (r = prompt('Enter regexp to search:', '')) === null) {
return;
}
pattern = r ? RegExp(r) : undefined;
const matched = render(root, rootLevel);
document.getElementById('matchval').textContent = pct(matched, root.width) + '%';
document.getElementById('match').style.display = r ? 'inherit' : 'none';
}
function render(newRoot, newLevel) {
if (root) {
c.fillStyle = '#ffffff';
c.fillRect(0, 0, canvasWidth, canvasHeight);
}
root = newRoot || levels[0][0];
rootLevel = newLevel || 0;
px = canvasWidth / root.width;
const x0 = root.left;
const x1 = x0 + root.width;
const marked = [];
function mark(f) {
return marked[f.left] >= f.width || (marked[f.left] = f.width);
}
function totalMarked() {
let total = 0;
let left = 0;
for (let x in marked) {
if (+x >= left) {
total += marked[x];
left = +x + marked[x];
}
}
return total;
}
function drawFrame(f, y, alpha) {
if (f.left < x1 && f.left + f.width > x0) {
c.fillStyle = pattern && f.title.match(pattern) && mark(f) ? '#ee00ee' : f.color;
c.fillRect((f.left - x0) * px, y, f.width * px, 15);
if (f.width * px >= 21) {
const chars = Math.floor(f.width * px / 7);
const title = f.title.length <= chars ? f.title : f.title.substring(0, chars - 2) + '..';
c.fillStyle = '#000000';
c.fillText(title, Math.max(f.left - x0, 0) * px + 3, y + 12, f.width * px - 6);
}
if (alpha) {
c.fillStyle = 'rgba(255, 255, 255, 0.5)';
c.fillRect((f.left - x0) * px, y, f.width * px, 15);
}
}
}
for (let h = 0; h < levels.length; h++) {
const y = reverse ? h * 16 : canvasHeight - (h + 1) * 16;
const frames = levels[h];
for (let i = 0; i < frames.length; i++) {
drawFrame(frames[i], y, h < rootLevel);
}
}
return totalMarked();
}
canvas.onmousemove = function() {
const h = Math.floor((reverse ? event.offsetY : (canvasHeight - event.offsetY)) / 16);
if (h >= 0 && h < levels.length) {
const f = findFrame(levels[h], event.offsetX / px + root.left);
if (f) {
hl.style.left = (Math.max(f.left - root.left, 0) * px + canvas.offsetLeft) + 'px';
hl.style.width = (Math.min(f.width, root.width) * px) + 'px';
hl.style.top = ((reverse ? h * 16 : canvasHeight - (h + 1) * 16) + canvas.offsetTop) + 'px';
hl.firstChild.textContent = f.title;
hl.style.display = 'block';
canvas.title = f.title + '\n(' + samples(f.width) + ', ' + pct(f.width, levels[0][0].width) + '%)';
canvas.style.cursor = 'pointer';
canvas.onclick = function() {
if (f != root) {
render(f, h);
canvas.onmousemove();
}
};
status.textContent = 'Function: ' + canvas.title;
return;
}
}
canvas.onmouseout();
}
canvas.onmouseout = function() {
hl.style.display = 'none';
status.textContent = '\xa0';
canvas.title = '';
canvas.style.cursor = '';
canvas.onclick = '';
}
document.getElementById('reverse').onclick = function() {
reverse = !reverse;
render();
}
document.getElementById('search').onclick = function() {
search(true);
}
document.getElementById('reset').onclick = function() {
search(false);
}
window.onkeydown = function() {
if (event.ctrlKey && event.keyCode === 70) {
event.preventDefault();
search(true);
} else if (event.keyCode === 27) {
search(false);
}
}
f(0,0,641,4,'all')
f(1,0,5,0,'com/sun/glass/ui/InvokeLaterDispatcher.run')
f(2,0,4,0,'com/sun/glass/ui/gtk/GtkApplication.submitForLaterInvocation')
f(3,0,4,0,'com/sun/glass/ui/gtk/GtkApplication._submitForLaterInvocation')
f(4,0,4,4,'Java_com_sun_glass_ui_gtk_GtkApplication__1submitForLaterInvocation')
f(5,0,4,4,'__write')
f(6,0,4,2,'entry_SYSCALL_64_after_hwframe')
f(7,0,4,2,'do_syscall_64')
f(8,0,4,2,'__x64_sys_write')
f(9,0,4,2,'ksys_write')
f(10,0,4,2,'vfs_write')
f(11,0,4,2,'__vfs_write')
f(12,0,4,2,'eventfd_write')
f(1,5,408,0,'java/lang/Thread.run')
f(2,5,179,0,'com/sun/glass/ui/gtk/GtkApplication$$Lambda$42/1642360923.run')
f(3,5,179,0,'com/sun/glass/ui/gtk/GtkApplication.lambda$null$48')
f(4,5,179,0,'com/sun/glass/ui/gtk/GtkApplication._runLoop')
f(5,5,4,4,'Java_com_sun_glass_ui_gtk_GtkApplication__1runLoop')
f(6,6,2,4,'__writev')
f(7,6,2,2,'entry_SYSCALL_64_after_hwframe')
f(8,6,2,2,'do_syscall_64')
f(9,6,2,2,'__x64_sys_writev')
f(10,6,2,2,'do_writev')
f(11,6,2,2,'vfs_writev')
f(12,6,2,2,'do_iter_write')
f(13,6,2,2,'do_iter_readv_writev')
f(14,6,2,2,'sock_write_iter')
f(15,6,2,2,'sock_sendmsg')
f(16,6,2,2,'inet_sendmsg')
f(17,6,2,2,'tcp_sendmsg')
f(18,6,2,2,'tcp_sendmsg_locked')
f(19,6,2,2,'tcp_push')
f(20,6,2,2,'__tcp_push_pending_frames')
f(21,6,2,2,'tcp_write_xmit')
f(22,6,2,2,'__tcp_transmit_skb')
f(23,6,2,2,'ip_queue_xmit')
f(24,6,2,2,'__ip_queue_xmit')
f(25,6,2,2,'ip_local_out')
f(26,6,2,2,'ip_output')
f(27,6,2,2,'ip_finish_output')
f(28,6,2,2,'__ip_finish_output')
f(29,6,2,2,'ip_finish_output2')
f(30,6,2,2,'dev_queue_xmit')
f(31,6,2,2,'__dev_queue_xmit')
f(32,6,2,2,'sch_direct_xmit')
f(33,6,2,2,'dev_hard_start_xmit')
f(34,6,2,2,'e1000_xmit_frame?[e1000]')
f(5,10,161,0,'com/sun/glass/ui/InvokeLaterDispatcher$Future.run')
f(6,10,6,3,'InterpreterRuntime::monitorexit(JavaThread*, BasicObjectLock*)')
f(7,10,6,3,'ObjectMonitor::ExitEpilog(Thread*, ObjectWaiter*)')
f(8,10,6,4,'pthread_cond_signal@@GLIBC_2.3.2')
f(9,10,6,2,'entry_SYSCALL_64_after_hwframe')
f(10,10,6,2,'do_syscall_64')
f(11,10,6,2,'__x64_sys_futex')
f(12,10,6,2,'do_futex')
f(13,10,6,2,'wake_up_q')
f(14,10,6,2,'try_to_wake_up')
f(15,10,6,2,'_raw_spin_unlock_irqrestore')
f(6,16,58,0,'com/sun/javafx/application/PlatformImpl$$Lambda$53/233530418.run')
f(7,16,58,0,'com/sun/javafx/application/PlatformImpl.lambda$runLater$173')
f(8,17,57,0,'java/security/AccessController.doPrivileged')
f(9,17,57,0,'com/sun/javafx/application/PlatformImpl$$Lambda$54/1140247440.run')
f(10,17,57,0,'com/sun/javafx/application/PlatformImpl.lambda$null$172')
f(11,17,55,0,'com/sun/javafx/application/PlatformImpl$$Lambda$52/1364335809.run')
f(12,17,55,0,'com/sun/javafx/application/PlatformImpl.lambda$runAndWait$174')
f(13,17,4,0,'com/sun/javafx/application/LauncherImpl$$Lambda$57/1790390841.run')
f(14,17,4,0,'com/sun/javafx/application/LauncherImpl.lambda$launchApplication1$160')
f(15,17,4,0,'java/lang/reflect/Constructor.newInstance')
f(16,17,4,0,'sun/reflect/DelegatingConstructorAccessorImpl.newInstance')
f(17,17,4,0,'sun/reflect/NativeConstructorAccessorImpl.newInstance')
f(18,17,4,0,'sun/reflect/NativeConstructorAccessorImpl.newInstance0')
f(19,17,4,0,'demo/parallel/Main.<init>')
f(20,17,2,0,'java/lang/ClassLoader.loadClass')
f(21,17,2,0,'java/lang/ClassLoader.loadClass')
f(22,17,2,0,'java/net/URLClassLoader.findClass')
f(23,17,2,0,'java/security/AccessController.doPrivileged')
f(24,17,2,0,'java/net/URLClassLoader$1.run')
f(25,17,2,0,'java/net/URLClassLoader$1.run')
f(26,17,2,0,'java/net/URLClassLoader.access$100')
f(27,17,2,0,'java/net/URLClassLoader.defineClass')
f(28,17,2,0,'java/security/SecureClassLoader.defineClass')
f(13,21,50,0,'com/sun/javafx/application/LauncherImpl$$Lambda$63/508611611.run')
f(14,21,50,0,'com/sun/javafx/application/LauncherImpl.lambda$launchApplication1$161')
f(15,21,49,0,'demo/parallel/Main.start')
f(16,22,17,0,'demo/parallel/Main.createContent')
f(17,23,14,0,'demo/parallel/Main.createControlPane')
f(18,26,8,0,'javafx/scene/control/Control.<clinit>')
f(19,26,8,0,'com/sun/javafx/application/PlatformImpl.setDefaultPlatformUserAgentStylesheet')
f(20,26,8,0,'com/sun/javafx/application/PlatformImpl.setPlatformUserAgentStylesheet')
f(21,26,8,0,'com/sun/javafx/application/PlatformImpl._setPlatformUserAgentStylesheet')
f(22,27,7,0,'java/security/AccessController.doPrivileged')
f(23,27,7,0,'com/sun/javafx/application/PlatformImpl$$Lambda$68/360857571.run')
f(24,27,7,0,'com/sun/javafx/application/PlatformImpl.lambda$_setPlatformUserAgentStylesheet$181')
f(25,27,7,0,'com/sun/javafx/css/StyleManager.setUserAgentStylesheets')
f(26,27,6,0,'com/sun/javafx/css/StyleManager._setDefaultUserAgentStylesheet')
f(27,28,5,0,'com/sun/javafx/css/StyleManager.loadStylesheet')
f(28,28,5,0,'com/sun/javafx/css/StyleManager.loadStylesheetUnPrivileged')
f(29,28,2,0,'com/sun/javafx/css/StyleManager.getURL')
f(30,28,2,0,'java/lang/Class.forName')
f(31,28,2,0,'java/lang/Class.forName0')
f(32,28,2,0,'com/sun/javafx/scene/control/skin/Utils.<clinit>')
f(29,30,3,0,'com/sun/javafx/css/Stylesheet.loadBinary')
f(30,30,3,0,'com/sun/javafx/css/Stylesheet.readBinary')
f(31,30,3,0,'com/sun/javafx/css/Rule.readBinary')
f(32,30,3,0,'com/sun/javafx/css/Selector.readBinary')
f(33,30,2,0,'com/sun/javafx/css/CompoundSelector.readBinary')
f(16,40,11,0,'javafx/scene/Scene.<init>')
f(17,40,11,0,'javafx/scene/Scene.<init>')
f(18,40,11,0,'javafx/scene/Scene.setRoot')
f(19,40,11,0,'javafx/beans/property/ObjectPropertyBase.set')
f(20,40,11,0,'javafx/beans/property/ObjectPropertyBase.markInvalid')
f(21,40,11,0,'javafx/scene/Scene$9.invalidated')
f(22,40,11,0,'javafx/scene/Node.setScenes')
f(23,40,11,0,'javafx/scene/Node.invalidatedScenes')
f(24,40,11,0,'javafx/scene/Node.impl_reapplyCSS')
f(25,41,10,0,'javafx/scene/Node.reapplyCss')
f(26,42,3,0,'javafx/scene/CssStyleHelper.<clinit>')
f(27,42,3,0,'javafx/scene/text/Font.getDefault')
f(28,42,3,0,'javafx/scene/text/Font.<init>')
f(29,42,3,0,'com/sun/javafx/font/PrismFontLoader.loadFont')
f(30,42,2,0,'com/sun/javafx/font/PrismFontFactory.createFont')
f(31,42,2,0,'com/sun/javafx/font/LogicalFont.getLogicalFont')
f(32,42,2,0,'com/sun/javafx/font/LogicalFont.getLogicalFont')
f(33,42,2,0,'com/sun/javafx/font/LogicalFont.<init>')
f(34,42,2,0,'com/sun/javafx/font/FontConfigManager.getFontConfigFont')
f(35,42,2,0,'com/sun/javafx/font/FontConfigManager.initFontConfigLogFonts')
f(36,42,2,0,'com/sun/javafx/font/FontConfigManager.getFontConfig')
f(26,45,2,0,'javafx/scene/CssStyleHelper.createStyleHelper')
f(26,47,4,0,'javafx/scene/Node.reapplyCss')
f(27,47,3,0,'javafx/scene/CssStyleHelper.createStyleHelper')
f(28,47,3,0,'com/sun/javafx/css/StyleManager.findMatchingStyles')
f(29,47,3,0,'com/sun/javafx/css/StyleManager.gatherParentStylesheets')
f(30,47,3,0,'com/sun/javafx/css/StyleManager.processStylesheets')
f(31,47,3,0,'com/sun/javafx/css/StyleManager.loadStylesheet')
f(32,47,3,0,'com/sun/javafx/css/StyleManager.loadStylesheetUnPrivileged')
f(33,48,2,0,'com/sun/javafx/css/parser/CSSParser.parse')
f(34,48,2,0,'com/sun/javafx/css/parser/CSSParser.parse')
f(16,51,19,0,'javafx/stage/Stage.show')
f(17,51,19,0,'javafx/stage/Window.show')
f(18,51,19,0,'javafx/stage/Window.setShowing')
f(19,51,19,0,'javafx/beans/property/BooleanPropertyBase.set')
f(20,51,19,0,'javafx/beans/property/BooleanPropertyBase.markInvalid')
f(21,51,19,0,'javafx/stage/Window$9.invalidated')
f(22,52,3,0,'javafx/scene/Scene.impl_initPeer')
f(22,55,14,0,'javafx/scene/Scene.impl_preferredSize')
f(23,55,14,0,'javafx/scene/Scene.preferredSize')
f(24,55,11,0,'javafx/scene/Scene.doCSSPass')
f(25,55,11,0,'javafx/scene/Node.processCSS')
f(26,55,11,0,'javafx/scene/Parent.impl_processCSS')
f(27,56,10,0,'javafx/scene/Parent.impl_processCSS')
f(28,56,10,0,'javafx/scene/control/Control.impl_processCSS')
f(29,56,3,0,'javafx/scene/Parent.impl_processCSS')
f(30,56,3,0,'javafx/scene/Node.impl_processCSS')
f(31,56,3,0,'javafx/scene/CssStyleHelper.transitionToState')
f(29,59,4,0,'javafx/scene/control/Button.createDefaultSkin')
f(30,59,4,0,'com/sun/javafx/scene/control/skin/ButtonSkin.<init>')
f(31,59,4,0,'com/sun/javafx/scene/control/skin/LabeledSkinBase.<init>')
f(32,61,2,0,'com/sun/javafx/scene/control/skin/LabeledText.<init>')
f(33,61,2,0,'javafx/css/StyleableObjectProperty.bind')
f(34,61,2,0,'javafx/beans/property/ObjectPropertyBase.bind')
f(35,61,2,0,'javafx/beans/property/ObjectPropertyBase.markInvalid')
f(36,61,2,0,'javafx/scene/text/Text$5.invalidated')
f(37,61,2,0,'javafx/scene/text/Text.access$200')
f(38,61,2,0,'javafx/scene/text/Text.needsFullTextLayout')
f(39,61,2,0,'javafx/scene/text/Text.getTextLayout')
f(40,61,2,0,'com/sun/javafx/text/PrismTextLayout.setContent')
f(41,61,2,0,'com/sun/javafx/font/PrismFont.getStrike')
f(42,61,2,0,'com/sun/javafx/font/LogicalFont.getStrike')
f(43,61,2,0,'com/sun/javafx/font/LogicalFont.getDefaultAAMode')
f(44,61,2,0,'com/sun/javafx/font/LogicalFont.getSlot0Resource')
f(45,61,2,0,'com/sun/javafx/font/PrismFontFactory.getFontResource')
f(46,61,2,0,'com/sun/javafx/font/PrismFontFactory.getFullNameToFileMap')
f(29,64,2,0,'javafx/scene/control/ProgressIndicator.createDefaultSkin')
f(24,67,2,0,'javafx/scene/Scene.resizeRootToPreferredSize')
f(25,67,2,0,'javafx/scene/Scene.getPreferredWidth')
f(26,67,2,0,'javafx/scene/layout/Region.prefWidth')
f(27,67,2,0,'javafx/scene/Parent.prefWidth')
f(28,67,2,0,'javafx/scene/layout/Region.computePrefWidth')
f(29,67,2,0,'javafx/scene/Parent.computePrefWidth')
f(30,67,2,0,'javafx/scene/layout/Region.prefWidth')
f(31,67,2,0,'javafx/scene/Parent.prefWidth')
f(32,67,2,0,'javafx/scene/layout/GridPane.computePrefWidth')
f(33,67,2,0,'javafx/scene/layout/GridPane.computePrefWidths')
f(34,67,2,0,'javafx/scene/layout/Region.computeChildPrefAreaWidth')
f(35,67,2,0,'javafx/scene/layout/Region.minWidth')
f(36,67,2,0,'javafx/scene/Parent.minWidth')
f(37,67,2,0,'javafx/scene/control/Control.computeMinWidth')
f(38,67,2,0,'com/sun/javafx/scene/control/skin/LabeledSkinBase.computeMinWidth')
f(39,67,2,0,'com/sun/javafx/scene/control/skin/LabeledSkinBase.computeMinLabeledPartWidth')
f(40,67,2,0,'com/sun/javafx/scene/control/skin/Utils.computeTextWidth')
f(41,67,2,0,'com/sun/javafx/text/PrismTextLayout.getBounds')
f(42,67,2,0,'com/sun/javafx/text/PrismTextLayout.ensureLayout')
f(43,67,2,0,'com/sun/javafx/text/PrismTextLayout.layout')
f(44,67,2,0,'com/sun/javafx/text/PrismTextLayout.buildRuns')
f(45,67,2,0,'com/sun/javafx/text/GlyphLayout.breakRuns')
f(6,74,12,0,'com/sun/javafx/tk/quantum/QuantumToolkit$$Lambda$46/1696939523.run')
f(7,74,12,0,'com/sun/javafx/tk/quantum/QuantumToolkit.lambda$runToolkit$403')
f(8,74,12,0,'com/sun/javafx/tk/quantum/QuantumToolkit.pulseFromQueue')
f(9,74,12,0,'com/sun/javafx/tk/quantum/QuantumToolkit.pulse')
f(10,74,12,0,'com/sun/javafx/tk/quantum/QuantumToolkit.pulse')
f(11,74,8,0,'com/sun/javafx/tk/Toolkit.firePulse')
f(12,74,6,0,'com/sun/javafx/tk/Toolkit.runPulse')
f(13,74,6,0,'java/security/AccessController.doPrivileged')
f(14,74,6,0,'com/sun/javafx/tk/Toolkit$$Lambda$193/1813875389.run')
f(15,74,6,0,'com/sun/javafx/tk/Toolkit.lambda$runPulse$29')
f(16,74,6,0,'javafx/scene/Scene$ScenePulseListener.pulse')
f(17,76,4,0,'javafx/scene/Scene.doLayoutPass')
f(18,76,4,0,'javafx/scene/Parent.layout')
f(19,76,4,0,'demo/parallel/Main$1.layoutChildren')
f(20,76,4,0,'javafx/scene/Parent.layoutChildren')
f(21,76,4,0,'javafx/scene/Node.autosize')
f(22,76,2,0,'javafx/scene/layout/Region.prefHeight')
f(23,76,2,0,'javafx/scene/Parent.prefHeight')
f(24,76,2,0,'javafx/scene/layout/GridPane.computePrefHeight')
f(25,76,2,0,'javafx/scene/layout/GridPane.computePrefHeights')
f(22,78,2,0,'javafx/scene/layout/Region.prefWidth')
f(23,78,2,0,'javafx/scene/Parent.prefWidth')
f(24,78,2,0,'javafx/scene/layout/GridPane.computePrefWidth')
f(25,78,2,0,'javafx/scene/layout/GridPane.computePrefWidths')
f(11,82,3,0,'com/sun/javafx/tk/quantum/PaintCollector.renderAll')
f(12,82,3,0,'com/sun/javafx/tk/quantum/ViewScene.repaint')
f(13,82,3,0,'com/sun/javafx/tk/quantum/QuantumToolkit.addRenderJob')
f(14,82,3,0,'com/sun/javafx/tk/quantum/QuantumRenderer.submitRenderJob')
f(15,82,3,0,'java/util/concurrent/AbstractExecutorService.submit')
f(16,82,3,0,'java/util/concurrent/ThreadPoolExecutor.execute')
f(17,82,3,0,'java/util/concurrent/LinkedBlockingQueue.offer')
f(18,82,3,0,'java/util/concurrent/LinkedBlockingQueue.signalNotEmpty')
f(19,82,3,0,'java/util/concurrent/locks/ReentrantLock.unlock')
f(20,82,3,0,'java/util/concurrent/locks/AbstractQueuedSynchronizer.release')
f(21,82,3,0,'java/util/concurrent/locks/AbstractQueuedSynchronizer.unparkSuccessor')
f(22,82,3,0,'java/util/concurrent/locks/LockSupport.unpark')
f(23,82,3,0,'sun/misc/Unsafe.unpark')
f(24,82,3,4,'Unsafe_Unpark')
f(25,82,3,4,'pthread_cond_signal@@GLIBC_2.3.2')
f(26,82,3,2,'entry_SYSCALL_64_after_hwframe')
f(27,82,3,2,'do_syscall_64')
f(28,82,3,2,'__x64_sys_futex')
f(29,82,3,2,'do_futex')
f(30,82,3,2,'wake_up_q')
f(31,82,3,2,'try_to_wake_up')
f(32,82,3,2,'_raw_spin_unlock_irqrestore')
f(6,86,85,0,'com/sun/javafx/tk/quantum/SceneState$$Lambda$205/1725489206.run')
f(7,86,85,0,'com/sun/javafx/tk/quantum/SceneState.lambda$uploadPixels$305')
f(8,86,85,0,'com/sun/javafx/tk/quantum/SceneState.access$001')
f(9,86,85,0,'com/sun/prism/PresentableState.uploadPixels')
f(10,86,85,0,'com/sun/glass/ui/View.uploadPixels')
f(11,86,85,0,'com/sun/glass/ui/gtk/GtkView._uploadPixels')
f(12,86,85,0,'com/sun/glass/ui/gtk/GtkView._uploadPixelsDirect')
f(13,86,85,4,'Java_com_sun_glass_ui_gtk_GtkView__1uploadPixelsDirect')
f(14,86,85,4,'__writev')
f(15,86,85,2,'entry_SYSCALL_64_after_hwframe')
f(16,86,85,2,'do_syscall_64')
f(17,86,85,2,'__x64_sys_writev')
f(18,86,85,2,'do_writev')
f(19,86,85,2,'vfs_writev')
f(20,86,85,2,'do_iter_write')
f(21,86,85,2,'do_iter_readv_writev')
f(22,86,85,2,'sock_write_iter')
f(23,86,85,2,'sock_sendmsg')
f(24,86,85,2,'inet_sendmsg')
f(25,86,85,2,'tcp_sendmsg')
f(26,86,3,2,'lock_sock_nested')
f(27,86,3,2,'_raw_spin_lock_bh')
f(28,86,3,2,'queued_spin_lock_slowpath')
f(29,86,3,2,'native_queued_spin_lock_slowpath')
f(26,90,81,2,'tcp_sendmsg_locked')
f(27,90,3,2,'__sk_flush_backlog')
f(28,90,3,2,'__release_sock')
f(29,90,3,2,'tcp_v4_do_rcv')
f(30,90,3,2,'tcp_rcv_established')
f(31,90,3,2,'__tcp_push_pending_frames')
f(32,90,3,2,'tcp_write_xmit')
f(33,90,3,2,'__tcp_transmit_skb')
f(34,90,3,2,'ip_queue_xmit')
f(35,90,3,2,'__ip_queue_xmit')
f(36,90,3,2,'ip_local_out')
f(37,90,3,2,'ip_output')
f(38,90,3,2,'ip_finish_output')
f(39,90,3,2,'__ip_finish_output')
f(40,90,3,2,'ip_finish_output2')
f(41,90,3,2,'dev_queue_xmit')
f(42,90,3,2,'__dev_queue_xmit')
f(43,90,3,2,'sch_direct_xmit')
f(44,90,3,2,'dev_hard_start_xmit')
f(45,90,3,2,'e1000_xmit_frame?[e1000]')
f(27,93,78,2,'tcp_push_one')
f(28,93,78,2,'tcp_write_xmit')
f(29,93,78,2,'__tcp_transmit_skb')
f(30,93,78,2,'ip_queue_xmit')
f(31,93,78,2,'__ip_queue_xmit')
f(32,93,78,2,'ip_local_out')
f(33,93,78,2,'ip_output')
f(34,93,78,2,'ip_finish_output')
f(35,93,78,2,'__ip_finish_output')
f(36,93,78,2,'ip_finish_output2')
f(37,93,9,2,'__local_bh_enable_ip')
f(38,93,9,2,'do_softirq')
f(39,93,9,2,'do_softirq_own_stack')
f(40,93,9,2,'__softirqentry_text_start')
f(41,93,9,2,'net_rx_action')
f(42,93,9,2,'e1000_clean?[e1000]')
f(37,102,69,2,'dev_queue_xmit')
f(38,102,69,2,'__dev_queue_xmit')
f(39,102,69,2,'sch_direct_xmit')
f(40,102,69,2,'dev_hard_start_xmit')
f(41,102,69,2,'e1000_xmit_frame?[e1000]')
f(5,171,3,0,'com/sun/glass/ui/View.notifyMouse')
f(6,171,3,0,'com/sun/glass/ui/View.handleMouseEvent')
f(7,171,3,0,'com/sun/javafx/tk/quantum/GlassViewEventHandler.handleMouseEvent')
f(8,171,3,0,'com/sun/javafx/tk/quantum/QuantumToolkit.runWithoutRenderLock')
f(9,171,3,0,'com/sun/javafx/tk/quantum/GlassViewEventHandler$$Lambda$181/241733715.get')
f(10,171,3,0,'com/sun/javafx/tk/quantum/GlassViewEventHandler.lambda$handleMouseEvent$353')
f(11,171,3,0,'java/security/AccessController.doPrivileged')
f(12,171,3,0,'com/sun/javafx/tk/quantum/GlassViewEventHandler$MouseEventNotification.run')
f(13,171,3,0,'com/sun/javafx/tk/quantum/GlassViewEventHandler$MouseEventNotification.run')
f(14,171,3,0,'javafx/scene/Scene$ScenePeerListener.mouseEvent')
f(15,171,3,0,'javafx/scene/Scene.impl_processMouseEvent')
f(16,171,3,0,'javafx/scene/Scene$MouseHandler.access$1500')
f(17,171,3,0,'javafx/scene/Scene$MouseHandler.process')
f(18,172,2,0,'javafx/scene/Scene.access$6700')
f(19,172,2,0,'javafx/scene/Scene.pick')
f(20,172,2,0,'javafx/scene/Scene$MouseHandler.access$1600')
f(21,172,2,0,'javafx/scene/Scene$MouseHandler.pickNode')
f(22,172,2,0,'javafx/scene/Node.impl_pickNode')
f(23,172,2,0,'javafx/scene/layout/Region.impl_pickNodeLocal')
f(5,174,2,0,'com/sun/javafx/tk/quantum/QuantumToolkit$$Lambda$47/605813029.run')
f(6,174,2,0,'com/sun/javafx/tk/quantum/QuantumToolkit.lambda$runToolkit$404')
f(7,174,2,0,'com/sun/javafx/tk/quantum/QuantumToolkit.postPulse')
f(8,174,2,0,'com/sun/glass/ui/Application.invokeLater')
f(9,174,2,0,'com/sun/glass/ui/gtk/GtkApplication._invokeLater')
f(10,174,2,0,'com/sun/glass/ui/InvokeLaterDispatcher.invokeLater')
f(11,174,2,0,'java/util/concurrent/LinkedBlockingDeque.addLast')
f(12,174,2,0,'java/util/concurrent/LinkedBlockingDeque.offerLast')
f(13,174,2,0,'java/util/concurrent/locks/ReentrantLock.unlock')
f(14,174,2,0,'java/util/concurrent/locks/AbstractQueuedSynchronizer.release')
f(15,174,2,0,'java/util/concurrent/locks/AbstractQueuedSynchronizer.unparkSuccessor')
f(16,174,2,0,'java/util/concurrent/locks/LockSupport.unpark')
f(17,174,2,0,'sun/misc/Unsafe.unpark')
f(18,174,2,4,'Unsafe_Unpark')
f(19,174,2,4,'pthread_cond_signal@@GLIBC_2.3.2')
f(20,174,2,2,'entry_SYSCALL_64_after_hwframe')
f(21,174,2,2,'do_syscall_64')
f(22,174,2,2,'__x64_sys_futex')
f(23,174,2,2,'do_futex')
f(24,174,2,2,'wake_up_q')
f(25,174,2,2,'try_to_wake_up')
f(26,174,2,2,'_raw_spin_unlock_irqrestore')
f(5,176,8,4,'recvmsg')
f(6,176,8,2,'entry_SYSCALL_64_after_hwframe')
f(7,176,8,2,'do_syscall_64')
f(8,176,8,2,'__x64_sys_recvmsg')
f(9,176,8,2,'__sys_recvmsg')
f(10,176,8,2,'___sys_recvmsg')
f(11,176,8,2,'sock_recvmsg')
f(12,176,8,2,'inet_recvmsg')
f(13,176,8,2,'tcp_recvmsg')
f(14,176,3,2,'lock_sock_nested')
f(15,176,3,2,'_raw_spin_lock_bh')
f(16,176,3,2,'queued_spin_lock_slowpath')
f(17,176,3,2,'native_queued_spin_lock_slowpath')
f(14,180,4,2,'tcp_cleanup_rbuf')
f(15,180,4,2,'tcp_send_ack')
f(16,180,4,2,'__tcp_send_ack.part.45')
f(17,180,4,2,'__tcp_transmit_skb')
f(18,180,4,2,'ip_queue_xmit')
f(19,180,4,2,'__ip_queue_xmit')
f(20,180,4,2,'ip_local_out')
f(21,180,4,2,'ip_output')
f(22,180,4,2,'ip_finish_output')
f(23,180,4,2,'__ip_finish_output')
f(24,180,4,2,'ip_finish_output2')
f(25,180,4,2,'dev_queue_xmit')
f(26,180,4,2,'__dev_queue_xmit')
f(27,180,4,2,'sch_direct_xmit')
f(28,180,4,2,'dev_hard_start_xmit')
f(29,180,4,2,'e1000_xmit_frame?[e1000]')
f(2,184,45,0,'com/sun/javafx/tk/quantum/QuantumRenderer$PipelineRunnable.run')
f(3,184,45,0,'java/util/concurrent/ThreadPoolExecutor$Worker.run')
f(4,184,45,0,'java/util/concurrent/ThreadPoolExecutor.runWorker')
f(5,184,45,0,'com/sun/javafx/tk/RenderJob.run')
f(6,184,45,0,'java/util/concurrent/FutureTask.runAndReset')
f(7,184,45,0,'java/util/concurrent/Executors$RunnableAdapter.call')
f(8,184,45,0,'com/sun/javafx/tk/quantum/UploadingPainter.run')
f(9,184,2,0,'com/sun/javafx/tk/quantum/SceneState.uploadPixels')
f(10,184,2,0,'com/sun/glass/ui/Application.invokeLater')
f(11,184,2,0,'com/sun/glass/ui/gtk/GtkApplication._invokeLater')
f(12,184,2,0,'com/sun/glass/ui/InvokeLaterDispatcher.invokeLater')
f(13,184,2,0,'java/util/concurrent/LinkedBlockingDeque.addLast')
f(14,184,2,0,'java/util/concurrent/LinkedBlockingDeque.offerLast')
f(15,184,2,0,'java/util/concurrent/locks/ReentrantLock.unlock')
f(16,184,2,0,'java/util/concurrent/locks/AbstractQueuedSynchronizer.release')
f(17,184,2,0,'java/util/concurrent/locks/AbstractQueuedSynchronizer.unparkSuccessor')
f(18,184,2,0,'java/util/concurrent/locks/LockSupport.unpark')
f(19,184,2,0,'sun/misc/Unsafe.unpark')
f(20,184,2,4,'Unsafe_Unpark')
f(21,184,2,4,'pthread_cond_signal@@GLIBC_2.3.2')
f(22,184,2,2,'entry_SYSCALL_64_after_hwframe')
f(23,184,2,2,'do_syscall_64')
f(24,184,2,2,'__x64_sys_futex')
f(25,184,2,2,'do_futex')
f(26,184,2,2,'wake_up_q')
f(27,184,2,2,'try_to_wake_up')
f(28,184,2,2,'_raw_spin_unlock_irqrestore')
f(9,186,40,0,'com/sun/javafx/tk/quantum/ViewPainter.paintImpl')
f(10,188,38,0,'com/sun/javafx/tk/quantum/ViewPainter.doPaint')
f(11,188,38,0,'com/sun/javafx/sg/prism/NGNode.render')
f(12,188,38,0,'com/sun/javafx/sg/prism/NGNode.doRender')
f(13,188,38,0,'com/sun/javafx/sg/prism/NGRegion.renderContent')
f(14,188,38,0,'com/sun/javafx/sg/prism/NGGroup.renderContent')
f(15,188,38,0,'com/sun/javafx/sg/prism/NGNode.render')
f(16,188,38,0,'com/sun/javafx/sg/prism/NGNode.doRender')
f(17,188,21,0,'com/sun/javafx/sg/prism/NGCanvas.renderContent')
f(18,188,15,0,'com/sun/javafx/sg/prism/NGCanvas.renderStream')
f(19,188,15,0,'com/sun/javafx/sg/prism/NGCanvas.handleRenderOp')
f(20,188,11,0,'com/sun/prism/impl/BaseResourceFactory.getCachedTexture')
f(21,188,11,0,'com/sun/prism/impl/BaseResourceFactory.getCachedTexture')
f(22,189,10,0,'com/sun/prism/sw/SWTexture.update')
f(23,189,10,0,'com/sun/prism/sw/SWArgbPreTexture.update')
f(24,189,10,0,'com/sun/javafx/image/impl/BaseByteToIntConverter.convert')
f(25,189,10,0,'com/sun/javafx/image/impl/BaseByteToIntConverter.convert')
f(26,189,10,0,'com/sun/javafx/image/impl/ByteBgra$ToIntArgbSameConv.doConvert')
f(20,199,3,0,'com/sun/prism/sw/SWGraphics.drawTexture')
f(21,199,3,0,'com/sun/prism/sw/SWGraphics.drawTexture')
f(22,199,3,0,'com/sun/prism/sw/SWGraphics.drawTexture')
f(23,199,3,0,'com/sun/pisces/PiscesRenderer.drawImage')
f(24,199,3,0,'com/sun/pisces/PiscesRenderer.drawImageImpl')
f(25,199,3,4,'Java_com_sun_pisces_PiscesRenderer_drawImageImpl')
f(26,199,3,4,'fillRect')
f(27,200,2,4,'emitLinePTSourceOver8888_pre')
f(18,203,6,0,'com/sun/prism/sw/SWGraphics.drawTexture')
f(19,203,6,0,'com/sun/prism/sw/SWGraphics.drawTexture')
f(20,203,6,0,'com/sun/prism/sw/SWGraphics.drawTexture')
f(21,203,6,0,'com/sun/pisces/PiscesRenderer.drawImage')
f(22,203,6,0,'com/sun/pisces/PiscesRenderer.drawImageImpl')
f(23,203,6,4,'Java_com_sun_pisces_PiscesRenderer_drawImageImpl')
f(24,203,6,4,'fillRect')
f(25,204,5,4,'emitLinePTSourceOver8888_pre')
f(17,209,17,0,'com/sun/javafx/sg/prism/NGNode.renderOpacity')
f(18,210,10,0,'com/sun/javafx/sg/prism/NGRegion.renderContent')
f(19,210,10,0,'com/sun/javafx/sg/prism/NGGroup.renderContent')
f(20,210,10,0,'com/sun/javafx/sg/prism/NGNode.render')
f(21,210,10,0,'com/sun/javafx/sg/prism/NGNode.doRender')
f(22,210,10,0,'com/sun/javafx/sg/prism/NGRegion.renderContent')
f(23,210,8,0,'com/sun/javafx/sg/prism/NGGroup.renderContent')
f(24,210,8,0,'com/sun/javafx/sg/prism/NGNode.render')
f(25,210,8,0,'com/sun/javafx/sg/prism/NGNode.doRender')
f(26,210,3,0,'com/sun/javafx/sg/prism/NGRegion.renderContent')
f(27,211,2,0,'com/sun/javafx/sg/prism/NGRegion.renderAsRectangle')
f(28,211,2,0,'com/sun/javafx/sg/prism/NGRegion.renderBackgroundRectangle')
f(29,211,2,0,'com/sun/javafx/sg/prism/NGRegion.renderBackgroundRectanglesDirectly')
f(30,211,2,0,'com/sun/prism/sw/SWGraphics.fill')
f(31,211,2,0,'com/sun/prism/sw/SWGraphics.paintShape')
f(32,211,2,0,'com/sun/prism/sw/SWGraphics.paintShapePaintAlreadySet')
f(33,211,2,0,'com/sun/prism/sw/SWContext.renderShape')
f(34,211,2,0,'com/sun/prism/sw/SWContext$JavaShapeRenderer.renderShape')
f(35,211,2,0,'com/sun/prism/impl/shape/OpenPiscesPrismUtils.setupRenderer')
f(26,213,5,0,'com/sun/javafx/sg/prism/NGShape.renderContent')
f(27,213,5,0,'com/sun/javafx/sg/prism/NGText.renderContent2D')
f(28,213,4,0,'com/sun/javafx/sg/prism/NGText.renderText')
f(29,213,4,0,'com/sun/prism/sw/SWGraphics.drawString')
f(30,214,3,0,'com/sun/prism/sw/SWGraphics.drawGlyph')
f(23,218,2,0,'com/sun/javafx/sg/prism/NGRegion.renderAsRectangle')
f(24,218,2,0,'com/sun/javafx/sg/prism/NGRegion.renderBackgroundRectangle')
f(18,220,5,0,'com/sun/prism/sw/SWGraphics.drawTexture')
f(19,220,5,0,'com/sun/prism/sw/SWGraphics.drawTexture')
f(20,220,5,0,'com/sun/prism/sw/SWGraphics.drawTexture')
f(21,220,5,0,'com/sun/prism/sw/SWGraphics.drawTexture')
f(22,220,5,0,'com/sun/pisces/PiscesRenderer.drawImage')
f(23,220,5,0,'com/sun/pisces/PiscesRenderer.drawImageImpl')
f(24,220,5,4,'Java_com_sun_pisces_PiscesRenderer_drawImageImpl')
f(25,220,5,4,'fillRect')
f(26,220,3,4,'emitLinePTSourceOver8888_pre')
f(26,223,2,4,'genTexturePaintMultiply')
f(9,227,2,0,'java/nio/DirectIntBufferU.put')
f(10,227,2,0,'java/nio/Bits.copyFromArray')
f(11,227,2,0,'sun/misc/Unsafe.copyMemory')
f(12,227,2,4,'acl_CopyRight')
f(2,229,184,0,'java/util/concurrent/FutureTask.run')
f(3,229,184,0,'javafx/concurrent/Task$TaskCallable.call')
f(4,229,184,0,'demo/parallel/MandelbrotSetTask.call')
f(5,229,184,0,'demo/parallel/MandelbrotSetTask.call')
f(6,233,175,0,'java/util/stream/IntPipeline$Head.forEach')
f(7,233,68,0,'java/util/stream/IntPipeline.forEach')
f(8,233,68,0,'java/util/stream/AbstractPipeline.evaluate')
f(9,233,68,0,'java/util/stream/ForEachOps$ForEachOp$OfInt.evaluateParallel')
f(10,233,68,0,'java/util/stream/ForEachOps$ForEachOp.evaluateParallel')
f(11,233,68,0,'java/util/concurrent/ForkJoinTask.invoke')
f(12,233,68,0,'java/util/concurrent/ForkJoinTask.doInvoke')
f(13,233,25,0,'java/util/concurrent/ForkJoinTask.doExec')
f(14,233,25,0,'java/util/concurrent/CountedCompleter.exec')
f(15,233,25,0,'java/util/stream/ForEachOps$ForEachTask.compute')
f(16,233,24,0,'java/util/stream/AbstractPipeline.copyInto')
f(17,233,24,0,'java/util/Spliterator$OfInt.forEachRemaining')
f(18,233,24,0,'java/util/stream/Streams$RangeIntSpliterator.forEachRemaining')
f(19,233,24,0,'java/util/stream/ForEachOps$ForEachOp$OfInt.accept')
f(20,233,24,0,'demo/parallel/MandelbrotSetTask$$Lambda$99/105194951.accept')
f(21,233,24,0,'demo/parallel/MandelbrotSetTask.lambda$call$19')
f(22,234,2,3,'SharedRuntime::complete_monitor_locking_C(oopDesc*, BasicLock*, JavaThread*)')
f(23,234,2,3,'ObjectMonitor::enter(Thread*)')
f(24,234,2,3,'ObjectMonitor::TrySpin_VaryDuration(Thread*)')
f(22,236,21,0,'demo/parallel/MandelbrotSetTask.calcAntialiasedPixel')
f(23,237,19,0,'demo/parallel/MandelbrotSetTask.calcPixel')
f(24,237,19,0,'demo/parallel/MandelbrotSetTask.calc')
f(25,248,5,0,'demo/parallel/Complex.lengthSQ')
f(25,253,3,0,'demo/parallel/Complex.plus')
f(13,258,43,0,'java/util/concurrent/ForkJoinTask.externalAwaitDone')
f(14,258,43,0,'java/util/concurrent/ForkJoinPool.externalHelpComplete')
f(15,258,43,0,'java/util/concurrent/ForkJoinPool.helpComplete')
f(16,258,14,0,'java/util/concurrent/ForkJoinPool$WorkQueue.pollAndExecCC')
f(17,258,14,0,'java/util/concurrent/ForkJoinTask.doExec')
f(18,258,14,0,'java/util/concurrent/CountedCompleter.exec')
f(19,258,14,0,'java/util/stream/ForEachOps$ForEachTask.compute')
f(20,258,14,0,'java/util/stream/AbstractPipeline.copyInto')
f(21,258,14,0,'java/util/Spliterator$OfInt.forEachRemaining')
f(22,258,14,0,'java/util/stream/Streams$RangeIntSpliterator.forEachRemaining')
f(23,258,14,0,'java/util/stream/ForEachOps$ForEachOp$OfInt.accept')
f(24,258,14,0,'demo/parallel/MandelbrotSetTask$$Lambda$99/105194951.accept')
f(25,258,14,0,'demo/parallel/MandelbrotSetTask.lambda$call$19')
f(26,258,14,0,'demo/parallel/MandelbrotSetTask.calcAntialiasedPixel')
f(27,259,13,0,'demo/parallel/MandelbrotSetTask.calcPixel')
f(28,259,13,0,'demo/parallel/MandelbrotSetTask.calc')
f(29,267,4,0,'demo/parallel/Complex.plus')
f(16,272,29,0,'java/util/concurrent/ForkJoinTask.doExec')
f(17,272,29,0,'java/util/concurrent/CountedCompleter.exec')
f(18,272,29,0,'java/util/stream/ForEachOps$ForEachTask.compute')
f(19,272,29,0,'java/util/stream/AbstractPipeline.copyInto')
f(20,272,29,0,'java/util/Spliterator$OfInt.forEachRemaining')
f(21,272,29,0,'java/util/stream/Streams$RangeIntSpliterator.forEachRemaining')
f(22,272,29,0,'java/util/stream/ForEachOps$ForEachOp$OfInt.accept')
f(23,272,29,0,'demo/parallel/MandelbrotSetTask$$Lambda$99/105194951.accept')
f(24,272,29,0,'demo/parallel/MandelbrotSetTask.lambda$call$19')
f(25,273,28,0,'demo/parallel/MandelbrotSetTask.calcAntialiasedPixel')
f(26,274,27,0,'demo/parallel/MandelbrotSetTask.calcPixel')
f(27,274,27,0,'demo/parallel/MandelbrotSetTask.calc')
f(28,287,3,0,'demo/parallel/Complex.lengthSQ')
f(28,290,8,0,'demo/parallel/Complex.plus')
f(28,298,3,0,'demo/parallel/Complex.times')
f(7,301,107,0,'java/util/stream/Streams$RangeIntSpliterator.forEachRemaining')
f(8,301,107,0,'demo/parallel/MandelbrotSetTask$$Lambda$99/105194951.accept')
f(9,301,107,0,'demo/parallel/MandelbrotSetTask.lambda$call$19')
f(10,301,105,0,'demo/parallel/MandelbrotSetTask.calcAntialiasedPixel')
f(11,309,97,0,'demo/parallel/MandelbrotSetTask.calcPixel')
f(12,312,94,0,'demo/parallel/MandelbrotSetTask.calc')
f(13,357,23,0,'demo/parallel/Complex.lengthSQ')
f(13,380,16,0,'demo/parallel/Complex.plus')
f(13,396,10,0,'demo/parallel/Complex.times')
f(6,408,5,0,'javafx/scene/image/WritableImage$2.setColor')
f(7,408,3,0,'java/lang/Math.round')
f(7,411,2,0,'javafx/scene/image/WritableImage$2.setArgb')
f(8,411,2,0,'com/sun/prism/Image.setArgb')
f(1,413,163,0,'java/util/concurrent/ForkJoinWorkerThread.run')
f(2,413,163,0,'java/util/concurrent/ForkJoinPool.runWorker')
f(3,413,163,0,'java/util/concurrent/ForkJoinPool$WorkQueue.runTask')
f(4,413,38,0,'java/util/concurrent/ForkJoinPool$WorkQueue.execLocalTasks')
f(5,413,38,0,'java/util/concurrent/ForkJoinTask.doExec')
f(6,413,38,0,'java/util/concurrent/CountedCompleter.exec')
f(7,413,38,0,'java/util/stream/ForEachOps$ForEachTask.compute')
f(8,413,38,0,'java/util/stream/AbstractPipeline.copyInto')
f(9,413,38,0,'java/util/Spliterator$OfInt.forEachRemaining')
f(10,413,38,0,'java/util/stream/Streams$RangeIntSpliterator.forEachRemaining')
f(11,413,38,0,'java/util/stream/ForEachOps$ForEachOp$OfInt.accept')
f(12,413,38,0,'demo/parallel/MandelbrotSetTask$$Lambda$99/105194951.accept')
f(13,413,38,0,'demo/parallel/MandelbrotSetTask.lambda$call$19')
f(14,415,32,0,'demo/parallel/MandelbrotSetTask.calcAntialiasedPixel')
f(15,421,26,0,'demo/parallel/MandelbrotSetTask.calcPixel')
f(16,424,22,0,'demo/parallel/MandelbrotSetTask.calc')
f(17,432,7,0,'demo/parallel/Complex.lengthSQ')
f(17,439,7,0,'demo/parallel/Complex.plus')
f(14,447,4,0,'javafx/scene/image/WritableImage$2.setColor')
f(15,448,3,0,'javafx/scene/image/WritableImage$2.setArgb')
f(16,449,2,0,'javafx/scene/image/Image.getWritablePlatformImage')
f(4,451,125,0,'java/util/concurrent/ForkJoinTask.doExec')
f(5,451,125,0,'java/util/concurrent/CountedCompleter.exec')
f(6,451,125,0,'java/util/stream/ForEachOps$ForEachTask.compute')
f(7,452,124,0,'java/util/stream/AbstractPipeline.copyInto')
f(8,452,124,0,'java/util/Spliterator$OfInt.forEachRemaining')
f(9,452,124,0,'java/util/stream/Streams$RangeIntSpliterator.forEachRemaining')
f(10,452,124,0,'java/util/stream/ForEachOps$ForEachOp$OfInt.accept')
f(11,452,124,0,'demo/parallel/MandelbrotSetTask$$Lambda$99/105194951.accept')
f(12,452,124,0,'demo/parallel/MandelbrotSetTask.lambda$call$19')
f(13,454,119,0,'demo/parallel/MandelbrotSetTask.calcAntialiasedPixel')
f(14,462,111,0,'demo/parallel/MandelbrotSetTask.calcPixel')
f(15,464,109,0,'demo/parallel/MandelbrotSetTask.calc')
f(16,504,39,0,'demo/parallel/Complex.lengthSQ')
f(16,543,22,0,'demo/parallel/Complex.plus')
f(16,565,8,0,'demo/parallel/Complex.times')
f(13,573,3,0,'javafx/scene/image/WritableImage$2.setColor')
f(1,576,65,4,'start_thread')
f(2,576,65,4,'java_start(Thread*)')
f(3,576,4,3,'GCTaskThread::run()')
f(4,577,3,3,'OldToYoungRootsTask::do_it(GCTaskManager*, unsigned int)')
f(5,577,3,3,'CardTableExtension::scavenge_contents_parallel(ObjectStartArray*, MutableSpace*, HeapWord*, PSPromotionManager*, unsigned int, unsigned int)')
f(6,577,3,3,'PSPromotionManager::drain_stacks_depth(bool)')
f(7,578,2,3,'oopDesc* PSPromotionManager::copy_to_survivor_space<false>(oopDesc*)')
f(3,580,61,3,'JavaThread::run()')
f(4,580,61,3,'JavaThread::thread_main_inner()')
f(5,580,61,3,'CompileBroker::compiler_thread_loop()')
f(6,580,58,3,'CompileBroker::invoke_compiler_on_method(CompileTask*)')
f(7,580,58,3,'C2Compiler::compile_method(ciEnv*, ciMethod*, int)')
f(8,580,58,3,'Compile::Compile(ciEnv*, C2Compiler*, ciMethod*, int, bool, bool, bool)')
f(9,580,32,3,'Compile::Code_Gen()')
f(10,582,3,3,'PhaseCFG::do_global_code_motion()')
f(11,582,3,3,'PhaseCFG::global_code_motion()')
f(10,585,27,3,'PhaseChaitin::Register_Allocate()')
f(11,585,2,3,'PhaseChaitin::Select()')
f(12,585,2,3,'PhaseIFG::re_insert(unsigned int)')
f(11,589,9,3,'PhaseChaitin::build_ifg_physical(ResourceArea*)')
f(12,592,3,3,'PhaseChaitin::interfere_with_live(unsigned int, IndexSet*)')
f(12,596,2,3,'RegMask::smear_to_sets(int)')
f(11,599,3,3,'PhaseChaitin::gather_lrg_masks(bool)')
f(11,602,5,3,'PhaseChaitin::post_allocate_copy_removal()')
f(12,604,2,3,'PhaseChaitin::elide_copy(Node*, int, Block*, Node_List&, Node_List&, bool)')
f(11,609,2,3,'PhaseIFG::init(unsigned int)')
f(12,609,2,3,'IndexSet::initialize(unsigned int)')
f(9,613,15,3,'Compile::Optimize()')
f(10,614,13,3,'PhaseIdealLoop::build_and_optimize(bool, bool)')
f(11,617,2,3,'PhaseIdealLoop::build_loop_early(VectorSet&, Node_List&, Node_Stack&)')
f(11,619,4,3,'PhaseIdealLoop::build_loop_late(VectorSet&, Node_List&, Node_Stack&)')
f(11,625,2,3,'PhaseIterGVN::optimize()')
f(12,625,2,3,'PhaseIterGVN::transform_old(Node*)')
f(9,629,3,3,'ParseGenerator::generate(JVMState*)')
f(10,629,3,3,'Parse::Parse(JVMState*, ciMethod*, float)')
f(11,629,3,3,'Parse::do_all_blocks()')
f(12,629,3,3,'Parse::do_one_block()')
f(13,629,3,3,'Parse::do_one_bytecode()')
f(14,629,3,3,'Parse::do_call()')
f(15,630,2,3,'PredictedCallGenerator::generate(JVMState*)')
f(16,630,2,3,'ParseGenerator::generate(JVMState*)')
f(17,630,2,3,'Parse::Parse(JVMState*, ciMethod*, float)')
f(18,630,2,3,'Parse::do_all_blocks()')
f(19,630,2,3,'Parse::do_one_block()')
f(20,630,2,3,'Parse::do_one_bytecode()')
f(21,630,2,3,'Parse::do_call()')
f(9,632,6,3,'ciEnv::register_method(ciMethod*, int, CodeOffsets*, int, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int, bool, bool, RTMState)')
f(10,632,6,3,'nmethod::post_compiled_method_load_event()')
f(11,632,6,4,'pthread_cond_signal@@GLIBC_2.3.2')
f(12,632,6,2,'entry_SYSCALL_64_after_hwframe')
f(13,632,6,2,'do_syscall_64')
f(14,632,6,2,'__x64_sys_futex')
f(15,632,6,2,'do_futex')
f(16,632,6,2,'wake_up_q')
f(17,632,6,2,'try_to_wake_up')
f(18,632,6,2,'_raw_spin_unlock_irqrestore')
f(6,638,3,3,'CompileQueue::get()')
f(7,638,3,4,'pthread_cond_signal@@GLIBC_2.3.2')
f(8,638,3,2,'entry_SYSCALL_64_after_hwframe')
f(9,638,3,2,'do_syscall_64')
f(10,638,3,2,'__x64_sys_futex')
f(11,638,3,2,'do_futex')
f(12,638,3,2,'wake_up_q')
f(13,638,3,2,'try_to_wake_up')
f(14,638,3,2,'_raw_spin_unlock_irqrestore')
render();
</script></body></html>

BIN
demo/flamegraph.png Normal file

Binary file not shown.

After

Width:  |  Height:  |  Size: 170 KiB

View File

@@ -3,7 +3,7 @@
<modelVersion>4.0.0</modelVersion>
<groupId>tools.profiler</groupId>
<artifactId>async-profiler</artifactId>
<version>1.8.3</version>
<version>2.0</version>
<packaging>jar</packaging>
<name>async-profiler</name>

View File

@@ -22,7 +22,7 @@ usage() {
echo " -s simple class names instead of FQN"
echo " -g print method signatures"
echo " -a annotate Java method names"
echo " -o fmt output format: flat|collapsed|html|tree|jfr"
echo " -o fmt output format: flat|traces|collapsed|flamegraph|tree|jfr"
echo " -I include output only stack traces containing the specified pattern"
echo " -X exclude exclude stack traces with the specified pattern"
echo " -v, --version display version string"
@@ -31,17 +31,20 @@ usage() {
echo " --minwidth pct skip frames smaller than pct%"
echo " --reverse generate stack-reversed FlameGraph / Call tree"
echo ""
echo " --all-kernel only include kernel-mode events"
echo " --alloc bytes allocation profiling interval in bytes"
echo " --lock duration lock profiling threshold in nanoseconds"
echo " --total accumulate the total value (time, bytes, etc.)"
echo " --all-user only include user-mode events"
echo " --cstack mode how to traverse C stack: fp|lbr|no"
echo " --begin function begin profiling when function is executed"
echo " --end function end profiling when function is executed"
echo " --ttsp time-to-safepoint profiling"
echo ""
echo "<pid> is a numeric process ID of the target JVM"
echo " or 'jps' keyword to find running JVM automatically"
echo " or the application's name as it would appear in the jps tool"
echo ""
echo "Example: $0 -d 30 -f profile.svg 3456"
echo "Example: $0 -d 30 -f profile.html 3456"
echo " $0 start -i 999000 jps"
echo " $0 stop -o flat jps"
echo " $0 -d 5 -e alloc MyAppName"
@@ -67,9 +70,8 @@ check_if_terminated() {
jattach() {
set +e
"$JATTACH" "$PID" load "$PROFILER" true "$1" > /dev/null
"$JATTACH" "$PID" load "$PROFILER" true "$1,log=$LOG" > /dev/null
RET=$?
set -e
# Check if jattach failed
if [ $RET -ne 0 ]; then
@@ -78,13 +80,20 @@ jattach() {
if [ "$(uname -s)" = "Darwin" ]; then
otool -L "$PROFILER"
else
ldd "$PROFILER"
LD_PRELOAD="$PROFILER" /bin/true
fi
fi
if [ -f "$LOG" ]; then
cat "$LOG" >&2
rm "$LOG"
fi
exit $RET
fi
rm -f "$LOG"
mirror_output
set -e
}
OPTIND=1
@@ -92,7 +101,6 @@ SCRIPT_DIR="$(cd "$(dirname "$0")" > /dev/null 2>&1; pwd -P)"
JATTACH=$SCRIPT_DIR/build/jattach
PROFILER=$SCRIPT_DIR/build/libasyncProfiler.so
ACTION="collect"
EVENT="cpu"
DURATION="60"
FILE=""
USE_TMP="true"
@@ -113,7 +121,7 @@ while [ $# -gt 0 ]; do
ACTION="version"
;;
-e)
EVENT="$(echo "$2" | sed 's/,/,event=/g')"
PARAMS="$PARAMS,event=$2"
shift
;;
-d)
@@ -175,8 +183,12 @@ while [ $# -gt 0 ]; do
--reverse)
FORMAT="$FORMAT,reverse"
;;
--all-kernel)
PARAMS="$PARAMS,allkernel"
--samples|--total)
FORMAT="$FORMAT,${1#--}"
;;
--alloc|--lock)
PARAMS="$PARAMS,${1#--}=$2"
shift
;;
--all-user)
PARAMS="$PARAMS,alluser"
@@ -189,6 +201,9 @@ while [ $# -gt 0 ]; do
PARAMS="$PARAMS,${1#--}=$2"
shift
;;
--ttsp)
PARAMS="$PARAMS,begin=SafepointSynchronize::begin,end=RuntimeService::record_safepoint_synchronized"
;;
--safe-mode)
PARAMS="$PARAMS,safemode=$2"
shift
@@ -243,10 +258,11 @@ else
;;
esac
fi
LOG=/tmp/async-profiler-log.$$.$PID
case $ACTION in
start|resume|check)
jattach "$ACTION,event=$EVENT,file=$FILE,$OUTPUT$FORMAT$PARAMS"
jattach "$ACTION,file=$FILE,$OUTPUT$FORMAT$PARAMS"
;;
stop)
jattach "stop,file=$FILE,$OUTPUT$FORMAT"
@@ -258,12 +274,18 @@ case $ACTION in
jattach "list,file=$FILE"
;;
collect)
jattach "start,event=$EVENT,file=$FILE,$OUTPUT$FORMAT$PARAMS"
jattach "start,file=$FILE,$OUTPUT$FORMAT$PARAMS"
echo Profiling for "$DURATION" seconds >&2
trap 'set +e; DURATION=0' INT
while [ "$DURATION" -gt 0 ]; do
DURATION=$(( DURATION-1 ))
check_if_terminated
sleep 1
done
trap - INT
echo Done >&2
jattach "stop,file=$FILE,$OUTPUT$FORMAT"
;;
version)

View File

@@ -15,7 +15,6 @@
*/
#include "allocTracer.h"
#include "os.h"
#include "profiler.h"
#include "stackFrame.h"
#include "vmStructs.h"
@@ -30,7 +29,7 @@ volatile u64 AllocTracer::_allocated_bytes;
// Called whenever our breakpoint trap is hit
void AllocTracer::signalHandler(int signo, siginfo_t* siginfo, void* ucontext) {
void AllocTracer::trapHandler(int signo, siginfo_t* siginfo, void* ucontext) {
StackFrame frame(ucontext);
int event_type;
uintptr_t total_size;
@@ -51,6 +50,7 @@ void AllocTracer::signalHandler(int signo, siginfo_t* siginfo, void* ucontext) {
instance_size = 0;
} else {
// Not our trap
Profiler::_instance.trapHandler(signo, siginfo, ucontext);
return;
}
@@ -59,14 +59,13 @@ void AllocTracer::signalHandler(int signo, siginfo_t* siginfo, void* ucontext) {
frame.ret();
if (_enabled) {
// TODO: _enabled also uses traps
recordAllocation(ucontext, event_type, klass, total_size, instance_size);
}
}
void AllocTracer::recordAllocation(void* ucontext, int event_type, uintptr_t rklass,
uintptr_t total_size, uintptr_t instance_size) {
if (_interval) {
if (_interval > 1) {
// Do not record allocation unless allocated at least _interval bytes
while (true) {
u64 prev = _allocated_bytes;
@@ -131,11 +130,9 @@ Error AllocTracer::start(Arguments& args) {
return error;
}
_interval = args._interval;
_interval = args._alloc;
_allocated_bytes = 0;
OS::installSignalHandler(SIGTRAP, signalHandler);
_in_new_tlab.install();
_outside_tlab.install();

View File

@@ -32,27 +32,15 @@ class AllocTracer : public Engine {
static u64 _interval;
static volatile u64 _allocated_bytes;
static void signalHandler(int signo, siginfo_t* siginfo, void* ucontext);
static void recordAllocation(void* ucontext, int event_type, uintptr_t rklass,
uintptr_t total_size, uintptr_t instance_size);
public:
const char* name() {
return "alloc";
}
const char* units() {
return "bytes";
}
CStack cstack() {
return CSTACK_NO;
}
Error check(Arguments& args);
Error start(Arguments& args);
void stop();
static void trapHandler(int signo, siginfo_t* siginfo, void* ucontext);
};
#endif // _ALLOCTRACER_H

View File

@@ -58,6 +58,9 @@ public class AsyncProfiler implements AsyncProfilerMXBean {
*/
@Override
public void start(String event, long interval) throws IllegalStateException {
if (event == null) {
throw new NullPointerException();
}
start0(event, interval, true);
}
@@ -71,6 +74,9 @@ public class AsyncProfiler implements AsyncProfilerMXBean {
*/
@Override
public void resume(String event, long interval) throws IllegalStateException {
if (event == null) {
throw new NullPointerException();
}
start0(event, interval, false);
}
@@ -116,7 +122,10 @@ public class AsyncProfiler implements AsyncProfilerMXBean {
* @throws IOException If failed to create output file
*/
@Override
public String execute(String command) throws IllegalArgumentException, IOException {
public String execute(String command) throws IllegalArgumentException, IllegalStateException, IOException {
if (command == null) {
throw new NullPointerException();
}
return execute0(command);
}
@@ -129,7 +138,22 @@ public class AsyncProfiler implements AsyncProfilerMXBean {
@Override
public String dumpCollapsed(Counter counter) {
try {
return execute0("collapsed,counter=" + counter.name().toLowerCase());
return execute0("collapsed," + counter.name().toLowerCase());
} catch (IOException e) {
throw new IllegalStateException(e);
}
}
/**
* Dump collected stack traces
*
* @param maxTraces Maximum number of stack traces to dump. 0 means no limit
* @return Textual representation of the profile
*/
@Override
public String dumpTraces(int maxTraces) {
try {
return execute0(maxTraces == 0 ? "traces" : "traces=" + maxTraces);
} catch (IOException e) {
throw new IllegalStateException(e);
}
@@ -144,7 +168,7 @@ public class AsyncProfiler implements AsyncProfilerMXBean {
@Override
public String dumpFlat(int maxMethods) {
try {
return execute0("flat=" + maxMethods);
return execute0(maxMethods == 0 ? "flat" : "flat=" + maxMethods);
} catch (IOException e) {
throw new IllegalStateException(e);
}
@@ -171,7 +195,7 @@ public class AsyncProfiler implements AsyncProfilerMXBean {
}
private void filterThread(Thread thread, boolean enable) {
if (thread == null) {
if (thread == null || thread == Thread.currentThread()) {
filterThread0(null, enable);
} else {
// Need to take lock to avoid race condition with a thread state change
@@ -186,6 +210,6 @@ public class AsyncProfiler implements AsyncProfilerMXBean {
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, IOException;
private native String execute0(String command) throws IllegalArgumentException, IllegalStateException, IOException;
private native void filterThread0(Thread thread, boolean enable);
}

View File

@@ -35,8 +35,9 @@ public interface AsyncProfilerMXBean {
long getSamples();
String getVersion();
String execute(String command) throws IllegalArgumentException, java.io.IOException;
String execute(String command) throws IllegalArgumentException, IllegalStateException, java.io.IOException;
String dumpCollapsed(Counter counter);
String dumpTraces(int maxTraces);
String dumpFlat(int maxMethods);
}

View File

@@ -31,18 +31,14 @@ const Error Error::OK(NULL);
const size_t EXTRA_BUF_SIZE = 512;
// Statically compute hash code of a string containing up to 12 [a-z] letters
#define HASH(s) (HASH12(s " "))
#define HASH12(s) (s[0] & 31LL) | (s[1] & 31LL) << 5 | (s[2] & 31LL) << 10 | (s[3] & 31LL) << 15 | \
(s[4] & 31LL) << 20 | (s[5] & 31LL) << 25 | (s[6] & 31LL) << 30 | (s[7] & 31LL) << 35 | \
(s[8] & 31LL) << 40 | (s[9] & 31LL) << 45 | (s[10] & 31LL) << 50 | (s[11] & 31LL) << 55
#define HASH(s) ((s[0] & 31LL) | (s[1] & 31LL) << 5 | (s[2] & 31LL) << 10 | (s[3] & 31LL) << 15 | \
(s[4] & 31LL) << 20 | (s[5] & 31LL) << 25 | (s[6] & 31LL) << 30 | (s[7] & 31LL) << 35 | \
(s[8] & 31LL) << 40 | (s[9] & 31LL) << 45 | (s[10] & 31LL) << 50 | (s[11] & 31LL) << 55)
// Simulate switch statement over string hashes
#define SWITCH(arg) long long arg_hash = hash(arg); if (0)
#define CASE(s) } else if (arg_hash == HASH(s)) {
#define CASE2(s1, s2) } else if (arg_hash == HASH(s1) || arg_hash == HASH(s2)) {
#define CASE(s) } else if (arg_hash == HASH(s " ")) {
// Parses agent arguments.
@@ -56,17 +52,22 @@ const size_t EXTRA_BUF_SIZE = 512;
// status - print profiling status (inactive / running for X seconds)
// list - show the list of available profiling events
// version[=full] - display the agent version
// event=EVENT - which event to trace (cpu, alloc, lock, cache-misses etc.)
// collapsed[=C] - dump collapsed stacks (the format used by FlameGraph script)
// html[=C] - produce Flame Graph in HTML format
// tree[=C] - produce call tree in HTML format
// C is counter type: 'samples' or 'total'
// event=EVENT - which event to trace (cpu, wall, cache-misses, etc.)
// alloc[=BYTES] - profile allocations with BYTES interval
// lock[=DURATION] - profile contended locks longer than DURATION ns
// collapsed - dump collapsed stacks (the format used by FlameGraph script)
// flamegraph - produce Flame Graph in HTML format
// tree - produce call tree in HTML format
// jfr - dump events in Java Flight Recorder format
// traces[=N] - dump top N call traces
// flat[=N] - dump top N methods (aka flat profile)
// samples - count the number of samples (default)
// total - count the total value (time, bytes, etc.) instead of samples"
// interval=N - sampling interval in ns (default: 10'000'000, i.e. 10 ms)
// jstackdepth=N - maximum Java stack depth (default: 2048)
// safemode=BITS - disable stack recovery techniques (default: 0, i.e. everything enabled)
// file=FILENAME - output file name for dumping
// log=FILENAME - log warnings and errors to the given dedicated stream
// filter=FILTER - thread filter
// threads - profile different threads separately
// cstack=MODE - how to collect C stack frames in addition to Java stack
@@ -100,6 +101,8 @@ Error Arguments::parse(const char* args) {
}
strcpy(_buf, args);
const char* msg = NULL;
for (char* arg = strtok(_buf, ","); arg != NULL; arg = strtok(NULL, ",")) {
char* value = strchr(arg, '=');
if (value != NULL) *value++ = 0;
@@ -128,54 +131,83 @@ Error Arguments::parse(const char* args) {
_action = value == NULL ? ACTION_VERSION : ACTION_FULL_VERSION;
// Output formats
CASE2("collapsed", "folded")
CASE("collapsed")
_output = OUTPUT_COLLAPSED;
_counter = value == NULL || strcmp(value, "samples") == 0 ? COUNTER_SAMPLES : COUNTER_TOTAL;
CASE2("flamegraph", "html")
CASE("flamegraph")
_output = OUTPUT_FLAMEGRAPH;
_counter = value == NULL || strcmp(value, "samples") == 0 ? COUNTER_SAMPLES : COUNTER_TOTAL;
CASE("tree")
_output = OUTPUT_TREE;
_counter = value == NULL || strcmp(value, "samples") == 0 ? COUNTER_SAMPLES : COUNTER_TOTAL;
CASE("jfr")
_output = OUTPUT_JFR;
_jfr_options = value == NULL ? 0 :
strcmp(value, "combine") == 0 ? JFR_COMBINE :
(int)strtol(value, NULL, 0);
CASE("traces")
_output = OUTPUT_TEXT;
_dump_traces = value == NULL ? INT_MAX : atoi(value);
CASE("flat")
_output = OUTPUT_FLAT;
_output = OUTPUT_TEXT;
_dump_flat = value == NULL ? INT_MAX : atoi(value);
CASE("samples")
_counter = COUNTER_SAMPLES;
CASE("total")
_counter = COUNTER_TOTAL;
// Basic options
CASE("event")
if (value == NULL || value[0] == 0) {
return Error("event must not be empty");
msg = "event must not be empty";
} else if (strcmp(value, EVENT_ALLOC) == 0) {
if (_alloc <= 0) _alloc = 1;
} else if (strcmp(value, EVENT_LOCK) == 0) {
if (_lock <= 0) _lock = 1;
} else if (_event != NULL) {
msg = "Duplicate event argument";
} else {
_event = value;
}
if (!addEvent(value)) {
return Error("multiple incompatible events");
CASE("alloc")
_alloc = value == NULL ? 1 : parseUnits(value);
if (_alloc < 0) {
msg = "alloc must be >= 0";
}
CASE("lock")
_lock = value == NULL ? 1 : parseUnits(value);
if (_lock < 0) {
msg = "lock must be >= 0";
}
CASE("interval")
if (value == NULL || (_interval = parseUnits(value)) <= 0) {
return Error("Invalid interval");
msg = "Invalid interval";
}
CASE("jstackdepth")
if (value == NULL || (_jstackdepth = atoi(value)) <= 0) {
return Error("jstackdepth must be > 0");
msg = "jstackdepth must be > 0";
}
CASE("safemode")
_safe_mode = value == NULL ? INT_MAX : atoi(value);
_safe_mode = value == NULL ? INT_MAX : (int)strtol(value, NULL, 0);
CASE("file")
if (value == NULL || value[0] == 0) {
return Error("file must not be empty");
msg = "file must not be empty";
}
_file = value;
CASE("log")
_log = value == NULL || value[0] == 0 ? NULL : value;
// Filters
CASE("filter")
_filter = value == NULL ? "" : value;
@@ -237,12 +269,25 @@ Error Arguments::parse(const char* args) {
}
}
// Return error only after parsing all arguments, when 'log' is already set
if (msg != NULL) {
return Error(msg);
}
if (_event == NULL && _alloc == 0 && _lock == 0) {
_event = EVENT_CPU;
}
if (_file != NULL && strchr(_file, '%') != NULL) {
_file = expandFilePattern(_buf + len + 1, EXTRA_BUF_SIZE - 1, _file);
}
if (_file != NULL && _output == OUTPUT_NONE) {
_output = detectOutputFormat(_file);
if (_output == OUTPUT_SVG) {
return Error("SVG format is obsolete, use .html for FlameGraph");
}
_dump_traces = 100;
_dump_flat = 200;
}
@@ -253,21 +298,6 @@ Error Arguments::parse(const char* args) {
return Error::OK;
}
bool Arguments::addEvent(const char* event) {
if (strcmp(event, EVENT_ALLOC) == 0) {
_events |= EK_ALLOC;
} else if (strcmp(event, EVENT_LOCK) == 0) {
_events |= EK_LOCK;
} else {
if (_events & EK_CPU) {
return false;
}
_events |= EK_CPU;
_event_desc = event;
}
return true;
}
// The linked list of string offsets is embedded right into _buf array
void Arguments::appendToEmbeddedList(int& list, char* value) {
((int*)value)[-1] = list;
@@ -324,9 +354,11 @@ Output Arguments::detectOutputFormat(const char* file) {
return OUTPUT_JFR;
} else if (strcmp(ext, ".collapsed") == 0 || strcmp(ext, ".folded") == 0) {
return OUTPUT_COLLAPSED;
} else if (strcmp(ext, ".svg") == 0) {
return OUTPUT_SVG;
}
}
return OUTPUT_FLAT;
return OUTPUT_TEXT;
}
long Arguments::parseUnits(const char* str) {

View File

@@ -53,12 +53,6 @@ enum Ring {
RING_USER
};
enum EventKind {
EK_CPU = 1,
EK_ALLOC = 2,
EK_LOCK = 4
};
enum Style {
STYLE_SIMPLE = 1,
STYLE_DOTTED = 2,
@@ -75,13 +69,25 @@ enum CStack {
enum Output {
OUTPUT_NONE,
OUTPUT_FLAT,
OUTPUT_TEXT,
OUTPUT_SVG, // obsolete
OUTPUT_COLLAPSED,
OUTPUT_FLAMEGRAPH,
OUTPUT_TREE,
OUTPUT_JFR
};
enum JfrOption {
NO_SYSTEM_INFO = 0x1,
NO_SYSTEM_PROPS = 0x2,
NO_CPU_LOAD = 0x4,
JFR_SYNC = 0x10,
JFR_TEMP_FILE = 0x20,
JFR_COMBINE = NO_SYSTEM_INFO | NO_SYSTEM_PROPS | NO_CPU_LOAD | JFR_SYNC | JFR_TEMP_FILE
};
class Error {
private:
@@ -119,12 +125,14 @@ class Arguments {
Action _action;
Counter _counter;
Ring _ring;
int _events;
const char* _event_desc;
const char* _event;
long _interval;
long _alloc;
long _lock;
int _jstackdepth;
int _safe_mode;
const char* _file;
const char* _log;
const char* _filter;
int _include;
int _exclude;
@@ -132,6 +140,8 @@ class Arguments {
int _style;
CStack _cstack;
Output _output;
int _jfr_options;
int _dump_traces;
int _dump_flat;
const char* _begin;
const char* _end;
@@ -146,12 +156,14 @@ class Arguments {
_action(ACTION_NONE),
_counter(COUNTER_SAMPLES),
_ring(RING_ANY),
_events(0),
_event_desc(NULL),
_event(NULL),
_interval(0),
_alloc(0),
_lock(0),
_jstackdepth(DEFAULT_JSTACKDEPTH),
_safe_mode(0),
_file(NULL),
_log(NULL),
_filter(NULL),
_include(0),
_exclude(0),
@@ -159,6 +171,9 @@ class Arguments {
_style(0),
_cstack(CSTACK_DEFAULT),
_output(OUTPUT_NONE),
_jfr_options(0),
_dump_traces(0),
_dump_flat(0),
_begin(NULL),
_end(NULL),
_title("Flame Graph"),
@@ -172,7 +187,13 @@ class Arguments {
Error parse(const char* args);
bool addEvent(const char* event);
bool hasOutputFile() const {
return _file != NULL && (_action == ACTION_DUMP ? _output != OUTPUT_JFR : _action >= ACTION_STATUS);
}
bool hasOption(JfrOption option) const {
return (_jfr_options & option) != 0;
}
friend class FrameName;
friend class Recording;

View File

@@ -22,6 +22,7 @@
static const u32 INITIAL_CAPACITY = 65536;
static const u32 CALL_TRACE_CHUNK = 8 * 1024 * 1024;
static const u32 OVERFLOW_TRACE_ID = 0x7fffffff;
static const size_t PAGE_ALIGNMENT = sysconf(_SC_PAGESIZE) - 1;
@@ -87,8 +88,11 @@ class LongHashTable {
};
CallTrace CallTraceStorage::_overflow_trace = {1, {BCI_ERROR, (jmethodID)"[storage_overflow]"}};
CallTraceStorage::CallTraceStorage() : _allocator(CALL_TRACE_CHUNK) {
_current_table = LongHashTable::allocate(NULL, INITIAL_CAPACITY);
_overflow = 0;
}
CallTraceStorage::~CallTraceStorage() {
@@ -103,6 +107,7 @@ void CallTraceStorage::clear() {
}
_current_table->clear();
_allocator.clear();
_overflow = 0;
}
void CallTraceStorage::collectTraces(std::map<u32, CallTrace*>& map) {
@@ -117,6 +122,10 @@ void CallTraceStorage::collectTraces(std::map<u32, CallTrace*>& map) {
}
}
}
if (_overflow > 0) {
map[OVERFLOW_TRACE_ID] = &_overflow_trace;
}
}
void CallTraceStorage::collectSamples(std::vector<CallTraceSample*>& samples) {
@@ -133,6 +142,20 @@ void CallTraceStorage::collectSamples(std::vector<CallTraceSample*>& samples) {
}
}
void CallTraceStorage::collectSamples(std::map<u64, CallTraceSample>& map) {
for (LongHashTable* table = _current_table; table != NULL; table = table->prev()) {
u64* keys = table->keys();
CallTraceSample* values = table->values();
u32 capacity = table->capacity();
for (u32 slot = 0; slot < capacity; slot++) {
if (keys[slot] != 0) {
map[keys[slot]] += values[slot];
}
}
}
}
// Adaptation of MurmurHash64A by Austin Appleby
u64 CallTraceStorage::calcHash(int num_frames, ASGCT_CallFrame* frames) {
const u64 M = 0xc6a4a7935bd1e995ULL;
@@ -231,13 +254,13 @@ u32 CallTraceStorage::put(int num_frames, ASGCT_CallFrame* frames, u64 counter)
if (++step >= capacity) {
// Very unlikely case of a table overflow
return 0;
atomicInc(_overflow);
return OVERFLOW_TRACE_ID;
}
// Improved version of linear probing
slot = (slot + step) & (capacity - 1);
}
// TODO: check overhead
CallTraceSample& s = table->values()[slot];
atomicInc(s.samples);
atomicInc(s.counter, counter);

View File

@@ -35,12 +35,26 @@ struct CallTraceSample {
CallTrace* trace;
u64 samples;
u64 counter;
CallTraceSample& operator+=(const CallTraceSample& s) {
trace = s.trace;
samples += s.samples;
counter += s.counter;
return *this;
}
bool operator<(const CallTraceSample& other) const {
return counter > other.counter;
}
};
class CallTraceStorage {
private:
static CallTrace _overflow_trace;
LinearAllocator _allocator;
LongHashTable* _current_table;
u64 _overflow;
u64 calcHash(int num_frames, ASGCT_CallFrame* frames);
CallTrace* storeCallTrace(int num_frames, ASGCT_CallFrame* frames);
@@ -53,6 +67,7 @@ class CallTraceStorage {
void clear();
void collectTraces(std::map<u32, CallTrace*>& map);
void collectSamples(std::vector<CallTraceSample*>& samples);
void collectSamples(std::map<u64, CallTraceSample>& map);
u32 put(int num_frames, ASGCT_CallFrame* frames, u64 counter);
};

View File

@@ -41,13 +41,15 @@ public class jfr2flame {
jfr.stackTraces.forEach(new Dictionary.Visitor<StackTrace>() {
@Override
public void visit(long id, StackTrace stackTrace) {
long[] methods = stackTrace.methods;
byte[] types = stackTrace.types;
String[] trace = new String[methods.length];
for (int i = 0; i < methods.length; i++) {
trace[trace.length - 1 - i] = getMethodName(methods[i], types[i]);
if (stackTrace.samples > 0) {
long[] methods = stackTrace.methods;
byte[] types = stackTrace.types;
String[] trace = new String[methods.length];
for (int i = 0; i < methods.length; i++) {
trace[trace.length - 1 - i] = getMethodName(methods[i], types[i]);
}
fg.addSample(trace, stackTrace.samples);
}
fg.addSample(trace, stackTrace.samples);
}
});
}

View File

@@ -67,11 +67,13 @@ public class jfr2nflx {
jfr.stackTraces.forEach(new Dictionary.Visitor<StackTrace>() {
@Override
public void visit(long id, StackTrace stackTrace) {
profile.field(5, nodes
.field(1, (int) id)
.field(2, packNode(node, stackTrace)));
nodes.reset();
node.reset();
if (stackTrace.samples > 0) {
profile.field(5, nodes
.field(1, (int) id)
.field(2, packNode(node, stackTrace)));
nodes.reset();
node.reset();
}
}
});

View File

@@ -69,6 +69,8 @@ public class JfrReader implements Closeable {
throw new IOException("Unsupported JFR version: " + (version >>> 16) + "." + (version & 0xffff));
}
buf.limit((int) buf.getLong(8));
this.startNanos = buf.getLong(32);
this.durationNanos = buf.getLong(40);
this.startTicks = buf.getLong(48);

View File

@@ -24,8 +24,11 @@ Error Engine::check(Arguments& args) {
return Error::OK;
}
CStack Engine::cstack() {
return CSTACK_FP;
Error Engine::start(Arguments& args) {
return Error::OK;
}
void Engine::stop() {
}
int Engine::getNativeTrace(void* ucontext, int tid, const void** callchain, int max_depth,

View File

@@ -26,14 +26,10 @@ class Engine {
static volatile bool _enabled;
public:
virtual const char* name() = 0;
virtual const char* units() = 0;
virtual Error check(Arguments& args);
virtual Error start(Arguments& args) = 0;
virtual void stop() = 0;
virtual Error start(Arguments& args);
virtual void stop();
virtual CStack cstack();
virtual int getNativeTrace(void* ucontext, int tid, const void** callchain, int max_depth,
CodeCache* java_methods, CodeCache* runtime_stubs);
@@ -42,26 +38,4 @@ class Engine {
}
};
class NoopEngine : public Engine {
public:
const char* name() {
return "noop";
}
const char* units() {
return "ns";
}
Error start(Arguments& args) {
return Error::OK;
}
void stop() {
}
CStack cstack() {
return CSTACK_NO;
}
};
#endif // _ENGINE_H

View File

@@ -18,6 +18,7 @@
#include <string>
#include <arpa/inet.h>
#include <cxxabi.h>
#include <errno.h>
#include <fcntl.h>
#include <stdint.h>
#include <stdlib.h>
@@ -28,20 +29,25 @@
#include "flightRecorder.h"
#include "jfrMetadata.h"
#include "dictionary.h"
#include "log.h"
#include "os.h"
#include "profiler.h"
#include "threadFilter.h"
#include "vmStructs.h"
static const unsigned char JFR_COMBINER_CLASS[] = {
#include "helper/one/profiler/JfrCombiner.class.h"
};
const int BUFFER_SIZE = 1024;
const int BUFFER_LIMIT = BUFFER_SIZE - 128;
const int RECORDING_BUFFER_SIZE = 65536;
const int RECORDING_BUFFER_LIMIT = RECORDING_BUFFER_SIZE - 4096;
const int MAX_STRING_LENGTH = 16383;
const int MAX_STRING_LENGTH = 8191;
static const char* const SETTING_COUNTER[] = {"samples", "total"};
static const char* const SETTING_RING[] = {NULL, "kernel", "user"};
static const char* const SETTING_CSTACK[] = {NULL, "no", "fp", "lbr"};
@@ -123,9 +129,9 @@ class Buffer {
_offset = 0;
}
void put(const char* v, int len) {
void put(const char* v, u32 len) {
memcpy(_data + _offset, v, len);
_offset += len;
_offset += (int)len;
}
void put8(char v) {
@@ -157,13 +163,27 @@ class Buffer {
put32(u.i);
}
void putVarint(u64 v) {
char b = v;
while ((v >>= 7) != 0) {
_data[_offset++] = b | 0x80;
b = v;
void putVar32(u32 v) {
while (v > 0x7f) {
_data[_offset++] = (char)v | 0x80;
v >>= 7;
}
_data[_offset++] = b;
_data[_offset++] = (char)v;
}
void putVar64(u64 v) {
int iter = 0;
while (v > 0x1fffff) {
_data[_offset++] = (char)v | 0x80; v >>= 7;
_data[_offset++] = (char)v | 0x80; v >>= 7;
_data[_offset++] = (char)v | 0x80; v >>= 7;
if (++iter == 3) return;
}
while (v > 0x7f) {
_data[_offset++] = (char)v | 0x80;
v >>= 7;
}
_data[_offset++] = (char)v;
}
void putUtf8(const char* v) {
@@ -174,9 +194,9 @@ class Buffer {
}
}
void putUtf8(const char* v, int len) {
void putUtf8(const char* v, u32 len) {
put8(3);
putVarint(len);
putVar32(len);
put(v, len);
}
@@ -206,6 +226,7 @@ class RecordingBuffer : public Buffer {
class Recording {
private:
static SpinLock _cpu_monitor_lock;
static int _append_fd;
static char* _agent_properties;
static char* _jvm_args;
@@ -214,7 +235,7 @@ class Recording {
RecordingBuffer _buf[CONCURRENCY_LEVEL];
int _fd;
off_t _file_offset;
off_t _chunk_start;
ThreadFilter _thread_set;
Dictionary _packages;
Dictionary _symbols;
@@ -229,17 +250,19 @@ class Recording {
Timer* _cpu_monitor;
CpuTimes _last_times;
void startCpuMonitor() {
void startCpuMonitor(bool enabled) {
_last_times.proc.real = OS::getProcessCpuTime(&_last_times.proc.user, &_last_times.proc.system);
_last_times.total.real = OS::getTotalCpuTime(&_last_times.total.user, &_last_times.total.system);
_cpu_monitor = OS::startTimer(1000000000, cpuMonitorCallback, this);
_cpu_monitor = enabled ? OS::startTimer(1000000000, cpuMonitorCallback, this) : NULL;
_cpu_monitor_lock.unlock();
}
void stopCpuMonitor() {
_cpu_monitor_lock.lock();
OS::stopTimer(_cpu_monitor);
if (_cpu_monitor != NULL) {
OS::stopTimer(_cpu_monitor);
}
}
void cpuMonitorCycle() {
@@ -265,10 +288,7 @@ class Recording {
}
recordCpuLoad(&_cpu_monitor_buf, proc_user, proc_system, machine_total);
if (_cpu_monitor_buf.offset() > BUFFER_LIMIT) {
flush(&_cpu_monitor_buf);
}
flushIfNeeded(&_cpu_monitor_buf, BUFFER_LIMIT);
_last_times = times;
}
@@ -286,7 +306,7 @@ class Recording {
public:
Recording(int fd, Arguments& args) : _fd(fd), _thread_set(), _packages(), _symbols(), _method_map() {
_file_offset = lseek(_fd, 0, SEEK_END);
_chunk_start = lseek(_fd, 0, SEEK_END);
_start_time = OS::millis();
_start_nanos = OS::nanotime();
_tid = OS::threadId();
@@ -297,12 +317,16 @@ class Recording {
writeMetadata(_buf);
writeRecordingInfo(_buf);
writeSettings(_buf, args);
writeOsCpuInfo(_buf);
writeJvmInfo(_buf);
writeSystemProperties(_buf);
if (!args.hasOption(NO_SYSTEM_INFO)) {
writeOsCpuInfo(_buf);
writeJvmInfo(_buf);
}
if (!args.hasOption(NO_SYSTEM_PROPS)) {
writeSystemProperties(_buf);
}
flush(_buf);
startCpuMonitor();
startCpuMonitor(!args.hasOption(NO_CPU_LOAD));
}
~Recording() {
@@ -320,25 +344,48 @@ class Recording {
writeCpool(_buf);
flush(_buf);
off_t chunk_size = lseek(_fd, 0, SEEK_CUR);
off_t chunk_end = lseek(_fd, 0, SEEK_CUR);
// Patch checkpoint size field
_buf->putVar32(0, chunk_size - cpool_offset);
// Patch cpool size field
_buf->putVar32(0, chunk_end - cpool_offset);
ssize_t result = pwrite(_fd, _buf->data(), 5, cpool_offset);
(void)result;
// Patch chunk header
_buf->put64(chunk_size);
_buf->put64(cpool_offset);
_buf->put64(chunk_end - _chunk_start);
_buf->put64(cpool_offset - _chunk_start);
_buf->put64(68);
_buf->put64(_start_time * 1000000);
_buf->put64(_stop_nanos - _start_nanos);
result = pwrite(_fd, _buf->data(), 40, 8);
result = pwrite(_fd, _buf->data(), 40, _chunk_start + 8);
(void)result;
if (_append_fd >= 0) {
OS::copyFile(_fd, _append_fd, 0, chunk_end);
}
close(_fd);
}
static void JNICALL appendRecording(JNIEnv* env, jclass cls, jstring file_name) {
const char* file_name_str = env->GetStringUTFChars(file_name, NULL);
if (file_name_str == NULL) {
return;
}
_append_fd = open(file_name_str, O_WRONLY);
if (_append_fd >= 0) {
lseek(_append_fd, 0, SEEK_END);
Profiler::_instance.stop();
close(_append_fd);
_append_fd = -1;
} else {
Log::warn("Failed to open JFR recording at %s: %s", file_name_str, strerror(errno));
}
env->ReleaseStringUTFChars(file_name, file_name_str);
}
Buffer* buffer(int lock_index) {
return &_buf[lock_index];
}
@@ -492,8 +539,8 @@ class Recording {
buf->reset();
}
void flushIfNeeded(Buffer* buf) {
if (buf->offset() >= RECORDING_BUFFER_LIMIT) {
void flushIfNeeded(Buffer* buf, int limit = RECORDING_BUFFER_LIMIT) {
if (buf->offset() >= limit) {
flush(buf);
}
}
@@ -514,13 +561,13 @@ class Recording {
void writeMetadata(Buffer* buf) {
int metadata_start = buf->skip(5); // size will be patched later
buf->putVarint(T_METADATA);
buf->putVarint(_start_nanos);
buf->putVarint(0);
buf->putVarint(1);
buf->putVar32(T_METADATA);
buf->putVar64(_start_nanos);
buf->putVar32(0);
buf->putVar32(1);
std::vector<std::string>& strings = JfrMetadata::strings();
buf->putVarint(strings.size());
buf->putVar32(strings.size());
for (int i = 0; i < strings.size(); i++) {
buf->putUtf8(strings[i].c_str());
}
@@ -531,15 +578,15 @@ class Recording {
}
void writeElement(Buffer* buf, const Element* e) {
buf->putVarint(e->_name);
buf->putVar32(e->_name);
buf->putVarint(e->_attributes.size());
buf->putVar32(e->_attributes.size());
for (int i = 0; i < e->_attributes.size(); i++) {
buf->putVarint(e->_attributes[i]._key);
buf->putVarint(e->_attributes[i]._value);
buf->putVar32(e->_attributes[i]._key);
buf->putVar32(e->_attributes[i]._value);
}
buf->putVarint(e->_children.size());
buf->putVar32(e->_children.size());
for (int i = 0; i < e->_children.size(); i++) {
writeElement(buf, e->_children[i]);
}
@@ -548,25 +595,24 @@ class Recording {
void writeRecordingInfo(Buffer* buf) {
int start = buf->skip(1);
buf->put8(T_ACTIVE_RECORDING);
buf->putVarint(_start_nanos);
buf->putVarint(0);
buf->putVarint(_tid);
buf->putVarint(1);
buf->putVar64(_start_nanos);
buf->putVar32(0);
buf->putVar32(_tid);
buf->putVar32(1);
buf->putUtf8("async-profiler " PROFILER_VERSION);
buf->putUtf8("async-profiler.jfr");
buf->putVarint(0x7fffffffffffffffULL);
buf->putVarint(0);
buf->putVarint(_start_time);
buf->putVarint(0x7fffffffffffffffULL);
buf->putVar64(0x7fffffffffffffffULL);
buf->putVar32(0);
buf->putVar64(_start_time);
buf->putVar64(0x7fffffffffffffffULL);
buf->put8(start, buf->offset() - start);
}
void writeSettings(Buffer* buf, Arguments& args) {
writeStringSetting(buf, T_ACTIVE_RECORDING, "version", PROFILER_VERSION);
writeStringSetting(buf, T_ACTIVE_RECORDING, "counter", SETTING_COUNTER[args._counter]);
writeStringSetting(buf, T_ACTIVE_RECORDING, "ring", SETTING_RING[args._ring]);
writeStringSetting(buf, T_ACTIVE_RECORDING, "cstack", SETTING_CSTACK[args._cstack]);
writeStringSetting(buf, T_ACTIVE_RECORDING, "event", args._event_desc);
writeStringSetting(buf, T_ACTIVE_RECORDING, "event", args._event);
writeStringSetting(buf, T_ACTIVE_RECORDING, "filter", args._filter);
writeStringSetting(buf, T_ACTIVE_RECORDING, "begin", args._begin);
writeStringSetting(buf, T_ACTIVE_RECORDING, "end", args._end);
@@ -574,21 +620,33 @@ class Recording {
writeListSetting(buf, T_ACTIVE_RECORDING, "exclude", args._buf, args._exclude);
writeIntSetting(buf, T_ACTIVE_RECORDING, "jstackdepth", args._jstackdepth);
writeIntSetting(buf, T_ACTIVE_RECORDING, "safemode", args._safe_mode);
writeBoolSetting(buf, T_EXECUTION_SAMPLE, "enabled", args._events & EK_CPU);
writeIntSetting(buf, T_EXECUTION_SAMPLE, "interval", args._interval);
writeBoolSetting(buf, T_ALLOC_IN_NEW_TLAB, "enabled", args._events & EK_ALLOC);
writeBoolSetting(buf, T_ALLOC_OUTSIDE_TLAB, "enabled", args._events & EK_ALLOC);
writeBoolSetting(buf, T_MONITOR_ENTER, "enabled", args._events & EK_LOCK);
writeBoolSetting(buf, T_THREAD_PARK, "enabled", args._events & EK_LOCK);
writeIntSetting(buf, T_ACTIVE_RECORDING, "jfropts", args._jfr_options);
writeBoolSetting(buf, T_EXECUTION_SAMPLE, "enabled", args._event != NULL);
if (args._event != NULL) {
writeIntSetting(buf, T_EXECUTION_SAMPLE, "interval", args._interval);
}
writeBoolSetting(buf, T_ALLOC_IN_NEW_TLAB, "enabled", args._alloc > 0);
writeBoolSetting(buf, T_ALLOC_OUTSIDE_TLAB, "enabled", args._alloc > 0);
if (args._alloc > 0) {
writeIntSetting(buf, T_ALLOC_IN_NEW_TLAB, "alloc", args._alloc);
}
writeBoolSetting(buf, T_MONITOR_ENTER, "enabled", args._lock > 0);
writeBoolSetting(buf, T_THREAD_PARK, "enabled", args._lock > 0);
if (args._lock > 0) {
writeIntSetting(buf, T_MONITOR_ENTER, "lock", args._lock);
}
}
void writeStringSetting(Buffer* buf, int category, const char* key, const char* value) {
int start = buf->skip(5);
buf->put8(T_ACTIVE_SETTING);
buf->putVarint(_start_nanos);
buf->putVarint(0);
buf->putVarint(_tid);
buf->putVarint(category);
buf->putVar64(_start_nanos);
buf->putVar32(0);
buf->putVar32(_tid);
buf->putVar32(category);
buf->putUtf8(key);
buf->putUtf8(value);
buf->putVar32(start, buf->offset() - start);
@@ -624,18 +682,18 @@ class Recording {
int start = buf->skip(5);
buf->put8(T_OS_INFORMATION);
buf->putVarint(_start_nanos);
buf->putVar64(_start_nanos);
buf->putUtf8(str);
buf->putVar32(start, buf->offset() - start);
start = buf->skip(5);
buf->put8(T_CPU_INFORMATION);
buf->putVarint(_start_nanos);
buf->putVar64(_start_nanos);
buf->putUtf8(u.machine);
buf->putUtf8(OS::getCpuDescription(str, sizeof(str) - 1) ? str : "");
buf->putVarint(1);
buf->putVarint(_available_processors);
buf->putVarint(_available_processors);
buf->putVar32(1);
buf->putVar32(_available_processors);
buf->putVar32(_available_processors);
buf->putVar32(start, buf->offset() - start);
}
@@ -651,18 +709,18 @@ class Recording {
jvmti->GetSystemProperty("java.vm.name", &jvm_name);
jvmti->GetSystemProperty("java.vm.version", &jvm_version);
flushIfNeeded(buf, RECORDING_BUFFER_LIMIT - 5 * MAX_STRING_LENGTH);
int start = buf->skip(5);
buf->put8(T_JVM_INFORMATION);
buf->putVarint(_start_nanos);
buf->putVar64(_start_nanos);
buf->putUtf8(jvm_name);
buf->putUtf8(jvm_version);
buf->putUtf8(_jvm_args);
buf->putUtf8(_jvm_flags);
buf->putUtf8(_java_command);
buf->putVarint(OS::processStartTime());
buf->putVarint(OS::processId());
buf->putVar64(OS::processStartTime());
buf->putVar32(OS::processId());
buf->putVar32(start, buf->offset() - start);
flushIfNeeded(buf);
jvmti->Deallocate((unsigned char*)jvm_version);
jvmti->Deallocate((unsigned char*)jvm_name);
@@ -680,30 +738,29 @@ class Recording {
char* key = keys[i];
char* value = NULL;
if (jvmti->GetSystemProperty(key, &value) == 0) {
flushIfNeeded(buf, RECORDING_BUFFER_LIMIT - 2 * MAX_STRING_LENGTH);
int start = buf->skip(5);
buf->put8(T_INITIAL_SYSTEM_PROPERTY);
buf->putVarint(_start_nanos);
buf->putVar64(_start_nanos);
buf->putUtf8(key);
buf->putUtf8(value);
buf->putVar32(start, buf->offset() - start);
flushIfNeeded(buf);
jvmti->Deallocate((unsigned char*)value);
}
}
jvmti->Deallocate((unsigned char*)keys);
}
void writeCpool(Buffer* buf) {
buf->skip(5); // size will be patched later
buf->putVarint(T_CPOOL);
buf->putVarint(_start_nanos);
buf->putVarint(0);
buf->putVarint(0);
buf->putVarint(1);
buf->putVar32(T_CPOOL);
buf->putVar64(_start_nanos);
buf->putVar32(0);
buf->putVar32(0);
buf->putVar32(1);
buf->putVarint(8);
buf->putVar32(8);
writeFrameTypes(buf);
writeThreadStates(buf);
@@ -716,21 +773,21 @@ class Recording {
}
void writeFrameTypes(Buffer* buf) {
buf->putVarint(T_FRAME_TYPE);
buf->putVarint(6);
buf->putVarint(FRAME_INTERPRETED); buf->putUtf8("Interpreted");
buf->putVarint(FRAME_JIT_COMPILED); buf->putUtf8("JIT compiled");
buf->putVarint(FRAME_INLINED); buf->putUtf8("Inlined");
buf->putVarint(FRAME_NATIVE); buf->putUtf8("Native");
buf->putVarint(FRAME_CPP); buf->putUtf8("C++");
buf->putVarint(FRAME_KERNEL); buf->putUtf8("Kernel");
buf->putVar32(T_FRAME_TYPE);
buf->putVar32(6);
buf->putVar32(FRAME_INTERPRETED); buf->putUtf8("Interpreted");
buf->putVar32(FRAME_JIT_COMPILED); buf->putUtf8("JIT compiled");
buf->putVar32(FRAME_INLINED); buf->putUtf8("Inlined");
buf->putVar32(FRAME_NATIVE); buf->putUtf8("Native");
buf->putVar32(FRAME_CPP); buf->putUtf8("C++");
buf->putVar32(FRAME_KERNEL); buf->putUtf8("Kernel");
}
void writeThreadStates(Buffer* buf) {
buf->putVarint(T_THREAD_STATE);
buf->putVarint(2);
buf->putVarint(THREAD_RUNNING); buf->putUtf8("STATE_RUNNABLE");
buf->putVarint(THREAD_SLEEPING); buf->putUtf8("STATE_SLEEPING");
buf->putVar32(T_THREAD_STATE);
buf->putVar32(2);
buf->putVar32(THREAD_RUNNING); buf->putUtf8("STATE_RUNNABLE");
buf->putVar32(THREAD_SLEEPING); buf->putUtf8("STATE_SLEEPING");
}
void writeThreads(Buffer* buf) {
@@ -742,8 +799,8 @@ class Recording {
std::map<int, jlong>& thread_ids = Profiler::_instance._thread_ids;
char name_buf[32];
buf->putVarint(T_THREAD);
buf->putVarint(threads.size());
buf->putVar32(T_THREAD);
buf->putVar32(threads.size());
for (int i = 0; i < threads.size(); i++) {
const char* thread_name;
jlong thread_id;
@@ -757,15 +814,15 @@ class Recording {
thread_id = 0;
}
buf->putVarint(threads[i]);
buf->putVar32(threads[i]);
buf->putUtf8(thread_name);
buf->putVarint(threads[i]);
buf->putVar32(threads[i]);
if (thread_id == 0) {
buf->put8(0);
} else {
buf->putUtf8(thread_name);
}
buf->putVarint(thread_id);
buf->putVar64(thread_id);
flushIfNeeded(buf);
}
}
@@ -774,25 +831,25 @@ class Recording {
std::map<u32, CallTrace*> traces;
Profiler::_instance._call_trace_storage.collectTraces(traces);
buf->putVarint(T_STACK_TRACE);
buf->putVarint(traces.size());
buf->putVar32(T_STACK_TRACE);
buf->putVar32(traces.size());
for (std::map<u32, CallTrace*>::const_iterator it = traces.begin(); it != traces.end(); ++it) {
CallTrace* trace = it->second;
buf->putVarint(it->first);
buf->putVarint(0); // truncated
buf->putVarint(trace->num_frames);
buf->putVar32(it->first);
buf->putVar32(0); // truncated
buf->putVar32(trace->num_frames);
for (int i = 0; i < trace->num_frames; i++) {
MethodInfo* mi = resolveMethod(trace->frames[i]);
buf->putVarint(mi->_key);
buf->putVar32(mi->_key);
jint bci = trace->frames[i].bci;
if (bci >= 0) {
buf->putVarint(mi->getLineNumber(bci));
buf->putVarint(bci);
buf->putVar32(mi->getLineNumber(bci));
buf->putVar32(bci);
} else {
buf->put8(0);
buf->put8(0);
}
buf->putVarint(mi->_type);
buf->putVar32(mi->_type);
flushIfNeeded(buf);
}
flushIfNeeded(buf);
@@ -802,16 +859,16 @@ class Recording {
void writeMethods(Buffer* buf) {
jvmtiEnv* jvmti = VM::jvmti();
buf->putVarint(T_METHOD);
buf->putVarint(_method_map.size());
buf->putVar32(T_METHOD);
buf->putVar32(_method_map.size());
for (std::map<jmethodID, MethodInfo>::const_iterator it = _method_map.begin(); it != _method_map.end(); ++it) {
const MethodInfo& mi = it->second;
buf->putVarint(mi._key);
buf->putVarint(mi._class);
buf->putVarint(mi._name);
buf->putVarint(mi._sig);
buf->putVarint(mi._modifiers);
buf->putVarint(0); // hidden
buf->putVar32(mi._key);
buf->putVar32(mi._class);
buf->putVar32(mi._name);
buf->putVar32(mi._sig);
buf->putVar32(mi._modifiers);
buf->putVar32(0); // hidden
flushIfNeeded(buf);
if (mi._line_number_table != NULL) {
@@ -824,15 +881,15 @@ class Recording {
std::map<u32, const char*> classes;
Profiler::_instance.classMap()->collect(classes);
buf->putVarint(T_CLASS);
buf->putVarint(classes.size());
buf->putVar32(T_CLASS);
buf->putVar32(classes.size());
for (std::map<u32, const char*>::const_iterator it = classes.begin(); it != classes.end(); ++it) {
const char* name = it->second;
buf->putVarint(it->first);
buf->putVarint(0); // classLoader
buf->putVarint(_symbols.lookup(name));
buf->putVarint(getPackage(name));
buf->putVarint(0); // access flags
buf->putVar32(it->first);
buf->putVar32(0); // classLoader
buf->putVar32(_symbols.lookup(name));
buf->putVar32(getPackage(name));
buf->putVar32(0); // access flags
flushIfNeeded(buf);
}
}
@@ -841,11 +898,11 @@ class Recording {
std::map<u32, const char*> packages;
_packages.collect(packages);
buf->putVarint(T_PACKAGE);
buf->putVarint(packages.size());
buf->putVar32(T_PACKAGE);
buf->putVar32(packages.size());
for (std::map<u32, const char*>::const_iterator it = packages.begin(); it != packages.end(); ++it) {
buf->putVarint(it->first);
buf->putVarint(_symbols.lookup(it->second));
buf->putVar32(it->first);
buf->putVar32(_symbols.lookup(it->second));
flushIfNeeded(buf);
}
}
@@ -854,10 +911,10 @@ class Recording {
std::map<u32, const char*> symbols;
_symbols.collect(symbols);
buf->putVarint(T_SYMBOL);
buf->putVarint(symbols.size());
buf->putVar32(T_SYMBOL);
buf->putVar32(symbols.size());
for (std::map<u32, const char*>::const_iterator it = symbols.begin(); it != symbols.end(); ++it) {
buf->putVarint(it->first);
buf->putVar32(it->first);
buf->putUtf8(it->second);
flushIfNeeded(buf);
}
@@ -866,65 +923,65 @@ class Recording {
void recordExecutionSample(Buffer* buf, int tid, u32 call_trace_id, ExecutionEvent* event) {
int start = buf->skip(1);
buf->put8(T_EXECUTION_SAMPLE);
buf->putVarint(OS::nanotime());
buf->putVarint(tid);
buf->putVarint(call_trace_id);
buf->putVarint(event->_thread_state);
buf->putVar64(OS::nanotime());
buf->putVar32(tid);
buf->putVar32(call_trace_id);
buf->putVar32(event->_thread_state);
buf->put8(start, buf->offset() - start);
}
void recordAllocationInNewTLAB(Buffer* buf, int tid, u32 call_trace_id, AllocEvent* event) {
int start = buf->skip(1);
buf->put8(T_ALLOC_IN_NEW_TLAB);
buf->putVarint(OS::nanotime());
buf->putVarint(tid);
buf->putVarint(call_trace_id);
buf->putVarint(event->_class_id);
buf->putVarint(event->_instance_size);
buf->putVarint(event->_total_size);
buf->putVar64(OS::nanotime());
buf->putVar32(tid);
buf->putVar32(call_trace_id);
buf->putVar32(event->_class_id);
buf->putVar64(event->_instance_size);
buf->putVar64(event->_total_size);
buf->put8(start, buf->offset() - start);
}
void recordAllocationOutsideTLAB(Buffer* buf, int tid, u32 call_trace_id, AllocEvent* event) {
int start = buf->skip(1);
buf->put8(T_ALLOC_OUTSIDE_TLAB);
buf->putVarint(OS::nanotime());
buf->putVarint(tid);
buf->putVarint(call_trace_id);
buf->putVarint(event->_class_id);
buf->putVarint(event->_total_size);
buf->putVar64(OS::nanotime());
buf->putVar32(tid);
buf->putVar32(call_trace_id);
buf->putVar32(event->_class_id);
buf->putVar64(event->_total_size);
buf->put8(start, buf->offset() - start);
}
void recordMonitorBlocked(Buffer* buf, int tid, u32 call_trace_id, LockEvent* event) {
int start = buf->skip(1);
buf->put8(T_MONITOR_ENTER);
buf->putVarint(event->_start_time);
buf->putVarint(event->_end_time - event->_start_time);
buf->putVarint(tid);
buf->putVarint(call_trace_id);
buf->putVarint(event->_class_id);
buf->putVarint(event->_address);
buf->putVar64(event->_start_time);
buf->putVar64(event->_end_time - event->_start_time);
buf->putVar32(tid);
buf->putVar32(call_trace_id);
buf->putVar32(event->_class_id);
buf->putVar64(event->_address);
buf->put8(start, buf->offset() - start);
}
void recordThreadPark(Buffer* buf, int tid, u32 call_trace_id, LockEvent* event) {
int start = buf->skip(1);
buf->put8(T_THREAD_PARK);
buf->putVarint(event->_start_time);
buf->putVarint(event->_end_time - event->_start_time);
buf->putVarint(tid);
buf->putVarint(call_trace_id);
buf->putVarint(event->_class_id);
buf->putVarint(event->_timeout);
buf->putVarint(event->_address);
buf->putVar64(event->_start_time);
buf->putVar64(event->_end_time - event->_start_time);
buf->putVar32(tid);
buf->putVar32(call_trace_id);
buf->putVar32(event->_class_id);
buf->putVar64(event->_timeout);
buf->putVar64(event->_address);
buf->put8(start, buf->offset() - start);
}
void recordCpuLoad(Buffer* buf, float proc_user, float proc_system, float machine_total) {
int start = buf->skip(1);
buf->put8(T_CPU_LOAD);
buf->putVarint(OS::nanotime());
buf->putVar64(OS::nanotime());
buf->putFloat(proc_user);
buf->putFloat(proc_system);
buf->putFloat(machine_total);
@@ -939,6 +996,7 @@ class Recording {
};
SpinLock Recording::_cpu_monitor_lock(1);
int Recording::_append_fd = -1;
char* Recording::_agent_properties = NULL;
char* Recording::_jvm_args = NULL;
@@ -951,9 +1009,17 @@ Error FlightRecorder::start(Arguments& args, bool reset) {
return Error("Flight Recorder output file is not specified");
}
int fd = open(args._file, O_CREAT | O_WRONLY | (reset ? O_TRUNC : 0), 0644);
if (args.hasOption(JFR_SYNC) && !loadJavaHelper()) {
return Error("Could not load JFR combiner class");
}
int fd = open(args._file, O_CREAT | O_RDWR | (reset ? O_TRUNC : 0), 0644);
if (fd == -1) {
return Error("Cannot open Flight Recorder output file");
return Error("Could not open Flight Recorder output file");
}
if (args.hasOption(JFR_TEMP_FILE)) {
unlink(args._file);
}
_rec = new Recording(fd, args);
@@ -967,10 +1033,29 @@ void FlightRecorder::stop() {
}
}
// TODO: record events with call_trace_id == 0, and use stack allocated buffer if needed
bool FlightRecorder::loadJavaHelper() {
if (!_java_helper_loaded) {
JNIEnv* jni = VM::jni();
const JNINativeMethod native_method = {
(char*)"appendRecording", (char*)"(Ljava/lang/String;)V",
(void*)Recording::appendRecording
};
jclass cls = jni->DefineClass(NULL, NULL, (const jbyte*)JFR_COMBINER_CLASS, sizeof(JFR_COMBINER_CLASS));
if (cls == NULL || jni->RegisterNatives(cls, &native_method, 1) != 0 || jni->GetMethodID(cls, "<init>", "()V") == NULL) {
jni->ExceptionClear();
return false;
}
_java_helper_loaded = true;
}
return true;
}
void FlightRecorder::recordEvent(int lock_index, int tid, u32 call_trace_id,
int event_type, Event* event, u64 counter) {
if (_rec != NULL && call_trace_id != 0) {
if (_rec != NULL) {
Buffer* buf = _rec->buffer(lock_index);
switch (event_type) {
case 0:

View File

@@ -26,9 +26,12 @@ class Recording;
class FlightRecorder {
private:
Recording* _rec;
bool _java_helper_loaded;
bool loadJavaHelper();
public:
FlightRecorder() : _rec(NULL) {
FlightRecorder() : _rec(NULL), _java_helper_loaded(false) {
}
Error start(Arguments& args, bool reset);

View File

@@ -0,0 +1 @@
202,254,186,190,0,0,0,50,0,11,10,0,3,0,8,7,0,9,7,0,10,1,0,6,60,105,110,105,116,62,1,0,3,40,41,86,1,0,4,67,111,100,101,1,0,12,114,101,99,111,114,100,83,97,109,112,108,101,12,0,4,0,5,1,0,23,111,110,101,47,112,114,111,102,105,108,101,114,47,73,110,115,116,114,117,109,101,110,116,1,0,16,106,97,118,97,47,108,97,110,103,47,79,98,106,101,99,116,0,33,0,2,0,3,0,0,0,0,0,2,0,2,0,4,0,5,0,1,0,6,0,0,0,17,0,1,0,1,0,0,0,5,42,183,0,1,177,0,0,0,0,1,9,0,7,0,5,0,0,0,0,

View File

@@ -0,0 +1,28 @@
/*
* Copyright 2021 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.
*/
package one.profiler;
/**
* Instrumentation helper for Java method profiling.
*/
public class Instrument {
private Instrument() {
}
public static native void recordSample();
}

View File

@@ -0,0 +1 @@
202,254,186,190,0,0,0,50,0,91,10,0,22,0,35,10,0,18,0,36,9,0,37,0,38,10,0,18,0,39,11,0,40,0,41,10,0,19,0,42,9,0,37,0,43,10,0,19,0,44,8,0,45,10,0,18,0,46,8,0,47,10,0,48,0,49,10,0,48,0,50,10,0,48,0,51,11,0,52,0,53,11,0,54,0,55,11,0,54,0,56,7,0,57,7,0,58,10,0,19,0,35,10,0,48,0,59,7,0,60,7,0,61,1,0,6,60,105,110,105,116,62,1,0,3,40,41,86,1,0,4,67,111,100,101,1,0,21,114,101,99,111,114,100,105,110,103,83,116,97,116,101,67,104,97,110,103,101,100,1,0,22,40,76,106,100,107,47,106,102,114,47,82,101,99,111,114,100,105,110,103,59,41,86,1,0,13,83,116,97,99,107,77,97,112,84,97,98,108,101,1,0,20,100,105,115,97,98,108,101,66,117,105,108,116,105,110,69,118,101,110,116,115,1,0,15,97,112,112,101,110,100,82,101,99,111,114,100,105,110,103,1,0,21,40,76,106,97,118,97,47,108,97,110,103,47,83,116,114,105,110,103,59,41,86,1,0,8,60,99,108,105,110,105,116,62,7,0,62,12,0,24,0,25,12,0,63,0,64,7,0,65,12,0,66,0,67,12,0,68,0,69,7,0,70,12,0,71,0,72,12,0,31,0,32,12,0,73,0,67,12,0,30,0,28,1,0,19,106,100,107,46,69,120,101,99,117,116,105,111,110,83,97,109,112,108,101,12,0,74,0,75,1,0,22,106,100,107,46,78,97,116,105,118,101,77,101,116,104,111,100,83,97,109,112,108,101,7,0,76,12,0,77,0,78,12,0,79,0,80,12,0,81,0,82,7,0,83,12,0,84,0,85,7,0,62,12,0,86,0,78,12,0,87,0,88,1,0,17,106,100,107,47,106,102,114,47,82,101,99,111,114,100,105,110,103,1,0,24,111,110,101,47,112,114,111,102,105,108,101,114,47,74,102,114,67,111,109,98,105,110,101,114,12,0,89,0,90,1,0,16,106,97,118,97,47,108,97,110,103,47,79,98,106,101,99,116,1,0,30,106,100,107,47,106,102,114,47,70,108,105,103,104,116,82,101,99,111,114,100,101,114,76,105,115,116,101,110,101,114,1,0,18,106,97,118,97,47,117,116,105,108,47,73,116,101,114,97,116,111,114,1,0,8,103,101,116,83,116,97,116,101,1,0,26,40,41,76,106,100,107,47,106,102,114,47,82,101,99,111,114,100,105,110,103,83,116,97,116,101,59,1,0,22,106,100,107,47,106,102,114,47,82,101,99,111,114,100,105,110,103,83,116,97,116,101,1,0,7,83,84,79,80,80,69,68,1,0,24,76,106,100,107,47,106,102,114,47,82,101,99,111,114,100,105,110,103,83,116,97,116,101,59,1,0,14,103,101,116,68,101,115,116,105,110,97,116,105,111,110,1,0,22,40,41,76,106,97,118,97,47,110,105,111,47,102,105,108,101,47,80,97,116,104,59,1,0,18,106,97,118,97,47,110,105,111,47,102,105,108,101,47,80,97,116,104,1,0,8,116,111,83,116,114,105,110,103,1,0,20,40,41,76,106,97,118,97,47,108,97,110,103,47,83,116,114,105,110,103,59,1,0,6,67,76,79,83,69,68,1,0,7,100,105,115,97,98,108,101,1,0,43,40,76,106,97,118,97,47,108,97,110,103,47,83,116,114,105,110,103,59,41,76,106,100,107,47,106,102,114,47,69,118,101,110,116,83,101,116,116,105,110,103,115,59,1,0,22,106,100,107,47,106,102,114,47,70,108,105,103,104,116,82,101,99,111,114,100,101,114,1,0,13,105,115,73,110,105,116,105,97,108,105,122,101,100,1,0,3,40,41,90,1,0,17,103,101,116,70,108,105,103,104,116,82,101,99,111,114,100,101,114,1,0,26,40,41,76,106,100,107,47,106,102,114,47,70,108,105,103,104,116,82,101,99,111,114,100,101,114,59,1,0,13,103,101,116,82,101,99,111,114,100,105,110,103,115,1,0,18,40,41,76,106,97,118,97,47,117,116,105,108,47,76,105,115,116,59,1,0,14,106,97,118,97,47,117,116,105,108,47,76,105,115,116,1,0,8,105,116,101,114,97,116,111,114,1,0,22,40,41,76,106,97,118,97,47,117,116,105,108,47,73,116,101,114,97,116,111,114,59,1,0,7,104,97,115,78,101,120,116,1,0,4,110,101,120,116,1,0,20,40,41,76,106,97,118,97,47,108,97,110,103,47,79,98,106,101,99,116,59,1,0,11,97,100,100,76,105,115,116,101,110,101,114,1,0,35,40,76,106,100,107,47,106,102,114,47,70,108,105,103,104,116,82,101,99,111,114,100,101,114,76,105,115,116,101,110,101,114,59,41,86,0,32,0,19,0,22,0,1,0,23,0,0,0,5,0,2,0,24,0,25,0,1,0,26,0,0,0,17,0,1,0,1,0,0,0,5,42,183,0,1,177,0,0,0,0,0,1,0,27,0,28,0,1,0,26,0,0,0,69,0,2,0,3,0,0,0,46,43,182,0,2,178,0,3,166,0,24,43,182,0,4,77,44,198,0,12,44,185,0,5,1,0,184,0,6,167,0,17,43,182,0,2,178,0,7,165,0,7,43,184,0,8,177,0,0,0,1,0,29,0,0,0,5,0,3,28,2,13,0,10,0,30,0,28,0,1,0,26,0,0,0,27,0,2,0,1,0,0,0,15,42,18,9,182,0,10,87,42,18,11,182,0,10,87,177,0,0,0,0,1,10,0,31,0,32,0,0,0,8,0,33,0,25,0,1,0,26,0,0,0,84,0,2,0,2,0,0,0,55,184,0,12,153,0,41,184,0,13,182,0,14,185,0,15,1,0,75,42,185,0,16,1,0,153,0,20,42,185,0,17,1,0,192,0,18,76,43,184,0,8,167,255,233,187,0,19,89,183,0,20,184,0,21,177,0,0,0,1,0,29,0,0,0,11,0,2,252,0,18,7,0,34,250,0,25,0,0,

View File

@@ -0,0 +1,62 @@
/*
* Copyright 2021 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.
*/
package one.profiler;
import jdk.jfr.FlightRecorder;
import jdk.jfr.FlightRecorderListener;
import jdk.jfr.Recording;
import jdk.jfr.RecordingState;
import java.nio.file.Path;
/**
* Appends async-profiler recording to an existing JFR recording.
*/
class JfrCombiner implements FlightRecorderListener {
private JfrCombiner() {
}
@Override
public void recordingStateChanged(Recording recording) {
if (recording.getState() == RecordingState.STOPPED) {
Path path = recording.getDestination();
if (path != null) {
appendRecording(path.toString());
}
} else if (recording.getState() != RecordingState.CLOSED) {
disableBuiltinEvents(recording);
}
}
private static void disableBuiltinEvents(Recording recording) {
recording.disable("jdk.ExecutionSample");
recording.disable("jdk.NativeMethodSample");
}
private static native void appendRecording(String path);
static {
if (FlightRecorder.isInitialized()) {
for (Recording recording : FlightRecorder.getFlightRecorder().getRecordings()) {
disableBuiltinEvents(recording);
}
}
FlightRecorder.addListener(new JfrCombiner());
}
}

View File

@@ -24,28 +24,9 @@
#include "instrument.h"
// A class with a single native recordSample() method
static const char INSTRUMENT_CLASS[] =
"\xCA\xFE\xBA\xBE" // magic
"\x00\x00\x00\x32" // version: 50
"\x00\x07" // constant_pool_count: 7
"\x07\x00\x02" // #1 = CONSTANT_Class: #2
"\x01\x00\x17one/profiler/Instrument" // #2 = CONSTANT_Utf8: "one/profiler/Instrument"
"\x07\x00\x04" // #3 = CONSTANT_Class: #4
"\x01\x00\x10java/lang/Object" // #4 = CONSTANT_Utf8: "java/lang/Object"
"\x01\x00\x0CrecordSample" // #5 = CONSTANT_Utf8: "recordSample"
"\x01\x00\x03()V" // #6 = CONSTANT_Utf8: "()V"
"\x00\x21" // access_flags: public super
"\x00\x01" // this_class: #1
"\x00\x03" // super_class: #3
"\x00\x00" // interfaces_count: 0
"\x00\x00" // fields_count: 0
"\x00\x01" // methods_count: 1
"\x01\x09" // access_flags: public static native
"\x00\x05" // name_index: #5
"\x00\x06" // descriptor_index: #6
"\x00\x00" // attributes_count: 0
"\x00"; // attributes_count: 0
static const unsigned char INSTRUMENT_CLASS[] = {
#include "helper/one/profiler/Instrument.class.h"
};
enum ConstantTag {
@@ -509,7 +490,7 @@ Error Instrument::start(Arguments& args) {
return Error("interval must be positive");
}
setupTargetClassAndMethod(args._event_desc);
setupTargetClassAndMethod(args._event);
_interval = args._interval ? args._interval : 1;
_calls = 0;
_running = true;

View File

@@ -30,18 +30,6 @@ class Instrument : public Engine {
static volatile bool _running;
public:
const char* name() {
return "instrument";
}
const char* units() {
return "calls";
}
CStack cstack() {
return CSTACK_NO;
}
Error check(Arguments& args);
Error start(Arguments& args);
void stop();

View File

@@ -28,14 +28,6 @@ class ITimer : public Engine {
static void signalHandler(int signo, siginfo_t* siginfo, void* ucontext);
public:
const char* name() {
return "itimer";
}
const char* units() {
return "ns";
}
Error check(Arguments& args);
Error start(Arguments& args);
void stop();

View File

@@ -268,7 +268,7 @@ static int check_file_owner(const char* path) {
static int start_attach_mechanism(int pid, int nspid) {
char path[MAX_PATH];
snprintf(path, sizeof(path), "/proc/%d/cwd/.attach_pid%d", nspid, nspid);
int fd = creat(path, 0660);
if (fd == -1 || (close(fd) == 0 && !check_file_owner(path))) {
// Failed to create attach trigger in current directory. Retry in /tmp
@@ -279,10 +279,10 @@ static int start_attach_mechanism(int pid, int nspid) {
}
close(fd);
}
// We have to still use the host namespace pid here for the kill() call
kill(pid, SIGQUIT);
// Start with 20 ms sleep and increment delay each iteration
struct timespec ts = {0, 20000000};
int result;
@@ -301,7 +301,7 @@ static int connect_socket(int pid) {
if (fd == -1) {
return -1;
}
struct sockaddr_un addr;
addr.sun_family = AF_UNIX;
int bytes = snprintf(addr.sun_path, sizeof(addr.sun_path), "%s/.java_pid%d", tmp_path, pid);
@@ -334,7 +334,7 @@ static int write_command(int fd, int argc, char** argv) {
}
// Mirror response from remote JVM to stdout
static int read_response(int fd) {
static int read_response(int fd, int argc, char** argv) {
char buf[8192];
ssize_t bytes = read(fd, buf, sizeof(buf) - 1);
if (bytes <= 0) {
@@ -346,10 +346,26 @@ static int read_response(int fd) {
buf[bytes] = 0;
int result = atoi(buf);
// Special treatment of 'load' command
if (result == 0 && argc > 0 && strcmp(argv[0], "load") == 0) {
size_t total = bytes;
while (total < sizeof(buf) - 1 && (bytes = read(fd, buf + total, sizeof(buf) - 1 - total)) > 0) {
total += (size_t)bytes;
}
bytes = total;
// The second line is the result of 'load' command; since JDK 9 it starts from "return code: "
buf[bytes] = 0;
result = atoi(strncmp(buf + 2, "return code: ", 13) == 0 ? buf + 15 : buf + 2);
}
// Mirror JVM response to stdout
printf("JVM response code = ");
do {
fwrite(buf, 1, bytes, stdout);
bytes = read(fd, buf, sizeof(buf));
} while (bytes > 0);
printf("\n");
return result;
}
@@ -357,12 +373,12 @@ static int read_response(int fd) {
int main(int argc, char** argv) {
if (argc < 3) {
printf("jattach " JATTACH_VERSION " built on " __DATE__ "\n"
"Copyright 2018 Andrei Pangin\n"
"Copyright 2021 Andrei Pangin\n"
"\n"
"Usage: jattach <pid> <cmd> [args ...]\n");
return 1;
}
int pid = atoi(argv[1]);
if (pid == 0) {
perror("Invalid pid provided");
@@ -418,7 +434,7 @@ int main(int argc, char** argv) {
perror("Could not connect to socket");
return 1;
}
printf("Connected to remote JVM\n");
if (!write_command(fd, argc - 2, argv + 2)) {
perror("Error writing to socket");
@@ -426,11 +442,7 @@ int main(int argc, char** argv) {
return 1;
}
printf("Response code = ");
fflush(stdout);
int result = read_response(fd);
printf("\n");
int result = read_response(fd, argc - 2, argv + 2);
close(fd);
return result;

View File

@@ -29,8 +29,15 @@ extern "C" JNIEXPORT void JNICALL
Java_one_profiler_AsyncProfiler_start0(JNIEnv* env, jobject unused, jstring event, jlong interval, jboolean reset) {
Arguments args;
const char* event_str = env->GetStringUTFChars(event, NULL);
args.addEvent(event_str);
args._interval = interval;
if (strcmp(event_str, EVENT_ALLOC) == 0) {
args._alloc = interval > 0 ? interval : 1;
} else if (strcmp(event_str, EVENT_LOCK) == 0) {
args._lock = interval > 0 ? interval : 1;
} else {
args._event = event_str;
args._interval = interval;
}
Error error = Profiler::_instance.start(args, reset);
env->ReleaseStringUTFChars(event, event_str);
@@ -60,21 +67,27 @@ Java_one_profiler_AsyncProfiler_execute0(JNIEnv* env, jobject unused, jstring co
return NULL;
}
if (args._file == NULL || args._output == OUTPUT_JFR) {
if (!args.hasOutputFile()) {
std::ostringstream out;
Profiler::_instance.runInternal(args, out);
return env->NewStringUTF(out.str().c_str());
error = Profiler::_instance.runInternal(args, out);
if (!error) {
return env->NewStringUTF(out.str().c_str());
}
} else {
std::ofstream out(args._file, std::ios::out | std::ios::trunc);
if (out.is_open()) {
Profiler::_instance.runInternal(args, out);
out.close();
return env->NewStringUTF("OK");
} else {
if (!out.is_open()) {
JavaAPI::throwNew(env, "java/io/IOException", strerror(errno));
return NULL;
}
error = Profiler::_instance.runInternal(args, out);
out.close();
if (!error) {
return env->NewStringUTF("OK");
}
}
JavaAPI::throwNew(env, "java/lang/IllegalStateException", error.message());
return NULL;
}
extern "C" JNIEXPORT jlong JNICALL

View File

@@ -21,11 +21,14 @@
#include "vmStructs.h"
jlong LockTracer::_threshold;
jlong LockTracer::_start_time = 0;
jclass LockTracer::_LockSupport = NULL;
jmethodID LockTracer::_getBlocker = NULL;
Error LockTracer::start(Arguments& args) {
_threshold = args._lock;
// Enable Java Monitor events
jvmtiEnv* jvmti = VM::jvmti();
jvmti->SetEventNotificationMode(JVMTI_ENABLE, JVMTI_EVENT_MONITOR_CONTENDED_ENTER, NULL);
@@ -38,7 +41,7 @@ Error LockTracer::start(Arguments& args) {
_getBlocker = env->GetStaticMethodID(_LockSupport, "getBlocker", "(Ljava/lang/Thread;)Ljava/lang/Object;");
}
// Intercent Unsafe.park() for tracing contended ReentrantLocks
// Intercept Unsafe.park() for tracing contended ReentrantLocks
if (VMStructs::_unsafe_park != NULL) {
bindUnsafePark(UnsafeParkTrap);
}
@@ -69,7 +72,7 @@ void JNICALL LockTracer::MonitorContendedEntered(jvmtiEnv* jvmti, JNIEnv* env, j
jvmti->GetTag(thread, &enter_time);
// Time is meaningless if lock attempt has started before profiling
if (_enabled && enter_time >= _start_time) {
if (_enabled && entered_time - enter_time >= _threshold && enter_time >= _start_time) {
char* lock_name = getLockName(jvmti, env, object);
recordContendedLock(BCI_LOCK, enter_time, entered_time, lock_name, object, 0);
jvmti->Deallocate((unsigned char*)lock_name);
@@ -89,12 +92,13 @@ void JNICALL LockTracer::UnsafeParkTrap(JNIEnv* env, jobject instance, jboolean
if (park_blocker != NULL) {
park_end_time = OS::nanotime();
char* lock_name = getLockName(jvmti, env, park_blocker);
if (lock_name == NULL || isConcurrentLock(lock_name)) {
recordContendedLock(BCI_PARK, park_start_time, park_end_time, lock_name, park_blocker, time);
if (park_end_time - park_start_time >= _threshold) {
char* lock_name = getLockName(jvmti, env, park_blocker);
if (lock_name == NULL || isConcurrentLock(lock_name)) {
recordContendedLock(BCI_PARK, park_start_time, park_end_time, lock_name, park_blocker, time);
}
jvmti->Deallocate((unsigned char*)lock_name);
}
jvmti->Deallocate((unsigned char*)lock_name);
}
}

View File

@@ -26,6 +26,7 @@ typedef void (JNICALL *UnsafeParkFunc)(JNIEnv*, jobject, jboolean, jlong);
class LockTracer : public Engine {
private:
static jlong _threshold;
static jlong _start_time;
static jclass _LockSupport;
static jmethodID _getBlocker;
@@ -38,18 +39,6 @@ class LockTracer : public Engine {
static void bindUnsafePark(UnsafeParkFunc entry);
public:
const char* name() {
return "lock";
}
const char* units() {
return "ns";
}
CStack cstack() {
return CSTACK_NO;
}
Error start(Arguments& args);
void stop();

72
src/log.cpp Normal file
View File

@@ -0,0 +1,72 @@
/*
* Copyright 2021 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 <string.h>
#include "log.h"
FILE* Log::_file = stdout;
void Log::open(const char* file_name) {
if (_file != stdout && _file != stderr) {
fclose(_file);
}
if (file_name == NULL || strcmp(file_name, "stdout") == 0) {
_file = stdout;
} else if (strcmp(file_name, "stderr") == 0) {
_file = stderr;
} else if ((_file = fopen(file_name, "w")) == NULL) {
_file = stdout;
warn("Could not open log file: %s", file_name);
}
}
void Log::close() {
if (_file != stdout && _file != stderr) {
fclose(_file);
_file = stdout;
}
}
inline void Log::log(const char* level, const char* msg, va_list args) {
fputs(level, _file);
vfprintf(_file, msg, args);
fputs("\n", _file);
fflush(_file);
}
void Log::info(const char* msg, ...) {
va_list args;
va_start(args, msg);
log("[INFO] ", msg, args);
va_end(args);
}
void Log::warn(const char* msg, ...) {
va_list args;
va_start(args, msg);
log("[WARN] ", msg, args);
va_end(args);
}
void Log::error(const char* msg, ...) {
va_list args;
va_start(args, msg);
log("[ERROR] ", msg, args);
va_end(args);
}

39
src/log.h Normal file
View File

@@ -0,0 +1,39 @@
/*
* Copyright 2021 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 _LOG_H
#define _LOG_H
#include <stdarg.h>
#include <stdio.h>
class Log {
private:
static FILE* _file;
static void log(const char* level, const char* msg, va_list args);
public:
static void open(const char* file_name);
static void close();
static void info(const char* msg, ...);
static void warn(const char* msg, ...);
static void error(const char* msg, ...);
};
#endif // _LOG_H

View File

@@ -19,9 +19,14 @@
#include <signal.h>
#include <stddef.h>
#include <sys/types.h>
#include "arch.h"
typedef void (*SigAction)(int, siginfo_t*, void*);
typedef void (*SigHandler)(int);
typedef void (*TimerCallback)(void*);
enum ThreadState {
THREAD_INVALID,
THREAD_RUNNING,
@@ -43,11 +48,6 @@ class ThreadList {
class OS {
private:
typedef void (*SigAction)(int, siginfo_t*, void*);
typedef void (*SigHandler)(int);
typedef void (*TimerCallback)(void*);
public:
static u64 nanotime();
static u64 millis();
@@ -65,7 +65,7 @@ class OS {
static bool isJavaLibraryVisible();
static void installSignalHandler(int signo, SigAction action, SigHandler handler = NULL);
static SigAction installSignalHandler(int signo, SigAction action, SigHandler handler = NULL);
static bool sendSignalToThread(int thread_id, int signo);
static void* safeAlloc(size_t size);
@@ -77,6 +77,8 @@ class OS {
static bool getCpuDescription(char* buf, size_t size);
static u64 getProcessCpuTime(u64* utime, u64* stime);
static u64 getTotalCpuTime(u64* utime, u64* stime);
static void copyFile(int src_fd, int dst_fd, off_t offset, size_t size);
};
#endif // _OS_H

View File

@@ -24,6 +24,7 @@
#include <stdlib.h>
#include <string.h>
#include <sys/mman.h>
#include <sys/sendfile.h>
#include <sys/stat.h>
#include <sys/syscall.h>
#include <sys/time.h>
@@ -208,8 +209,9 @@ bool OS::isJavaLibraryVisible() {
return false;
}
void OS::installSignalHandler(int signo, SigAction action, SigHandler handler) {
SigAction OS::installSignalHandler(int signo, SigAction action, SigHandler handler) {
struct sigaction sa;
struct sigaction oldsa;
sigemptyset(&sa.sa_mask);
if (handler != NULL) {
@@ -220,7 +222,8 @@ void OS::installSignalHandler(int signo, SigAction action, SigHandler handler) {
sa.sa_flags = SA_SIGINFO | SA_RESTART;
}
sigaction(signo, &sa, NULL);
sigaction(signo, &sa, &oldsa);
return oldsa.sa_sigaction;
}
bool OS::sendSignalToThread(int thread_id, int signo) {
@@ -316,4 +319,15 @@ u64 OS::getTotalCpuTime(u64* utime, u64* stime) {
return real;
}
void OS::copyFile(int src_fd, int dst_fd, off_t offset, size_t size) {
// copy_file_range() is probably better, but not supported on all kernels
while (size > 0) {
ssize_t bytes = sendfile(dst_fd, src_fd, &offset, size);
if (bytes <= 0) {
break;
}
size -= (size_t)bytes;
}
}
#endif // __linux__

View File

@@ -28,6 +28,7 @@
#include <sys/sysctl.h>
#include <sys/time.h>
#include <sys/times.h>
#include <unistd.h>
#include "os.h"
@@ -157,8 +158,9 @@ bool OS::isJavaLibraryVisible() {
return true;
}
void OS::installSignalHandler(int signo, SigAction action, SigHandler handler) {
SigAction OS::installSignalHandler(int signo, SigAction action, SigHandler handler) {
struct sigaction sa;
struct sigaction oldsa;
sigemptyset(&sa.sa_mask);
if (handler != NULL) {
@@ -169,7 +171,8 @@ void OS::installSignalHandler(int signo, SigAction action, SigHandler handler) {
sa.sa_flags = SA_SIGINFO | SA_RESTART;
}
sigaction(signo, &sa, NULL);
sigaction(signo, &sa, &oldsa);
return oldsa.sa_sigaction;
}
bool OS::sendSignalToThread(int thread_id, int signo) {
@@ -209,10 +212,8 @@ Timer* OS::startTimer(u64 interval, TimerCallback callback, void* arg) {
void OS::stopTimer(Timer* timer) {
dispatch_source_t source = (dispatch_source_t)timer;
if (source != NULL) {
dispatch_source_cancel(source);
dispatch_release(source);
}
dispatch_source_cancel(source);
dispatch_release(source);
}
bool OS::getCpuDescription(char* buf, size_t size) {
@@ -255,4 +256,22 @@ u64 OS::getTotalCpuTime(u64* utime, u64* stime) {
return user + system + idle;
}
void OS::copyFile(int src_fd, int dst_fd, off_t offset, size_t size) {
char* buf = (char*)mmap(NULL, size + offset, PROT_READ, MAP_PRIVATE, src_fd, 0);
if (buf == NULL) {
return;
}
while (size > 0) {
ssize_t bytes = write(dst_fd, buf + offset, size < 262144 ? size : 262144);
if (bytes <= 0) {
break;
}
offset += (size_t)bytes;
size -= (size_t)bytes;
}
munmap(buf, offset);
}
#endif // __APPLE__

View File

@@ -32,17 +32,10 @@ class PerfEvents : public Engine {
static long _interval;
static Ring _ring;
static CStack _cstack;
static bool _print_extended_warning;
static void signalHandler(int signo, siginfo_t* siginfo, void* ucontext);
public:
const char* name() {
return "perf";
}
const char* units();
Error check(Arguments& args);
Error start(Arguments& args);
void stop();
@@ -50,10 +43,14 @@ class PerfEvents : public Engine {
int getNativeTrace(void* ucontext, int tid, const void** callchain, int max_depth,
CodeCache* java_methods, CodeCache* runtime_stubs);
const char* units();
static void resetBuffer(int tid);
static bool supported();
static const char* getEventName(int event_id);
static bool createForThread(int tid);
static int createForThread(int tid);
static void destroyForThread(int tid);
};

View File

@@ -31,6 +31,7 @@
#include <sys/syscall.h>
#include <linux/perf_event.h>
#include "arch.h"
#include "log.h"
#include "os.h"
#include "perfEvents.h"
#include "profiler.h"
@@ -301,17 +302,16 @@ PerfEventType* PerfEvents::_event_type = NULL;
long PerfEvents::_interval;
Ring PerfEvents::_ring;
CStack PerfEvents::_cstack;
bool PerfEvents::_print_extended_warning;
bool PerfEvents::createForThread(int tid) {
int PerfEvents::createForThread(int tid) {
if (tid >= _max_events) {
fprintf(stderr, "WARNING: tid[%d] > pid_max[%d]. Restart profiler after changing pid_max\n", tid, _max_events);
return false;
Log::warn("tid[%d] > pid_max[%d]. Restart profiler after changing pid_max", tid, _max_events);
return -1;
}
PerfEventType* event_type = _event_type;
if (event_type == NULL) {
return false;
return -1;
}
struct perf_event_attr attr = {0};
@@ -356,24 +356,19 @@ bool PerfEvents::createForThread(int tid) {
int fd = syscall(__NR_perf_event_open, &attr, tid, -1, -1, 0);
if (fd == -1) {
int err = errno;
perror("perf_event_open failed");
if (err == EACCES && _print_extended_warning) {
fprintf(stderr, "Due to permission restrictions, you cannot collect kernel events.\n"
"Try with --all-user option, or 'echo 1 > /proc/sys/kernel/perf_event_paranoid'\n");
_print_extended_warning = false;
}
return false;
Log::warn("perf_event_open failed: %s", strerror(errno));
return err;
}
if (!__sync_bool_compare_and_swap(&_events[tid]._fd, 0, fd)) {
// Lost race. The event is created either from start() or from onThreadStart()
close(fd);
return false;
return -1;
}
void* page = mmap(NULL, 2 * PERF_PAGE_SIZE, PROT_READ | PROT_WRITE, MAP_SHARED, fd, 0);
if (page == MAP_FAILED) {
perror("perf_event mmap failed");
Log::warn("perf_event mmap failed: %s", strerror(errno));
page = NULL;
}
@@ -391,7 +386,7 @@ bool PerfEvents::createForThread(int tid) {
ioctl(fd, PERF_EVENT_IOC_RESET, 0);
ioctl(fd, PERF_EVENT_IOC_REFRESH, 1);
return true;
return 0;
}
void PerfEvents::destroyForThread(int tid) {
@@ -434,6 +429,8 @@ void PerfEvents::signalHandler(int signo, siginfo_t* siginfo, void* ucontext) {
ExecutionEvent event;
Profiler::_instance.recordSample(ucontext, counter, 0, &event);
} else {
resetBuffer(OS::threadId());
}
ioctl(siginfo->si_fd, PERF_EVENT_IOC_RESET, 0);
@@ -452,7 +449,7 @@ const char* PerfEvents::units() {
}
Error PerfEvents::check(Arguments& args) {
PerfEventType* event_type = PerfEventType::forName(args._event_desc);
PerfEventType* event_type = PerfEventType::forName(args._event);
if (event_type == NULL) {
return Error("Unsupported event type");
}
@@ -501,7 +498,7 @@ Error PerfEvents::check(Arguments& args) {
}
Error PerfEvents::start(Arguments& args) {
_event_type = PerfEventType::forName(args._event_desc);
_event_type = PerfEventType::forName(args._event);
if (_event_type == NULL) {
return Error("Unsupported event type");
}
@@ -513,13 +510,12 @@ Error PerfEvents::start(Arguments& args) {
_ring = args._ring;
if (_ring != RING_USER && !Symbols::haveKernelSymbols()) {
fprintf(stderr, "WARNING: Kernel symbols are unavailable due to restrictions. Try\n"
" echo 0 > /proc/sys/kernel/kptr_restrict\n"
" echo 1 > /proc/sys/kernel/perf_event_paranoid\n");
Log::warn("Kernel symbols are unavailable due to restrictions. Try");
Log::warn(" sysctl kernel.kptr_restrict=0");
Log::warn(" sysctl kernel.perf_event_paranoid=1");
_ring = RING_USER;
}
_cstack = args._cstack;
_print_extended_warning = _ring != RING_USER;
int max_events = OS::getMaxThreadId();
if (max_events != _max_events) {
@@ -534,16 +530,23 @@ Error PerfEvents::start(Arguments& args) {
Profiler::_instance.switchThreadEvents(JVMTI_ENABLE);
// Create perf_events for all existing threads
int err;
bool created = false;
ThreadList* thread_list = OS::listThreads();
for (int tid; (tid = thread_list->next()) != -1; ) {
created |= createForThread(tid);
if ((err = createForThread(tid)) == 0) {
created = true;
}
}
delete thread_list;
if (!created) {
Profiler::_instance.switchThreadEvents(JVMTI_DISABLE);
return Error("Perf events unavailable. See stderr of the target process.");
if (err == EACCES || err == EPERM) {
return Error("No access to perf events. Try --all-user option or 'sysctl kernel.perf_event_paranoid=1'");
} else {
return Error("Perf events unavailable");
}
}
return Error::OK;
}
@@ -627,6 +630,22 @@ stack_complete:
return depth;
}
void PerfEvents::resetBuffer(int tid) {
PerfEvent* event = &_events[tid];
if (!event->tryLock()) {
return; // the event is being destroyed
}
struct perf_event_mmap_page* page = event->_page;
if (page != NULL) {
u64 head = page->data_head;
rmb();
page->data_tail = head;
}
event->unlock();
}
bool PerfEvents::supported() {
// The official way of knowing if perf_event_open() support is enabled
// is checking for the existence of the file /proc/sys/kernel/perf_event_paranoid

View File

@@ -24,7 +24,6 @@ PerfEvent* PerfEvents::_events;
PerfEventType* PerfEvents::_event_type;
long PerfEvents::_interval;
Ring PerfEvents::_ring;
bool PerfEvents::_print_extended_warning;
void PerfEvents::signalHandler(int signo, siginfo_t* siginfo, void* ucontext) {
@@ -50,6 +49,9 @@ int PerfEvents::getNativeTrace(void* ucontext, int tid, const void** callchain,
return 0;
}
void PerfEvents::resetBuffer(int tid) {
}
bool PerfEvents::supported() {
return false;
}
@@ -58,8 +60,8 @@ const char* PerfEvents::getEventName(int event_id) {
return NULL;
}
bool PerfEvents::createForThread(int tid) {
return false;
int PerfEvents::createForThread(int tid) {
return -1;
}
void PerfEvents::destroyForThread(int tid) {

View File

@@ -33,6 +33,7 @@
#include "flameGraph.h"
#include "flightRecorder.h"
#include "frameName.h"
#include "log.h"
#include "os.h"
#include "stackFrame.h"
#include "symbols.h"
@@ -41,7 +42,7 @@
Profiler Profiler::_instance;
static NoopEngine noop_engine;
static Engine noop_engine;
static PerfEvents perf_events;
static AllocTracer alloc_tracer;
static LockTracer lock_tracer;
@@ -59,9 +60,15 @@ enum StackRecovery {
SCAN_STACK = 0x8,
LAST_JAVA_PC = 0x10,
GC_TRACES = 0x20,
JAVA_STATE = 0x40,
MAX_RECOVERY = 0x7f
};
HOTSPOT_ONLY = LAST_JAVA_PC | GC_TRACES,
MAX_RECOVERY = MOVE_SP | MOVE_SP2 | POP_FRAME | SCAN_STACK | LAST_JAVA_PC | GC_TRACES
enum EventMask {
EM_CPU = 1,
EM_ALLOC = 2,
EM_LOCK = 4
};
@@ -69,12 +76,9 @@ struct MethodSample {
u64 samples;
u64 counter;
MethodSample() : samples(0), counter(0) {
}
void add(CallTraceSample* s) {
samples += s->samples;
counter += s->counter;
void add(u64 add_samples, u64 add_counter) {
samples += add_samples;
counter += add_counter;
}
};
@@ -130,14 +134,15 @@ const char* Profiler::asgctError(int code) {
case ticks_not_walkable_not_Java:
// Not in Java context at all; this is not an error
return NULL;
case ticks_thread_exit:
// The last Java frame has been popped off, only native frames left
return NULL;
case ticks_GC_active:
return "GC_active";
case ticks_unknown_Java:
return "unknown_Java";
case ticks_not_walkable_Java:
return "not_walkable_Java";
case ticks_thread_exit:
return "thread_exit";
case ticks_deopt:
return "deoptimization";
case ticks_safepoint:
@@ -150,6 +155,23 @@ const char* Profiler::asgctError(int code) {
}
}
const char* Profiler::units() {
switch (_event_mask) {
case EM_ALLOC:
return "bytes";
case EM_LOCK:
return "ns";
default:
if (_engine == &perf_events) {
return perf_events.units();
} else if (_engine == &instrument) {
return "calls";
} else {
return "ns";
}
}
}
inline u32 Profiler::getLockIndex(int tid) {
u32 lock_index = tid;
lock_index ^= lock_index >> 8;
@@ -222,10 +244,27 @@ const char* Profiler::findNativeMethod(const void* address) {
return lib == NULL ? NULL : lib->binarySearch(address);
}
int Profiler::getNativeTrace(void* ucontext, ASGCT_CallFrame* frames, int tid) {
// Make sure the top frame is Java, otherwise AsyncGetCallTrace
// will attempt to use frame pointer based stack walking
bool Profiler::inJavaCode(void* ucontext) {
if (ucontext == NULL) {
return true;
}
const void* pc = (const void*)StackFrame(ucontext).pc();
if (_runtime_stubs.contains(pc)) {
_stubs_lock.lockShared();
jmethodID method = _runtime_stubs.find(pc);
_stubs_lock.unlockShared();
return method == NULL || strcmp((const char*)method, "call_stub") != 0;
}
return _java_methods.contains(pc);
}
int Profiler::getNativeTrace(Engine* engine, void* ucontext, ASGCT_CallFrame* frames, int tid) {
const void* native_callchain[MAX_NATIVE_FRAMES];
int native_frames = _engine->getNativeTrace(ucontext, tid, native_callchain, MAX_NATIVE_FRAMES,
&_java_methods, &_runtime_stubs);
int native_frames = engine->getNativeTrace(ucontext, tid, native_callchain, MAX_NATIVE_FRAMES,
&_java_methods, &_runtime_stubs);
int depth = 0;
jmethodID prev_method = NULL;
@@ -257,9 +296,24 @@ int Profiler::getJavaTraceAsync(void* ucontext, ASGCT_CallFrame* frames, int max
return 0;
}
if (_safe_mode & JAVA_STATE) {
int state = vm_thread->state();
if ((state == 8 || state == 9) && !inJavaCode(ucontext)) {
// Thread is in Java state, but does not have a valid Java frame on top of the stack
atomicInc(_failures[-ticks_unknown_Java]);
frames->bci = BCI_ERROR;
frames->method_id = (jmethodID)asgctError(ticks_unknown_Java);
return 1;
}
}
ASGCT_CallTrace trace = {jni, 0, frames};
VM::_asyncGetCallTrace(&trace, max_depth, ucontext);
if (trace.num_frames > 0) {
return trace.num_frames;
}
if ((trace.num_frames == ticks_unknown_Java || trace.num_frames == ticks_not_walkable_Java) && _safe_mode < MAX_RECOVERY) {
// If current Java stack is not walkable (e.g. the top frame is not fully constructed),
// try to manually pop the top frame off, hoping that the previous frame is walkable.
@@ -346,32 +400,48 @@ int Profiler::getJavaTraceAsync(void* ucontext, ASGCT_CallFrame* frames, int max
}
}
} else if (trace.num_frames == ticks_unknown_not_Java && !(_safe_mode & LAST_JAVA_PC)) {
VMThread* thread = VMThread::fromEnv(jni);
if (thread != NULL) {
uintptr_t& sp = thread->lastJavaSP();
uintptr_t& pc = thread->lastJavaPC();
if (sp != 0 && pc == 0) {
// We have the last Java frame anchor, but it is not marked as walkable.
// Make it walkable here
uintptr_t saved_sp = sp;
pc = ((uintptr_t*)saved_sp)[-1];
uintptr_t& sp = vm_thread->lastJavaSP();
uintptr_t& pc = vm_thread->lastJavaPC();
if (sp != 0 && pc == 0) {
// We have the last Java frame anchor, but it is not marked as walkable.
// Make it walkable here
uintptr_t saved_sp = sp;
pc = ((uintptr_t*)saved_sp)[-1];
AddressType addr_type = getAddressType((instruction_t*)pc);
if (addr_type != ADDR_UNKNOWN) {
// AGCT fails if the last Java frame is a Runtime Stub with an invalid _frame_complete_offset.
// In this case we manually replace last Java frame to the previous frame
if (addr_type == ADDR_STUB) {
RuntimeStub* stub = RuntimeStub::findBlob((instruction_t*)pc);
if (stub != NULL && stub->frameSize() > 0 && stub->frameSize() < 256) {
sp = saved_sp + stub->frameSize() * sizeof(uintptr_t);
pc = ((uintptr_t*)sp)[-1];
}
AddressType addr_type = getAddressType((instruction_t*)pc);
if (addr_type != ADDR_UNKNOWN) {
// AGCT fails if the last Java frame is a Runtime Stub with an invalid _frame_complete_offset.
// In this case we manually replace last Java frame to the previous frame
if (addr_type == ADDR_STUB) {
RuntimeStub* stub = RuntimeStub::findBlob((instruction_t*)pc);
if (stub != NULL && stub->frameSize() > 0 && stub->frameSize() < 256) {
sp = saved_sp + stub->frameSize() * sizeof(uintptr_t);
pc = ((uintptr_t*)sp)[-1];
}
VM::_asyncGetCallTrace(&trace, max_depth, ucontext);
}
VM::_asyncGetCallTrace(&trace, max_depth, ucontext);
}
sp = saved_sp;
pc = 0;
}
} else if (trace.num_frames == ticks_not_walkable_not_Java && !(_safe_mode & LAST_JAVA_PC)) {
uintptr_t& sp = vm_thread->lastJavaSP();
uintptr_t& pc = vm_thread->lastJavaPC();
if (sp != 0 && pc != 0 && getAddressType((instruction_t*)pc) == ADDR_STUB) {
// Similar to the above: last Java frame is set,
// but points to a Runtime Stub with an invalid _frame_complete_offset
RuntimeStub* stub = RuntimeStub::findBlob((instruction_t*)pc);
if (stub != NULL && stub->frameSize() > 0 && stub->frameSize() < 256) {
uintptr_t saved_sp = sp;
uintptr_t saved_pc = pc;
sp = saved_sp + stub->frameSize() * sizeof(uintptr_t);
pc = ((uintptr_t*)sp)[-1];
VM::_asyncGetCallTrace(&trace, max_depth, ucontext);
sp = saved_sp;
pc = 0;
pc = saved_pc;
}
}
} else if (trace.num_frames == ticks_GC_active && !(_safe_mode & GC_TRACES)) {
@@ -503,9 +573,9 @@ void Profiler::recordSample(void* ucontext, u64 counter, jint event_type, Event*
// Too many concurrent signals already
atomicInc(_failures[-ticks_skipped]);
if (event_type == 0) {
if (event_type == 0 && _engine == &perf_events) {
// Need to reset PerfEvents ring buffer, even though we discard the collected trace
_engine->getNativeTrace(ucontext, tid, NULL, 0, &_java_methods, &_runtime_stubs);
PerfEvents::resetBuffer(tid);
}
return;
}
@@ -516,8 +586,12 @@ void Profiler::recordSample(void* ucontext, u64 counter, jint event_type, Event*
if (!_jfr.active() && event_type <= BCI_ALLOC && event_type >= BCI_PARK && event->id()) {
num_frames = makeEventFrame(frames, event_type, event->id());
}
if (_cstack != CSTACK_NO) {
num_frames += getNativeTrace(ucontext, frames + num_frames, tid);
// Use engine stack walker for execution samples, or basic stack walker for other events
if (event_type == 0 && _cstack != CSTACK_NO) {
num_frames += getNativeTrace(_engine, ucontext, frames + num_frames, tid);
} else if (event_type != 0 && _cstack > CSTACK_NO) {
num_frames += getNativeTrace(&noop_engine, ucontext, frames + num_frames, tid);
}
int first_java_frame = num_frames;
@@ -604,13 +678,13 @@ void Profiler::bindNativeLibraryLoad(JNIEnv* env, bool enable) {
}
} else {
fprintf(stderr, "WARNING: Failed to intercept NativeLibraries.load()\n");
Log::warn("Failed to intercept NativeLibraries.load()");
return;
}
strcat(original_jni_name, _load_method.name);
if ((_original_NativeLibrary_load = dlsym(VM::_libjava, original_jni_name)) == NULL) {
fprintf(stderr, "WARNING: Could not find %s\n", original_jni_name);
Log::warn("Could not find %s", original_jni_name);
return;
}
@@ -619,7 +693,7 @@ void Profiler::bindNativeLibraryLoad(JNIEnv* env, bool enable) {
? "jdk/internal/loader/NativeLibraries"
: "java/lang/ClassLoader$NativeLibrary";
if ((NativeLibrary = env->FindClass(class_name)) == NULL) {
fprintf(stderr, "WARNING: Could not find %s\n", class_name);
Log::warn("Could not find %s", class_name);
return;
}
}
@@ -677,7 +751,6 @@ Error Profiler::installTraps(const char* begin, const char* end) {
_engine->enableEvents(true);
} else {
_engine->enableEvents(false);
OS::installSignalHandler(SIGTRAP, trapHandler);
_begin_trap.install();
}
@@ -690,10 +763,6 @@ void Profiler::uninstallTraps() {
}
void Profiler::trapHandler(int signo, siginfo_t* siginfo, void* ucontext) {
_instance.trapHandlerImpl(ucontext);
}
void Profiler::trapHandlerImpl(void* ucontext) {
StackFrame frame(ucontext);
if (_begin_trap.covers(frame.pc())) {
@@ -706,6 +775,15 @@ void Profiler::trapHandlerImpl(void* ucontext) {
_end_trap.uninstall();
_begin_trap.install();
frame.pc() = _end_trap.entry();
} else if (_orig_trapHandler != NULL) {
_orig_trapHandler(signo, siginfo, ucontext);
}
}
void Profiler::setupTrapHandler() {
_orig_trapHandler = OS::installSignalHandler(SIGTRAP, AllocTracer::trapHandler);
if (_orig_trapHandler == (void*)SIG_DFL || _orig_trapHandler == (void*)SIG_IGN) {
_orig_trapHandler = NULL;
}
}
@@ -716,7 +794,7 @@ void Profiler::setThreadInfo(int tid, const char* name, jlong java_thread_id) {
}
void Profiler::updateThreadName(jvmtiEnv* jvmti, JNIEnv* jni, jthread thread) {
if (_update_thread_names) {
if (_update_thread_names && VMThread::hasNativeId()) {
VMThread* vm_thread = VMThread::fromJavaThread(jni, thread);
jvmtiThreadInfo thread_info;
if (vm_thread != NULL && jvmti->GetThreadInfo(thread, &thread_info) == 0) {
@@ -728,7 +806,7 @@ void Profiler::updateThreadName(jvmtiEnv* jvmti, JNIEnv* jni, jthread thread) {
}
void Profiler::updateJavaThreadNames() {
if (_update_thread_names) {
if (_update_thread_names && VMThread::hasNativeId()) {
jvmtiEnv* jvmti = VM::jvmti();
jint thread_count;
jthread* thread_objects;
@@ -790,10 +868,6 @@ Engine* Profiler::selectEngine(const char* event_name) {
return &noop_engine;
} else if (strcmp(event_name, EVENT_CPU) == 0) {
return PerfEvents::supported() ? (Engine*)&perf_events : (Engine*)&wall_clock;
} else if (strcmp(event_name, EVENT_ALLOC) == 0) {
return &alloc_tracer;
} else if (strcmp(event_name, EVENT_LOCK) == 0) {
return &lock_tracer;
} else if (strcmp(event_name, EVENT_WALL) == 0) {
return &wall_clock;
} else if (strcmp(event_name, EVENT_ITIMER) == 0) {
@@ -815,7 +889,7 @@ Error Profiler::checkJvmCapabilities() {
}
if (VMStructs::_get_stack_trace == NULL) {
fprintf(stderr, "WARNING: Install JVM debug symbols to improve profile accuracy\n");
Log::warn("Install JVM debug symbols to improve profile accuracy");
}
return Error::OK;
@@ -832,9 +906,12 @@ Error Profiler::start(Arguments& args, bool reset) {
return error;
}
if (args._events == 0) {
_event_mask = (args._event != NULL ? EM_CPU : 0) |
(args._alloc > 0 ? EM_ALLOC : 0) |
(args._lock > 0 ? EM_LOCK : 0);
if (_event_mask == 0) {
return Error("No profiling events specified");
} else if ((args._events & (args._events - 1)) && args._output != OUTPUT_JFR) {
} else if ((_event_mask & (_event_mask - 1)) && args._output != OUTPUT_JFR) {
return Error("Only JFR output supports multiple events");
}
@@ -871,14 +948,18 @@ Error Profiler::start(Arguments& args, bool reset) {
updateSymbols(args._ring != RING_USER);
_safe_mode = args._safe_mode | (VM::hotspot_version() ? 0 : HOTSPOT_ONLY);
_safe_mode = args._safe_mode;
if (VM::hotspot_version() < 8) {
// Cannot use JVM TI stack walker during GC on non-HotSpot JVMs or with PermGen
_safe_mode |= GC_TRACES | LAST_JAVA_PC;
}
_add_thread_frame = args._threads && args._output != OUTPUT_JFR;
_update_thread_names = (args._threads || args._output == OUTPUT_JFR) && VMThread::hasNativeId();
_update_thread_names = args._threads || args._output == OUTPUT_JFR;
_thread_filter.init(args._filter);
_engine = selectEngine(args._event_desc);
_cstack = args._cstack == CSTACK_DEFAULT ? _engine->cstack() : args._cstack;
_engine = selectEngine(args._event);
_cstack = args._cstack;
if (_cstack == CSTACK_LBR && _engine != &perf_events) {
return Error("Branch stack is supported only with PMU events");
}
@@ -898,15 +979,21 @@ Error Profiler::start(Arguments& args, bool reset) {
error = _engine->start(args);
if (error) {
uninstallTraps();
_jfr.stop();
return error;
goto error1;
}
// TODO: check if engines available
_events = args._events;
if (_events & EK_ALLOC) alloc_tracer.start(args);
if (_events & EK_LOCK) lock_tracer.start(args);
if (_event_mask & EM_ALLOC) {
error = alloc_tracer.start(args);
if (error) {
goto error2;
}
}
if (_event_mask & EM_LOCK) {
error = lock_tracer.start(args);
if (error) {
goto error3;
}
}
// Thread events might be already enabled by PerfEvents::start
switchThreadEvents(JVMTI_ENABLE);
@@ -915,6 +1002,19 @@ Error Profiler::start(Arguments& args, bool reset) {
_state = RUNNING;
_start_time = time(NULL);
return Error::OK;
error3:
if (_event_mask & EM_ALLOC) alloc_tracer.stop();
error2:
_engine->stop();
error1:
uninstallTraps();
for (int i = 0; i < CONCURRENCY_LEVEL; i++) _locks[i].lock();
_jfr.stop();
for (int i = 0; i < CONCURRENCY_LEVEL; i++) _locks[i].unlock();
return error;
}
Error Profiler::stop() {
@@ -925,8 +1025,8 @@ Error Profiler::stop() {
uninstallTraps();
if (_events & EK_LOCK) lock_tracer.stop();
if (_events & EK_ALLOC) alloc_tracer.stop();
if (_event_mask & EM_LOCK) lock_tracer.stop();
if (_event_mask & EM_ALLOC) alloc_tracer.stop();
_engine->stop();
@@ -955,7 +1055,7 @@ Error Profiler::check(Arguments& args) {
return error;
}
_engine = selectEngine(args._event_desc);
_engine = selectEngine(args._event);
return _engine->check(args);
}
@@ -968,6 +1068,25 @@ void Profiler::switchThreadEvents(jvmtiEventMode mode) {
}
}
void Profiler::dump(std::ostream& out, Arguments& args) {
switch (args._output) {
case OUTPUT_COLLAPSED:
dumpCollapsed(out, args);
break;
case OUTPUT_FLAMEGRAPH:
dumpFlameGraph(out, args, false);
break;
case OUTPUT_TREE:
dumpFlameGraph(out, args, true);
break;
case OUTPUT_TEXT:
dumpText(out, args);
break;
default:
break;
}
}
/*
* Dump stacks in FlameGraph input format:
*
@@ -1036,88 +1155,118 @@ void Profiler::dumpFlameGraph(std::ostream& out, Arguments& args, bool tree) {
flamegraph.dump(out, tree);
}
void Profiler::dumpFlat(std::ostream& out, Arguments& args) {
void Profiler::dumpText(std::ostream& out, Arguments& args) {
MutexLocker ml(_state_lock);
if (_state != IDLE || _engine == NULL) return;
FrameName fn(args, args._style | STYLE_DOTTED, _thread_names_lock, _thread_names);
char buf[1024] = {0};
std::map<std::string, MethodSample> histogram;
std::vector<CallTraceSample> samples;
u64 total_counter = 0;
{
std::map<u64, CallTraceSample> map;
_call_trace_storage.collectSamples(map);
samples.reserve(map.size());
std::vector<CallTraceSample*> samples;
_call_trace_storage.collectSamples(samples);
for (std::vector<CallTraceSample*>::const_iterator it = samples.begin(); it != samples.end(); ++it) {
total_counter += (*it)->counter;
CallTrace* trace = (*it)->trace;
if (trace->num_frames == 0 || excludeTrace(&fn, trace)) continue;
const char* frame_name = fn.name(trace->frames[0]);
histogram[frame_name].add(*it);
for (std::map<u64, CallTraceSample>::const_iterator it = map.begin(); it != map.end(); ++it) {
total_counter += it->second.counter;
CallTrace* trace = it->second.trace;
if (trace->num_frames == 0 || excludeTrace(&fn, trace)) continue;
samples.push_back(it->second);
}
}
std::vector<NamedMethodSample> methods(histogram.begin(), histogram.end());
std::sort(methods.begin(), methods.end(), sortByCounter);
// Print summary
snprintf(buf, sizeof(buf) - 1,
"--- Execution profile ---\n"
"Total samples : %lld\n",
_total_samples);
out << buf;
double percent = 100.0 / _total_samples;
double spercent = 100.0 / _total_samples;
for (int i = 1; i < ASGCT_FAILURE_TYPES; i++) {
const char* err_string = asgctError(-i);
if (err_string != NULL && _failures[i] > 0) {
snprintf(buf, sizeof(buf), "%-20s: %lld (%.2f%%)\n", err_string, _failures[i], _failures[i] * percent);
snprintf(buf, sizeof(buf), "%-20s: %lld (%.2f%%)\n", err_string, _failures[i], _failures[i] * spercent);
out << buf;
}
}
out << std::endl;
out << "\n"
" counter percent samples top\n"
" ---------- ------- ------- ---\n";
double cpercent = 100.0 / total_counter;
const char* units_str = units();
percent = 100.0 / total_counter;
int max_count = args._dump_flat;
for (std::vector<NamedMethodSample>::const_iterator it = methods.begin(); it != methods.end() && --max_count >= 0; ++it) {
snprintf(buf, sizeof(buf) - 1, "%12lld %6.2f%% %7lld %s\n",
it->second.counter, it->second.counter * percent, it->second.samples, it->first.c_str());
// Print top call stacks
if (args._dump_traces > 0) {
std::sort(samples.begin(), samples.end());
int max_count = args._dump_traces;
for (std::vector<CallTraceSample>::const_iterator it = samples.begin(); it != samples.end() && --max_count >= 0; ++it) {
snprintf(buf, sizeof(buf) - 1, "--- %lld %s (%.2f%%), %lld sample%s\n",
it->counter, units_str, it->counter * cpercent,
it->samples, it->samples == 1 ? "" : "s");
out << buf;
CallTrace* trace = it->trace;
for (int j = 0; j < trace->num_frames; j++) {
const char* frame_name = fn.name(trace->frames[j]);
snprintf(buf, sizeof(buf) - 1, " [%2d] %s\n", j, frame_name);
out << buf;
}
out << "\n";
}
}
// Print top methods
if (args._dump_flat > 0) {
std::map<std::string, MethodSample> histogram;
for (std::vector<CallTraceSample>::const_iterator it = samples.begin(); it != samples.end(); ++it) {
const char* frame_name = fn.name(it->trace->frames[0]);
histogram[frame_name].add(it->samples, it->counter);
}
std::vector<NamedMethodSample> methods(histogram.begin(), histogram.end());
std::sort(methods.begin(), methods.end(), sortByCounter);
snprintf(buf, sizeof(buf) - 1, "%12s percent samples top\n"
" ---------- ------- ------- ---\n", units_str);
out << buf;
int max_count = args._dump_flat;
for (std::vector<NamedMethodSample>::const_iterator it = methods.begin(); it != methods.end() && --max_count >= 0; ++it) {
snprintf(buf, sizeof(buf) - 1, "%12lld %6.2f%% %7lld %s\n",
it->second.counter, it->second.counter * cpercent, it->second.samples, it->first.c_str());
out << buf;
}
}
}
void Profiler::runInternal(Arguments& args, std::ostream& out) {
Error Profiler::runInternal(Arguments& args, std::ostream& out) {
switch (args._action) {
case ACTION_START:
case ACTION_RESUME: {
Error error = start(args, args._action == ACTION_START);
if (error) {
out << error.message() << std::endl;
} else {
out << "Profiling started" << std::endl;
return error;
}
out << "Profiling started" << std::endl;
break;
}
case ACTION_STOP: {
Error error = stop();
if (error) {
out << error.message() << std::endl;
} else {
out << "Profiling stopped after " << uptime() << " seconds. No dump options specified" << std::endl;
return error;
}
out << "Profiling stopped after " << uptime() << " seconds. No dump options specified" << std::endl;
break;
}
case ACTION_CHECK: {
Error error = check(args);
if (error) {
out << error.message() << std::endl;
} else {
out << "OK" << std::endl;
return error;
}
out << "OK" << std::endl;
break;
}
case ACTION_STATUS: {
@@ -1160,39 +1309,25 @@ void Profiler::runInternal(Arguments& args, std::ostream& out) {
break;
case ACTION_DUMP:
stop();
switch (args._output) {
case OUTPUT_COLLAPSED:
dumpCollapsed(out, args);
break;
case OUTPUT_FLAMEGRAPH:
dumpFlameGraph(out, args, false);
break;
case OUTPUT_TREE:
dumpFlameGraph(out, args, true);
break;
case OUTPUT_FLAT:
dumpFlat(out, args);
break;
default:
break;
}
dump(out, args);
break;
default:
break;
}
return Error::OK;
}
void Profiler::run(Arguments& args) {
if (args._file == NULL || args._output == OUTPUT_JFR) {
runInternal(args, std::cout);
Error Profiler::run(Arguments& args) {
if (!args.hasOutputFile()) {
return runInternal(args, std::cout);
} else {
std::ofstream out(args._file, std::ios::out | std::ios::trunc);
if (out.is_open()) {
runInternal(args, out);
out.close();
} else {
std::cerr << "Could not open " << args._file << std::endl;
if (!out.is_open()) {
return Error("Could not open output file");
}
Error error = runInternal(args, out);
out.close();
return error;
}
}
@@ -1201,11 +1336,10 @@ void Profiler::shutdown(Arguments& args) {
// The last chance to dump profile before VM terminates
if (_state == RUNNING) {
if (args._output == OUTPUT_NONE) {
stop();
} else {
args._action = ACTION_DUMP;
run(args);
args._action = ACTION_DUMP;
Error error = args._output == OUTPUT_NONE ? stop() : run(args);
if (error) {
Log::error(error.message());
}
}

View File

@@ -83,7 +83,7 @@ class Profiler {
CallTraceStorage _call_trace_storage;
FlightRecorder _jfr;
Engine* _engine;
int _events;
int _event_mask;
time_t _start_time;
u64 _total_samples;
@@ -120,10 +120,9 @@ class Profiler {
void switchNativeMethodTraps(bool enable);
void (*_orig_trapHandler)(int signo, siginfo_t* siginfo, void* ucontext);
Error installTraps(const char* begin, const char* end);
void uninstallTraps();
static void trapHandler(int signo, siginfo_t* siginfo, void* ucontext);
void trapHandlerImpl(void* ucontext);
void addJavaMethod(const void* address, int length, jmethodID method);
void removeJavaMethod(const void* address, jmethodID method);
@@ -133,8 +132,10 @@ class Profiler {
void onThreadEnd(jvmtiEnv* jvmti, JNIEnv* jni, jthread thread);
const char* asgctError(int code);
const char* units();
u32 getLockIndex(int tid);
int getNativeTrace(void* ucontext, ASGCT_CallFrame* frames, int tid);
bool inJavaCode(void* ucontext);
int getNativeTrace(Engine* engine, void* ucontext, ASGCT_CallFrame* frames, int tid);
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, uintptr_t id);
@@ -181,16 +182,17 @@ class Profiler {
Dictionary* classMap() { return &_class_map; }
ThreadFilter* threadFilter() { return &_thread_filter; }
void run(Arguments& args);
void runInternal(Arguments& args, std::ostream& out);
Error run(Arguments& args);
Error runInternal(Arguments& args, std::ostream& out);
void shutdown(Arguments& args);
Error check(Arguments& args);
Error start(Arguments& args, bool reset);
Error stop();
void switchThreadEvents(jvmtiEventMode mode);
void dump(std::ostream& out, Arguments& args);
void dumpCollapsed(std::ostream& out, Arguments& args);
void dumpFlameGraph(std::ostream& out, Arguments& args, bool tree);
void dumpFlat(std::ostream& out, Arguments& args);
void dumpText(std::ostream& out, Arguments& args);
void recordSample(void* ucontext, u64 counter, jint event_type, Event* event);
void updateSymbols(bool kernel_symbols);
@@ -198,6 +200,9 @@ class Profiler {
NativeCodeCache* findNativeLibrary(const void* address);
const char* findNativeMethod(const void* address);
void trapHandler(int signo, siginfo_t* siginfo, void* ucontext);
void setupTrapHandler();
// 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,

View File

@@ -32,6 +32,7 @@
#include <string>
#include "symbols.h"
#include "arch.h"
#include "log.h"
class SymbolDesc {
@@ -174,12 +175,7 @@ bool ElfParser::parseFile(NativeCodeCache* cc, const char* base, const char* fil
close(fd);
if (addr == MAP_FAILED) {
if (strcmp(file_name, "/") == 0) {
// https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1843018
fprintf(stderr, "Could not parse symbols due to the OS bug\n");
} else {
fprintf(stderr, "Could not parse symbols from %s: %s\n", file_name, strerror(errno));
}
Log::warn("Could not parse symbols from %s: %s", file_name, strerror(errno));
} else {
ElfParser elf(cc, base, addr, file_name);
elf.loadSymbols(use_debug);

View File

@@ -28,6 +28,7 @@
#include <mach-o/nlist.h>
#include "symbols.h"
#include "arch.h"
#include "log.h"
class MachOParser {
@@ -117,7 +118,7 @@ class MachOParser {
close(fd);
if (addr == MAP_FAILED) {
fprintf(stderr, "Could not parse symbols from %s: %s\n", file_name, strerror(errno));
Log::warn("Could not parse symbols from %s: %s", file_name, strerror(errno));
} else {
MachOParser parser(cc, image_base);
parser.parse((mach_header*)addr);

View File

@@ -14,7 +14,6 @@
* limitations under the License.
*/
#include <fstream>
#include <dlfcn.h>
#include <stdlib.h>
#include <string.h>
@@ -25,9 +24,14 @@
#include "profiler.h"
#include "instrument.h"
#include "lockTracer.h"
#include "log.h"
#include "vmStructs.h"
// JVM TI agent return codes
const int ARGUMENTS_ERROR = 100;
const int COMMAND_ERROR = 200;
static Arguments _agent_args;
JavaVM* VM::_vm;
@@ -42,11 +46,13 @@ jvmtiError (JNICALL *VM::_orig_RetransformClasses)(jvmtiEnv*, jint, const jclass
volatile int VM::_in_redefine_classes = 0;
void VM::init(JavaVM* vm, bool attach) {
if (_jvmti != NULL) return;
bool VM::init(JavaVM* vm, bool attach) {
if (_jvmti != NULL) return true;
_vm = vm;
_vm->GetEnv((void**)&_jvmti, JVMTI_VERSION_1_0);
if (_vm->GetEnv((void**)&_jvmti, JVMTI_VERSION_1_0) != 0) {
return false;
}
char* prop;
if (_jvmti->GetSystemProperty("java.vm.name", &prop) == 0) {
@@ -67,14 +73,6 @@ void VM::init(JavaVM* vm, bool attach) {
}
_jvmti->Deallocate((unsigned char*)prop);
}
if (is_hotspot) {
JVMTIFunctions* functions = *(JVMTIFunctions**)_jvmti;
_orig_RedefineClasses = functions->RedefineClasses;
_orig_RetransformClasses = functions->RetransformClasses;
functions->RedefineClasses = RedefineClassesHook;
functions->RetransformClasses = RetransformClassesHook;
}
}
_libjvm = getLibraryHandle("libjvm.so");
@@ -126,6 +124,8 @@ void VM::init(JavaVM* vm, bool attach) {
_jvmti->GenerateEvents(JVMTI_EVENT_DYNAMIC_CODE_GENERATED);
_jvmti->GenerateEvents(JVMTI_EVENT_COMPILED_METHOD_LOAD);
}
return true;
}
// Run late initialization when JVM is ready
@@ -136,7 +136,16 @@ void VM::ready() {
VMStructs::init(libjvm);
}
Profiler::_instance.setupTrapHandler();
_libjava = getLibraryHandle("libjava.so");
// Make sure we reload method IDs upon class retransformation
JVMTIFunctions* functions = *(JVMTIFunctions**)_jvmti;
_orig_RedefineClasses = functions->RedefineClasses;
_orig_RetransformClasses = functions->RetransformClasses;
functions->RedefineClasses = RedefineClassesHook;
functions->RetransformClasses = RetransformClassesHook;
}
void* VM::getLibraryHandle(const char* name) {
@@ -145,7 +154,7 @@ void* VM::getLibraryHandle(const char* name) {
if (handle != NULL) {
return handle;
}
std::cerr << "Failed to load " << name << ": " << dlerror() << std::endl;
Log::warn("Failed to load %s: %s", name, dlerror());
}
return RTLD_DEFAULT;
}
@@ -189,7 +198,10 @@ void JNICALL VM::VMInit(jvmtiEnv* jvmti, JNIEnv* jni, jthread thread) {
loadAllMethodIDs(jvmti, jni);
// Delayed start of profiler if agent has been loaded at VM bootstrap
Profiler::_instance.run(_agent_args);
Error error = Profiler::_instance.run(_agent_args);
if (error) {
Log::error(error.message());
}
}
void JNICALL VM::VMDeath(jvmtiEnv* jvmti, JNIEnv* jni) {
@@ -231,12 +243,16 @@ jvmtiError VM::RetransformClassesHook(jvmtiEnv* jvmti, jint class_count, const j
extern "C" JNIEXPORT jint JNICALL
Agent_OnLoad(JavaVM* vm, char* options, void* reserved) {
VM::init(vm, false);
Error error = _agent_args.parse(options);
Log::open(_agent_args._log);
if (error) {
std::cerr << error.message() << std::endl;
return -1;
Log::error(error.message());
return ARGUMENTS_ERROR;
}
if (!VM::init(vm, false)) {
Log::error("JVM does not support Tool Interface");
return COMMAND_ERROR;
}
return 0;
@@ -244,27 +260,39 @@ Agent_OnLoad(JavaVM* vm, char* options, void* reserved) {
extern "C" JNIEXPORT jint JNICALL
Agent_OnAttach(JavaVM* vm, char* options, void* reserved) {
VM::init(vm, true);
Arguments args;
Error error = args.parse(options);
Log::open(args._log);
if (error) {
std::cerr << error.message() << std::endl;
return -1;
Log::error(error.message());
return ARGUMENTS_ERROR;
}
if (!VM::init(vm, true)) {
Log::error("JVM does not support Tool Interface");
return COMMAND_ERROR;
}
// Save the arguments in case of shutdown
if (args._action == ACTION_START || args._action == ACTION_RESUME) {
_agent_args.save(args);
}
Profiler::_instance.run(args);
error = Profiler::_instance.run(args);
if (error) {
Log::error(error.message());
return COMMAND_ERROR;
}
return 0;
}
extern "C" JNIEXPORT jint JNICALL
JNI_OnLoad(JavaVM* vm, void* reserved) {
VM::init(vm, true);
if (!VM::init(vm, true)) {
return 0;
}
JavaAPI::registerNatives(VM::jvmti(), VM::jni());
return JNI_VERSION_1_6;
}

View File

@@ -103,7 +103,7 @@ class VM {
static void* _libjava;
static AsyncGetCallTrace _asyncGetCallTrace;
static void init(JavaVM* vm, bool attach);
static bool init(JavaVM* vm, bool attach);
static jvmtiEnv* jvmti() {
return _jvmti;

View File

@@ -92,7 +92,7 @@ Error WallClock::start(Arguments& args) {
return Error("interval must be positive");
}
_sample_idle_threads = strcmp(args._event_desc, EVENT_WALL) == 0;
_sample_idle_threads = strcmp(args._event, EVENT_WALL) == 0;
// 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);

View File

@@ -47,14 +47,6 @@ class WallClock : public Engine {
static void sleep(long interval);
public:
const char* name() {
return _sample_idle_threads ? EVENT_WALL : EVENT_CPU;
}
const char* units() {
return "ns";
}
Error start(Arguments& args);
void stop();
};