Massive memory hemorrhage that causes heap size to go from about 64mb, to 1.5gb in roughly 8 seconds. Issue with garbage collector?

Question

Here's the problem:

As you can see, the memory usage balloons out of control! I've had to add arguments to the JVM to increase the heapsize just to avoid out of memory errors while I figure out what's going on. Not good!

Basic Application Summary (for context)

This application is (eventually) going to be used for basic on screen CV and template matching type things for automation purposes. I want to achieve as high of a frame rate as possible for watching the screen, and handle all of the processing via a series of separate consumer threads.

I quickly found out that the stock Robot class is really terrible speed wise, so I opened up the source, took out all of the duplicated effort and wasted overhead, and rebuilt it as my own class called FastRobot.

The Class' Code:

public class FastRobot {     private Rectangle screenRect;     private GraphicsDevice screen;     private final Toolkit toolkit;     private final Robot elRoboto;     private final RobotPeer peer;     private final Point gdloc;     private final DirectColorModel screenCapCM;     private final int[] bandmasks;      public FastRobot() throws HeadlessException, AWTException {         this.screenRect = new Rectangle(Toolkit.getDefaultToolkit().getScreenSize());         this.screen = GraphicsEnvironment.getLocalGraphicsEnvironment().getDefaultScreenDevice();         toolkit = Toolkit.getDefaultToolkit();         elRoboto = new Robot();         peer = ((ComponentFactory)toolkit).createRobot(elRoboto, screen);          gdloc = screen.getDefaultConfiguration().getBounds().getLocation();         this.screenRect.translate(gdloc.x, gdloc.y);          screenCapCM = new DirectColorModel(24,                 /* red mask */    0x00FF0000,                 /* green mask */  0x0000FF00,                 /* blue mask */   0x000000FF);         bandmasks = new int[3];         bandmasks[0] = screenCapCM.getRedMask();         bandmasks[1] = screenCapCM.getGreenMask();         bandmasks[2] = screenCapCM.getBlueMask();          Toolkit.getDefaultToolkit().sync();     }      public void autoResetGraphicsEnv() {         this.screenRect = new Rectangle(Toolkit.getDefaultToolkit().getScreenSize());         this.screen = GraphicsEnvironment.getLocalGraphicsEnvironment().getDefaultScreenDevice();     }      public void manuallySetGraphicsEnv(Rectangle screenRect, GraphicsDevice screen) {         this.screenRect = screenRect;         this.screen = screen;     }       public BufferedImage createBufferedScreenCapture(int pixels[]) throws HeadlessException, AWTException { //      BufferedImage image;         DataBufferInt buffer;         WritableRaster raster;          pixels = peer.getRGBPixels(screenRect);         buffer = new DataBufferInt(pixels, pixels.length);          raster = Raster.createPackedRaster(buffer, screenRect.width, screenRect.height, screenRect.width, bandmasks, null);         return new BufferedImage(screenCapCM, raster, false, null);     }      public int[] createArrayScreenCapture() throws HeadlessException, AWTException {             return peer.getRGBPixels(screenRect);     }      public WritableRaster createRasterScreenCapture(int pixels[]) throws HeadlessException, AWTException {     //  BufferedImage image;         DataBufferInt buffer;         WritableRaster raster;          pixels = peer.getRGBPixels(screenRect);         buffer = new DataBufferInt(pixels, pixels.length);          raster = Raster.createPackedRaster(buffer, screenRect.width, screenRect.height, screenRect.width, bandmasks, null);     //  SunWritableRaster.makeTrackable(buffer);         return raster;     } } 

In essence, all I've changed from the original is moving many of the allocations from function bodies, and set them as attributes of the class so they're not called every time. Doing this actually had a significant affect on frame rate. Even on my severely under powered laptop, it went from ~4 fps with the stock Robot class, to ~30fps with my FastRobot class.

First Test:

When I started outofmemory errors in my main program, I set up this very simple test to keep an eye on the FastRobot. Note: this is the code which produced the heap profile above.

public class TestFBot {     public static void main(String[] args) {         try {             FastRobot fbot = new FastRobot();              double startTime = System.currentTimeMillis();             for (int i=0; i < 1000; i++)                 fbot.createArrayScreenCapture();             System.out.println("Time taken: " + (System.currentTimeMillis() - startTime)/1000.);          } catch (AWTException e) {             e.printStackTrace();         }     } } 

Examined:

It doesn't do this every time, which is really strange (and frustrating!). In fact, it rarely does it at all with the above code. However, the memory issue becomes easily reproducible if I have multiple for loops back to back.

Test 2

public class TestFBot {     public static void main(String[] args) {         try {             FastRobot fbot = new FastRobot();              double startTime = System.currentTimeMillis();             for (int i=0; i < 1000; i++)                 fbot.createArrayScreenCapture();             System.out.println("Time taken: " + (System.currentTimeMillis() - startTime)/1000.);              startTime = System.currentTimeMillis();             for (int i=0; i < 500; i++)                 fbot.createArrayScreenCapture();             System.out.println("Time taken: " + (System.currentTimeMillis() - startTime)/1000.);              startTime = System.currentTimeMillis();             for (int i=0; i < 200; i++)                 fbot.createArrayScreenCapture();             System.out.println("Time taken: " + (System.currentTimeMillis() - startTime)/1000.);              startTime = System.currentTimeMillis();             for (int i=0; i < 1500; i++)                 fbot.createArrayScreenCapture();             System.out.println("Time taken: " + (System.currentTimeMillis() - startTime)/1000.);          } catch (AWTException e) {             e.printStackTrace();         }     } } 

Examined

The out of control heap is now reproducible I'd say about 80% of the time. I've looked all though the profiler, and the thing of most note (I think) is that the garbage collector seemingly stops right as the fourth and final loop begins.

The output form the above code gave the following times:

Time taken: 24.282    //Loop1 Time taken: 11.294    //Loop2 Time taken: 7.1       //Loop3 Time taken: 70.739    //Loop4 

Now, if you sum the first three loops, it adds up to 42.676, which suspiciously corresponds to the exact time that the garbage collector stops, and the memory spikes.

Now, this is my first rodeo with profiling, not to mention the first time I've ever even thought about garbage collection -- it was always something that just kind of worked magically in the background -- so, I'm unsure what, if anything, I've found out.

Additional Profile Information

Augusto suggested looking at the memory profile. There are 1500+ int[] that are listed as "unreachable, but not yet collected." These are surely the int[] arrays that the peer.getRGBPixels() creates, but for some reason they're not being destroyed. This additional info, unfortunately, only adds to my confusion, as I'm not sure why the GC wouldn't be collecting them

---

Profile using small heap argument -Xmx256m:

At irreputable and Hot Licks suggestion I set the max heap size to something significantly smaller. While this does prevent it from making the 1gb jump in memory usage, it still doesn't explain why the program is ballooning to its max heap size upon entering the 4th iteration.

As you can see, the exact issue still exists, it's just been made smaller. ;) The issue with this solution is that the program, for some reason, is still eating through all of the memory it can -- there is also a marked change in fps performance from the first the iterations, which consume very little memory, and the final iteration, which consumes as much memory as it can.

The question remains why is it ballooning at all?

---

Results after hitting "Force Garbage Collection" button:

At jtahlborn's suggestion, I hit the Force Garbage Collection button. It worked beautifully. It goes from 1gb of memory usage, down to the baseline of 60mb or so.

So, this seems to be the cure. The question now is, how do I programmatically force the GC to do this?

---

Results after adding local Peer to function's scope:

At David Waters suggestion, I modified the createArrayCapture() function so that it holds a local Peer object.

Unfortunately no change in the memory usage pattern.

Still gets huge on the 3rd or 4th iteration.

---

Memory Pool Analysis:

ScreenShots from the different memory pools

All pools:

Eden Pool:

Old Gen:

Just about all of the memory usage seems to fall in this pool.

Note: PS Survivor Space had (apparently) 0 usage

---

I'm left with several questions:

(a) does the Garbage Profiler graph mean what I think it means? Or am I confusing correlation with causation? As I said, I'm in an unknown area with these issues.

(b) If it is the garbage collector... what do I do about it..? Why is it stopping altogether, and then running at a reduced rate for the remainder of the program?

(c) How do I fix this?

What's going on here?

Answer 1

Try specifying a garbage collector manually.

Concurrent Mark Sweep is a good general purpose one that provides a good balance between low-pause and reasonable throughput.

If you are on Java 7 or later Java 6, G1 collector is probably better since it is able to also prevent memory fragmentation.

You can check the Java SE Hotspot Virtual Machine Garbage Collection Tuning page for more information and pointers :-D