The Gluster Blog

Gluster blog stories provide high-level spotlights on our users all over the world

Java Management Extensions, Raw profiling, and ThreadMXBeans.

Gluster
2013-02-14

The Java Management Extensions are a hidden gem in the JDK that many plain Java developers ignore- probably because of the deceptively enterprisey name.  These APIs are not just useful for profiling large Java EE apps.  Rather – they give you a precise and unbiased view into any snippet of code, by allowing you to look at CPU time and thread usage in a very direct fashion.

The poor man’s JMX profiling might look something like this: 

long startTime=System.currentTimeInMilliseconds();
doSomething();
long mseconds = System.currentTimeInMilliseconds()-mseconds();
System.out.println(“It took ” + seconds +” milliseconds”);

This might work on a simple machine that is not running any other applications.  But in a multiuser (or worse multithreaded) envioronment, the meaning of a raw time stamp before and after a method is lost.  A better way to do the same test: 


long startTime=ManagementFactory.getThreadMXBean().getCurrentThreadCpuTime()/1000000;
doSomething();
long mseconds =ManagementFactory.getThreadMXBean().getCurrentThreadCpuTime()1000000;
System.out.println(“It took ” + mseconds + ” cpu milliseconds”);

CPU time, if measured in Milliseconds, can have a HUGE standard deviation because of the fact that we run so many different applications on a machine.  The ThreadMXBeans are able to lock down the time, specifically, when your JVM is actually USING the CPU.  

I’m really serious here:  Check out how, in a simple test which adds several elements to a vector, we can see that, as we increase the size of the test the CPU time and real time diverge very rapidly ():

SIZE OF TEST : 10000
raw time:6 milliseconds
cpu time:5 milliseconds

SIZE OF TEST : 19952
raw time:6 milliseconds
cpu time:2 milliseconds

SIZE OF TEST : 39810
raw time:2 milliseconds
cpu time:1 milliseconds

SIZE OF TEST : 79432
raw time:3 milliseconds
cpu time:3 milliseconds

SIZE OF TEST : 158489
raw time:6 milliseconds
cpu time:6 milliseconds

SIZE OF TEST : 316228
raw time:11 milliseconds
cpu time:8 milliseconds

SIZE OF TEST : 630959
raw time:21 milliseconds
cpu time:16 milliseconds

SIZE OF TEST : 1258929
raw time:78 milliseconds
cpu time:33 milliseconds

SIZE OF TEST : 2511895
raw time:204 milliseconds
cpu time:69 milliseconds

The code (RudolF sandbox repository git@github.com:jayunit100/RudolF.git, or just paste this and run it as a main class).

package net.rudolfcode.jvm;

import java.lang.management.ManagementFactory;
import java.util.ArrayList;
import java.util.Collection;
import java.util.Vector;

/**
* You can use this class to profile insert times for a collection type 
(Vector in the example, but swapping it with an ArrayList is 10X faster at large scale).
 */
public class Example3 {

public static void main(String[] args) throws Exception{
profile((int)Math.pow(10, i));
}

private static void profile(int nums) {

ManagementFactory.getThreadMXBean().getCurrentThreadCpuTime();
System.out.println("SIZE OF TEST : " +nums);
final long cpuStart1=System.currentTimeMillis();
run(new Vector(),nums);
final long cpu1=(System.currentTimeMillis()-cpuStart1);
System.out.println("raw time:"+cpu1 + " milliseconds ");

final long cpuStart2=ManagementFactory.getThreadMXBean().getCurrentThreadCpuTime()/1000000;
run(new Vector(),nums);
final long cpu2=ManagementFactory.getThreadMXBean().getCurrentThreadCpuTime()/1000000;
System.out.println("cpu time:"+(cpu2-cpuStart2) +" milliseconds");
System.out.println();
}

public static float average(Collection<Long> l){
long value=0;
for(Long v : l){
value+=v;
}
return ((float)value)/(float)l.size();
}

/**
* Add "size" elements into a collection .
*/
public static void run(Collection impl, int size) {
impl.clear();
//add a bunch of stuff to a collection
for(int x = 10 ; x < size; x++){
impl.add((short)x);
}
}

}

BLOG

  • 06 Dec 2020
    Looking back at 2020 – with g...

    2020 has not been a year we would have been able to predict. With a worldwide pandemic and lives thrown out of gear, as we head into 2021, we are thankful that our community and project continued to receive new developers, users and make small gains. For that and a...

    Read more
  • 27 Apr 2020
    Update from the team

    It has been a while since we provided an update to the Gluster community. Across the world various nations, states and localities have put together sets of guidelines around shelter-in-place and quarantine. We request our community members to stay safe, to care for their loved ones, to continue to be...

    Read more
  • 03 Feb 2020
    Building a longer term focus for Gl...

    The initial rounds of conversation around the planning of content for release 8 has helped the project identify one key thing – the need to stagger out features and enhancements over multiple releases. Thus, while release 8 is unlikely to be feature heavy as previous releases, it will be the...

    Read more