Investigating Performance Changes with git bisect

This week, I have been working an issue with LALRPOP. Basically, at some point there was a performance degradation on a newer version of the library. Niko Matsakis mentioned that this is likely due to failing to cache some regular expressions that we need repeatedly. I assume he’s correct, but I want to understand how this performance degradation was introduced, and I’m very new to this code base, so I’m going to try to find the change that introduced it. To find this change, I will use a tool called git bisect.

Git bisect is basically automated binary searching of commits, looking for the earliest commit that introduced a bad change. The basic idea is:

  1. Give git a SHA known to be “good.”
  2. Give git a SHA known to be “bad.”
  3. Git git a script or command that will only exit 0 on “good” SHAs.
  4. Wait for git bisect to do its magic.

Git will efficiently search through the intermediate commits and find the SHA of the first commit that counts as bad. Presumably, this is the commit that introduced the bug, problem, or whatever. Then we can look at that commit, and hopefully not have to read too much code in order to understand the problem. I wrote a script that will be called in the middle of this process:

  1. Checkout a SHA
  2. Run my script
  3. Note the status code

My script will basically rebuild the csv-game lalr-reader executable with local dependency on LALRPOP, and then run the parser with a short timeout. There were a few problems that I ran into along the way, and I wanted to share the solutions. To achieve this script, I’ll use timeout, which is called gtimeout on Mac. timeout or gtimeout is a command line utility that accepts another command and a time limit. It returns 0 if the command returns before the time limit, and exits with an error if the time limit is exceeded.

This proved to have a few more steps than I thought, so I wanted to outline them, in case someone else ever has to do this.

The step one is making the csv reader game depend on my local copy of LALRPOP instead of installing it from crates.io. This is a simple change to the Cargo.toml:

Old:

[dependencies]
lalrpop-util = "0.13"

New:

[dependencies]
lalrpop-util = { path =  "/Projects/rust/lalrpop/lalrpop-util"}

I thought that would be it. My bisect script was basically just re-compiling and then timing the new binary. But the first time I ran it, I got a bunch of version mismatch errors from the compiler. I eventually realized that neither LALRPOP’s Cargo.lock file, nor the csv-reader’s Cargo.lock file, were under the control of the git repo I was manipulating. That means that when git bisect checked out an old version of the code, the existing lock files stuck around. So when I ran the script, the builds would all fail because they were trying to respect the lock files, and wouldn’t be able to find the appropriate versions of local dependencies, because those weren’t the versions I was building. To fix this, I added the following to my bisect script:

[ -e Projects/rust/lalrpop/Cargo.lock ] && rm /Projects/rust/lalrpop/Cargo.lock
[ -e /Projects/csv-game/rust/lalr-reader/Cargo.lock ] && rm /Projects/csv-game/rust/lalr-reader/Cargo.lock

The [ -e /path ] && rm /path is an idiom for removing a file only if it exists. So now my builds will succeed, because the lock files are deleted each time, so the builds are free to use the newly-built version of their local dependencies.

The next thing I ran into was a peculiarity of the git bisect command: It only accepts exit codes between 0 and 127, but I had passed --preserve-status to gtimeout. This option makes gtimeout exit with the same status that command passed to it exited with. So when the timeouts failed, it would always exit with status 143, which is the status processes return if they’re killed by SIGTERM, see also this StackOverflow question.

In retrpospect, I fixed this in a rather round about way. After some googling, I put this at the end of my test script:

rv=$?
if [ $rv -gt 127 ]; then
  exit 127
else
  exit $rv
fi

Now I realize that I am, in effect, telling gtimeout to preserve the status, then obscuring the status myself to keep git bisect happy. Instead I should just remove --preserve-status from the gtimeout call.

The last problem I ran into, and one I haven’t completely solved yet, is that not every commit to master will build. This caused git bisect to think that very many SHAs were bad when they weren’t. To try to fix this, I told the bisect script to exit 0 if the build failed. In this way, I was hoping that git bisect would simply skip SHAs that don’t build. However, these are too numerous, perhaps because of some other problem with my environment. In any event, here’s the finished shell script:

#!/usr/bin/env bash
[ -e /Projects/rust/lalrpop/Cargo.lock ] && rm /Projects/rust/lalrpop/Cargo.lock
[ -e /Projects/csv-game/rust/lalr-reader/Cargo.lock ] && rm /Projects/csv-game/rust/lalr-reader/Cargo.lock
cargo clean --manifest-path /Projects/csv-game/rust/lalr-reader/Cargo.toml
cargo build --release --manifest-path /Projects/csv-game/rust/lalr-reader/Cargo.toml
echo "build finished"
[ -e /Projects/csv-game/rust/lalr-reader/target/release/lalr-reader ] || exit 0
gtimeout 5 /Projects/csv-game/rust/lalr-reader/target/release/lalr-reader /tmp/count.csv

This does what it should, but the first bad SHA seems to be one that I can’t compile locally at the moment, so I’ll need to find a different approach to solving my particular problem. Still, I learned a lot, and it was fun.

Till next time, happy learning!

-Will

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s