1.1 --- a/en/undo.tex	Thu Dec 28 09:56:47 2006 -0800
     1.2 +++ b/en/undo.tex	Thu Dec 28 14:06:15 2006 -0800
     1.3 @@ -454,6 +454,296 @@
     1.4  \texttt{examples} directory works, but doesn't handle merge
     1.5  changesets.  Kind of an important omission.
     1.6  
     1.7 +\section{Finding the source of a bug}
     1.8 +
     1.9 +While it's all very well to be able to back out a changeset that
    1.10 +introduced a bug, this requires that you know which changeset to back
    1.11 +out.  Mercurial provides an invaluable extension, called
    1.12 +\hgext{bisect}, that helps you to automate this process and accomplish
    1.13 +it very efficiently.
    1.14 +
    1.15 +The idea behind the \hgext{bisect} extension is that a changeset has
    1.16 +introduced some change of behaviour that you can identify with a
    1.17 +simple binary test.  You don't know which piece of code introduced the
    1.18 +change, but you know how to test for the presence of the bug.  The
    1.19 +\hgext{bisect} extension uses your test to direct its search for the
    1.20 +changeset that introduced the code that caused the bug.
    1.21 +
    1.22 +Here are a few scenarios to help you understand how you might apply this
    1.23 +extension.
    1.24 +\begin{itemize}
    1.25 +\item The most recent version of your software has a bug that you
    1.26 +  remember wasn't present a few weeks ago, but you don't know when it
    1.27 +  was introduced.  Here, your binary test checks for the presence of
    1.28 +  that bug.
    1.29 +\item You fixed a bug in a rush, and now it's time to close the entry
    1.30 +  in your team's bug database.  The bug database requires a changeset
    1.31 +  ID when you close an entry, but you don't remember which changeset
    1.32 +  you fixed the bug in.  Once again, your binary test checks for the
    1.33 +  presence of the bug.
    1.34 +\item Your software works correctly, but runs~15\% slower than the
    1.35 +  last time you measured it.  You want to know which changeset
    1.36 +  introduced the performance regression.  In this case, your binary
    1.37 +  test measures the performance of your software, to see whether it's
    1.38 +  ``fast'' or ``slow''.
    1.39 +\item The sizes of the components of your project that you ship
    1.40 +  exploded recently, and you suspect that something changed in the way
    1.41 +  you build your project.
    1.42 +\end{itemize}
    1.43 +
    1.44 +From these examples, it should be clear that the \hgext{bisect}
    1.45 +extension is not useful only for finding the sources of bugs.  You can
    1.46 +use it to find any ``emergent property'' of a repository (anything
    1.47 +that you can't find from a simple text search of the files in the
    1.48 +tree) for which you can write a binary test.
    1.49 +
    1.50 +We'll introduce a little bit of terminology here, just to make it
    1.51 +clear which parts of the search process are your responsibility, and
    1.52 +which are Mercurial's.  A \emph{test} is something that \emph{you} run
    1.53 +when \hgext{bisect} chooses a changeset.  A \emph{probe} is what
    1.54 +\hgext{bisect} runs to tell whether a revision is good.  Finally,
    1.55 +we'll use the word ``bisect'', as both a noun and a verb, to stand in
    1.56 +for the phrase ``search using the \hgext{bisect} extension''.
    1.57 +
    1.58 +One simple way to automate the searching process would be simply to
    1.59 +probe every changeset.  However, this scales poorly.  If it took ten
    1.60 +minutes to test a single changeset, and you had 10,000 changesets in
    1.61 +your repository, the exhaustive approach would take on average~35
    1.62 +\emph{days} to find the changeset that introduced a bug.  Even if you
    1.63 +knew that the bug was introduced by one of the last 500 changesets,
    1.64 +and limited your search to those, you'd still be looking at over 40
    1.65 +hours to find the changeset that introduced your bug.
    1.66 +
    1.67 +What the \emph{bisect} extension does is use its knowledge of the
    1.68 +``shape'' of your project's revision history to perform a search in
    1.69 +time proportional to the \emph{logarithm} of the number of changesets
    1.70 +to check (the kind of search it performs is called a dichotomic
    1.71 +search).  With this approach, searching through 10,000 changesets will
    1.72 +take less than two hours, even at ten minutes per test.  Limit your
    1.73 +search to the last 500 changesets, and it will take less than an hour.
    1.74 +
    1.75 +The \hgext{bisect} extension is aware of the ``branchy'' nature of a
    1.76 +Mercurial project's revision history, so it has no problems dealing
    1.77 +with branches, merges, or multiple heads in a repoository.  It can
    1.78 +prune entire branches of history with a single probe, which is how it
    1.79 +operates so efficiently.
    1.80 +
    1.81 +\subsection{Using the \hgext{bisect} extension}
    1.82 +
    1.83 +Here's an example of \hgext{bisect} in action.  To keep the core of
    1.84 +Mercurial simple, \hgext{bisect} is packaged as an extension; this
    1.85 +means that it won't be present unless you explicitly enable it.  To do
    1.86 +this, edit your \hgrc\ and add the following section header (if it's
    1.87 +not already present):
    1.88 +\begin{codesample2}
    1.89 +  [extensions]
    1.90 +\end{codesample2}
    1.91 +Then add a line to this section to enable the extension:
    1.92 +\begin{codesample2}
    1.93 +  hbisect =
    1.94 +\end{codesample2}
    1.95 +\begin{note}
    1.96 +  That's right, there's a ``\texttt{h}'' at the front of the name of
    1.97 +  the \hgext{bisect} extension.  The reason is that Mercurial is
    1.98 +  written in Python, and uses a standard Python package called
    1.99 +  \texttt{bisect}.  If you omit the ``\texttt{h}'' from the name
   1.100 +  ``\texttt{hbisect}'', Mercurial will erroneously find the standard
   1.101 +  Python \texttt{bisect} package, and try to use it as a Mercurial
   1.102 +  extension.  This won't work, and Mercurial will crash repeatedly
   1.103 +  until you fix the spelling in your \hgrc.  Ugh.
   1.104 +\end{note}
   1.105 +
   1.106 +Now let's create a repository, so that we can try out the
   1.107 +\hgext{bisect} extension in isolation.
   1.108 +\interaction{bisect.init}
   1.109 +We'll simulate a project that has a bug in it in a simple-minded way:
   1.110 +create trivial changes in a loop, and nominate one specific change
   1.111 +that will have the ``bug''.  This loop creates 50 changesets, each
   1.112 +adding a single file to the repository.  We'll represent our ``bug''
   1.113 +with a file that contains the text ``i have a gub''.
   1.114 +\interaction{bisect.commits}
   1.115 +
   1.116 +The next thing that we'd like to do is figure out how to use the
   1.117 +\hgext{bisect} extension.  We can use Mercurial's normal built-in help
   1.118 +mechanism for this.
   1.119 +\interaction{bisect.help}
   1.120 +
   1.121 +The \hgext{bisect} extension works in steps.  Each step proceeds as follows.
   1.122 +\begin{enumerate}
   1.123 +\item You run your binary test.
   1.124 +  \begin{itemize}
   1.125 +  \item If the test succeeded, you tell \hgext{bisect} by running the
   1.126 +    \hgcmdargs{bisect}{good} command.
   1.127 +  \item If it failed, use the \hgcmdargs{bisect}{bad} command to let
   1.128 +    the \hgext{bisect} extension know.
   1.129 +  \end{itemize}
   1.130 +\item The extension uses your information to decide which changeset to
   1.131 +  test next.
   1.132 +\item It updates the working directory to that changeset, and the
   1.133 +  process begins again.
   1.134 +\end{enumerate}
   1.135 +The process ends when \hgext{bisect} identifies a unique changeset
   1.136 +that marks the point where your test transitioned from ``succeeding''
   1.137 +to ``failing''.
   1.138 +
   1.139 +To start the search, we must run the \hgcmdargs{bisect}{init} command.
   1.140 +\interaction{bisect.search.init}
   1.141 +
   1.142 +In our case, the binary test we use is simple: we check to see if any
   1.143 +file in the repository contains the string ``i have a gub''.  If it
   1.144 +does, this changeset contains the change that ``caused the bug''.  By
   1.145 +convention, a changeset that has the property we're searching for is
   1.146 +``bad'', while one that doesn't is ``good''.
   1.147 +
   1.148 +Most of the time, the revision to which the working directory is
   1.149 +synced (usually the tip) already exhibits the problem introduced by
   1.150 +the buggy change, so we'll mark it as ``bad''.
   1.151 +\interaction{bisect.search.bad-init}
   1.152 +
   1.153 +Our next task is to nominate a changeset that we know \emph{doesn't}
   1.154 +have the bug; the \hgext{bisect} extension will ``bracket'' its search
   1.155 +between the first pair of good and bad changesets.  In our case, we
   1.156 +know that revision~10 didn't have the bug.  (I'll have more words
   1.157 +about choosing the first ``good'' changeset later.)
   1.158 +\interaction{bisect.search.good-init}
   1.159 +
   1.160 +Notice that this command printed some output.
   1.161 +\begin{itemize}
   1.162 +\item It told us how many changesets it must consider before it can
   1.163 +  identify the one that introduced the bug, and how many tests that
   1.164 +  will require.
   1.165 +\item It updated the working directory to the next changeset to test,
   1.166 +  and told us which changeset it's testing.
   1.167 +\end{itemize}
   1.168 +
   1.169 +We now run our test in the working directory.  We use the
   1.170 +\command{grep} command to see if our ``bad'' file is present in the
   1.171 +working directory.  If it is, this revision is bad; if not, this
   1.172 +revision is good.
   1.173 +\interaction{search.step1}
   1.174 +
   1.175 +This test looks like a perfect candidate for automation, so let's turn
   1.176 +it into a shell function.
   1.177 +\interaction{search.mytest}
   1.178 +We can now run an entire test step with a single command,
   1.179 +\texttt{mytest}.
   1.180 +\interaction{search.step2}
   1.181 +A few more invocations of our canned test step command, and we're
   1.182 +done.
   1.183 +\interaction{search.rest}
   1.184 +
   1.185 +Even though we had~40 changesets to search through, the \hgext{bisect}
   1.186 +extension let us find the changeset that introduced our ``bug'' with
   1.187 +only five tests.  Because the number of tests that the \hgext{bisect}
   1.188 +extension grows logarithmically with the number of changesets to
   1.189 +search, the advantage that it has over the ``brute force'' search
   1.190 +approach increases with every changeset you add.
   1.191 +
   1.192 +\subsection{Cleaning up after your search}
   1.193 +
   1.194 +When you're finished using the \hgext{bisect} extension in a
   1.195 +repository, you can use the \hgcmdargs{bisect}{reset} command to drop
   1.196 +the information it was using to drive your search.  The extension
   1.197 +doesn't use much space, so it doesn't matter if you forget to run this
   1.198 +command.  However, \hgext{bisect} won't let you start a new search in
   1.199 +that repository until you do a \hgcmdargs{bisect}{reset}.
   1.200 +\interaction{search.reset}
   1.201 +
   1.202 +\section{Tips for finding bugs effectively}
   1.203 +
   1.204 +\subsection{Give consistent input}
   1.205 +
   1.206 +The \hgext{bisect} extension requires that you correctly report the
   1.207 +result of every test you perform.  If you tell it that a test failed
   1.208 +when it really succeeded, it \emph{might} be able to detect the
   1.209 +inconsistency.  If it can identify an inconsistency in your reports,
   1.210 +it will tell you that a particular changeset is both good and bad.
   1.211 +However, it can't do this perfectly; it's about as likely to report
   1.212 +the wrong changeset as the source of the bug.
   1.213 +
   1.214 +\subsection{Automate as much as possible}
   1.215 +
   1.216 +When I started using the \hgext{bisect} extension, I tried a few times
   1.217 +to run my tests by hand, on the command line.  This is an approach
   1.218 +that I, at least, am not suited to.  After a few tries, I found that I
   1.219 +was making enough mistakes that I was having to restart my searches
   1.220 +several times before finally getting correct results.  
   1.221 +
   1.222 +My initial problems with driving the \hgext{bisect} extension by hand
   1.223 +occurred even with simple searches on small repositories; if the
   1.224 +problem you're looking for is more subtle, or the number of tests that
   1.225 +\hgext{bisect} must perform increases, the likelihood of operator
   1.226 +error ruining the search is much higher.  Once I started automating my
   1.227 +tests, I had much better results.
   1.228 +
   1.229 +The key to automated testing is twofold:
   1.230 +\begin{itemize}
   1.231 +\item always test for the same symptom, and
   1.232 +\item always feed consistent input to the \hgcmd{bisect} command.
   1.233 +\end{itemize}
   1.234 +In my tutorial example above, the \command{grep} command tests for the
   1.235 +symptom, and the \texttt{if} statement takes the result of this check
   1.236 +and ensures that we always feed the same input to the \hgcmd{bisect}
   1.237 +command.  The \texttt{mytest} function marries these together in a
   1.238 +reproducible way, so that every test is uniform and consistent.
   1.239 +
   1.240 +\subsection{Check your results}
   1.241 +
   1.242 +Because the output of a \hgext{bisect} search is only as good as the
   1.243 +input you give it, don't take the changeset it reports as the
   1.244 +absolute truth.  A simple way to cross-check its report is to manually
   1.245 +run your test at each of the following changesets:
   1.246 +\begin{itemize}
   1.247 +\item The changeset that it reports as the first bad revision.  Your
   1.248 +  test should still report this as bad.
   1.249 +\item The parent of that changeset (either parent, if it's a merge).
   1.250 +  Your test should report this changeset as good.
   1.251 +\item A child of that changeset.  Your test should report this
   1.252 +  changeset as bad.
   1.253 +\end{itemize}
   1.254 +
   1.255 +\subsection{Beware interference between bugs}
   1.256 +
   1.257 +It's possible that your search for one bug could be disrupted by the
   1.258 +presence of another.  For example, let's say your software crashes at
   1.259 +revision 100, and worked correctly at revision 50.  Unknown to you,
   1.260 +someone else introduced a different crashing bug at revision 60, and
   1.261 +fixed it at revision 80.  This could distort your results in one of
   1.262 +several ways.
   1.263 +
   1.264 +It is possible that this other bug completely ``masks'' yours, which
   1.265 +is to say that it occurs before your bug has a chance to manifest
   1.266 +itself.  If you can't avoid that other bug (for example, it prevents
   1.267 +your project from building), and so can't tell whether your bug is
   1.268 +present in a particular changeset, the \hgext{bisect} extension cannot
   1.269 +help you directly.  Instead, you'll need to manually avoid the
   1.270 +changesets where that bug is present, and do separate searches
   1.271 +``around'' it.
   1.272 +
   1.273 +A different problem could arise if your test for a bug's presence is
   1.274 +not specific enough.  If you checks for ``my program crashes'', then
   1.275 +both your crashing bug and an unrelated crashing bug that masks it
   1.276 +will look like the same thing, and mislead \hgext{bisect}.
   1.277 +
   1.278 +\subsection{Bracket your search lazily}
   1.279 +
   1.280 +Choosing the first ``good'' and ``bad'' changesets that will mark the
   1.281 +end points of your search is often easy, but it bears a little
   1.282 +discussion neverthheless.  From the perspective of \hgext{bisect}, the
   1.283 +``newest'' changeset is conventionally ``bad'', and the older
   1.284 +changeset is ``good''.
   1.285 +
   1.286 +If you're having trouble remembering when a suitable ``good'' change
   1.287 +was, so that you can tell \hgext{bisect}, you could do worse than
   1.288 +testing changesets at random.  Just remember to eliminate contenders
   1.289 +that can't possibly exhibit the bug (perhaps because the feature with
   1.290 +the bug isn't present yet) and those where another problem masks the
   1.291 +bug (as I discussed above).
   1.292 +
   1.293 +Even if you end up ``early'' by thousands of changesets or months of
   1.294 +history, you will only add a handful of tests to the total number that
   1.295 +\hgext{bisect} must perform, thanks to its logarithmic behaviour.
   1.296 +
   1.297  %%% Local Variables: 
   1.298  %%% mode: latex
   1.299  %%% TeX-master: "00book"