If you know more than the average bear about CSS, and you’d be willing to spend a couple of hours tuning the look and feel of the Software Carpentry course notes, please give me a shout.
Karen Reid’s having so much fun writing a little Python CGI to do some on-line data entry that I decided to take some time off from editing the Software Carpentry course notes, and get my del.icio.us bookmarks on-line. Enjoy…
JYI is a peer-reviewed forum for undergraduate science. Very cool idea—I wonder if they take Computer Science articles?
“House” and “CSI” (the original) are two of my favorite TV shows.
Partly, it’s the characters—Hugh Laurie and Marg Helgenberger are
both brilliant—but I also enjoy watching smart people debugging.
Sure, they’re dealing with diseases and crime scenes, but deep down
it’s all the same: something’s wrong, and you have to figure out
what.
The Argon team spent a lot of the last five days doing exactly
that. For those of you who haven’t been following along, Argon is a
fork of Trac, a
lightweight web-based project management framework that’s implemented
in Python. We’ve been working for several months to modify it so that
we can use it to run undergraduate programming projects; the interface
has been redesigned, it now handles multiple projects, we’re using
PostgreSQL instead of SQLite (partly for performance, and partly
because SQLite contains a synchronization bug), and so on.
A couple of weeks ago, we finally installed it on CDF, the
Computing Disciplines Facility servers that host undergraduate work
during term. It took longer than anticipated to find a set of file
ownerships and permissions that would allow students access to their
projects, but only their projects, while giving TAs and
lecturers access to everything.
We got it sorted out eventually, but then we ran into another
problem: our application was really, really slow—it was taking 10
seconds or more to service each CGI request. There was no way we
could put it into production as it was.
While we were poking around at our end, Chris Lenz had a look. The first
thing he told us was that we should map the htdocs
directory (the one containing all the static resources) to some URL
that wouldn’t trigger an invocation of the CGI, so that Apache
wouldn’t have to invoke Python for each image or icon.
The second thing was that our code ran in under half a second on
his unplugged Powerbook. He and Keir Mierle (one of the students
working here in Toronto) profiled the code, and found that almost all
the difference lay in the time it was taking the CGI to import the
libraries it needed. On Chris’s machine, this was a few hundred
milliseconds; on ours, it was several seconds.
All right, down a layer we go. Keir profiled Python itself using
gprof, and found this:
| % time | cumulative seconds | self seconds | calls | self s/call | total s/call | name |
|---|---|---|---|---|---|---|
| 38.46 | 0.70 | 0.70 | 51442563 | 0.00 | 0.00 | _PyUnicodeUCS2_IsLinebreak |
| 15.93 | 0.99 | 0.29 | 28141 | 0.00 | 0.00 | PyUnicodeUCS2_Splitlines |
| 3.85 | 1.06 | 0.07 | 83334 | 0.00 | 0.00 | classify |
| 3.30 | 1.12 | 0.06 | 55512 | 0.00 | 0.00 | PyFrame_New |
| 2.20 | 1.16 | 0.04 | 1233298 | 0.00 | 0.00 | _PyUnicode_New |
| 2.20 | 1.20 | 0.04 | 50779 | 0.00 | 0.00 | list_dealloc |
| 1.65 | 1.23 | 0.03 | 1416785 | 0.00 | 0.00 | app1 |
| 1.65 | 1.26 | 0.03 | 660223 | 0.00 | 0.00 | dict_subscript |
| 1.65 | 1.29 | 0.03 | 515599 | 0.00 | 0.00 | PyDict_GetItem |
That’s right: for some reason, each time the CGI ran, it called the
function that sees whether a character is a Unicode end-of-line marker
50 million times.
Hm… If we were parsing XML or some other data files, I could see
why we’d call _PyUnicodeUCS2_IsLinebreak, but this was
happening as we were importing libraries. Ah, but: each of the source
files we inherited from Trac began with the line:
# -*- coding: iso8859-1 -*-
This is an Emacsism that recent versions of Python have adopted to
tell the interpreter how the characters in the source file are
encoded. (If you don’t know what that means, please check out Joel
Spolsky’s excellent
article.) When we took those pragmas out of our files, the number
of calls to _PyUnicodeUCS2_IsLinebreak dropped to 29
million. That’s still a lot, but it was a sign we were on the right
track.
We then got tangled up for a while with .pyc files. When Python
imports a .py module, it compiles it to bytecode, and then saves the
bytecode to disk. The next time it’s asked to import the module, it
checks the timestamp on the corresponding .pyc; if the .pyc is
fresher, Python slurps that into memory instead of recompiling the
source. Of course, this only works if the Python interpreter has
permission to write to the directory that the .py file is stored in.
In our case, it couldn’t, because the interpreter was running with
the user ID of the web server, and giving it write access to the
source directory would open up a fairly large security hole.
Our solution was to compile all the .py files to .pyc’s manually
every time we updated the source code (just as Python does to its
standard library when you install it on a new machine). For a while,
though, we were running our tests with some .pyc’s deleted, but others
still present, which is why we were still getting those 29 million
calls to _PyUnicodeUCS2_IsLinebreak. Once we got that
cleaned up, the number of calls dropped to zero, and the run time went
from over 10 seconds per hit to 2 or less—well within our comfort
zone.
OK, we’d fixed our problem, but we still didn’t really understand
it. Karen Reid (my co-supervisor) and I have learned the hard way
that just making bugs go away usually isn’t enough: if you don’t
understand where they came from, they’ll probably come back when you
least expect them.
We had Keir post a note to the Python developers’ list. It went
out at 16:10 on Tuesday, August 23. At 05:45 the next morning, Walter
D�rwald replied to say:
This is caused by the chances to the codecs in 2.4. Basically the codecs
no longer rely on C’s readline() to do line splitting (which can’t work
for UTF-16), but do it themselves (via unicode.splitlines()).
Half an hour later, Martin v. L�wis followed up with:
That explains why you get any calls to IsLineBreak; it doesn’t explain
why you get so many of them.
I investigated this a bit, and one issue seems to be that
StreamReader.readline performs splitline on the entire input, only to
fetch the first line. It then joins the rest for later processing.
In addition, it also performs splitlines on a single line, just to
strip any trailing line breaks.
The net effect is that, for a file with N lines, IsLineBreak is invoked
up to N*N/2 times per character (at least for the last character).
Yup—the reader was invoking
_PyUnicodeUCS2_IsLinebreak N2 times. Square
root of fifty million is… carry the three… about seven thousand,
which happens to be about the number of lines of code we were
loading.
There have been over a dozen messages on the Python developers’
list since then about how to fix this. The most interesting part for
me hasn’t been the proposals themselves, but rather the fact that the
first thing Walter and Martin did was write little test programs and
profile them to find out how fast things would actually run. To put
it another way, good programmers like Walter and Martin automatically
apply the scientific method to problems—they design and run
experiments, collect data, and then formulate a hypothesis
(a.k.a. a bug fix). It’s cool to be able to watch this in action, and
even cooler to have code that runs fast enough to be called
interactive.
Over the past four months, our five undergraduate students have done a ton of work on our fork of Trac (which we’re now calling DrProject). They’ve designed a new interface, written a ton of code, refactored another ton, and fixed and filed a anthill’s worth of bugs. I think they’ve learned a few things too—Karen Reid and I certainly have. So, um, thanks, kids—it’s been a great summer.
Argon (our re-worked Trac) is now up and running on the CDF lab machines, but it’s very, very slow: 5-10 seconds per request at best. We’ve tracked the problem down to the import statements, which are taking 3.5 seconds or more each time the CGI is executed (we’re running as a pure CGI for now). This is puzzling, because (a) they take less than half a second on Chris Lenz’s Powerbook (slower processor and less memory than the CDF servers), and (b) Bin Liang’s installation on his hosted Debian service in Dallas, Texas takes 1-2 seconds per page request max. Something’s seriously confused here, and we need to track it down.
On the bright side, we seem to be over the last of the many ownership/permission hurdles that have bedevilled us for the past two weeks, and Keir Mierle says that email is finally working too. Greg Lapouchnian has been doing a lot of testing, finding problems of various sizes, and filing some very professional bug reports; hopefully, the other 49X alumni who volunteered to help will be able to kick in this week as well.
Twenty person-days left to get this one baked and on the table…
Andy Lumsdaine is offering the Software Carpentry course at Indiana University starting on August 29, under the heading B649 Software Tools and Practices.
The September 2005 issue of Doctor Dobb’s Journal has an article on testing web applications written by Sean Dawson and Kristin Kerr. Sean and Kristin did the work the article describes as a CSC49X project in Fall 2004.
Computer characters mugged in virtual crime spree is just more proof of Toffler’s Law: the future always arrives too soon, and in the wrong order.
Recent Comments