Debugging infinite loops in Haskell programs with GHCi

Question

For the first time I've encountered an infinite loop in a Haskell program I'm writing. I've narrowed it down to a quite specific section of code, but I cannot seem to pinpoint exactly where I have a non-terminating recursive definition. I'm vaguely familiar with :trace and :history in GHCi, but the problem is that some branches of my code involve quite a bit of recursive modifications of a Data.Map.Map in the sense that the map x is obtained by adjusting something in the map x' based on values in another map depending on x'. The specifics don't matter here, but as you can probably tell, if this happens in an intertwined recursive way, my call history gets completely bogged down in all the various comparisons involved in map lookups, adjustments and insertions.

Can anyone recommend a more efficient way to locate infinite loops? It would, for example, help a lot to restrict the call history to calls from a single source file.

Answer 1

I'm surprised no one has mentioned the ubiquitous response that all Haskell performance issues get (infinite runtime being a rather extreme example of a "performance issue"): profiling!

I was just able to quickly identify an infinite loop using profiling. For completeness, compile with -prof -fprof-auto, then run the program for enough time that the offending function should be apparent in the profiling stats. For example, I expected my program to complete in <1 second, so I let the profiler run for about 30 seconds, then killed my program with Ctrl+C. (Note: Profiling saves incremental results, so you can still get meaningful data even if you kill the program before it runs to completion. EDIT: Except when it doesn't.)

In the .prof file, I found the following block:

                                                 individual      inherited
COST CENTRE         MODULE     no.    entries   %time  %alloc   %time %alloc
...
primroot.\          Zq         764          3    10.3    13.8    99.5  100.0
 primroot.isGen     Zq         1080   50116042    5.3     6.9    89.2   86.2
  primroot.isGen.\  Zq         1087   50116042   43.4    51.7    83.8   79.3
   fromInteger      ZqBasic    1088          0   40.4    27.6    40.4   27.6

So there are 50 million entries to primroot.isGen, and the next most-called function had only 1024 calls. Additionally, 99.5% of runtime was spent computing primroot, which seems highly suspicious. I checked out that function and quickly found the error, a simple typo in my case: (`div` foo) instead of (div foo).

I think it's worth noting that GHC warnings wouldn't have caught this problem, nor -fbreak-on-exceptions. The code base is huge; trying to track down the problem by inserting debugging statements (of any sort) didn't get me anywhere. I was also unsuccessful using the GHCi debugger because the history was essentially non-existent, and HPC didn't reveal anything useful.

Answer 2

As ShiDoiSi says, solving "by eye" is often the most successful way.

If you are binding to different similarly named variables x, x' etc. in the same functions you could try enabling warnings at the top of your file:

{-# OPTIONS -Wall #-} 

If it is a problem where you are binding to the wrong thing and making runaway recursion this might help you spot it - e.g. by indicating an unexpected use of shadowing.

Answer 3

Be sure you've used the GHCi debugger to it's full extent, including setting -fbreak-on-exception (useful if you're getting <<loop>>, are you?) and be sure you've tried Stephen's advice of using GHC's warnings.

If these fail (GHCi debugger really shouldn't 'fail', it's just a matter of interpreting the data) then try to run HPC on the looping case so you can visually see branches and values that aren't being evaluated, if it's looping then something that should be getting done probably isn't even being evaluated and that will show up in the marked up HTML.

Answer 4

I'm in the middle of a long debugging session for finding the cause of an infinite loop. I'm getting very close, and this is what helped me the most. Suppose your loop is caused by something like this:

...
x1 = f1 x2 y
x2 = f2 z x3
x3 = f3 y x1
...

So x1 depends on x2, which depends on x3, which depends on x1. BAD!

Sprinkle trace functions in the definitions of f1, f2, f3. Something like:

f1 x y | trace ("f1: ") False = undefined
f1 x y = ... -- definition of f1

f2 x y | trace ("f2: ") False = undefined
f2 x y = ... -- definition of f2

-- same for f3

Run your program to see which of these functions is called. The output might be something like

f3:
f2:
f1: 
<<loop>>

Then start showing some variables in the trace functions. For example, if you change the trace of f2 to

f2 x y | trace ("f2: x: " ++ show x) False = undefined

then the output will look something like:

f3:
f2: x: x_value
f1: 
<<loop>>

But if you then change the trace of f2 to

f2 x y | trace ("f2: x: " show x ++ " y: " ++ show y) False = undefined

Then the output will be

f3:
<<loop>>

because the second argument of f2 can't be evaluated due to the circular dependence.

So you now know that one of functions in the infinite loop is f2 and that its second argument (but not its first) has a circular dependence.

Happy debugging!

Answer 5

Can't you use :back and :forward to visit your history/trace and figure out the evolution of your maps between the calls?

You should be able to spot the pattern that leads to the recursive loop.

--If it's too tricky, you might have reached the point where you write some code too intelligent for you to debug (or maybe too complicated and you should refactor it ^^)--