I was wondering why my game, SlowPoke Blitz, was severely underperforming when the scoreboard appeared. An easy way to figure out what processes were eating up CPU time was to view the trace log.
Note: Code benchmarking is a different process where you compare the performance of applications. Profiling helps you determine bottlenecks and inefficient coding.
To begin profiling your code, you'll need to ensure you have met these requirements:
- Permission to write a trace log file
- An emulator which has internal memory specified
- Decided a suitable starting point for logging
- Decided a suitable ending point for logging
Generating Trace Log
To begin profiling your code, you'll first need to generate the trace file.
In your code, add in:
Debug.startMethodTracing("traceFile");
I place this in Activity.onCreate(), but you can do this anywhere you think is suitable.
Next, find a fitting end point for the code you're profiling. Then paste in:
Debug.stopMethodTracing();
Now you'll need to open up "AndroidManifest.xml" and add:
<uses-permission android:name="android.permission.WRITE_EXTERNAL_STORAGE" />
Run your application as normal and then exit. It'll run a little slower than usual, but that's OK because the results we're after are given in percentages.
Retrieving the trace file
Using the Android SDK, you should have access to "adb" and "traceview".
Using ADB, you can extract the file from the emulator using:
adb pull /sdcard/traceFile.trace C:\trace\
This will download and save the file to C:\trace\traceFile.trace
Using traceview.bat, type:
traceview C:\trace\traceFile.trace
Note: you need to specify the full pathname.
This will start the Traceview program.
Reading the trace data
The bars at the top help you visualise the CPU time which each thread consumes.
The tree list at the bottom indicates which functions are called, ordered by the amount of processing time it takes.
You can see that GameCanvasView:DrawThread.run() is eating a whopping 70% of the CPU time. That's ok, because it's a game which redraws often and encompasses the 2 chunky functions in spot #2 and #3, GameCanvasView.onDraw() and GameCanvasView.drawScoreboard().
Wait, drawScoreboard() is #3? Why? It's only being shown for about 4 seconds at the end! Why is it using up so much CPU?
Wow, ScoreboardData.draw() is #4, using 38.2% of the CPU draw time. Something just isn't right.
Expading the ScoreboardData.draw() tree shows some interesting information. It shows that String.format() is proving to be VERY expensive in the display process.
That explains why the rest of the Traceview screenshot showed mainly java.lang.String and java.util.Formatter functions.
Speeding up the app
Be very careful with string allocations!
The code before:
public long draw(Canvas c) {
c.drawText(String.format("2x %d = %d", comboHit2, comboHit2 * 2), x, y, m_paint);
c.drawText(String.format("3x %d = %d", comboHit3, comboHit3 * 3), x, y, m_paint);
}
I found a very easy way to reduce the CPU usage. Rather than rebuild the String every 25ms (40 times a second), I found Strings which were unlikely to change and moved them out of the draw() method.
The code after:
private String str2HitCombos;
private String str3HitCombos;
public void gameFinished() {
str2HitCombos = String.format("2x %d = %d", comboHit2, comboHit2 * 2);
str3HitCombos = String.format("3x %d = %d", comboHit3, comboHit3 * 3);
}
public long draw(Canvas c) {
c.drawText(comboHit2, x, y, m_paint);
c.drawText(comboHit3, x, y, m_paint);
}
Once the game ends, I built the Strings in gameFinished() and only read them in the display. This dramatically improved the rendering speed of the scoreboard!
This was the end result. I forgot to take an intermediate screenshot.
After performing another trace, the call to drawScoreboard() dropped off the first page of the Traceview to below 4.8%, along with all the java.lang.String and java.util.Formatter methods.
Such a simple change and the results above show it's well worth it! I also took the time to make a few other changes around the place with similar design patterns.
Only initialise when you need to
Another method called by onDraw(), drawHud(), was eating up 17% CPU. This method simply displays the bar indicating how much time was left.
In that method, I was initialising Rect objects over and over and giving them the same values. Those values could have been determined when the View was created, so I moved them out of the draw loop and set them once.
After the simple change, it dropped to 5.0% CPU usage.
Avoid internal use of get/set methods
This is straight off the Android documentation. They're expensive and you'd rather be using the variables directly rather than through a get/set method.
I've personally extended this tip a bit more. Although frowned upon in the encapsulation world, I've declared more class variables to be public than I should rather than forcing external classes to go through getter and setter methods.
Remove defensive code once your app is grown up
Initially, my BitmapCache was a bit experimental. I wrote defensive code in case the test cases failed so I had some sort of fallback in debugging.
private HashMap<Integer, Bitmap> m_cache = new HashMap<Integer, Bitmap>();
public static Bitmap loadBitmap(int resid) {
if (m_cache.containsKey(resid)) {
return m_cache.get(resid);
}
Bitmap bmp;
bmp = BitmapFactory.decodeResource(activity.getApplicationContext().getResources(), resid);
m_cache.put(resid, bmp);
return bmp;
}
Now this may seem fine, but the defensive call to HashMap.containsKey() becomes VERY expensive if you're calling this every 25ms.
Especially when all the images are pre-loaded when the game starts, this becomes unnecessary.
Rewriting it to be less defensive, it now looks like:
public static Bitmap loadBitmap(int resid) {
Bitmap bmp = m_cache.get(resid);
if (bmp == null) {
bmp = BitmapFactory.decodeResource(activity.getApplicationContext().getResources(), resid);
m_cache.put(resid, bmp);
}
return bmp;
}
Now with the assumption that bitmaps are loaded, the code is much more efficient.
Cast primitives correctly
Assuming elapsedTime is an int, this:
String.valueOf((double) elapsedTime / 1000);
is slower than:
String.valueOf(elapsedTime / 1000.0);
Try/catch is expensive
Another silly mistake I made was using try/catch around something which didn't always need it.
try {
if (sleep_time > 0) {
Thread.sleep(sleep_time);
}
}
catch (InterruptedException e) {
}
This would stupidly create an expensive try/catch block around the if case even though (potentially) the Thread.sleep() is not called.
After:
if (sleep_time > 0) {
try { Thread.sleep(sleep_time); }
catch (InterruptedException e) { }
}
Summary
Of course, there are many more ways to increase the speed of your code. These are the only silly mistakes I could remember to share.
I tried not to cover topics which are already in the documentation page for optimising performance. You should also apply those methods to your application.