I did my first profiling of Crinch’s hashing code this evening at it’s been interesting. Guava’s new hash package gives me something against which I can benchmark.
My methodology, briefly, was to implement the murmur3 32 bit hash then use the hash on a million randomly populated POJOs that look like this:
private static class Pojo {
String strVal;
int intVal;
long longVal;
boolean boolVal;
}
Hashing them all with Crinch using:
private static class PojoSource implements HashSource<Pojo> {
public void sourceData(Pojo pojo, WriteStream out) {
out.writeChars(pojo.strVal);
out.writeInt(pojo.intVal);
out.writeLong(pojo.longVal);
out.writeBoolean(pojo.boolVal);
}
}
And hashing them all with Guava using:
private static class PojoFunnel implements Funnel<Pojo> {
@Override
public void funnel(Pojo pojo, Sink into) {
into.putString(pojo.strVal)
.putInt(pojo.intVal)
.putLong(pojo.longVal)
.putBoolean(pojo.boolVal);
}
}`
And storing the hashes in a million element int[], recording the median number of milliseconds required for both Crinch and Guava over 10 repetitions. Yes, this is a very rough first investigation, but you have to start somewhere. Code for the test case is available at:
The variance between repetitions was very low and on my machine (running OpenJDK 6) the times were consistently:
This is a much larger disparity than I anticipated. So I attached a profiler and used method sampling to profile the call tree (instrumentation would have provided more complete information but may have skewed the timings). It appears that much (though not all) of the disparity is due to the time spent in Crinch’s WriteStream.writeChars() method compared to Guava’s equivalent Sink.putString() method.
Here’s a barely legible screenshot of the call tree breakdown:
Both methods take a single CharSequence, iterate over its characters and hash them individually, but Crinch has an optimized path for the common case where a String is passed to the method; Guava does not. There is actually further scope for optimizing Crinch here too that I may investigate.
It’s too early to draw any conclusions about the relative overhead of hashing in Guava compared to that of Crinch. I’ll want to revisit the comparison when I’ve found time to build a patched version of Guava containing some appropriate optimizations.
I’ve been unable to code for the past week, so as I started to ease myself back in today, I took time to investigate a phenomenon I first noticed months back.
Reto Meier has been a strong advocate for the use of analytics, his code and all the available sample code indicate that you call the analytics tracker on the UI thread. But if you use the Google Analytics SDK for Android like this, calling the tracker on the UI thread, it can make your app very unresponsive. I noticed this after adding the library to my Metaglow application, buttons that had felt very snappy immediately felt sluggish, even though I’d taken care to keep the UI thread ‘hygenic’.
Today I sat down and wrote a little stub of code that collects some basic call-time statistics for the GoogleAnalyticsTracker class from version 1.1 of the SDK. I made a few runs on my Nexus One by proceeding to use Metaglow over an extended session. In each run I collected timings for approximately 100 calls to the trackPageView and trackEvent methods.
Of the three runs, these were the most typical numbers (one set slightly was slightly faster, one set was significantly slower):
So, you can expect users to occasionally encounter UI glitches of 1/5th* of a second or more just from queuing an analytics event; and (admittedly I don’t have figures for this) it’s my experience that the pauses are more significant than this; infrequent, but long when they occur; this gives a bad user experience.
It’s documented that the analytics data is queued into batches and dispatched separately from the call that records them, so this behaviour (infrequent but lengthy pauses) can’t be due to network I/O. But it is what we are told to expect when we are performing writes to Flash storage. So I used traceview to peek inside the execution of the analytics code and confirm that this was the cause.
Those green blocks, which are just about visible, are writes inside Sqlite3 and this explains the uneven performance.
Since I want to keep analytics I will probably write my own event queue around the Google analytics tracker, to decouple it from the UI thread. If you use Google analytics and want to give users a smooth experience, you may need to do this work too.
(*) this figure is based on 2 standard deviations above the mean
