Profiling mayfly

One of the key goals for an in-memory database for unit testing is that it should be fast. And mayfly is faster than the other databases I've tried for some things, like creating or altering tables. However, it is some 3x slower than hypersonic for inserting rows ("insert into foo(a,b) values(3,4)" kinds of commands). I've been meaning to profile it for a long time now, but I finally got around to it.

First I added the JIP jar to the project and added a profile-test target to build.xml. Because JIP doesn't work with gcj, I ran it under Sun java. JIP writes a text file report, and I worked off that.

The results surprised me. They showed that 70% of the time was being consumed in the lexer and parser. Conventional wisdom is that lexing and parsing just isn't your big bottleneck in a compiler these days, but perhaps that is more for an optimizing compiler which spends more time in code generation and optimization passes. I inlined a few short methods which were bottlenecks (at the cost of a small amount of code duplication, but not so much as to be really shocking, and remember I was careful to only do this for the bottlenecks). This was also a surprise: that method invocation seemed to be such a cost. Given my limited knowledge of java internals, that sort of makes sense, but it kind of seems like a step backwards, in the sense that in the C/Pascal/etc days we made so much effort to make method invocation fast, and tell people they didn't need to make their code ugly to avoid method calls. (At the risk of belaboring the obvious, even if method calls are expensive you still don't need to make your code (very) ugly to avoid them: it is only a handful of invocations which are actually going to make a difference in your run-time, and the profile shows you which ones).

I was also able to streamline the non-parsing part of the code, mostly by taking out some extra steps (for example, transforming a column name to a Column and back to a name more times than needed). Some of that had built up through a series of changes which had left in vestiges of previous ways of doing things. So cleaning this up left the code simpler and clearer, as well as faster.

Other changes, like changing Row to be a HashMap rather than a List, didn't seem to help at all (or even hurt slightly). It has been conceptually a map for some time now, but apparently those linear searches were not particularly more expensive than the many calls to hashCode you get with the map. I guess the fact that we don't expect more than a few dozen columns in a table is responsible.

So what is next when I look at this again? For the lexer, I may have run out of obvious ideas (given that it has duties like tracking the line and column numbers of every token, and I don't see giving up that feature, which provides good error messages). For the parser, there is a lot of expression handling machinery that is involved in parsing the "3" in "insert into foo(a) values(3)". Unless I think of a better way, having the top-level expression parser look for a literal followed by something like "," or ")", and going into a fast-path special case might be worth it. I know that looks like a kluged-up wannabe bottom up parser, but I've been happy enough with recursive descent in other ways, that I have trouble seeing switching back to a parser generator. As for the execution (building up rows, modifying the tables, etc), I'd have to look at the profile more. Although I've seen some hot spots, fixed them (and perhaps created others), I don't have as much of an intuitive feel for what is slow here as I do for the lexing and parsing.

Database upgrades: SQL versus code

When last I wrote about database upgrades, one of the design designs was whether to have a database upgrade be a hunk of code (as in rails and other systems I've worked with), or an SQL script (as in the non-automated upgrade scripts that were checked in to MIFOS prior to December's work).

For the first cut (last December), I went with SQL, on the theory that (1) it might be easier for people to understand, especially sysadmins and others who wouldn't necessarily read much of the Java code, (2) many of the cases which came to mind, such as adding a column or adding a table, could be done this way, and (3) if the automated upgrade runs into trouble, it may be easier to run some scripts one at a time, perhaps with changes, rather than trying to mess around with Java (again, for some people). But I did have in mind, even then, that I might need to add code upgrades at some point.

Well, we found a case where the SQL scripts don't work. The MIFOS database contains tables which store things like strings which are displayed to the user. MIFOS ships with a whole bunch of these ("loan", "client", etc), but such strings can also be added by the microfinance institution. In adding them (at least the way our database is currently set up), one needs to assign at least one ID which is not referenced directly from the Java code, but which also is referenced elsewhere in the database. Although there are variants of SQL which have variables and the like (PL/SQL, PL/pgSQL, etc), I don't think MySQL has those kinds of extensions (and trying to turn SQL into a procedural language is somewhat awkward anyway). So the solution will be to implement Java upgrades. I have in mind keeping the ability to do SQL upgrades (that is, each upgrade is either a java upgrade or a SQL one). That is largely to ease the transition (we have about 19 upgrades already, and won't need to convert them over all at once). We'll also see whether writing upgrades in SQL, in those cases where it is possible, ends up being appealing or just a source of confusion.

Test speedups

The MIFOS tests (ApplicationTestSuite, or pretty much all the junit tests) run in 2600 seconds on my laptop. When you are checking in several times a day, that adds up to a lot of time spent waiting for tests. It also discourages good habits like running the tests frequently to find problems early, checking in frequently, certain kinds of experiments (for example "if I clean up this ugly code, will anything break?") and the like.

There are a few reasons for this. First of all, I'll agree with something that Eric Du or Li Mo (I forget which) said a month or so ago, which was that too many of our tests are integration tests (test many classes) as opposed to unit tests (test a small number of classes). This is very much a case-by-case thing, so I guess I'll just mention the case which came up today: I was testing generateId in AccountBO. And it turns out there is no need to access the database to test this method (see AccountBOTest).

I've also known for a long time that many of the tests get caught in a familiar trap of writing many objects to the database (I need a client, and a client needs a group, and a group needs a center....). Or of creating objects via the database when creating them in-memory would work just fine, be faster, and avoid problems with getting rid of them at the end of the test.

But I was surprised at the speedups around getUserContext(). Someone (sorry, I tried finding out who in the archives but I didn't find it) posted some numbers to the MIFOS mailing list saying that
replacing TestObjectFactory#getUserContext (which involves several database calls) with something faster (TestUtils#makeUser() is the usual choice) cut the run-time of a certain test in half (or something - the number varies from one test to the next and once I convinced myself that the speedup is significant I haven't really been measuring things further).

Unfortunately, globally changing getUserContext to makeUser doesn't quite work - some tests fail that way. But one of my projects lately has been going through tests and changing all those that can be changed.

Getting tests to run fast can take work (especially if you don't have the luxury of writing fast tests from the start of a project). But tests that run slowly don't tend to get run.