my experience with ghci debugger extensions

[Pepe Iborra]

Hello Peter,

Your efforts are simply outstanding. Thanks a lot for sharing your
experiences. I want to add a few comments:

- Regarding your :logLocal, you should rename it to :stepLocal, open a
ticket, and attach your patch. We should really try to get this into
6.10.2.
  :stepLocal is broken right now, as you say it traces a lot of
garbage. I implemented it and shortly later
  noticed the problem you mention, but never got around to fixing it.
Thanks for shouting.
  (unless you think it makes sense to keep two versions of this
command, :logLocal and :stepLocal)

- Your idea of forcing _result to implement step over is very nice.
  A while ago I tried and failed at implementing :next. The conclusion
was it cannot be done without a lexical call stack.
  Your idea could be useful as a pseudo :next, as long as the user of
the debugger is ok with changing the evaluation semantics of the
program. However, I don't know if there is a fix for the _result bug
at hand's reach.

I look forward to playing this.
Your custom ghc tar.gz file contains an additional patch,
network.patch, but there are no instructions about it. I assume it is
ok to ignore it.
I applied the two other patches succesfully and hopefully in a few
minutes will have a working build.
Evidently this is a suboptimal way to distribute your changes. If GHCi
lived in its own package as a real GHC api client, it would certainly
be much easier to distribute modifications like these.Although it
would not have helped in this occasion: the changes you needed
required modifying the API.

Finallly, please do not forget to add a link to this in the GHCi
Debugger wiki page at

http://haskell.org/haskellwiki/GHC/GHCi_debugger

and/or at the debugging page at

http://haskell.org/haskellwiki/Debugging

Thanks,
pepe


2009/2/5 Peter Hercek <phercek at gmail.com>:
> Hi users of ghci debugger,
>
> This post is going to be a bit longer. Here are few cookies to motivate you
> to go on:
> * you will probably like it more than printf debugging for a lot of cases
> * it can provide a way of implementing Claus Reinke's idea of breakpoints
> with a list of identifiers which should be available at breakpoint location
> and doing it without recompilation; here is the link to Claus' message:
> http://permalink.gmane.org/gmane.comp.lang.haskell.glasgow.user/15900
> * it gives some idea to ghc team about importance of ghci debugger related
> tickets (and whether to implement them just the way they were proposed)
>
> A note to ghc developers: Stepping program in ghci debugger sometimes purges
> top level bindings and sometimes not. Not sure this is a bug or feature
> (whether there is some logic in it). I do not have a simple example when it
> purges the bindings. But I did not really look for one.
>
> I would probably post later, but some ghci bugs and missing features are
> badly limiting my progress. There is not much more I can think of to
> investigate. Maybe somebody will have better ideas how to solve the
> obstacles I'm hitting. I'm also posting with hope that people will find this
> interesting and ghc team will fix some of the critical bugs and adds the
> most critical features, especially if somebody will not have better
> debugging tips.
>
> You can get my extensions here:
> http://www.hck.sk/users/peter/pub/ghciext-0.1.tar.gz
> The extensions are not in a single .ghci file now. The new .ghci file needs
> to install a library. The reason is that without the library it is not
> manageable any more.
>
> And here are arch linux packaging instructions for my custom ghc (if you are
> an arch linux user just download and run makepkg :) ):
> http://www.hck.sk/users/peter/pub/ghc-custom-6.10.1.tar.gz
> The custom ghc is just the same one as ghc 6.10.1 with two more patches:
> t2740.patch and loglocal.patch. The first one fixes ticket 2740 and you will
> get it in 6.10.2. The second one adds :loglocal command to ghci. You can
> extract the patches from the tar file.
>
> If you already read ghci scripting tutorial from Claus Reinke then you will
> know how to customize ghciext (that is if you would feel like doing so). The
> tutorial is here:
> http://www.haskell.org/pipermail/haskell-cafe/2007-September/032260.html
>
> Here is the list of custom commands in ghciext package:
> :defs                     -- list user-defined commands
> :. <file>                 -- source commands from <file>
> :redir <var> <cmd>...     -- execute <cmd> redirecting stdout to <var>
> :grep <pat> <cmd>...      -- filter lines matching <pat> from <cmd> output
> :* <count> <cmd>...       -- run <cmd> <count> times
> :x <cmd>...               -- run <cmd> with stdout suppressed
> :bp <bpArgs>              -- put breakpoint at location <bpArgs> (adds hit
> count)
> :inject <cc> <c> <sc> <b> -- at location <b> execute <c> if <cc>, and stop
> if <sc>
> :monitor ["<c>"] <vs> <b> -- show comma separated variables at location <b>
> if <c>
> :watch <cond> <bpArgs>    -- break at location <bpArgs> when <cond> is True
> :count (_|<N>) [<bpArgs>] -- count/query/stop execution at location <bpArgs>
> :find <var> <cmd>...      -- step with <cmd> until <var> is found
> :findex <str> <cmd>...    -- step with <cmd> until <str> is found
> :next [lazy]              -- step over; lazy version forces only the top
> constructor
> :xout                     -- redirect ghci stdout to /dev/null
> :out                      -- redirect ghci stdout back to console
>
> :defs, :., :redir, :grep, are the same as the commands in Claus' tutorial.
> The only differences I recall now are:
>  * grep pattern can be in quotation marks (easier search for spaces)
>  * grep merges :browse output more nicely
>  * redir can accept :step, :steplocal etc; i.e. also the commands which
> sometimes remove top level bindings
>  * the commands do not pollute top level bindings so much
>
> The rest will describe my custom commands and now they relate to tickets in
> ghci track. If you want to check the tickets mentioned here then the most
> easy way is probably selecting them from this list:
> http://hackage.haskell.org/trac/ghc/search?q=phercek&noquickjump=1&ticket=on
>
> The initial big problem was how to limit the amount of information ghci
> debugger spits at you when breakpoints with custom scripts are used. This is
> also mentioned in forth point of the "unknown" section of ticket #1377:
> We can disable a breakpoint with ":set stop N :continue", but this still
> prints out the breakpoint info when we stop. Should we print the info only
> if there were no commands?
> So I say: yes do it! Just disable any ghci output related to a breakpoint
> when the breakpoint has a custom code attached. We can disable the output
> ourselves, but then we disable all the output (including the output of the
> debugged program). People who are debugging console applications are busted
> (especially if the applications are interactive). This is not an issue for
> me since my application is not using console almost at all. I'm solving the
> problem by prefixing commands like :main and :continue with my command :x.
> This makes output by default disabled and ghciExt enables it just before a
> breakpoint code is run. If the breakpoint continues execution it disables it
> again. If the debugged function finishes the output is enabled by :x itself.
> A small problem happens when you forget to use :x e.g. with your :main. Then
> you do not get a prompt when the program finishes. It's time to notice it
> and use :out to switch it on. This is the only minor disadvantage for a gui
> application debugging. :xout in not that useful (it is mostly used
> internally by :x). It could be a hidden command (i.e. not registered in
> defs).
>
> Now when we have ghci "muted" we can get to real goodies: :monitor, :watch,
> and :count.
> If you like printf debugging, then :monitor can help you. It can monitor
> only free variables in the selected expression (on which a breakpoint is
> hit) but that was always enough for me during debug sessions I had. Write a
> script file (lets say it is named ghciInit (I'll also call it this way later
> on in this text)) which is like this example:
> :monitor var1,var2 ModuleName 23
> :monitor var3 ModuleName 40
> :x :main mainArgument
>
> Then open ghci with your program and run :. ghciInit
> And you will get nice log like this:
> (0): var1 = <value01>
> var2 = <value02>
> (1): var3 = <value03>
> (0): var1 = <value11>
> var2 = <value12>
> (1): var3 = <value13>
> ... etc
>
> Moreover :monitor allows condition in quotation marks to be specified as the
> first argument. If you do it then the variable values will be printed only
> when the condition is True. Of course the condition can contain only free
> variables in the selected expression. Mostly it is not a problem.
> :watch is a conditional breakpoint which stops when the specified condition
> is True.
> :count has 3 forms:
> :count _ ModuleName 23
>    This never breaks just counts number of times the execution reached
> position ModuleName 23
> :count 5 ModuleNmae 23
>    This breaks when we reach position ModuleName 23 fifth time
> :count 0
>    This tells how many times breakpoint number 0 was hit (it can report the
> number of hits for any breakpoint created with :bp, :inject, :monitor,
> :watch, and :count).
>
> The first form of :count is interesting when you want to stop earlier than
> something bad happens so that you can see why the bad think happened. Put
> the first form of :count at the start of the function with the bug and then
> put a break in the function which is hit when the bad think happens maybe
> with :watch. When you stop at the bug place, check hit count at the start of
> the function. Add the hit count in your :count breakpoint in your ghciInt
> file restart and you can use :steplocal or :loglocal to find out what went
> wrong.
>
> :loglocal is implemented directly in ghc source code. It does exactly the
> same as :steplocal but makes sure that the trace history does not contain
> anything outside of the function we step with :steplocal. The problem is
> that :steplocal works like the code was traced while it is executing. Mostly
> the result is that your trace history is loaded with crap outside of the
> scope you are interested in. I'll return to :loglocal later again.
>
> :inject is there when you need something special (:monitor, :watch, and
> :count are implemented with something very like :inject). E.g. when you want
> to do monitoring of a value but do not want the associated breakpoint number
> printed.
>
> :find and :findex are there primary to search trace history.
> :find var1 :back
>    will find the variable var1 in your trace history by back stepping it
> :find var1 :step
>    will single step forward till variable var1 is in the list of free
> variables
> :findex BL/Logic.hs:23 :loglocal
>   will fill in your trace history will all the local breakpoints till
> location BL/Logic.hs:23 is hit. Having the trace history filled in with the
> right stuff is useful for checking out why you got bad results later.
>
> Now lets return to Claus' idea of breakpoints with a list of identifiers
> which should be available at the breakpoint location. You can make sure the
> identifiers are available with the first form of :count. It never stops but
> it puts records to the trace history. So the trace history will contain free
> variables at the locations where you put :count. This will be even more
> useful when automatic search of trace history is built in (see ticket
> #2737). So a weaker form of Claus' idea can be implemented by carefully
> selecting what should bet to the trace history. Why a weaker form only?
> Well, in some cases, the  variable instances in trace log may not be the
> expected ones (they may be from a different lexical scope). Experience with
> my code indicates this should be rare.
>
> :next is an idea how to implement a kind of step over. That is if by step
> over you mean something else than steplocal. The non-lazy form of :next
> forces _result and does a :step. The lazy form forces only the top level
> constructor of _result before the step. Hey, I even had a case when it
> worked just like I expected. But typically it does not work because of bug
> #1531. _result is not correctly bound to the result of selected expression
> in most of the practical cases. This bug is also critical for all the forms
> of conditional breakpoints. It would be cool if we could specify the
> condition based on _result or some part of it. The implementation of ghciExt
> conditional breakpoints would need to be extended to support conditions on
> _result (in particular the breakpoint would need to be disabled during the
> condition execution) but that is easy to do. Even more worrying thing about
> bug #1531 is that it has the milestone set to _|_.
>
> It is easy to add :enable and :disable to support enabling and disabling
> breakpoints. I just did not need it yet. Here is how a GhciExt breakpoint
> looks like:
> *Main> :show breaks
> [0] Main a.hs:4:2-8 ":cmd return$GhciExt.getStopCode 0 (True) "putStr \"(0):
> \"\n:force x" "False""
> *Main>
> Just replace getStopCode with getDisabledStopCode and you have it disabled.
> Return back to enable. Yeah, and implement getDisabledStopCode which will
> just continue.
>
> I added :loglocal mostly to simulate how :tracelocal in ticket #2737 would
> help. I was also trying how full tracing is helping. In both cases the
> answer is: full tracing almost never helps. :tracelocal from ticket #2737 as
> proposed originally would rarely help. The problem is that trace log gets
> overwhelmed with crap when we cannot control what can be saved in it and
> what cannot be saved. My idea is that user should be able to specify what
> can go in it and also what should not go in it. Here is an alternative
> solution to the ones I proposed in tickets #2737 and #2946. I think this one
> would be best. The command to control the tracing should look like:
>  -- should everything be traced?
> :set trace (True|False)
> -- scopes which should be traced (or should not be traced when ! is present)
> :set trace ( (!)? scopeid )*
> -- add/remove individual scopeids to/from the trace specification
> :set trace (+|-) (!)? scopeid
> where scopeid = ( conid . )* ( varid . )* varid
> Notice how scopeid looks. It can have a sequence of varids at the end. The
> reason is so that user can leave out a scope of a function which is defined
> in a where clause. The scope specification is similar to the proposal in
> ticket #3000. E.g. for this code:
> fn s = 'a' : add s
>   where add = (++"z")
> it could look like
> :set trace Main.fn !Main.fn.add
> meaning trace whole scope of fn but not the stuff in the scope of add.
> Order should not be important, requests for not tracing should have
> precedence before requests to trace.
> The scopes which we want typically exclude are the ones which contain loops.
> The loop content often fills in the trace log forcing the interesting stuff
> out of it. It is better to investigate functions with loops separately in
> nested context.
>
> Notice that there is a bit difference between this proposal of controlling
> trace content and the one in ticket #2737. #2737 assumes usage of breakpoint
> arguments to specify a scope. The breakpoint arguments give an ability to
> define scopes at finer level but there is no option to define exclude scopes
> which I find important now.
>
> The summary is: Trace log is as useful as much you can control what can get
> in it. The :trace command looks to me like an error. It is better to control
> it by allowing/disallowing scopes.
>
> I also changed my opinion a bit about ticket #2945. :mergetrace would be
> better than global trace history. Being able to investigate something
> separately in a nested context is useful.
>
> If I should order the ghci debugger related tickets then the order would be
> like (more important first):
> #1531 (_result can get bound to the wrong value in a breakpoint)
> #2737 and #2946 (add :tracelocal to ghci debugger...  and    add command
> :mergetrace...)
> #3000 (:break command should recognize also nonexported top level
> symbols...)
> #2803 (bring full top level of a module in scope when a breakpoint is hit in
> the ...)
> #1377 (the task: "We should print breakpoint related info only if breakpoint
> has no commands set") but people debugging interactive console applications
> would like to have this one the very top; IIRC this may be easy to do, looks
> like all the printing is done in one function (something like afterCmd???);
> also #2950 looked like trivial to do (like 15 mins without the compile
> time???)
>
> And the last thing: my first time experiences hacking in the :loglocal into
> ghc. I cannot tell much, I spend with it only one long Sunday afternoon, but
> here are my two points:
> * I needed to extend ghc interface. The type of function GHC.resume changed
> from:
>     resume :: GhcMonad m => SingleStep -> m RunResult
>     to:
>     resume :: GhcMonad m => (SrcSpan->Bool) -> SingleStep -> m RunResult
>     ... plus the corresponding implementation change. The added argument is
> a filtering function to limit source spans which can recorded in the trace
> history.
> * It would be cool if ghci has its own dir in the souce tree where only the
> ghci source files are. It would encourage people to hack it more since it
> would be easier to maintain private patches and merging upstream. It would
> be also easier to make sure one modifies only ghci source code so that it
> works with other ghc releases.
>
> Hopefully this helps somebody,
>   Peter.
>
>
> _______________________________________________
> Glasgow-haskell-users mailing list
> Glasgow-haskell-users at haskell.org
> http://www.haskell.org/mailman/listinfo/glasgow-haskell-users
>
>