Monday, April 27, 2009

Analyzing the memory usage of your Android application


The new Android 1.5 Early Look SDK  is out since a few weeks. The "Android 1.5 highlights" page does not mention one highlight, which IMHO will become very important for all developers on the Android platform because it allows you to find memory leaks easily and analyze the memory usage of your Android applications.

I'm talking about the hprof-conv tool that allows you to convert an Android/Dalvik heap dump into an .hprof heap dump. The tool does not preserve all the information, because Dalvik has some unique features such as cross-process data sharing, that are not available in a "standard" JVM. Still the .hprof file is a good starting point and can be read with the Eclipse Memory Analyzer, which will interpret it like a normal file from a Sun 32 bit JVM. In the future it should also be not that difficult to read the Dalvik heap dump format directly and provide more information for memory analysis, such as which objects are shared and also maybe how much memory is used by native Objects (haven't checked that).

How to get a heap dump

First we must of course get a heap dump. I do not yet own an Android phone, also I plan to get on this year. If you want to donate one, please let me know. Donating lot's of money would also help ;)
I therefore created the heap dump using the emulator.
I created a new avd for the 1.5 preview:

android create avd -n test -t 2
emulator -avd test

Then you can logon to the emulated phone and make sure that the /data/misc directory is writable :

adb shell
chmod 777 /data/misc
exit

Heap dumps are actually created by sending the process a SIGUSR1 (-10) signal.

adb shell ps

check for the pid of your application

adb shell kill -10 pid


You can check with

adb shell logcat

whether it works. You should see something like:

I/dalvikvm( ): threadid=7: reacting to signal 10 I/dalvikvm( ): SIGUSR1 forcing GC and HPROF dump I/dalvikvm( ): hprof: dumping VM heap to "/data/misc/heap-dump-tm- pid.hprof-hptemp". I/dalvikvm( ): hprof: dumping heap strings to "/data/misc/heap-dump-tm124026 3144-pid.hprof". I/dalvikvm( ): hprof: heap dump completed, temp file removed D/dalvikvm( ): GC freed 1292 objects / 92440 bytes in 11 sec D/dalvikvm( ): GC freed 215 objects / 9400 bytes in 963ms

now you can copy the heap dump from the (emulated) phone to the Desktop machine:

adb pull /data/misc/heap-dump-tm-pid.hprof address.hprof

Now the file you will get does not conform to the "standard" Sun .hprof format but is written in Dalvik's own format and you need to convert it:


hprof-conv heap-dump-tm-pid.hprof 4mat.hprof

Now you can use the Eclipse Memory analyzer to analyze the memory usage of your application.

Typical optimization opportunities

I described some typical issues already here in this blog for example a problem with Finalizers in Netbeans,
 or  finding "String duplicates"  in Eclipse (my favourite memory analysis trick).

You might also take the time and check all my memory related posts.

Now I would like to present you a new typical memory usage issue that I just found when playing around with the new Android cupcake 1.5 prerelease.

YouShouldHaveDoneLazyInitialization



I did a heap dump of the android gmail application and loaded it into the Eclipse Memory Analyzer.
In the histogram view I filtered the android classes:



The high number of Rect (Rectangle) objects looked suspicious to me. Also they retain not that much memory, I thought it would be interesting why such a high number of Rect instances was alive.
When checking the Rect objects I immediately saw that most of them seemed to be empty e.g. bottom=0 and left=0 and right=0 and top=0.

It seemed to me that this was the time to again use the most advanced feature in MAT. I'm talking about the OQL view, which allows you to execute SQL like queries against the objects in your heap dump.
I very rarely used this feature in the past because the standard queries are good enough almost all times and because writing your own command in Java is not that difficult.
Still here it would help me to find how many of the Rect instances where empty.

I entered

select * from android.graphics.Rect where bottom=0 and left=0 and right=0 and top=0




Which showed me that out of 1320 Rect instances 941 where "empty", which means that over 70% of the instances where "useless".
I used "immediate dominators" on the first 20 of those 941 instances, which showed me that those empty Rect instances were retained by several UI related
classes which are subclasses of android.graphics.drawable.Drawable.




I checked the source and quickly found that Drawable always instantiates a Rect using the default constructor:



public abstract class Drawable {    private int[] mStateSet = StateSet.WILD_CARD;    private int mLevel = 0;    private int mChangingConfigurations = 0;    private Rect mBounds = new Rect();


Also this issue might not increase the memory usage of gmail that much it's still a fundamental/systematic problem, which IMHO should be fixed.
Even if we would tolerate the memory overhead, we are still left with the problem that the number of objects the garbage collector has to trace during Full GC is higher than needed, which at least potentially can lead to sluggish UI.
It's also a kind of fundamental problem because all subclasses of Drawable inherit the problem.

So instead of always using the default constructor it would most likely better to use lazy initalization  and only initialize the field when it's first needed.
A copy on write strategy  could also be used by sharing an "empty" Rect instance in the beginning, which would be replaced by a new one as soon as the field is written ( haven't checked the code whether this can still be done).

Disclaimer:
This is not a sign that Android is a poor platform. This is a kind of a problem that I've seen in the past more than once and I'm sure this kind of antipattern can be found in a lot of software out there.

UPDATE:


The issue has been fixed a few hours (or minutes?) after my post!
Check
https://review.source.android.com/Gerrit#patch,sidebyside,9684,2,graphics/java/android/graphics/drawable/Drawable.java

To see how simple the change was!


Just take the Eclipse Memory Analyzer and have a look at your application(s).
May the force be with you! ;)

Update 2:
In Android 2.3 (Gingerbread) a new command is available to trigger the heap dump.
The kill command is not supported anymore.




Wednesday, April 08, 2009

Some facts about the JVM used by Google's App engine

As you probably have noticed Google has released Java support for it's App Engine!

I wrote a small servlet to find out more about which Java they are running:

java.specification.version: 1.6
java.vendor: Sun Microsystems Inc.
line.separator:

java.class.version: 50.0
java.util.logging.config.file: WEB-INF/logging.properties
java.specification.name: Java Platform API Specification
java.vendor.url: http://java.sun.com/
java.vm.version: 1.6.0_13
os.name: Linux
java.version: 1.6.0_13
java.vm.specification.version: 1.0
user.dir: /base/data/home/apps/wanlatency/1.332645732335305520
java.specification.vendor: Sun Microsystems Inc.
java.vm.specification.name: Java Virtual Machine Specification
java.vm.vendor: Sun Microsystems Inc.
file.separator: /
path.separator: :
java.vm.specification.vendor: Sun Microsystems Inc.
java.vm.name: Java HotSpot(TM) Client VM
file.encoding: ANSI_X3.4-1968
Total Memory 104857600
Free Memory 6293011

Note that the Free Memory does not change if you allocate 10Mbyte (nor the Total memory). It might therefore by faked.
Allocating 1Gbyte results in a very simplistic error.

They use jetty!


java.lang.OutOfMemoryError: Java heap space at org.kohlerm.wanTestGoogleServlet.doGet(wanTestGoogleServlet.java:24) at javax.servlet.http.HttpServlet.service(HttpServlet.java:689) at javax.servlet.http.HttpServlet.service(HttpServlet.java:802) at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:487) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1093) at com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(SaveSessionFilter.java:35) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084) at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43) at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084) at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:360) at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216) at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181) at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:712) at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:405) at com.google.apphosting.runtime.jetty.AppVersionHandlerMap.handle(AppVersionHandlerMap.java:237) at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139) at org.mortbay.jetty.Server.handle(Server.java:313) at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:506) at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:830) at com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable(RpcRequestParser.java:63) at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:381) at com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.serviceRequest(JettyServletEngineAdapter.java:125) at com.google.apphosting.runtime.JavaRuntime.handleRequest(JavaRuntime.java:235) at com.google.apphosting.base.RuntimePb$EvaluationRuntime$6.handleBlockingRequest(RuntimePb.java:4547) at com.google.apphosting.base.RuntimePb$EvaluationRuntime$6.handleBlockingRequest(RuntimePb.java:4545) at com.google.net.rpc.impl.BlockingApplicationHandler.handleRequest(BlockingApplicationHandler.java:24) at com.google.net.rpc.impl.RpcUtil.runRpcInApplication(RpcUtil.java:359) at com.google.net.rpc.impl.Server$2.run(Server.java:792) at com.google.tracing.LocalTraceSpanRunnable.run(LocalTraceSpanRunnable.java:56) at com.google.tracing.LocalTraceSpanBuilder.internalContinueSpan(LocalTraceSpanBuilder.java:489) at com.google.net.rpc.impl.Server.startRpc(Server.java:748) at com.google.net.rpc.impl.Server.processRequest(Server.java:340)



Because my "hobby" is memory usage analysis, I ran another test on the appengine and it seems you can allocate about 110Mbyte.
Allocation seems to be very slow. I first tried to allocate a byte array in 1Mbyte steps, but until it reached 100 Mbyte it would need 30 seconds "CPU time".
Maybe they persist larger blocks to disk???