Next Time Think of Some Tests

If you volunteer to help your sister-in-law with wedding preparations on Thursday, and you don't get to it until Friday, and you decide to write a program to do it, don't forget to think about some basic sanity checks on the final output. Otherwise on Sunday you'll hear from your father-in-law wondering why some people didn't have placecards and didn't know where to sit.

So yeah, wedding preparations in the sense of "can you research how to go from an Excel spreadsheet of names and table assignments to a Word document with the names in the right places to print on these pre-scored placecard sheets from Hobby Lobby, SKU #717694."


The more you think about Excel, you think "Not too bad, Mathematica imports from Excel," and the more you think about Word you think "Ugh". And the more you think about Mathematica, the more you remember the vector graphics language, and that you can trivially export to PDF or rasterized image files.

tables = Import["c:/tables.xls"];
sheet = First[tables];
(* Extract name from row by pattern match *)
nameOfRow[{title_, names_, ___}] := 
   trim[title] <> " " <> trim[names];
(* extract table assignment text from row *)
tableOfRow[{_, _, _, tbl_, ___}] := trim[tbl];
(* filter out blank rows *)
rowsWithNames[sheet_] := Select[sheet, 
   Function[row, trim[row] =!= ""]];

Some Opening Lines of Code, Which May Become Important Later

Not very long after, it seems, the Excel spreadsheet is imported, blank rows are skipped, the names and table numbers are constructed and placed onto the vectorized layout of the placecard sheet, with or without preview construction lines. Very cool.

placecardPageTemplate[] := 
  With[{w = placecardPageWidth, h = placecardPageHeight, 
    pgborder = placecardPageBorder}, 
    {
     (* Solid page border *) 
     Dashing[{}], Line[{{0, 0}, {w, 0}, {w, h}, {0, h}, {0, 0}}],

     (* Scored page borders *) Dashed, 
     Line[{{pgborder, 0}, {pgborder, h}}], 
     Line[{{w - pgborder, 0}, {w - pgborder, h}}], 
     Line[{{0, pgborder}, {w, pgborder}}], 
     Line[{{0, h - pgborder}, {w, h - pgborder}}],

     (* Scored between-card borders *)
     (* vertical *) Line[{{w/2, 0}, {w/2, h}}]}
    ~Join~ 
    Table[With[{cardHt = pgborder + i*placecardHeight}, 
      Line[{{pgborder, cardHt}, {w - pgborder, cardHt}}]], {i, 1, 2}]
    ~Join~ 
    Flatten[Table[placecardTemplate[r, c], 
               {c, 1, numPlaceCardColumns}, 
               {r, 1, numPlaceCardRows}], 2]];

Sample of the Vector Graphics Code



More time is spent rasterizing, with long interruptions for meals, toddler nap and bedtime, and the necessary socializing that comes from being in the bride's family's house the day before the wedding (e.g. rehearsal and dinner).

By late evening the table assignments are finalized and the requested high-resolution JPGs are being rasterized from the vector graphic objects. Sometime the next morning, the placecards are printed. The ceremony comes off with only one hitch, and by evening the reception is ready to swing.

Except... for that one little hack. When you wrote that simple filter to remove blank rows, you did it by checking if the first column was blank. And as it turns out, the first column is for titles and some names, about 6, didn't have a title.

Fault? Everyone agreed it was the you the programmer's. Some issue can be made about the the given spreadsheet format, with a separate column for titles. But the bottom line is you had all the data, and simply spent too much time coding and not enough time planning. There was time to do it right, and no time to do it over. There should have been some time devoted up front to thinking about how to check for correctness of the final output.

Oh well. The next time someone asks to help print placecards you're all set...

---

If you are interested in the Mathematica notebook that can generate custom placecards with your database of names, send to the gmail.com account jfkbits. And please note I've fixed the aforementioned bug.

Hashtables and Wedding Days

While using a commercial STL hash implementation a few years ago, my program appeared to hang (the old halting problem dilemma; is it in an infinite loop or just slow?) on a hash table insert. I got a trace of the key/value pairs inserted and wrote a minimal program only doing the inserts. That hung too. Sent it off to the vendor who found a bug in his bucket rebalancing code.

He sent back a patch for the implementation with the advice to get a better hash function, since a lot of the inserts were hashing to the same location. Using the key object's address as the hash value was a poor choice: it was word aligned, and the lower 2 bits were always zero. So we changed the hash function to right-shift the address, and with the patched code, we were off and running again.

Jeff Atwood draws an analogy of the birthday paradox and the probability of two objects hashing to the same location. The problem with my poor hash function resembles the Wedding Day Paradox, as I'm calling it. I recently had a conversation with a coworker:

Me: My anniversary is coming up.
Coworker: Mine too! How many years?
Me: Four.
Coworker: Me too. When were you married?
Me: October, how about you?

We quickly discovered we both had our weddings fall on the same day of the same year. We realized this should not surprise us, since most weddings occur on a Saturday. Knowing that we were both married in the same month of the same year gives only 4 or 5 choices. This effect is even more significant than the seasonal variations of birthdays with more concentration in some ranges than in others.

I've filed this under bugs, so let this serve as a cautionary tale if you undertake to do your own hash functions; consider well the distribution of your keys. Also, if you write a hash table implementation, include in your test suite a scenario where the hash function is really dumb.

Types of garbage

At some point, many a Java programmer has had a little bulb go on, and exclaimed with dropped jaw "I thought Java couldn't have memory leaks!"

Well, you don't have leaks like in C or C++, where leak occurs simply by forgetting to call free or delete. Objects leak by default:

   new std::string("hello");

is a leak. In Java, objects get deleted by default:

   new String("hello");

is instant garbage to be collected. You have to do something to remember an object, like assign it to a variable or store it in a live object. And that's actually the type of "leak" that can happen, where the programmer stores a reference to an object in a long-lived structure but never uses the object again.

I was pleased to discover that the Wikipedia article on garbage collection and on garbage give terms to distinguish these two cases:

Syntactic garbage

Memory that is unreachable from variables in the program.

Semantic garbage

Memory that is unusable by further execution of the program.

The latter category is not possible to algorithmically determine in the general case (halting problem type of stuff, bad idea to want by algorithm how the execution of a program will turn out), garbage collection algorithms tend to focus on the syntactic variety of garbage.

The next time someone asks you to take out the trash, you have fuel for a smart remark. Something like "which did you mean, the objects that we're not using because they're in the trashcan, or the objects that we could use but we haven't been using, and we never will, but we don't know that for sure now, so we better not discard them yet..." Let me know how far you get with this type of reasoning as a way of avoiding your GC chores.

Novel Internationalization Technique

FilZip is a great utility for working with ZIP files and numerous other archive and compression formats. When creating a new folder to hold the extracted contents of the JSP specification, I got to learn a new German word "abbrechen", which apparently means "cancel".

Contract Violation in Tomcat or "Hey, I was still using that!"

This is a bug story. I don't have all the detail yet. But I know what I saw.

If you're really impatient, you can skip to the end ("Light Dawns").

Scene of the Crime

Picture a Java Server Page (JSP) which runs some code to check the server to see if some heavy computing job is done yet. If it is, the HTML page returned will immediately redirect to a page showing the results of the job. Otherwise the page will wait a few seconds and refresh. A polling loop.

The JSP takes two parameters, a job identifier and a status string, like this:

http://seti.example.com/search/poller.jsp?jobid=28&whatsup=Searching%20for%20ETs...

Now assuming that the job will take a long time, what would you expect to see on your browser? Probably not this sequence:

Fetch #1 of http://seti.example.com/search/poller.jsp?jobid=28&whatsup=Searching%20for%20ETs...

Waiting on job 28.
Searching for ETs...

and three seconds later, Fetch #2 of
http://seti.example.com/search/poller.jsp?jobid=28&whatsup=Searching%20for%20ETs...

Waiting on job 28.
Searching for ETs...

and three seconds later, Fetch #3 of http://seti.example.com/search/poller.jsp?jobid=28&whatsup=Searching%20for%20ETs...

Waiting on job null.
null

A program with certain inputs that produced one output the first two times it was invoked, and then a different output. Either my senses deceived me, the program had changed for some mysterious reason, or there were more inputs involved than I had in mind.

An Investigation is Opened

In trying to debug this, I found that while the HttpServletRequest's getParameter method was returning null, the getQueryString showed the right stuff, "jobid=28&whatsup=Searching%20for%20ETs...". I searched the web, and found there are categories of problems in Java servlet land where by forwarding and redirecting and various contortions you can end up losing your query string. But still, why should the result change after it was just working seconds earlier?

The Plot Thickens

The above simulated screenshots are not what I saw originally. In my JSP I had a null check, and redirected to an error page in that case. This stopped the looping. But when I removed the null check and let the polling loop continue, I found that the null condition went away. In other words, on one request the query string had the right stuff, but the request parameter map was empty. On the next request, the request parameter map was populated again.

A Correlation

This waiting page is what gets returned by a request to initiate the heavy duty compute job. What I was trying to do was emulate a common metaphor where the user makes a request of the server which will take some time to process, and a "waiting" page gets immediately returned. I decided to run Tomcat in the debugger and step through this initial request, where the waiting page URL got formulated and all that. Let's see roughly what that code looked like:

void handleSetiSearch(HttpServletRequest request, HttpServletResponse response)
{
   String id = allocateJobId();
   String waitingPage = "poller.jsp?jobid"+id
      +"&whatsup=Searching%20for%20ETs...";
   setRedirectResponse(waitingPage,response);

   // Start heavy computing job in another thread
   SearchParameters params = getSearchParameters(request);
   TimerTask performSetiSearch = new SetiSearch(params,request);
   Timer timer = allocateTimer();
   timer.schedule(performSetiSearch, 0);
}

This is the method that is invoked from the servlet's doGet or doPost methods, and handles the web request. Unimportant details have been reduced to a method call above.

I put a breakpoint here and in the SetiSearch code (not the real code I was using, if you've been wondering). After the above shown method returned, so that the browser got its poller.jsp page, but with the debugger stopped at the beginning of the SetiSearch code, the browser would loop the poller page for a long time without mishap.

Only when I started stepping through the compute job code did the poller page suddenly get a null parameter.

You now have all the clues, Sherlock. If you're a Tomcat developer or a very experienced Java webapp developer, you're probably screaming the answer. But let everybody else think for a few moments to see if they can spot the error.

Light Dawns

The insight is in noticing that while the web request is handled when the handleSetiSearch method returns, the SetiSearch object running in a separate thread after the request is handled still has the request object in its hot little hands.

And guess what? Tomcat recycles HttpServletRequest objects.

As this forum discussion shows, back in Tomcat 3 they were finding a significant performance boost by recycling request and response objects, instead of always allocating and garbage collecting them.

My suspicions were confirmed when I started printing the request objects and noticed that the same request object used to handle the original "SETI search" request had been recycled into the poller.jsp request.

So, although I can't explain why I saw what I saw, I know that when I extracted, copied, cloned, and otherwise slurped all the information out of the request object that the big compute job required, and did not pass on the request object itself, all my troubles went away.

Conclusions

Whose mistake is this? Mine, of course. But it's a gray line. I'm sure the contract of "don't use a request or response object after the request is handled" is stated in some documentation somewhere. I just hope they add the line "Even if you're still post-processing the request."

So, even though Java has automatic garbage collection, this experience teaches me that memory management by the program can still be done.

Afterword: Functional languages

Could this have happened if I was writing in a functional language? Not nearly as likely, if requests are represented in a "usual" way of data constructed on the fly, and state updates modeled by creating new copies. The performance issue solved by Tomcat's management of its own memory would fall to the language implementation. For example, consider this SML snippet:

  (* Sets a request attribute and forwards to a display JSP *)
  fun valueAdd(request as HttpRequest{params=p,attrs=a},response) = 
  let
     val newValue = database.getValue()
     val request2 = HttpRequest{params=p, attrs=Hash.set(a,"value",newValue)}
  in
     forward("value.jsp",request2,response)
  end

The memory requirements are (1) the creation of a new HttpRequest record and depending on the hash implementation, (2) a new hash table with an additional value. This even though request and request2 probably share the same params value. Depending on analysis of the call chain, the system could possibly decide that request is never used by any valueAdd caller, and could perform an update in place of the original request object to create request2. But I'm not up on functional language implementations to know if such things are being done. Chez Scheme has a lot of performance enhancement built in. Does anybody know how Ruby would fare in a situation like this? Is there any language out there that would be up to the task of recycling very frequently allocated data as needed for web server request and response objects that would not try to reclaim an object in use after the immediate request was handled?

Rantlet: Look who (or what) knows so much

My CD is dirty or damaged. I knew this already. My computer knows it too:



So it knows the problem. I'm impressed. But I don't know how to turn on error correction. Why doesn't it do something about it? Why isn't there a button labelled "So turn on error correction already!"? I don't want to get my hopes up here, but maybe they could even just turn on error correction for me, if they think that might help.

OK, I'm calming down. I had popped in a familiar CD to help me focus, and now I'm having to write to get out my frustration. If you click "More information", it does at least tell you how to turn on error correction. And the error correction, as they tell you, doesn't always work and might cause your CD to skip when it wasn't skipping before. OK, so there's a legitimate choice involved that is best left to the user. And I'll allow that this dialog may be fitting into a standardized error dialog which always has those two buttons, "Close" and "More information". OK, no more to say. Just a vague, undefined dissatisfaction that will probably induce me to try something different if it comes along.

False friends and Picasa web movies

Yesterday I tried out Python for real, applied to a problem I have with Picasa's web page generator.

What problem? For movie files, Picasa generates an embedded Windows Media Player control that does nothing. This is easily fixed by substituting this simple embed link:

<embed src="movie-filename" width="320" height="256" />

It was an interesting, refreshing experience to write in a new language, bringing to it expectations and baggage from Perl, Scheme, ML, and Mathematica. It was a process of "how do I read command line argument?", "now how do open a file?", and "what about creating an empty list?" I could bring my assumptions about the language semantics and capabilities and ask "how do I..." over and over.

A little like learning one Romance language after knowing two or three others, yes?

I spent most of my time consulting the Quick Reference and occasionally to the full Library Reference, with a boost from Introduction to Python/Hello World! to get started.

The things that gave me the most frustration in writing my 89 line script were definitely novice mistakes. If your critical attention is on a piece of code and you say "hey, that's not right!" it's a step up from the novice who doesn't realize something is out of place.

Mistake #1: Using parens to surround list literals: list = (). Not sure where I picked this up. Just as in SML, my native language, Python lists are surrounded by square brackets: [], [1,2,3],["and","so","on"]. Parentheses surround tuples, which are fixed-length. Since Python uses dynamic types, I could write list = () and nothing bad ever happened to me until I tried to append something to it. The error message finally clued me in on what type my variable was.

Mistake #2: Using comma instead of colon in a slice. I had written an expression like line[i+1,j]. Again, not sure why my fingers glibly typed the comma. The error was TypeError: string indices must be integers. That communicated to me that a substring, which is what I meant, could only be done with literal integers, not with integer-valued expressions. Spent a bunch of time in the documentation for other ways to get a substring before figuring out I had a comma when I needed a colon: line[i+1:j]. I think a non-novice Python programmer would have spotted the mistake immediately.

I explained all this to my linguistically-minded wife, someone who actually does speak multiple languages, and she thought it sounded like I had made the "false friends" mistake. I used something with a meaning in one language, and instead of being gibberish in the current language meant something else. Something related enough to cause confusion for a while.

These trivial problems were fixed, and the fixpicasamovies.py script worked great.

Classpath not working in Ant junit task

Pop quiz: spot the error in the following Ant fragment:

<path id="common.classpath">
  <!-- some classpath content -->
</path>

<path id="common.test.classpath">
  <path refid="common.classpath"/>
  <pathelement location="${basedir}/lib/junit.jar"/>
  <pathelement location="${basedir}/build/common/test/bin"/>
</path>

<target name="test" depends="compile-tests"
  <junit fork="yes" forkmode="once" printsummary="on">
    <classpath>
      <path refid="${common.test.classpath}"/>
    </classpath>

    <formatter type="plain" />

    <batchtest>
      <fileset dir="common/test/java" includes="**/*.java"/>
    </batchtest>
  </junit>
</target>

You may not even need to know ant syntax to spot the error, since it's an internal inconsistency.

The clue is that you get "class not found" errors for all tests when you run the "test" target.

Give up?

The nested classpath element for "test" is not referring to an existing path ID. I confused an Ant property with an Ant ID. It should say

    <classpath>
      <path refid="common.test.classpath"/>
    </classpath>

without the ${} wrappers that are used to refer to Ant properties. There's a correct path reference in the test classpath definition itself.

Passing system properties from Ant's command line to java or junit

The other day I wanted to do something like this, and have the property passed to a junit task:

% ant -Dcom.blogspot.jfkbits.tmpfile=/tmp/grzlgmpfer-78

My task never saw the property; Ant doesn't automatically pass-through properties. That's fine, it just surprised me, coming from the shell environment variable mindset.

It turns out that sysproperty, syspropertyset, and jvmarg are the only ways to do it.

The jvmarg nested element is the simplest form, as in the example from the Ant documentation:

  <jvmarg value="-Djava.compiler=NONE"/>

If you have a lot of properties this gets tedious.

If the properties you want to pass have a common prefix, as in the example com.blogspot.jfkbits, you can use syspropertyset with the prefix attribute, like this:

<junit>
 <classpath refid="classpath"/>
 <syspropertyset>
   <propertyref prefix="com.blogspot.jfkbits" />
 </syspropertyset>
 <!-- tests go here -->
</junit>

---

Update 17 July 2006:Added text for jvmarg, since that is a way to pass system properties that I previously omitted, and tweaked the description of how to use syspropertyset.

Bug Story: When Is 9+1 not supposed to be 10

It was a simple mistake, but in an embedded system it was hard to debug and had mysterious effects. Our team had a limited region of RAM for each task to store its own copy of a fixed-sized chunk of data. (A "task" in our operating system, pSOS, is the same as a thread or process.) In a C header, we defined constants to use as the start of each tasks's fixed region of memory, something like this:

#define TASK_ALPHA_STATICS    BASE+0x1 * sizeof(STATIC_DATA)
#define TASK_BRAVO_STATICS    BASE+0x2 * sizeof(STATIC_DATA)

And so on. Things tooled along, we got the first features going, and quite a ways into the project we started seeing weird crashes and unexplained error conditions. We found that some of the tasks were writing past that limited region of RAM. But why? While it was limited, we had calculated it had room enough for twenty-some tasks, and we only had 18 or so in our application.

What went wrong? Well, imagine you are an engineer who has just finished some feature development, and for the next feature in the application needs to code up a new task (thread), let's say to process a new stream of input from a real-time source. One of the various things you need to do is edit that header we talked about, and add your task, let's say it's the Golf task:

#define TASK_ALPHA_STATICS    BASE+0x0 * sizeof(STATIC_DATA)
#define TASK_BRAVO_STATICS    BASE+0x1 * sizeof(STATIC_DATA)
#define TASK_CHARLIE_STATICS  BASE+0x2 * sizeof(STATIC_DATA)
#define TASK_DELTA_STATICS    BASE+0x3 * sizeof(STATIC_DATA)
#define TASK_ECHO_STATICS     BASE+0x4 * sizeof(STATIC_DATA)
#define TASK_FOXTROT_STATICS  BASE+0x5 * sizeof(STATIC_DATA)
#define TASK_GOLF_STATICS     BASE+0x6 * sizeof(STATIC_DATA)

Simple: it's a cut-and-paste job, you just change the name and the number of your task, so your pointer points to the next section in this self-constructed array.
Let's look at the next few entries in this progression:

#define TASK_HOTEL_STATICS    BASE+0x7 * sizeof(STATIC_DATA)
#define TASK_INDIA_STATICS    BASE+0x8 * sizeof(STATIC_DATA)
#define TASK_JULIET_STATICS   BASE+0x9 * sizeof(STATIC_DATA)
#define TASK_KILO_STATICS     BASE+0x10 * sizeof(STATIC_DATA)

and so on up to eighteen, which in this telling is the last task:

#define TASK_SIERRA_STATICS   BASE+0x18 * sizeof(STATIC_DATA)

The keen-eyed C programmers among you will have seen the error. What we have here is the Sierra task addressing data that is actually 24 entries past the BASE pointer, not 18, because every one of those multipliers that a programmer had to edit has the "0x" hex prefix, that is the constant is in base 16, not base 10. So really those latter tasks were actually writing past their permitted region of memory, as if we really had 24 tasks in the system. It was a false lack of resources. We could have but didn't test for this at runtime, because we figured we had already accounted for it when we counted tasks and added up the memory.

It is interesting to see where the error crept it. The TASK_KILO_STATICS entry is most likely where things went awry, continuing the subtly wrong pattern of "8, 9, 10" when it should have been "8,9,A", or, "0x8, 0x9, 0xA".

How could this error have been prevented? Is writing our constants in hex not the best choice? What other code structures could have prevented this? The only reasonable alternative I can think of is the "previous+1" approach:

#define TASK_ALPHA_STATICS    BASE+0x0 * sizeof(STATIC_DATA)
#define TASK_BRAVO_STATICS    TASK_ALPHA_STATICS+sizeof(STATIC_DATA)

This eliminates the "9+1" problem, but did we introduce some other possible problem, like forgetting to link an entry to a previous entry, especially when rearranging the order of these entries?

If anyone can think of other ways to have avoided or tested for this problem (without resorting to another programming language), I especially invite your comments.

If you're interested in reading excerpts of other bug stories and a discussion of causal analyses, check out "My hairiest bug war stories" by Marc Eisenstadt. I like the way he refers to the "detective work" programmers do in debugging.