Aprof
by Devexperts
Page History
In this tutorial we will demonstrate how to use Aprof. Note, that this guide is actual for version 1921.
| Table of Contents |
|---|
Getting Started
First of all, extract aprof.jar from downloaded zip downloaded zip file with AProf Aprof binaries. This JAR is the file you will be using.
...
That's it! While you are using the demo, Aprof collects its memory allocation statistics and flushes it to aprof.txt file every minute.
Examples
Aforementioned SwingSet2 demo is a complex application, hence its profiling results are not suitable for this tutorial. We will be using a series of specifically designed samples. Some of them make no sense, some are written in non-optimal way, some might even contain bugs. Most likely you will never see them in real applications. However, they help us demonstrate key features of Aprof.
Fibonacci Numbers
Let's take a look at the following program.
| No Format |
|---|
package com.devexperts.sample;
public class FibonacciNumbers {
private static Integer fib(int n) {
if (n < 2)
return 1;
return fib(n - 1) + fib(n - 2);
}
public static void main(String[] args) {
int n = Integer.parseInt(args[0]);
System.out.printf("fib(%d)=%d\n", n, fib(n));
}
}
|
It calculates nth Fibonacci number and prints it to stdout. However, the method returns Integer instead of int which leads to a lot of garbage generated by the program. In large applications it is usually hard to find all such ineffective pieces of code.
Let's run this program under Aprof.
| No Format |
|---|
java -javaagent:aprof.jar com.devexperts.sample.FibonacciNumbers 40 |
And look at generated file aprof.txt.
...
Understanding Statistics
In order to understand aprof.txt file you should be aware of the following specifics of Aprof.
Imagine we are interested in allocations of char[]. Aprof will collect all locations where these allocations take place. Naturally, some of them occur in constructor of String object. However, it is not enough to know that, for instance, 3 char[] with total size of 120 bytes were allocated at location java.lang.String.<init>. We are also interested in locations from which we called constructor of class String. In order to collect such additional information without taking stack-traces the following method is used.
In Aprof configuration some constructors/methods are marked as tracked. What exactly does that mean? When we mark the method as tracked, we tell Aprof that we are interested in occurrences of the method on stack-trace taken at the moment of memory allocation. The trick we use is the fact that knowledge of the outermost tracked method and location from which it was called is enough to pinpoint the problem. Hence, for each memory allocation the following data is collected by Aprof:
- type of allocated object;
- location where the allocation took place;
- the outermost tracked method (if any) on stack-trace of the allocation;
- location where the tracked method was called from.
These data is organized in a tree structure with types of objects being tree roots and reverse "stack-traces" of allocation context that can be at most 3 items deep as show in the above list. Items in the tree are ordered by the allocated size with most heavily allocated data types and most heavily used allocation context going first. Here is the example of how it might look like in the actual output:
| No Format |
|---|
char[]: 488,329,896 (63%) bytes in 1,602,894 (25%) objects (avg size 305 bytes) java.lang.AbstractStringBuilder.expandCapacity: 335,290,736 (68%) bytes in 170,262 (10%) objects (avg size |
...
1,969 bytes) |
...
java.lang. |
...
reflect.Constructor. |
...
newInstance: |
...
310, |
...
510, |
...
624 ( |
...
92%) bytes in |
...
56, |
...
810 ( |
...
33%) objects |
...
(avg size |
...
5,466 bytes) SwingSet2.loadDemo: 310,508,240 (99%) bytes in |
...
56, |
...
768 (99%) objects |
...
(avg |
...
size 5,470 bytes) java.awt.AWTKeyStroke.getCachedStroke: 1,456 (0%) bytes in |
...
26 (0%) objects |
...
(avg size |
...
56 bytes) sun.swing.SwingLazyValue.createValue: 928 (0%) bytes in |
...
16 (0%) objects |
...
(avg size |
...
58 bytes) java.lang. |
...
StringBuilder. |
...
append: |
...
20,999,752 ( |
...
6%) bytes in |
...
35,880 ( |
...
21%) objects |
...
(avg |
...
size 585 bytes) DemoModule.loadSourceCode: 19,179,264 (91%) bytes in 1, |
...
412 ( |
...
3%) objects |
...
|
...
(avg size 13, |
...
583 |
...
bytes |
...
) |
...
com.devexperts.aprof.transformer. |
...
Context. |
...
getLocation: |
...
662, |
...
968 ( |
...
3%) bytes in |
...
11,364 ( |
...
31%) objects |
...
( |
...
avg |
...
size 58 bytes) com.devexperts.aprof.transformer. |
...
MethodTransformer. |
...
visitAllocateArray: |
...
355, |
...
408 ( |
...
1%) bytes in |
...
6,336 ( |
...
17%) objects |
...
(avg |
...
size 56 bytes) com.devexperts.aprof. |
...
transformer.AbstractMethodVisitor. |
...
visitTypeInsn: |
...
214, |
...
640 ( |
...
1%) bytes in |
...
4,944 ( |
...
13%) objects |
...
(avg |
...
size 43 bytes)
... |
As you can see, AProf also profiles itself.
Examples
Aforementioned SwingSet2 demo is a complex application, hence its profiling results are not suitable for this tutorial. We will be using a series of specifically designed samples. Some of them make no sense, some are written in non-optimal way, some might even contain bugs. Most likely you will never see them in real applications. However, they help us demonstrate key features of Aprof.
Fibonacci Numbers
Let's take a look at the following program.
| Code Block |
|---|
We see that 42% of all memory allocations were made for Integer objects. And almost all of them were done in method fib of class FibonacciNumbers.
Let's fix the bug with unnecessary boxing/unboxing.
| No Format |
|---|
package com.devexperts.sample; public class FibonacciNumbers { private static intInteger fib(int n) { if (n < 2) return 1; return fib(n - 1) + fib(n - 2); } public static void main(String[] args) { int n = Integer.parseInt(args[0]); System.out.printf("fib(%d)=%d\n", n, fib(n)); } } |
It calculates nth Fibonacci number and prints it to stdout. However, the method returns Integer instead of int which leads to a lot of garbage generated by the program. In large applications it is usually hard to find all such ineffective pieces of code.
Let's run this program under Aprof.
| No Format |
|---|
java -javaagent:aprof.jar com.devexperts.sample.FibonacciNumbers 40 |
And look at generated file aprof.txt.And run the program under Aprof again. We will get the following results in aprof.txt file:
| No Format |
|---|
TOTAL allocation dump for 2429,267423 ms (0h00m24s0h00m29s) Allocated 4866,231155,872144 bytes in 7572,870,672108 objects in 9531,108 locations of 299230 classes ------------------------------------------------------------------------------- char[]: 12,568,176 (26%) bytes in 185,145 (24%) objects (avg size 68 bytes) java.utillang.Arrays.copyOfRangeInteger: 334,392953,160568 (26%52%) bytes in 51,140 (27%) objects (avg size 66 bytes) com.devexperts.aprof.AProfAgent.go: 2,370,320 (69%) bytes in 35,586 (69%) 2,184,598 (76%) objects (avg size 6716 bytes) com.devexperts.aprof.transformer.AProfTransformer.transform: 1,014,592 (29% java.lang.Integer.valueOf: 34,931,824 (99%) bytes in 152,183,487239 (30%99%) objects (avg size 66 bytes) java.lang.StringBuilder.toString: 4,896 (0%) bytes in 49 (0%) objects (avg size 100 bytes) java.net.URLStreamHandler.parseURL: 1,504 (30% FibonacciNumbers.fib: 34,852,928 (99%) bytes in 10 (20%) objects (avg size 150 bytes) sun.net.www.protocol.jar.Handler.parseContextSpec: 624 (12%) bytes in 2 (4%) objects (avg size 312 bytes) sun.net.www.protocol.jar.Handler.parseURL: 624 (12%) bytes in 2 (4%) objects (avg size 312 bytes) sun.net.www.ParseUtil.decode: 560 (11%) bytes in 4 (8%) objects (avg size 140 bytes) java.util.ResourceBundle$Control.toBundleName: 256 (5%) bytes in 3 (6%) objects (avg size 85 bytes) java.util.ServiceLoader$LazyIterator.hasNext: 256 (5%) bytes in 2 (4%) objects (avg size 128 bytes) java.io.ObjectStreamClass.getClassSignature: 224 (4%) bytes in 5 (10%) objects (avg size 45 bytes) java.util.Locale.toString: 112 (2%) bytes in 6 (12%) objects (avg size 19 bytes) sun.util.resources.LocaleData$LocaleDataResourceBundleControl.getCandidateLocales: 112 (2%) bytes in 4 (8%) objects (avg size 28 bytes) java.net.URLClassLoader.getPermissions: 104 (2%) bytes in 1 (2%) objects (avg size 104 bytes) ...2,178,308 (99%) objects ... |
We see that 52% of all memory allocations were made for Integer objects. And almost all of them were done in method fib of class FibonacciNumbersThere are no suspicious memory allocations here. Note, that usually the most garbage is generated on char[] objects.
Overview
Content Tools