git bisect FTW
We had an issue yesterday where the test suite on one of our packages was failing for unknown reason. I had written both the package and the test suite and Basil was attempting to put them both up on travis-ci. He was confounded by the test suite’s inability to pass and called me over to help out.
The error that we were seeing where… odd. The sqlite database layer was trying to convert the geometry column to binary. It seemed like spatialite wasn’t enabled, but I could have sworn that I solved all of those problems a long time ago. I had a sneaking suspicious that some of my recent work had broken the test suite, but maybe I didn’t check? That is why we’re getting our continuous integration set up, afterall. So that we do check, automatically, every commit, that the tests pass.
So… how to find out whether one of my commits broke the test suite? Well, I could go back to each commit, one-by-one, check each revision out, run the test suite, and find out which ones fail. But that sounds like a linear search through an ordered list. Any intro level computer science class will teach you that you search an ordered list by bisecting the search space, completing your search with the number of operations equal to the log (base 2) of the number of items to search.
git implements an operation aptly named “bisect” where you give it a known “good” revision (i.e. where you’re tests pass) and a known “bad” revision and a command, and it will search the whole revision space and tell you which revision broke your tests in log(n) operations. Let’s give it a try.
First, I’m going to guess that one of our recent tagged versions is “good”.
james@basalt ~/code/git/pydap.handlers.pcic $ git checkout f3e3cb0550e1c5795 Previous HEAD position was 1e2efe7... Added tag 0.0.2 for changeset bd1edf2eeda1 HEAD is now at f3e3cb0... Added tag 0.0.3 for changeset bf0ebc9ab908 james@basalt ~/code/git/pydap.handlers.pcic $ ~/devenv/bin/py.test -v --tb=no ============================== test session starts ============================== platform linux2 -- Python 2.7.6 -- py-1.4.20 -- pytest-2.5.2 -- /home/james/devenv/bin/python2.7 collected 9 items tests/test_pydap_handlers_pcic.py:29: test_get_vars[input0-expected0] PASSED tests/test_pydap_handlers_pcic.py:29: test_get_vars[input1-expected1] PASSED tests/test_pydap_handlers_pcic.py:158: test_create_ini[EC_raw-1106200-expected0] PASSED tests/test_pydap_handlers_pcic.py:158: test_create_ini[ARDA-109147-expected1] PASSED tests/test_pydap_handlers_pcic.py:182: test_monkey PASSED tests/test_pydap_handlers_pcic.py:186: test_404s[/EC/913/junk] PASSED tests/test_pydap_handlers_pcic.py:186: test_404s[/EC/913.sql.html] PASSED tests/test_pydap_handlers_pcic.py:196: test_returns_content PASSED tests/test_pydap_handlers_pcic.py:210: test_returns_html_content PASSED =========================== 9 passed in 0.35 seconds ============================
And it is! So let’s start our search there and end our search at the current revision.
james@basalt ~/code/git/pydap.handlers.pcic $ git bisect start f3e3cb0550e1c5795 james@basalt ~/code/git/pydap.handlers.pcic $ git bisect run ~/devenv/bin/py.test -v --tb=no You need to give me at least one good and one bad revisions. (You can use "git bisect bad" and "git bisect good" for that.)
Ummm, right, I need to tell it which are good and bad. Well, our start point is good.
james@basalt ~/code/git/pydap.handlers.pcic $ git bisect good f3e3cb0550e1c5795cbcc5 f3e3cb0550e1c5795cbcc5073ee0d4fa10a44200 was both good and bad
and I’m pretty sure that our last revision is bad, but let me check…
james@basalt ~/code/git/pydap.handlers.pcic $ git checkout master Previous HEAD position was f3e3cb0... Added tag 0.0.3 for changeset bf0ebc9ab908 Switched to branch 'master' Your branch is behind 'origin/master' by 4 commits, and can be fast-forwarded. (use "git pull" to update your local branch) james@basalt ~/code/git/pydap.handlers.pcic $ ~/devenv/bin/py.test -v --tb=no ============================== test session starts ============================== platform linux2 -- Python 2.7.6 -- py-1.4.20 -- pytest-2.5.2 -- /home/james/devenv/bin/python2.7 collected 9 items tests/test_pydap_handlers_pcic.py:29: test_get_vars[input0-expected0] PASSED tests/test_pydap_handlers_pcic.py:29: test_get_vars[input1-expected1] PASSED tests/test_pydap_handlers_pcic.py:158: test_create_ini[EC_raw-1106200-expected0] FAILED tests/test_pydap_handlers_pcic.py:158: test_create_ini[ARDA-109147-expected1] FAILED tests/test_pydap_handlers_pcic.py:182: test_monkey PASSED tests/test_pydap_handlers_pcic.py:186: test_404s[/EC/913/junk] PASSED tests/test_pydap_handlers_pcic.py:186: test_404s[/EC/913.sql.html] PASSED tests/test_pydap_handlers_pcic.py:196: test_returns_content FAILED tests/test_pydap_handlers_pcic.py:210: test_returns_html_content FAILED ====================== 4 failed, 5 passed in 0.51 seconds =======================
Bad indeed.
james@basalt ~/code/git/pydap.handlers.pcic $ git bisect bad master Bisecting: 3 revisions left to test after this (roughly 2 steps) [ba141e5d8df0d2fbc43fbf58e1906d262499993e] Added a context manager for all database connections so that they get cleaned up on error
Now, I’m pretty sure that we just run it.
james@basalt ~/code/git/pydap.handlers.pcic $ git bisect run ~/devenv/bin/py.test -v --tb=no
running /home/james/devenv/bin/py.test -v --tb=no
============================== test session starts ==============================
platform linux2 -- Python 2.7.6 -- py-1.4.20 -- pytest-2.5.2 -- /home/james/devenv/bin/python2.7
collected 9 items
tests/test_pydap_handlers_pcic.py:29: test_get_vars[input0-expected0] PASSED
tests/test_pydap_handlers_pcic.py:29: test_get_vars[input1-expected1] PASSED
tests/test_pydap_handlers_pcic.py:158: test_create_ini[EC_raw-1106200-expected0] FAILED
tests/test_pydap_handlers_pcic.py:158: test_create_ini[ARDA-109147-expected1] FAILED
tests/test_pydap_handlers_pcic.py:182: test_monkey PASSED
tests/test_pydap_handlers_pcic.py:186: test_404s[/EC/913/junk] PASSED
tests/test_pydap_handlers_pcic.py:186: test_404s[/EC/913.sql.html] PASSED
tests/test_pydap_handlers_pcic.py:196: test_returns_content FAILED
tests/test_pydap_handlers_pcic.py:210: test_returns_html_content FAILED
====================== 4 failed, 5 passed in 0.51 seconds =======================
Bisecting: 0 revisions left to test after this (roughly 1 step)
[becb8946195fff56a9aa74d61c767716a089a324] Fixed bug in path handler that didn't match hyphen in the network name
running /home/james/devenv/bin/py.test -v --tb=no
============================== test session starts ==============================
platform linux2 -- Python 2.7.6 -- py-1.4.20 -- pytest-2.5.2 -- /home/james/devenv/bin/python2.7
collected 9 items
tests/test_pydap_handlers_pcic.py:29: test_get_vars[input0-expected0] PASSED
tests/test_pydap_handlers_pcic.py:29: test_get_vars[input1-expected1] PASSED
tests/test_pydap_handlers_pcic.py:158: test_create_ini[EC_raw-1106200-expected0] PASSED
tests/test_pydap_handlers_pcic.py:158: test_create_ini[ARDA-109147-expected1] PASSED
tests/test_pydap_handlers_pcic.py:182: test_monkey PASSED
tests/test_pydap_handlers_pcic.py:186: test_404s[/EC/913/junk] PASSED
tests/test_pydap_handlers_pcic.py:186: test_404s[/EC/913.sql.html] PASSED
tests/test_pydap_handlers_pcic.py:196: test_returns_content PASSED
tests/test_pydap_handlers_pcic.py:210: test_returns_html_content PASSED
=========================== 9 passed in 0.34 seconds ============================
ba141e5d8df0d2fbc43fbf58e1906d262499993e is the first bad commit
commit ba141e5d8df0d2fbc43fbf58e1906d262499993e
Author: James Hiebert <hiebert@uvic.ca>
Date: Thu Mar 20 17:40:04 2014 -0700
Added a context manager for all database connections so that they get cleaned up on error
:040000 040000 3d70fded05aa3a94ea02a63aaa6b182347b8454e 55b1005b6e57b2b35b7e5c44ce478234c5d08c8d M pydap
:100644 100644 16c667861a0af38f37b470f9cb9696b79d51275e ea5fedda7326dcf99d2800bedb94f8dd3f516dd5 M setup.py
bisect run success
Success! It turns out that the first commit that is bad, is mine that “[a]dded a context manager for all database connections so that they get cleaned up on error”. So, it looks like I added the context management, but then it doesn’t get used in the testing suite, which broke it. And apparently I never checked, for some weird reason. Crap. Well at least git makes it easy to go back and find your errors when you make them, and know exactly why you made them, rather than just let you wonder in ignorance for the rest of your life.
In short, yay for revision control and git bisect in particular.
blog comments powered by Disqus