hgbook
diff en/undo.tex @ 130:26b7a4e943aa
Describe the bisect extension.
author | Bryan O'Sullivan <bos@serpentine.com> |
---|---|
date | Thu Dec 28 14:06:15 2006 -0800 (2006-12-28) |
parents | 73efa1a01a6c |
children | 153efeaa8f57 |
line diff
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"