Saturday, February 09, 2008

Debugging and Profiling with Eclipse

This post contains some settings I use for remote debugging web applications using the Jetty and Tomcat containers, and profiling web applications deployed on a remote Tomcat server, using the Eclipse IDE. By remote I mean connecting over a socket, the container can (and does in my case, unless I am connecting from home) listen on a port on the local host. The stuff here is hardly original, it has been gleaned from various web pages and blogs, which I reference in the appropriate places. If you use (or are considering using) Eclipse and want to know how to do remote debugging and profiling, this information may be of some use to you.

Debugging

I have been using the Eclipse IDE (with the MyEclipse extension) for about 3 years now. Most of the time, when debugging, I just use logger.debug() calls within the code to see whats going on. I do know how to debug using the Eclipse Debug perspective, but I guess its just a habit I developed, and old habits die hard. I don't even use Eclipse's CVS perspective anymore, based on some bad experiences at a previous company where I tried but ended up inadvertently removing from CVS code that I removed locally in my IDE (it was incorrect usage on my part). However, lately, I am starting to find debugging very useful, mainly because of the long stop-deploy-start cycle for our main web application.

Unlike a lot of IDE users, I like to run my web container from the command line rather than from the IDE. This is because of two reasons. First, I think the primary goal should be being able to build a WAR file using Ant (or Maven) and being able to deploy to a container. A lot of IDEs make you go through various hoops to make the webapp "compliant", where the definition of what constitutes compliance can vary from IDE to IDE. As an Eclipse user, I have been a minority at my last two jobs, where the majority of Java developers use IDEA, so it usually turns out that I have to make Eclipse comply with what IDEA thinks is a webapp. Second, having to stop and restart the app within a container running within your IDE involves using your mouse (or in case of a laptop, your touchpad), which is way less convenient than the command line with command-history enabled.

We run and develop our main web application using Tomcat. I have been building Maven apps for quite a while now, and I tend to use the Maven-Jetty plugin because its so much more convenient. For Maven webapps, I tend to do most of my development using Jetty, then deploy to the Tomcat server. The upshot is that I need to be able to debug using remote Tomcat and Jetty instances.

Remote Debugging with Tomcat

The information here is from the Tomcat FAQ Wiki. Basically, you add this in to the $CATALINA_HOME/bin/setenv.sh file. My CATALINA_HOME is at /opt/apache-tomcat-5.5.25. If you already have a JAVA_OPTS defined for application-specific stuff, just add the stuff below to your JAVA_OPTS.

1
2
3
# /opt/apache-tomcat-5.5.25/bin/setenv.sh
export JAVA_OPTS="-Xdebug \
  -Xrunjdwp:transport=dt_socket,address=8787,server=y,suspend=n"

The address=8787 enables a debug listener on Tomcat that Eclipse can connect to to get debug information. On the Eclipse, side, open the Debug Launch Configuration Dialog by clicking "Run > Open Debug Dialog". On the left pane of the dialog, find "Remote Java Application", select and right-click (or click on the New icon on the top). This will open up a Dialog for setting parameters for a Debug Launch configuration. Here are my values:

Tab name Property name Property value Description
- Name Tomcat (Pluto:8080) Can be any name you want to give it. Mine says what and where
Connect Project hl-www This is your project name
Connect Connection Type Standard - Socket Attach Connect over a socket
Connect Connection Properties : Host pluto.healthline.com DNS name of the host, could be an IP address (I think)
Connect Connection Properties : Port 8787 Same port as specified in address above
Connect Allow termination of remote VM No This is really your choice, I just don't want it.
Source Source Lookup Path Select your project This is so you can see the sources as you debug
Source Source Lookup Path Select any other source jars you have This is so you can see the sources as you debug
Common Display in Favorites Menu Yes This adds the config as a bookmark under the debug icon.

Deploy your app to the Tomcat container and restart Tomcat. In Eclipse, switch to the Debug perspective and a breakpoint in in your code (say a controller you want to call). In Eclipse's Debug perspective, [Alt]-[Shift]-B allows you to set (or unset) breakpoints at particular points in your code. Open up a browser and point to the page you want to debug. Bringing the page up will activate the debugger in Eclipse and you will see the code where you set the breakpoint being highlighted, with the top right corner containing the variables to be inspected. You can use [F6] through [F8] keys to step over, into and out of breakpoints. You probably know how to take it from here.

Remote Debugging with the Maven-Jetty plugin

Information for this comes from Dan Allen's blog post Remote Debugging with Jetty. Unlike Tomcat, this time you have to set the debugging parameters within MAVEN_OPTS since Maven runs its classworlds Launcher instead of Java. The MAVEN_OPTS need to be set in your configuration (either in your ~/.bash_profile or in a shell script that calls the mvn jetty6:run command). As before, if you already have other stuff in your MAVEN_OPTS, the stuff below needs to go after that.

1
2
export MAVEN_OPTS="-Xdebug -Xnoagent -Djava.compiler=NONE \
  -Xrunjdwp:transport=dt_socket,address=8781,server=y,suspend=n"

You also need to disable the Jetty maxIdleTime interval by setting it to 0. This is done in the pom.xml file like so:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
<project ...>
  ...
  <build>
    <plugins>
      <plugin>
        <groupId>org.mortbay.jetty</groupId>
        <artifactId>maven-jetty6-plugin</artifactId>
        <configuration>
          <scanIntervalSeconds>10</scanIntervalSeconds>
          <connectors>
            <connector implementation="org.mortbay.jetty.nio.BlockingChannelConnector">
              <port>8081</port>
              <maxIdleTime>0</maxIdleTime>
            </connector>
          </connectors>
        </configuration>
        <dependencies>
          <dependency>
            <groupId>org.apache.geronimo.specs</groupId>
            <artifactId>geronimo-j2ee_1.4_spec</artifactId>
            <version>1.0</version>
            <scope>provided</scope>
          </dependency>
        </dependencies>
      </plugin>
    </plugins>
  </build>
</project>

On the Eclipse side, the setup is identical to the Tomcat setup described above. Simply change the name (mine is called Jetty (Pluto:8081)) and the port number of the listener to what you set it to in MAVEN_OPTS (mine is 8781).

Profiling

Recently, I needed to profile a web application I wrote. It was taking 4-8 seconds to serve a single page on a production class machine, compared to an expectation of about 40-80 milliseconds. Response times on my much less powerful development box, while not 40-80ms, were tolerable. My initial reaction was to put StopWatch calls within the handleRequest() method of the Controller, timing the blocks which I thought could do with improvement. That detected some places where it was spending more time than I thought it should, so I fixed those, but the pages were still dog slow on production. Moreover, it seemed that response times were degrading under load, and load on the database machines was spiking so as to make them almost unusable. What I needed was a profiler, but I did not know how to set one up, much less know how to run it and interpret the results.

However, good things sometimes happen to bad programmers, and our local performance guru was kind enough to set up a profiling instance on his Netbeans IDE (he is an IDEA user, but he uses Netbeans for its awesome profiling tool) and run a profile for me. It did identify several more hotspots in the code that could be optimized, and I fixed them. The performance did improve somewhat as a result, but we were still seeing spikes on the database machines.

The problem turned out to be contention for the same database resource with another web application, which I figured out by just thinking through it and looking through the code. However, the profiler output helped me weed out the unnecessary stuff quickly. So although the best way to find performance problems is still, in my opinion, just trolling through code coupled with an understanding of the program flow, a profiler makes the process much faster, because it has already told you what you are not looking for.

While I now know (thanks to the same guy who helped me out with the performance numbers before) how to do profiling with the Netbeans IDE, I wanted to do this from within Eclipse using the TPTP plugin, so what follows is my setup for doing that.

Remote Profiling Tomcat apps

Information from this comes from this profiling java blog post, which has a link to a Eclipse-TPTP setup Howto on Windows XP, which I adapted for my use. TPTP needs a client component to be installed in the Eclipse IDE (the TPTP plugin), and an agent component RAServer which mediates between the performance data from the Tomcat server and the Eclipse TPTP client. Huge amounts of profiling data are transferred as XML documents, so using this from a remote (not localhost) client is very slow. Therefore, three things need to be setup to use TPTP to profile remote apps under Eclipse.

First, we need to download the TPTP plugin. If you are using a recent version of Eclipse (I am using 3.3.1.1) then you can get the plugin from the Europa Discovery Site. Simply click on "Help > Software Updates > Find and Install > Search for new features to install", then select the Performance and Monitoring features and click on "Select Required". This will download the TPTP plugin to your IDE. Restart your IDE to see the Profile icon on the toolbar, and "Run > Profile..." entries in your menu. The complete procedure is explained in detail in the Installing TPTP using Update Manager page.

Second, we need to install the agent component. This is available as a separate download for the particular architecture and operating system from the TPTP home page (scroll down to Agent Controller). Here is a link to the one I used.

Setting this up was easy, but not totally straightforward. The first step is to unzip the download into /opt/tptpdc-4.1.0, then set up the following environment variables in your ~/.bash_profile and source it. Here is the snippet from my ~/.bash_profile file.

1
2
3
4
# TPTP settings
export RASERVER_HOME=/opt/tptpdc-4.1.0
export PATH=$RASERVER_HOME/bin:$PATH
export LD_LIBRARY_PATH=$RASERVER_HOME/lib:$LD_LIBRARY_PATH

We then need to navigate to $RASERVER_HOME/bin, then run SetConfig.sh (the very first time only) to set up the XML file for RAServer to work. Then from the same directory, we need to start the server using RAStart.sh (the corresponding stop script is RAStop.sh in the same directory). However, when I ran the RAStart.sh script, I discovered that there were missing libraries on my Fedora Core 7 system. To fix that, I had to download the libstdc++ compatibility RPM from the RPMFind page and install it using the following command:

1
$ sudo rpm -ivh compat-libstdc++-296-2.96-138.i386.rpm

Finally, we need to set up the JAVA_OPTS environment variable in the $CATALINA_HOME/bin/setenv.sh file, like so. Also, since we are starting Tomcat with the profiling instrumentation enabled, I found that it would complain about missing libraries, which went away after I added the RASERVER_HOME paths to PATH and LD_LIBRARY_PATH to the setenv.sh file.

1
2
3
4
5
# /opt/apache-tomcat-5.5.25/bin/setenv.sh
export RASERVER_HOME=/opt/tptpdc-4.1.0
export PATH=$RASERVER_HOME/bin:$PATH
export LD_LIBRARY_PATH=$RASERVER_HOME/lib:$LD_LIBRARY_PATH
export JAVA_OPTS="-XrunpiAgent:server=enabled"

To start using profiling, I deployed the web application to Tomcat, started RAServer, then started Tomcat.

On the Eclipse side, I built a Profiling Launch configuration by clicking "Run > Profile", then right-clicking New on "Attach to Agent" on the left pane of the resulting dialog. Here are the settings for my IDE.

Tab name Property name Property value Description
- Name WWW (Pluto:8080) Can be anything. Mine says what and where.
Hosts Default Hosts Added pluto.healthline.com:10002 localhost:10002 was already there and could not remove it. Adding the new one and selecting it makes that the current host.
Agents Available Agents Click on Refresh to get the standard Agent exposed by RAServer and select it. localhost:10002 was already there and could not remove it. Adding the new one and selecting it makes that the current host.
Destination Profiling Project I just chose the same project name I was monitoring. -
Destination Monitor Choose Default Monitor (the default) -
Common Display in Favorites Menu Yes Makes the configuration appear when the Profile icon is clicked.

Once this is done, switch to the profiling perspective. If the agent has been discovered, Eclipse will attach to it and start collecting statistics. Since a web app's job is to serve pages, what I do is to aim a URL generating script at the application. Here is an example of a Python script that reads a list of URLs from a text file and hits the app with the URLs.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
#!/usr/bin/python
# Simple harness to run the URLs from the systemtesturls.txt manually
import sys
import string
import httplib
import time

def usage():
  print "Usage:" + sys.argv[0] + " www.myhost.com:80 /path/to/urllist"
  sys.exit(-1)

def main():
  if (len(sys.argv) != 3):
    usage()
  host = sys.argv[1]
  urllist = open(sys.argv[2], 'r')
  totaltime = 0
  maxtime = 0
  mintime = 0
  lno = 0
  okresults = 0
  badresults = 0
  while 1:
    urlline = urllist.readline()
    if (not urlline):
      break
    if (urlline.startswith("#")):
      continue
    lno = lno + 1
    testurl = string.rstrip(urlline)
    print "Testing (" + str(lno) + "): " + testurl
    start = time.clock()
    conn = httplib.HTTPConnection(host)
    conn.request("GET", testurl)
    resp = conn.getresponse()
    status = resp.status
    if (status == 200):
      okresults = okresults + 1
    else:
      badresults = badresults + 1
      print "Error:", status, resp.reason, str(lno)
    data = resp.read()
    conn.close()
    stop = time.clock()
    elapsed = stop - start
    if (elapsed < mintime):
      mintime = elapsed
    if (elapsed > maxtime):
      maxtime = elapsed
    totaltime = totaltime + elapsed
  urllist.close()
  print "quality results, Ok=" + str(okresults) + ", Bad=" + str(badresults) + ", Total=" + str(lno)
  print "timing results: min(s)=" + str(mintime) + ", max(s)=" + str(maxtime) + ", avg(s)=" + str((totaltime / lno))

if __name__ == "__main__":
  main()

Once the script completes, you can stop the profiling. I was able to generate three reports from it - Execution Statistics, Memory Statistics and Coverage Statistics. Of these, I found the Execution statistics the most useful since it told me how many times a method was called, and what processing time on average was spent in each of these methods. Undoubtedly I will find more use for the other reports in the future, but for the moment I am happy to have profiling working under Eclipse.

Update Feb 16 2008

I was able to profile using Maven's Jetty plugin as well recently. Instead of setting the string "-XrunpiAgent:server=enabled" to JAVA_OPTS, we just set it to MAVEN_OPTS instead, then run mvn -o jetty6:run. The RASERVER_HOME, LD_LIBRARY_PATH and PATH setting also needs to be in there for the agent to work correctly. So my new improved jetty.sh now looks like this:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
#!/bin/bash
BASE_MAVEN_OPTS="-Xmx2048m"
DEBUG_MAVEN_OPTS="-Xdebug -Xnoagent -Djava.compiler=NONE -Xrunjwdb:transport=dt_cket,address=8781,server=y,suspend=n"
PROFILE_MAVEN_OPTS="-XrunpiAgent:server=enabled"
case $1 in
  'debug')
    MAVEN_OPTS=$BASE_MAVEN_OPTS" "$DEBUG_MAVEN_OPTS
    ;;
  'profile')
    export RASERVER_HOME=/opt/tptpdc-4.1.0
    export PATH=$RASERVER_HOME/bin:$PATH
    export LD_LIBRARY_PATH=$RASERVER_HOME/lib:$LD_LIBRARY_PATH
    MAVEN_OPTS=$BASE_MAVEN_OPTS" "$PROFILE_MAVEN_OPTS
    ;;
  *)
    MAVEN_OPTS=$BASE_MAVEN_OPTS
    ;;
esac
export MAVEN_OPTS
mvn -o jetty6:run

To start a normal session, I just call jetty.sh, for debugging and profiling, I call jetty.sh debug and jetty.sh profile respectively. On the Eclipse side, I create a profile configuration in the same way as for Tomcat, by attaching the profiling client to the running Java application. The RAServer detects the Java app that is exposing profiling information, and automatically discovers it.

Update Feb 27 2008

This post was republished by the folks at SYS-CON Media in their Open Web Developer's Journal and is available here. Goes to show that one should be careful about what one writes, it may end up anywhere :-). Thanks to Jeremy Geelan for making this happen.

2 comments:

  1. You have written "Deploy your app to the Tomcat container and restart Tomcat" - but how can you do that. it always start a new server for me. I want to tell eclipse that i want him to work with already running tomcat server.

    ReplyDelete
  2. Hi Zion, I meant that you have to restart Tomcat with the debug listener on, one time only. You can then do multiple debugging sessions without restarting Tomcat, simply relaunch the client in Eclipse if you need to.

    ReplyDelete

Comments are moderated to prevent spam.