Revision as of 00:34, 15 October 2010

When you're trying to figure out why your application is slow, or when you're performance tuning to improve the performance, you can use the Profile tab in /resin-admin to quickly find the methods that are taking the most time.

The Profile allows dynamic measurement of the application's CPU usage as measured by taking periodic thread dumps. Since the overhead of the profiling is relatively low, you can even use it in a live server to troubleshoot performance problems.

In general, you want to focus on the top 10 or 20 methods because a method that only takes 0.1% of the total time generally isn't worth performance work.

The profile is organized as a list of methods with columns summarizing the time taken by the method.

Profile Sample

Profile Columns

 % time

The time taken by the method as a percentage of the profile time. Because multiple threads can be executing the same method simultaneously, this number can be larger than 100%.

time self

The time in seconds taken by this method. Because the time includes all threads, it can be larger than the total profile time.

 % sum

Measures the percentage of the total time taken by all the members in the group.

Tabs

The profile samples are sorted into groups, primarily so you can focus on active threads and not have to sort through the threads waiting for an event.

Active

A thread currently executing code.

Block

A thread blocked, typically waiting for another thread to release a lock.

JNI

Threads currently in JNI. Often, these are waiting for a new HTTP keepalive request or a new TCP remote request.

Resin

Internal Resin threads.

Wait

Sleeping and parked threads, waiting for another thread to wake them up. The idle thread pool threads are in this group.

All

All the threads.

Example

The following example shows the results of a short profile under load. The total time is 17s. The sample period is 10ms (as short as Resin supports), and the stack trace for each sample is the default 16. The example is a trivial JSP page that displays a short table from a database.

In the sample, the first few methods are reads and writes to and from the TCP socket.

• JniSocketImpl.writeNative is writing data to the browser
• JniSocketImpl.nativeClose is closing the TCP socket
• JniSocketImpl.accept is opening the new request
• JniSocketImpl.write is writing data

The ConnectionPool.findPoolItem is the most interesting method, followed by the new object creation, the Object.<init>. If the stack trace is opened, it will show the actual object being created.

Because this trace shows a relatively even distribution, any of the top ten methods would be reasonable candidates for optimization.