New Cows

Ever saw HTTP status code 103 appearing in your Apache access.log files?

At work we have, and we were highly confused by it as there's no "official" status code 103. We could not find a pattern for their occurrence in the logs either. The user agent didn't seem to matter, nor referrer, nor requested resource. No timing pattern, just every now and then a 103 response:

92.64.192.217 - - [23/Sep/2009:11:33:10 +0200] \
"GET /@@/jquery/jquery-1.3.2.min.js \
HTTP/1.1" 103 57254 "-" "-"

Grepping through the Apache sources (and just to be sure, through Zope's sources as well) didn't show up anything "103″ related to response or status codes.

In a moment of inspiration I looked in the error.log (duh) and found:

[Wed Sep 23 18:48:39 2009] [error] \
(103)Software caused connection abort: cache: \
error returned while trying to return disk \
cached data

Aha! Somehow the mod_cache sub system seemed involved. Indeed, for this particular site we are using Apache's caching module. Now more focussed, I had a look in the mod_cache source code again (what would you do if were you not using open source software??). There I found the error message that was in the error.log file.

I'm still not sure why exactly, but then I tried opening a connection to the server step by step and see what'd happen:

>>> import httplib
>>> conn = httplib.HTTPConnection(site_address)
>>> conn.request('GET', '/somepage')
>>> conn.getresponse()
>>> conn.close()

With this script I could reliably trigger the 103s. At the office that is, not at home… Apparently the time between the getresponse() and the close() calls is crucial for this to happen.

Our hypotheses now is that the real-life 103 errors probably come from browser windows being closed just before the page and its assets has been fully loaded.