Debugging cabal-install and Cabal with ghci 6.7

[Pepe Iborra]

Simon (and whom ever is interested)
As promised, here go the details of my debugging session with Cabal.

I was updating cabal-install to use Distribution.Verbosity,
and as I was finishing I hit a bug, either in cabal-install or Cabal.
This happened while I was asking my modified cabal-install to
install a random library for me, in this case Lemmih's xslt binding,  
for me.

$ cabal-install install xslt
ghc-6.7.20070520: malformed integer argument in -vNormal

Usage: For basic information, try the `--help' option.
*** Exception: exit: ExitFailure 1

Since I'm not a contributor to either of two projects, I don't know  
how things work in
the insides. I decided this was a great chance to use the debugger.

Firstly I loaded cabal-install in GHCi in the obvious way.
I first tried to capture the exception in a breakpoint with :trace plus
-fbreak-on-exception, and go back in the lazy trace from there  
using :history,
which has worked wonders for me so far with bugs of the type head of  
empty list.
Unfortunately that didn't work very well this time. For the record,
I used this macro to launch main, with arguments, under :trace

let ss args  = concat $ Data.List.intersperse "," (map (\ s -> ('"':s) 
++"\"") (words args))
:def maintraced \args -> return (":trace " ++ '[': ss args ++ "]  
`System.Environment.withArgs` main")

And then launched cabal-install from the GHCi command line with the  
command

:maintraced install xslt

What happened is that GHCi started to interrupt on all sorts of  
exceptions
that I wasn't interested in.
It turns out that these exceptions were not actually uncaught, but still
the debugger would interrupt at them; as you told me there are still  
some
issues with -fbreak-on-exception.

I decided to try another route and use manual breakpoints instead.
So I made a guess and put a breakpoint approximately near the bug  
source, by
line, and :step'ped from there. I'd have done it by function name,  
which is the most
convenient way for setting breakpoints, but unfortunately this name  
was not
in scope (it looks like only module exported names are available, is  
this by
design or a bug?).

This worked pretty well. I used :step in combination with :list  
thanks to
this macro that you suggested which lives now in my .ghci

:set stop :list

:list is awesome, but I hit this bug in GHCi itself with :list and  
paths. It was
easy to fix -and yes, I tried and did load ghc itself in the  
debugger, but
that's a tale for another day- and I continued my debugging adventures.
In a few :step's I found the offending call. Turns out the bug was in  
Cabal
Distribution.SetupWrapper.setupWrapper function, which was being  
called from
cabal-install, and since it is not possible to put breakpoints in  
library
code, I needed to load Cabal in GHCi. That was not a problem at all, but
note that I had two options here:

a) Load cabal-install _plus_ Cabal in GHCi, using an include option  
pointing
    to the folder with Cabal sources
b) Load only Cabal and call setupWrapper myself with the same arguments

I guess a) would be the right thing in general, but in this case I opted
for b). So before leaving
I :print'ed the values of the arguments. By the way, no need to use type
reconstruction at all in this real life example. All the bindings were
monomorphic most of the time, lots of type signatures in the Cabal and
cabal-install sources. Hell, I know it is a good practice, but after  
so much
work on :print I was almost angry at those type signatures! :)

I loaded Cabal in GHCi, set my breakpoint in setupWrapper (by now I  
had a
pretty good idea of where the bug was, but I wanted to keep going  
till the
end). I again tried to use -fbreak-on-exception but unfortunately had
the same issues. It looks like there is some piece of code
(using System.Directory.withFileStatus perhaps?) that when asked
to find a file in the PATH, works by trying every path component and  
just
handling the raised exception in case of failure, but -fbreak-on- 
exception
was capturing that exception nonetheless.

So all in all, I couldn't really succeed with -fbreak-on-exception in  
the
whole session. Finding the bug however proceeded very easily anyway  
using :step's.
Now that I think, I could have
used the trick of approximating a breakpoint which I know is _after_ the
problematic exceptions code, stopped there, enabled
-fbreak-on-exception at that point, and continued with :trace.


Lessons learned:

a) If technically possible, we really must have -fbreak-on-exception
    at any cost :)
b) :history works wonders too, but perhaps storing only applications  
would
    make it more agile. Worth a try?
c) Real Life code is much less intrincate than we had expected! No HOF
    debugging, no multiple threads, no polymorphic bindings, no  
existentials,
    circular structures,
    unboxed values, template haskell or younameit involved! (just  
kidding)
    This was a reassuring experience that the debugger will break  
less than
    expected. In retrospect, I must say that this was a rather simple
    debugging session.
d) The debugger is easily usable at this point. There are still some  
wibbles
    and details to improve, but things are looking really really nice.
e) To me, it looks like the debugger will become a really useful  
tool, but
    I am biased :)

A list of wibbles:

- Autocompletion for :break only provides names, not modules
- :break <functionName> only works for exported names
- :history could show the top level name for each row


I include some logs of the whole experience below, for the curious. A
1280x1024 terminal is advised ;)

Notes for the session below:
* I loaded both cabal-install and Cabal in ghci doing option a) above  
for the logs
* Failed attempts with -fbreak-on-exception removed
* I used the trick of enabling -fbreak-on-exception after the exception
   raising code.
* Those lines of code look really much prettier in my console, with  
the current
   subexpression highlighted.


pep:~/scratch/cabal-install$ ghci -isrc  
Network.Hackage.CabalInstall.Main -idist/build/autogen -idependencies/ 
HTTP-2006.7.7/ -i../Cabal.work
    ___         ___ _
   / _ \ /\  /\/ __(_)
/ /_\// /_/ / /  | |    GHC Interactive, version 6.7.20070520, for  
Haskell 98.
/ /_\\/ __  / /___| |    http://www.haskell.org/ghc/
\____/\/ /_/\____/|_|    Type :? for help.

Loading package base ... linking ... done.
[ 1 of 55] Compiling Network.Stream   ( dependencies/HTTP-2006.7.7// 
Network/Stream.hs, interpreted )
..
..
[55 of 55] Compiling Network.Hackage.CabalInstall.Main ( src/Network/ 
Hackage/CabalInstall/Main.hs, interpreted )
Ok, modules loaded: Distribution.Compiler,  
Distribution.InstalledPackageInfo, Distribution.License,  
Distribution.Make, Distribution.Program, Distribution.Package,  
Distribution.PackageDescription, Distribution.ParseUtils,  
Distribution.PreProcess, Distribution.PreProcess.Unlit,  
Distribution.Setup, Distribution.SetupWrapper, Distribution.Simple,  
Distribution.Simple.Build, Distribution.Simple.Configure,  
Distribution.Simple.GHC, Distribution.Simple.GHCPackageConfig,  
Distribution.Simple.Hugs, Distribution.Simple.Install,  
Distribution.Simple.JHC, Distribution.Simple.LocalBuildInfo,  
Distribution.Simple.NHC, Distribution.Simple.Register,  
Distribution.Simple.SrcDist, Distribution.Simple.Utils,  
Distribution.Verbosity, Distribution.Version,  
Distribution.Compat.ReadP, Language.Haskell.Extension,  
Distribution.Compat.FilePath, Distribution.GetOpt,  
Distribution.Compat.Map, Distribution.Compat.Directory,  
Distribution.Compat.Exception, Distribution.Compat.RawSystem,  
Distribution.Compat.TempFile, Network.Hackage.CabalInstall.Main,  
Network.Hackage.CabalInstall.BuildDep,  
Network.Hackage.CabalInstall.Types,  
Network.Hackage.CabalInstall.Install,  
Network.Hackage.CabalInstall.TarUtils,  
Network.Hackage.CabalInstall.Fetch,  
Network.Hackage.CabalInstall.Dependency,  
Network.Hackage.CabalInstall.Config, Paths_cabal_install,  
Network.HTTP, Network.TCP, Network.Stream,  
Network.Hackage.CabalInstall.Clean,  
Network.Hackage.CabalInstall.Update,  
Network.Hackage.CabalInstall.Utils,  
Network.Hackage.CabalInstall.Info, Network.Hackage.CabalInstall.List,  
Network.Hackage.CabalInstall.Configure,  
Network.Hackage.CabalInstall.Setup.

*Network.Hackage.CabalInstall.Main> :main install xslt
Loading package filepath-1.0 ... linking ... done.
..
..
Loading package regex-compat-0.71 ... linking ... done.

configure: Reading installed packages...
'libxml-0.1' is present.
Building 'libxml-0.1'
   Configuring...
ghc-6.7.20070520: malformed integer argument in -vNormal

Usage: For basic information, try the `--help' option.
*** Exception: exit: ExitFailure 1

*Network.Hackage.CabalInstall.Main> :break  
Network.Hackage.CabalInstall.Install 108
Breakpoint 0 activated at src/Network/Hackage/CabalInstall/Install.hs: 
108:25-61

*Network.Hackage.CabalInstall.Main> :main install xslt
configure: Reading installed packages...
'libxml-0.1' is present.
Building 'libxml-0.1'
   Configuring...
Stopped at src/Network/Hackage/CabalInstall/Install.hs:108:25-61
_result :: IO ()
path :: FilePath
cmd :: String
cmdOps :: [String]
107                                   unwords ["setupWrapper", show  
(cmd:cmdOps), show path]
108                           setupWrapper (cmd:cmdOps) (Just path)
109           bracket_ (createDirectoryIfMissing True tmpDirPath)

[src/Network/Hackage/CabalInstall/Install.hs:108:25-61]  
*Network.Hackage.CabalInstall.Main> :p cmd
cmd = (_t1::String)
[src/Network/Hackage/CabalInstall/Install.hs:108:25-61]  
*Network.Hackage.CabalInstall.Main> :force cmd
cmd = "configure"
[src/Network/Hackage/CabalInstall/Install.hs:108:25-61]  
*Network.Hackage.CabalInstall.Main> :force cmdOps
cmdOps = ["--verbose=1","--user","--prefix=/Users/pep/usr"]
[src/Network/Hackage/CabalInstall/Install.hs:108:25-61]  
*Network.Hackage.CabalInstall.Main> :force path
path = "/tmp/TMPlibxml-0.1TMP/libxml-0.1"
[src/Network/Hackage/CabalInstall/Install.hs:108:25-61]  
*Network.Hackage.CabalInstall.Main> :continue
ghc-6.7.20070520: malformed integer argument in -vNormal

Usage: For basic information, try the `--help' option.
*** Exception: exit: ExitFailure 1

*Network.Hackage.CabalInstall.Main> :break Distribution.SetupWrapper 81
*Network.Hackage.CabalInstall.Main> :delete 0
*Network.Hackage.CabalInstall.Main> :main install xslt
configure: Reading installed packages...
'libxml-0.1' is present.
Building 'libxml-0.1'
   Configuring...
Stopped at ../Cabal.work/Distribution/SetupWrapper.hs:81:14-30
_result :: FilePath
comp :: Distribution.Compiler.Compiler
80             rawSystemExit (verbosity flags)
81               (compilerPath comp)
82               (cabal_flag ++
[../Cabal.work/Distribution/SetupWrapper.hs:81:14-30]  
*Network.Hackage.CabalInstall.Main> :set -fbreak-on-exception
[../Cabal.work/Distribution/SetupWrapper.hs:81:14-30]  
*Network.Hackage.CabalInstall.Main> :trace
ghc-6.7.20070520: malformed integer argument in -vNormal

Usage: For basic information, try the `--help' option.
Stopped at <exception thrown>
_exception :: e
unable to list source for <exception thrown>
[<exception thrown>] *Network.Hackage.CabalInstall.Main> :history
-1  : ../Cabal.work/Distribution/Simple/Utils.hs:144:32-43
-2  : ../Cabal.work/Distribution/Simple/Utils.hs:144:10-27
-3  : ../Cabal.work/Distribution/Simple/Utils.hs:144:2-28
-4  : ../Cabal.work/Distribution/Simple/Utils.hs:144:2-43
-5  : ../Cabal.work/Distribution/SetupWrapper.hs:83:55-69
-6  : ../Cabal.work/Distribution/Verbosity.hs:51:5-13
-7  : ../Cabal.work/Distribution/SetupWrapper.hs:83:49-70
-8  : ../Cabal.work/Distribution/SetupWrapper.hs:83:43-70
-9  : ../Cabal.work/Distribution/SetupWrapper.hs:(82,14)-(83,71)
-10 : ../Cabal.work/Distribution/Simple/Configure.hs:(398,15)-(401,26)
<end of history>
[<exception thrown>] *Network.Hackage.CabalInstall.Main> :back
Logged breakpoint at ../Cabal.work/Distribution/Simple/Utils.hs: 
144:32-43
_result :: IO ()
res :: GHC.IOBase.ExitCode
143    res <- cmd
144    unless (res == ExitSuccess) $ exitWith res
145
[-1: ../Cabal.work/Distribution/Simple/Utils.hs:144:32-43]  
*Network.Hackage.CabalInstall.Main> :back
Logged breakpoint at ../Cabal.work/Distribution/Simple/Utils.hs: 
144:10-27
_result :: Bool
res :: GHC.IOBase.ExitCode
143    res <- cmd
144    unless (res == ExitSuccess) $ exitWith res
145
[-2: ../Cabal.work/Distribution/Simple/Utils.hs:144:10-27]  
*Network.Hackage.CabalInstall.Main> :back
Logged breakpoint at ../Cabal.work/Distribution/Simple/Utils.hs:144:2-28
_result :: IO () -> IO ()
res :: GHC.IOBase.ExitCode
143    res <- cmd
144    unless (res == ExitSuccess) $ exitWith res
145
[-3: ../Cabal.work/Distribution/Simple/Utils.hs:144:2-28]  
*Network.Hackage.CabalInstall.Main> :back
Logged breakpoint at ../Cabal.work/Distribution/Simple/Utils.hs:144:2-43
_result :: IO ()
res :: GHC.IOBase.ExitCode
143    res <- cmd
144    unless (res == ExitSuccess) $ exitWith res
145
[-4: ../Cabal.work/Distribution/Simple/Utils.hs:144:2-43]  
*Network.Hackage.CabalInstall.Main> :back
Logged breakpoint at ../Cabal.work/Distribution/SetupWrapper.hs:83:55-69
_result :: Distribution.Verbosity.Verbosity
flags :: Distribution.SetupWrapper.Flags
82               (cabal_flag ++
83                ["--make", f, "-o", "setup", "-v"++show (verbosity  
flags)])
84           rawSystemExit (verbosity flags)
[-5: ../Cabal.work/Distribution/SetupWrapper.hs:83:55-69]  
*Network.Hackage.CabalInstall.Main> _result
Normal
[-5: ../Cabal.work/Distribution/SetupWrapper.hs:83:55-69]  
*Network.Hackage.CabalInstall.Main> show it
"Normal"
[-5: ../Cabal.work/Distribution/SetupWrapper.hs:83:55-69]  
*Network.Hackage.CabalInstall.Main>