Thursday, July 17, 2014

reactive-banana mystery leak

So I accidentally let my reactive-banana toy app opened all night, and in the morning the computer was horribly unresponsive until I killed it. After starting a new instance, I noticed that the CPU goes up from ~5% to 100%, during which the memory usage also grows uncontrollably. What is causing this?

The first thing I try is to lower the refresh rate at which gloss recomputes its frames, in case the problem is that the computer can't keep up with the work it has to do. The resource usage still increases, but much more slowly. Next, I try to isolate the commit in which the problem was introduced. Did the problem exist when I was using gloss, but not reactive-banana? No. Git-bisecting, I find that the problem was introduced by commit 66f4e7, "accumulating clicks":

@@ -27,13 +28,31 @@ reactiveMain :: forall t. Frameworks t
              => Event t Float
              -> Event t InputEvent
              -> Moment t (Behavior t Picture)
-reactiveMain floats _ = return pictures
+reactiveMain floats events = return pictures
   where
-    partialSums :: Behavior t Float
-    partialSums = accumB 0 (fmap (+) floats)
+    buttonClicks :: [Event t ()]
+    buttonClicks = map (flip buttonClick events) buttons
+    
+    countA,countB,countC :: Behavior t Int
+    [countA,countB,countC] = map countEventsB buttonClicks
+    
+    clickCounts :: Behavior t (Int,Int,Int)
+    clickCounts = liftA3 (,,) countA countB countC
     
     pictures :: Behavior t Picture
-    pictures = fmap renderFloat partialSums
+    pictures = fmap render clickCounts
+
+countEventsB :: Num a => Event t b -> Behavior t a
+countEventsB = accumB 0 . fmap (+) . fmap (const 1)
+
+buttons :: [Extent]
+buttons = [extentA, extentB, extentC]
+
+buttonClick :: Extent -> Event t InputEvent -> Event t ()
+buttonClick ex = fmap (const ()) . filterE isInside
+  where
+    isInside (EventKey (MouseButton LeftButton) Down _ p) = pointInExtent ex p
+    isInside _                                            = False
 
 renderFloat :: Float -> Picture
 renderFloat = uscale 0.2 . text . show

This is the commit in which I switched from displaying the accumulated time to displaying the number of accumulating clicks on three buttons.

After a little more experimentation, I notice that the CPU and memory get released whenever I click on one of the buttons. Weird! Which special thing happens when I click one of the buttons? Well, one thing is that the graphics change. What if I force the graphics to change all the time by displaying the running elapsed time? The problem disappears. That's good, but I don't want to display the running elapsed time. Can I instead compute the running time, but display a fixed string? Embarrassingly, the first time I tested this I forgot to force the computed value, so the problem reappeared. When I do force the value, the problem remains hidden.

Ok, so I don't understand why the CPU usage would go up, but the memory increase seems to be due to a laziness issue.

I wish I could use ghci to step through the code, but the app hangs when I do. Seems to be an issue with gloss, not reactive-banana. Maybe if I disable the timed updates by setting the refresh rate to zero? Still hangs, but the leak disappears. Which is not a surprise, really: the fact that the leak grew more slowly when the refresh rate was lower clearly indicates that the leak is caused by the Float events.

Or it is that clear? With the refresh rate set to zero, there are no Float events, and at first the leak doesn't seem present. But if I click outside the buttons or move the mouse a lot, this generates a bunch of ignored events, which causes the memory to rise. Since this is not how I have previously been testing the leaks, I re-perform the git-bisect with a refresh rate of zero, and discover that the problem was actually introduced by commit 1386bf, "accumulating time":

@@ -18,7 +21,19 @@ main :: IO ()
 main = playBanana (InWindow "Nice Window" (200, 200) (800, 200))
                   white
                   30
-                  (\floats _ -> return $ fmap renderFloat $ stepper 0 floats)
+                  reactiveMain
+
+reactiveMain :: forall t. Frameworks t
+             => Event t Float
+             -> Event t InputEvent
+             -> Moment t (Behavior t Picture)
+reactiveMain floats _ = return pictures
+  where
+    partialSums :: Behavior t Float
+    partialSums = accumB 0 (fmap (+) floats)
+    
+    pictures :: Behavior t Picture
+    pictures = fmap renderFloat partialSums

This is the commit in which I switched from displaying the Float values to displaying the sum of all Float values so far. Interestingly, I am not even using the mouse events in my FRP computation, so the problem can't possibly be that my code is doing something it shouldn't. Maybe there is something it should do which it isn't doing? Perhaps I should be actively consuming and ignoring the events, instead of simply not using them?

reactiveMain floats events = return pictures
  where
    pictures :: Behavior t Picture
    pictures = fmap renderFloat partialSums <* stepper undefined events
It works! In the most recent commit, which handles mouse events but filters out most time events, it is the floats which must be ignored. And in general, just to be safe, both kinds of events should be actively ignored:
pictures :: Behavior t Picture
pictures = fmap render buttonTexts
        <* stepper undefined floats
        <* stepper undefined events
Or, better yet, let's hide this inside gloss-banana, so that nobody has to think about this again.

No comments: