- 12.1 Understanding
- 12.2 Defects
- 12.3 Bisection
- 12.4 Conclusion
This chapter is from the book
This chapter is from the book
This chapter is from the book
12.3 Bisection
Some defects can be elusive. When I developed the restaurant system I ran into one that took me most of a day to understand. After wasting hours following several false leads, I finally realised that I couldn’t crack the nut only by staring long enough at the code. I had to use a method.
Fortunately, such a method exists. We can call it bisection for lack of a better word. In all its simplicity, it works like this:
Find a way to detect or reproduce the problem.
Remove half of the code.
If the problem is still present, repeat from step 2. If the problem goes away, restore the code you removed, and remove the other half. Again, repeat from step 2.
Keep going until you’ve whittled down the code that reproduces the problem to a size so small that you understand what’s going on.
You can use an automated test to detect the problem, or use some ad hoc way to detect whether the problem is present or absent. The exact way you do this doesn’t matter for the technique, but I find that an automated test is often the easiest way to go about it, because of the repetition involved.
I often use this technique when I rubber duck by writing a question on Stack Overflow. Good questions on Stack Overflow should come with a minimal working example. In most cases I find that the process of producing the minimal working example is so illuminating that I get unstuck before I have a chance to post the question.
12.3.1 Bisection with Git
You can also use the bisection technique with Git to identify the commit that introduced the defect. I ultimately used that with the problem I ran into.
I’d added a secure resource to the REST API to list the schedule for a particular day. A restaurant’s maître d’ can make a GET request against that resource to see the schedule for the day, including all reservations and who arrives when. The schedule includes names and emails of guests, so it shouldn’t be available without authentication and authorisation13.
This particular resource demands that a client presents a valid JSON Web Token (JWT). I’d developed this security feature with test-driven development and I had enough tests to feel safe.
Then one day, as I was interacting with the deployed REST API, I could no longer access this resource! I first thought that I’d supplied an invalid JWT, so I wasted hours troubleshooting that. Dead end.
It finally dawned on me that this security feature had worked. I’d interacted with the deployed REST API earlier and seen it work. At one time it worked, and now it didn’t. In between these two known states a commit must have introduced the defect. If I could identify that particular code change, I might have a better chance of understanding the problem.
Unfortunately, there was some 130 commits between those two extremes.
Fortunately, I’d found an easy way to detect the problem, if given a commit.
This meant that I could use Git’s bisect feature to identify the exact commit that caused the problem.
Git can run an automated bisection for you if you have an automated way to detect the problem. Usually, you don’t. When you bisect, you’re looking for a commit that introduced a defect that went unnoticed at the time. This means that even if you have an automated test suite, the tests didn’t catch that bug.
For that reason, Git can also bisect your commits in an interactive session. You start such a session with git bisect start, as shown in listing 12.9.
Listing 12.9 The start of a Git bisect session. I ran it from Bash, but you can run it in any shell where you use Git. I’ve edited the terminal output by removing irrelevant data that Bash tends to show, so that it fits on the page.
~/Restaurant ((56a7092...)) $ git bisect start ~/Restaurant ((56a7092...)|BISECTING)
This starts an interactive session, which you can tell from the Git integration in Bash (it says BISECTING). If the current commit exhibits the defect you’re investigating, you mark it as shown in listing 12.10
Listing 12.10 Marking a commit as bad in a bisect session.
$ git bisect bad ~/Restaurant ((56a7092...)|BISECTING)
If you don’t provide a commit ID, Git is going to assume that you meant the current commit (in this case 56a7092).
You now tell it about a commit ID that you know is good. This is the other extreme of the range of commits you’re investigating. Listing 12.11 shows how that’s done.
Listing 12.11 Marking a commit as good in a bisect session. I’ve trimmed the output a little to make it fit on the page.
$ git bisect good 58fc950 Bisecting: 75 revisions left to test after this (roughly 6 steps) [3035c14...] Use InMemoryRestaurantDatabase in a test ~/Restaurant ((3035c14...)|BISECTING)
Notice that Git is already telling you how many iterations to expect. You can also see that it checked out a new commit (3035c14) for you. That’s the half-way commit.
You now have to check whether or not the defect is present in this commit. You can run an automated test, start the system, or any other way you’ve identified to answer that question.
In my particular case, the half-way commit didn’t have the defect, so I told Git, as shown in listing 12.12.
Listing 12.12 Marking the half-way commit as good in a bisect session. I’ve trimmed the output a little to make it fit on the page.
$ git bisect good Bisecting: 37 revisions left to test after this (roughly 5 steps) [aa69259...] Delete Either API ~/Restaurant ((aa69259...)|BISECTING)
Again, Git estimates how many more steps are left and checks out a new commit (aa69259).
Listing 12.13 Finding the commit responsible for the defect, using a Git bisect session.
$ git bisect bad Bisecting: 18 revisions left to test after this (roughly 4 steps) [75f3c56...] Delete redundant Test Data Builders ~/Restaurant ((75f3c56...)|BISECTING) $ git bisect good Bisecting: 9 revisions left to test after this (roughly 3 steps) [8f93562...] Extract WillAcceptUpdate helper method ~/Restaurant ((8f93562...)|BISECTING) $ git bisect good Bisecting: 4 revisions left to test after this (roughly 2 steps) [1c6fae1...] Extract ConfigureClock helper method ~/Restaurant ((1c6fae1...)|BISECTING) $ git bisect good Bisecting: 2 revisions left to test after this (roughly 1 step) [8e1f1ce] Compact code ~/Restaurant ((8e1f1ce...)|BISECTING) $ git bisect good Bisecting: 0 revisions left to test after this (roughly 1 step) [2563131] Extract CreateTokenValidationParameters method ~/Restaurant ((2563131...)|BISECTING) $ git bisect bad Bisecting: 0 revisions left to test after this (roughly 0 steps) [fa0caeb...] Move Configure method up ~/Restaurant ((fa0caeb...)|BISECTING) $ git bisect good 2563131c2d06af8e48f1df2dccbf85e9fc8ddafc is the first bad commit commit 2563131c2d06af8e48f1df2dccbf85e9fc8ddafc Author: Mark Seemann <mark@example.com> Date: Wed Sep 16 07:15:12 2020 +0200 Extract CreateTokenValidationParameters method Restaurant.RestApi/Startup.cs | 32 +++++++++++++++++++------------- 1 file changed, 19 insertions(+), 13 deletions(-) ~/Restaurant ((fa0caeb...)|BISECTING)
I repeated the process for each step, marking the commit as either good or bad, depending on whether or not my verification step passed. This is shown in listing 12.13.
After just eight iterations, Git found the commit responsible for the defect. Notice that the last step tells you which commit is the ‘first bad commit’.
Once I saw the contents of the commit, I immediately knew what the problem was and could easily fix it. I’m not going to tire you with a detailed description of the error, or how I fixed it. If you’re interested, I wrote a blog post [101] with all the details, and you can also peruse the Git repository that accompanies the book.
The bottom line is that bisection is a potent technique for finding and isolating the source of an error. You can use it with or without Git.