Sunday, July 27, 2008

Profiler Integration

I've run the profiler plugin with jmemprof support, but it has some disadvantages:
  • Doesn't have timings support
  • Doesn't run on j2se 6+
  • The profiler haven't been updated since year 2005
  • SC starts working very slowly with it, about 5 times slower than usual.
But I found another profiler that supports timings and is more agile than other profilers - JIP, you can find information how the profiler is build in the article "Build your own profiling tool" by the project's author Andrew Wilcox.

I tried JIP with SC and got the next results:

Pluses:
  • Has timings support
  • Runs on j2se 5+, the profiler needs the version 5 too hook the classloader.
  • SC is working almost as fast as usually.
  • It outputs the results in txt and xml formats
  • Has GUI for the results




Minuses:

  • It doesn't support memory analyzing
  • The results can be reprsented in GUI only by using the xml file with the results as an input.
  • You need to siwtch off and on the profiler to update the results (may be there is any other possibility)
  • The updated results don't contain previous ones after profiler stop/start issues (so called updates)

Next steps:

  • Now the profiler gives mostly the timings of OSGI framework, I'll need SC ones.
  • Try to get bundle separated results by package filtering.

Monday, July 21, 2008

New objectives

We have decided to change the objectives of my GSOC project by adding an integrated mem/cpu profiler for sip-communicator to give bundle dependent results.
The profiler will be used as a plugin for SC and print out UI such information:

bundle1: CPU 50% Mem 510kb
bundle2: CPU 12% Mem 120kb
bundle3: CPU 0.1% Mem 12kb

Also here can be added an information about a bundle loading time.

What is done:
- Java code is changed to suit the new version of SC

I am doing right now:
- integration with jmemprof, actually compile jmemprof for windows, it seems that jdk 6 doesn't have needed includes (jvmpi was depricated), so I now trying old versions of java, to get it compiled

Next steps:
- get bundle separated profiling information

The results of the first part of profiling SC

The found problems from user perspective were:
1. slow sip-communicator loading
2. graphics slow loading
3. large chat history slow processing

The starting up of the sip-communicator is slow enough, it takes about 10 - 15 seconds. SC uses apache felix for loading up the bundles, it takes up to 330 milliseconds for every bundle to start up. Other time for starting up is going to the drawing swing/awt components and loading up images. When profiling the functionality I just see Felix and JDK methods invocations, it is up profiling JDK and Felix, their methods are time-consumptive.Very similar situation was with big chat history slow processing.

The slowest part is the text parsing with javax.swing.text.html.HTMLFactory (see net.java.sip.communicator.impl.gui.utils.SIPCommHTMLEditorKit's inner class HTMLFactoryX).
There are two ways for eliminating the problem:
- wait for updated and more optimized java version
- to profile jdk
- to use other technology for text formating

Then I just monitored the sip-communicator with a profile to search for anomalies (took the 10 most expensive methods). I found that processSmilies() method from ChattConversationPanel class class is also consumpitve with big texts, thist uses regular expressions for smilies finding and the regular expression is very complex for it.

I noticed that net.java.sip.communicator.util.ScLogFormatter is also time-consumptive, it takes about 2-3% of sip-communicator execution. The problems are format(LogRecord record) and inferCaller(LogRecord record) methods. First is using DecimalFormat for formatting is required time to process and also sending the messages to the output. The second is using StackTraceElement objects and processings, that are time consumptive.
These methods are made with help of JDK and those are not very effective.There are Thread.sleep's in sip-comm code which are look like performance problems in profiler (look in net.java.sip.communicator.plugin.statusupdate.StatusUpdateActivator or just search for .sleep in sip-comm's source, you will found some), is the value of the sleeping time correct ?
There are minor time problems that are also connected with libraries that are slow.

Notes for developers.
What I can suggest to community is to continue adhere design patterns. Also quite effective is not to return a new created object, but reuse an already existing one - a creation of an object take more time and makes the heap larger. Of course it is not often possible, for example in net.java.sip.communicator.impl.gui.utils.SIPCommHTMLEditorKit inner class HTMLFactoryX.

static class HTMLFactoryX extends HTMLFactory
implements ViewFactory {
public View create(Element elem) {
View v = super.create(elem);
if(v instanceof ImageView){
return new SIPCommImageView(elem);
} else if (v instanceof ParagraphView) {
return new ParagraphViewX(elem);
}
return v;
}
}

Namely View is created by create(Element element) method from javax.swing.text.html.HTMLFactory class, the Element object is necessary for the new instance of view, and there is no possible to clean up and return existing View class. But if we see the createDefaultDocument() in c class, we see that HTMLDocument doc variable can be reused - there is no in parameter for the object:

public Document createDefaultDocument() {
if(doc != null) return doc;
StyleSheet styles = getStyleSheet();
StyleSheet ss = new StyleSheet();
ss.addStyleSheet(styles);
doc = new HTMLDocument(ss);
doc.setParser(getParser());
doc.setAsynchronousLoadPriority(4);
doc.setTokenThreshold(100);
return doc;
}

Also I reused the creation of new SIPCommHTMLEditorKit classes in ChatConversationPanel. Actually the fix is not very helpful, because the method createDefaultDocument() is called only once from ChatConversationPanel but the same logic you can use in your projects.

Next Steps for SC profiling:
1. Profile and fix increasing threads problem
2. Look for memory leaks using different profilers