Profiling a Java Spring application

Question

I have a Spring application that I believe has some bottlenecks, so I'd like to run it with a profiler to measure what functions take how much time. Any recommendations to how I should do that?

I'm running STS, the project is a maven project, and I'm running Spring 3.0.1

Answer 1

I've done this using Spring AOP.

Sometime I need an information about how much time does it take to execute some methods in my project (Controller's method in example).

In servlet xml I put

<aop:aspectj-autoproxy/>

Also, I need to create the class for aspects:

@Component
@Aspect
public class SystemArchitecture {

    @Pointcut("execution(* org.mywebapp.controller..*.*(..))")
    public void businessController() {
    }
}

And profiler aspect:

@Component
@Aspect
public class TimeExecutionProfiler {

    private static final Logger logger = LoggerFactory.getLogger(TimeExecutionProfiler.class);

    @Around("org.mywebapp.util.aspects.SystemArchitecture.businessController()")
    public Object profile(ProceedingJoinPoint pjp) throws Throwable {
        long start = System.currentTimeMillis();
        logger.info("ServicesProfiler.profile(): Going to call the method: {}", pjp.getSignature().getName());
        Object output = pjp.proceed();
        logger.info("ServicesProfiler.profile(): Method execution completed.");
        long elapsedTime = System.currentTimeMillis() - start;
        logger.info("ServicesProfiler.profile(): Method execution time: " + elapsedTime + " milliseconds.");

        return output;
    }

    @After("org.mywebapp.util.aspects.SystemArchitecture.businessController()")
    public void profileMemory() {
        logger.info("JVM memory in use = {}", (Runtime.getRuntime().totalMemory() - Runtime.getRuntime().freeMemory()));
    }
}

That's all. When I request a page from my webapp, the information about method executing time and JVM memory usage prints out in my webapp's log file.

Answer 2

I recommend VisualVM for general application profiling. It is available in the JDK from version 1.6_10, and imho much faster and usable than Eclipse TPTP.

(If your Spring application works in an application server (e.g. Tomcat) you could try to deploy it to the tc Server developer edition (available in the STS downloads). It has interesting monitoring capabilities. It seems that tc Server developer edition is not maintained anymore.)

UPDATE 2019.02.22.: updated VisualVM url (thanks for @Jeff) and tc Server information. Personally I currently use Glowroot for monitoring Spring applications running in an application server.

Answer 3

You can use an open source java profiler such as Profiler4J:

http://profiler4j.sourceforge.net/

or Netbeans comes with a built in profiler and Eclipse also has profiling capabilities, however I found Profiler4J easier to use since it has a nice graph showing you the most time consuming methods.

This works well in STS (eclipse), just follow the instructions on the site.

Answer 4

Here's a general discussion with recommended tools & techniques.

Basically, it is entirely natural to assume if you want to find out how to make an app faster, that you should start by measuring how long functions take. That's a top-down approach.

There's a bottom-up approach that when you think about it is just as natural. That is not to ask about time, but to ask what it is doing, predominantly, and why it is doing it.

Answer 5

We developed a JMX & Spring AOP based @Profiled annotation which does production monitoring (active invocations, invocations count, time spent during invocations, exceptions count, etc) . Metrics are exposed via JMX and can be collected via Visual VM / JConsole and by monitoring systems ; we developed an Hyperic HQ Plugin.

This @profiled annotation is packaged with many other JMX extras to ease monitoring of common components (dbcp, util.concurrent, cxf, jms, etc) and proposed under a business friendly Apache Software License at http://code.google.com/p/xebia-france/wiki/XebiaManagementExtras .

Hope this helps,

Cyrille (Xebia)

Answer 6

I liked JRat, although like profiler4j it doesn't seem to be actively developed. In any case, it was simple to use.

Answer 7

A bit modified version of Yuri's answer on top (the selected answer) that auto calculates the totals of durations and arranges them desc. The totals gets printed in the end only. Might save you 10 mns.

    @Component
    @Aspect
    public class SystemArchitecture
    {

         @Pointcut("execution(* erp..*.*(..))")
         public void businessController()
         {
         }

         @Pointcut("execution(* TestMain..*.*(..))")
         public void theEnd()
         {
         }
    }



    @Component
    @Aspect
    public class TimeExecutionProfiler
    {

        static Hashtable<String, Long>  ht  = new Hashtable<String, Long>();

        @Around("profiler.SystemArchitecture.businessController()")
        public Object profile(ProceedingJoinPoint pjp) throws Throwable
        {
            long start = System.nanoTime();
            Object output = pjp.proceed();
            long elapsedTime = System.nanoTime() - start;
            String methodName = pjp.getSignature().toString();
            if (ht.get(methodName) == null)
            {
                ht.put(methodName, elapsedTime);
            }
            else
            {
                ht.put(methodName, ht.get(methodName) + elapsedTime);
            }
            // System.out.println(methodName + " : " + elapsedTime + " milliseconds.");

            return output;
        }

        @After("profiler.SystemArchitecture.theEnd()")
        public void profileMemory()
        {
            List<Object> keys = Arrays.asList(ht.keySet().toArray());
            java.util.Collections.sort(keys, new Comparator<Object>()
            {

                @Override
                public int compare(Object arg0, Object arg1)
                {
                    return ht.get(arg1).compareTo(ht.get(arg0));
                }
            });

            System.out.println("totals Used:");
            for (Object name : keys)
            {
                System.out.println("--" + name + " : " + (ht.get(name) / 1000000));
            }
            System.out.println("JVM memory in use = " + (Runtime.getRuntime().totalMemory() - Runtime.getRuntime().freeMemory()));
        }
    }

Answer 8

You could always use Java Mission Controls Flight Recorder that is bundled with Java, to profile your code execution