ghci debugger :trace command does not always extend trace history

[Simon Marlow]

I agree with most of what you say - there should be a way to get access to 
the history after :trace has finished.  Perhaps the right way is just to 
have a single global trace history.

Please submit a feature request, with a proposal for the user interface, to 
the GHC bug tracker:

http://hackage.haskell.org/trac/ghc/newticket?type=feature+request

Cheers,
	Simon

Peter Hercek wrote:
> Hi Simon ... and whoever thinks he/she can help me with the right way of 
> debugging with ghci,
> 
> Sorry for the long post but I cannot explain more shortly what I would 
> like to be able to do ... and maybe you find my ":find" and ":monitor" 
> commands at the end useful ... and maybe you can propose some other 
> useful user defined commands for ghci which were not mentioned in Claus' 
> tutorial :-)
> 
> Ok, so it is not a bug because each trace command creates a new context 
> and trace history is context specific. This means my question now is: 
> How can I get access to trace history of a nested trace command which 
> just finished?
> Here are some explanations so that we understand each other:
> The top level trace of my old example is ":trace test 0".
> The nested trace of my old example is ":trace z".
> I would like to get access to the trace history of the nested trace 
> after the nested trace finishes (e.g. after the command ":trace z" 
> finished by printing the z value).
> Or the other option would be: How to launch ":trace z" so that a new 
> nested trace is not created but the current trace (the one before 
> launching ":trace z") is extended?
> 
> I know I can use ":trace" to continue the current trace but this 
> requires that I have some suitable breakpoint later on a place where 
> value z is already forced and before the interesting trace history is 
> not replaced with newer stuff. It may not be trivial to find such a place.
> Other option would be to place breakpoints on all the interesting places 
> which lead to the computation of the result being forced with ":trace 
> <varName>" and investigate the traces in the nested context. The problem 
> here is that it is more work. If I would know the result first then I 
> could focus only on the places which are the probable reason of the 
> wrong value, moreover the lure of ":find" is tempting (I explain ":find" 
> later). Typically the situation is more complicated (there are more 
> options) than my small example.
> 
> My requests/questions may look strange, but here is reasoning why I 
> think I need the functionality. If you have better approach to debugging 
> please let me know. Maybe there is still some interesting tutorial I did 
> not read about ghc debugging or I just forgot something.
> 
> When I debug, I typically know what is probably wrong based on the 
> program output. So I place a breakpoint at one logical step before the 
> output. When stopped at the breakpoint I force variables which do not 
> need to stay lazy and from which the program output is printed. Then I 
> can see if some part of the force result/output is unexpected. Then I 
> would like to search the trace history to see values of variables which 
> probably contributed to the wrong value of the force result/output. I 
> hoped that using :trace instead of force would append the trace history.
> 
> This backward search for a bug means less work since I need to 
> investigate only the path from the dynamic evaluation tree root (the 
> wrong program result) to a given node where the bug is. An ability to 
> access trace history of a value I just forced would save me some program 
> restarts. How much restarts would be saved depends on the trace history 
> depth and my ability not to get lost in the order of lazy calls. If I do 
> not have access to the trace history, the only option is to put a 
> breakpoint at a place where the variable value I wanted to check is 
> available and restart the program so that I can check the value.
> 
> Since there is no way to print partially applied functions this value 
> based approach is probably the only one working. This is supported by 
> recommendations to use printf debugging.
> 
> One more reason I would like to learn how to access the trace history of 
> a forced value is that my :monitor commands conflict with ghci trace 
> history. I was able to implement :monitor and :find commands based on 
> Claus' ghci scripting tutorial:
> 
> :monitor displays value of a given variable at a given location while 
> discarding all the other output. It is a way to do printf debugging 
> solely from ghci without changing source code (i.e. without adding 
> Debug.Trace.trace calls). :monitor (used together with ":x") is not 
> always better than printf debugging  because it discards program output 
> too, and cannot add an identifier to scope. But often it is ... at least 
> for me because it separates printf debugging (defined using ":monitor" 
> commands in a script I source with ":.") from the source code.
> 
> :find finds a variable name in trace history, prints its value, and a 
> location where it was found. The location is needed here because of name 
> conflicts. The value located may not be the right one. Taking static 
> scopes into account could discard a lot of false finds (not all of 
> them). I think that taking static scopes and (maybe more detailed) trace 
> history into account could rule out all false positives. But nobody 
> wants to implement this in a ghci script ... I guess :-)
> 
> Currently my :monitor command makes holes in trace history, lowering the 
> value of :find command :-(
> 
> If you are interested you can find :find and :monitor implementations 
> here: http://www.hck.sk/users/peter/pub/.ghci
> 
> It looks to me that the way tracing is done is unfortunate from the 
> point of view of scripting custom ghci commands. It would be better to 
> have a global trace history which would be activated/deactivated with 
> command like ":trace on/off" and this would modify the behavior of the 
> rest of the ghci commands appropriately. E.g. :continue would behave 
> like :trace (without arguments) when tracing is on. It would be probably 
> interesting to have more tracing buffers (but I did not think about this 
> much). Now, it is done in a cool functional way which means more 
> complicated user defined ghci commands ... unless I'm missing something :-)
> 
> 
> Thanks,
> Peter.
> 
> 
> Simon Marlow wrote:
>> Peter Hercek wrote:
>>> Hi,
>>>
>>> I expected ":trace expr" to always add data to the trace history but 
>>> it does not do so for CAFs (which are not reduced yet).
>>> My point is that the command ":trace z" did not add anything to the 
>>> trace history and I cannot check why value z is 2, because value of y 
>>> is not in the trace history. Is this the expected behavior? If it is, 
>>> how can I make ghci to extend the trace history when "forcing" 
>>> variables?
>>>
>>> Peter.
>>>
>>> Here is the example:
>>>
>>> status:0 peter at metod [765] ~/tmp
>>> % cat a.hs
>>> test :: Int -> Int
>>> test x =
>>>   let y = x+1 in
>>>   let z = y+1 in
>>>   z
>>> status:0 peter at metod [766] ~/tmp
>>> % ghci a.hs
>>> GHCi, version 6.8.2: http://www.haskell.org/ghc/  :? for help
>>> Loading package base ... linking ... done.
>>> [1 of 1] Compiling Main             ( a.hs, interpreted )
>>> Ok, modules loaded: Main.
>>> *Main> :break Main 5
>>> Breakpoint 0 activated at a.hs:5:2
>>> *Main> :trace test 0
>>> Stopped at a.hs:5:2
>>> _result :: Int = _
>>> z :: Int = _
>>> 4    let z = y+1 in
>>> 5    z
>>> 6
>>> [a.hs:5:2] *Main> :back
>>> Logged breakpoint at a.hs:(2,0)-(5,2)
>>> _result :: Int
>>> 1  test :: Int -> Int
>>> 2  test x =
>>> 3    let y = x+1 in
>>> 4    let z = y+1 in
>>> 5    z
>>> 6
>>> [-1: a.hs:(2,0)-(5,2)] *Main> :back
>>> no more logged breakpoints
>>
>> ok so far - y and z have not been evaluated.
>>
>>> [-1: a.hs:(2,0)-(5,2)] *Main> :forward
>>> Stopped at a.hs:5:2
>>> _result :: Int
>>> z :: Int
>>> 4    let z = y+1 in
>>> 5    z
>>> 6
>>> [a.hs:5:2] *Main> :trace z
>>> 2
>>
>> this evaluates z.
>>
>>> [a.hs:5:2] *Main> :back
>>> Logged breakpoint at a.hs:(2,0)-(5,2)
>>> _result :: Int
>>> 1  test :: Int -> Int
>>> 2  test x =
>>> 3    let y = x+1 in
>>> 4    let z = y+1 in
>>> 5    z
>>> 6
>>
>> You are going back in the original context, but I presume you were 
>> expecting to go back in the evaluation of z.  You can only go back in 
>> the context of the current evaluation, however.
>>
>> Try this:
>>
>> *Main> :break 3
>> Breakpoint 4 activated at trace.hs:3:10-12
>> *Main> :trace test 0
>> Stopped at trace.hs:3:10-12
>> _result :: Int = _
>> x :: Int = 90
>> 2  test x =
>> 3    let y = x+1 in
>> 4    let z = y+1 in
>> [trace.hs:3:10-12] *Main> :history
>> -1  : test (trace.hs:4:10-12)
>> -2  : test (trace.hs:5:2)
>> -3  : test (trace.hs:(2,0)-(5,2))
>> <end of history>
>> [trace.hs:3:10-12] *Main> :back
>> Logged breakpoint at trace.hs:4:10-12
>> _result :: Int
>> y :: Int
>> 3    let y = x+1 in
>> 4    let z = y+1 in
>> 5    z
>> [-1: trace.hs:4:10-12] *Main> :back
>> Logged breakpoint at trace.hs:5:2
>> _result :: Int
>> z :: Int
>> 4    let z = y+1 in
>> 5    z
>> 6
>>
>> Cheers,
>>     Simon
> 
> _______________________________________________
> Glasgow-haskell-users mailing list
> Glasgow-haskell-users at haskell.org
> http://www.haskell.org/mailman/listinfo/glasgow-haskell-users