Page History

...

First of all, extract aprof.jar from downloaded zip downloaded zip file with Aprof binaries. This JAR is the file you will be using.

...

These data is organized in a tree structure with types of objects being tree roots . Here 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

...
java.util.LinkedHashMap$Entry: 18,880 (0%char[]: 488,329,896 (63%) bytes in 5901,602,894 (0%25%) objects (avg size 32305 bytes)
    	java.utillang.LinkedHashMapAbstractStringBuilder.createEntryexpandCapacity: 18335,290,560736 (98%68%) bytes in 580170,262 (98%10%) objects
 (avg       com.devexperts.aprof.AProfAgent.go: 18,432 (99%) bytes in 576 (99%) objects
        java.util.HashMap.put: 128 (0%size 1,969 bytes)
		java.lang.reflect.Constructor.newInstance: 310,510,624 (92%) bytes in 456,810 (0%33%) objects
 (avg           java.io.ExpiringCache.put: 128 (100%) bytes in 4 (100%) objects
    java.util.LinkedHashMap.init: 320 (1%size 5,466 bytes)
			SwingSet2.loadDemo: 310,508,240 (99%) bytes in 1056,768 (1%99%) objects
 (avg       com.devexperts.aprof.AProfAgent.go: 128 (40%) bytes in 4 (40%) objects
        java.util.HashMap.<init>: 128 (40%size 5,470 bytes)
			java.awt.AWTKeyStroke.getCachedStroke: 1,456 (0%) bytes in 426 (40%0%) objects
 (avg           java.util.LinkedHashMap.<init>: 128 (100%) bytes in 4 (100%) objects
        java.util.HashSet.<init>: 64 (20%size 56 bytes)
			sun.swing.SwingLazyValue.createValue: 928 (0%) bytes in 216 (20%0%) objects
 (avg size          java.util.LinkedHashSet.<init>: 64 (100%) bytes in 2 (100%) objects
58 bytes)
		java.lang.LongStringBuilder.append: 1820,999,336752 (0%6%) bytes in 135,146880 (0%21%) objects (avg size 16585 bytes)
    org.objectweb.asm.ClassReader.readConst: 18,304 (99%			DemoModule.loadSourceCode: 19,179,264 (91%) bytes in 1,144412 (99%3%) objects
 (avg size      13,583 bytes)
			com.devexperts.aprof.transformer.AProfAgentContext.gogetLocation: 16662,992968 (92%3%) bytes in 111,062364 (92%31%) objects
 (avg size      58 bytes)
			com.devexperts.aprof.transformer.AProfTransformerMethodTransformer.transformvisitAllocateArray: 1355,312408 (7%1%) bytes in 826,336 (7%17%) objects
    java.lang.Long.valueOf: 16 (0%) bytes in 1 (0%) objects
        java.lang.Long.valueOf: 16 (100%) bytes in 1 (100%) objects
            com.devexperts.sample.FibonacciNumbers.main: 16 (100%(avg size 56 bytes)
			com.devexperts.aprof.transformer.AbstractMethodVisitor.visitTypeInsn: 214,640 (1%) bytes in 14,944 (100%13%) objects
    sun.reflect.UnsafeLongFieldAccessorImpl.get: 16 (0%)avg bytes in 1 (0%) objects
        com.devexperts.aprof.AProfAgent.go: 16 (100%) bytes in 1 (100%) objectssize 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.

...

Let's take a look at the following program.

Code Block

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));
	}
}

...

No Format

TOTAL allocation dump for 3429,124423 ms (0h00m34s0h00m29s)
Allocated 8366,091155,888144 bytes in 2,936870,168108 objects in 9531,108 locations of 299230 classes
-------------------------------------------------------------------------------
java.lang.Integer: 34,953,936568 (42%52%) bytes in 2,184,621598 (74%76%) objects (avg size 16 bytes)
    	java.lang.Integer.valueOf: 34,926931,944824 (99%) bytes in 2,182183,934239 (99%) objects
        java.lang.Integer.valueOf		FibonacciNumbers.fib: 34,852,928 (99%) bytes in 2,178,308 (99%) objects
            com.devexperts.sample.FibonacciNumbers.fib: 34,852,928 (100%) bytes in 2,178,308 (100%) objects
        com.devexperts.aprof.AProfAgent.go: 52,816 (0%) bytes in 3,301 (0%) objects
        com.devexperts.aprof.AProfRegistry.makeSnapshot: 21,184 (0%) bytes in 1,324 (0%) objects
        java.lang.Integer.getInteger: 16 (0%) bytes in 1 (0%) objects
            com.intellij.rt.execution.application.AppMain.main: 16 (100%) bytes in 1 (100%) objects
    org.objectweb.asm.ClassReader.readConst: 18,112 (0%) bytes in 1,132 (0%) objects
        com.devexperts.aprof.AProfAgent.go: 13,696 (75%) bytes in 856 (75%) objects
        com.devexperts.aprof.transformer.AProfTransformer.transform: 4,416 (24%) bytes in 276 (24%) objects
    org.objectweb.asm.tree.LookupSwitchInsnNode.<init>: 4,736 (0%) bytes in 296 (0%) objects
        com.devexperts.aprof.AProfAgent.go: 2,848 (60%) bytes in 178 (60%) objects
        com.devexperts.aprof.transformer.AProfTransformer.transform: 1,888 (39%) bytes in 118 (39%) objects
    java.lang.Integer$IntegerCache.<clinit>: 4,096 (0%) bytes in 256 (0%) objects
        com.devexperts.aprof.AProfAgent.go: 4,096 (100%) bytes in 256 (100%) objects
    sun.reflect.UnsafeIntegerFieldAccessorImpl.get: 48 (0%) bytes in 3 (0%) objects
        com.devexperts.aprof.AProfAgent.go: 48 (100%) bytes in 3 (100%) objects
...

We see that 42% 52% 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.

...

FibonacciNumbers

...

And run the program under Aprof again. We will get the following results in aprof.txt file:

No Format

TOTAL allocation dump for 26,142 ms (0h00m26s)
Allocated 48,231,592 bytes in 757,741 objects in 953 locations of 299 classes
-------------------------------------------------------------------------------
char[]: 12,568,720 (26%) bytes in 185,155 (24%) objects (avg size 68 bytes)
    java.util.Arrays.copyOfRange: 3,392,352 (26%) bytes in 51,144 (27%) objects (avg size 66 bytes)
        com.devexperts.aprof.AProfAgent.go: 2,370,320 (69%) bytes in 35,586 (69%) objects (avg size 67 bytes)
        com.devexperts.aprof.transformer.AProfTransformer.transform: 1,014,784 (29%) bytes in 15,491 (30%) 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%) 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)
...

There are no suspicious memory allocations here. Note, that for many programs it is normal to have the most garbage generated for char[] objects.

Aprof

Child pages

Versions Compared

Old Version 14

New Version Current

Key

Examples