JDK-4649647 : JFrame instances are not garbage collected upon disposal
  • Type: Bug
  • Component: client-libs
  • Sub-Component: java.awt
  • Affected Version: 1.3.0,1.3.1,1.4.0,5.0
  • Priority: P4
  • Status: Closed
  • Resolution: Duplicate
  • OS:
    linux,solaris_7,solaris_8,windows_nt linux,solaris_7,solaris_8,windows_nt
  • CPU: x86,sparc
  • Submitted: 2002-03-08
  • Updated: 2005-12-28
  • Resolved: 2005-12-28
Related Reports
Duplicate :  
Relates :  
Description
On JVM 1.3.0, 1.3.1 and 1.4, JFrame instances are not garbage collected upon disposal.
Exception occurred during event dispatching:
java.lang.OutOfMemoryError
        <<no stack trace available>>

================================================================================
To reproduce problem
-Compile SimpleFrame.java and JFrameBug.java
- execute JFrameBug
- on the "JFrameBug Test" window choice "Open Frame" to Start program:

Program failed with this message "Exception occurred during event dispatching:
java.lang.OutOfMemoryError
        <<no stack trace available>>"

==============================================================================
Files following

file SimpleFrame.java
-------------------


import java.awt.*;
import java.awt.event.*;
import javax.swing.*;


public class SimpleFrame extends JFrame{

  public SimpleFrame() {
    setSize(600, 600);
    JPanel panel = new JPanel();
    JButton openButton = new JButton("Ouvrir");
    JButton closeButton = new JButton("Fermer");
    openButton.addActionListener(new ActionListener()  {
      public void actionPerformed(ActionEvent e) {
        SimpleFrame s = new SimpleFrame();
        s.show();
      }
    });
    closeButton.addActionListener(new ActionListener()  {
      public void actionPerformed(ActionEvent e) {
        dispose();
      }
    });
    for (int i=0; i<50; i++) {
      panel.add(new JLabel("Simple Frame - "));
    }
    panel.add(openButton);
    panel.add(closeButton);
    getContentPane().add(panel);
  }
}


file JFrameBug.java
-------------------
import java.awt.*;
import java.awt.event.*;
import javax.swing.*;

public class JFrameBug extends JFrame {
  JPanel contentPane;
  JMenuBar jMenuBar1 = new JMenuBar();
  JMenu jMenuFile = new JMenu();
  JMenuItem jMenuFileOpenFrame = new JMenuItem();
  JMenuItem jMenuFileExit = new JMenuItem();
  BorderLayout borderLayout1 = new BorderLayout();

  /**Construct the frame*/
  public JFrameBug() {
    enableEvents(AWTEvent.WINDOW_EVENT_MASK);
    try {
      jbInit();
    }
    catch(Exception e) {
      e.printStackTrace();
    }
    show();
  }
  public static void main(String[] args) {
    JFrameBug JFramBug1 = new JFrameBug();

  }

  private void jbInit() throws Exception  {
    //setIconImage(Toolkit.getDefaultToolkit().createImage(JFrameBug.class.getRe
source("[Your Icon]")));
    contentPane = (JPanel) this.getContentPane();
    contentPane.setLayout(borderLayout1);
    this.setSize(new Dimension(800, 600));
    this.setTitle("JFrameBug Test");
    jMenuFile.setText("File");
    jMenuFileExit.setText("Exit");
    jMenuFileOpenFrame.setText("Open Frame");
    jMenuFileExit.addActionListener(new ActionListener()  {
      public void actionPerformed(ActionEvent e) {
        jMenuFileExit_actionPerformed(e);
      }
    });
    jMenuFileOpenFrame.addActionListener(new ActionListener()  {
      public void actionPerformed(ActionEvent e) {
        jMenuFileOpenFrame_actionPerformed(e);
      }
    });
    jMenuFile.add(jMenuFileOpenFrame);
    jMenuFile.add(jMenuFileExit);
    jMenuBar1.add(jMenuFile);
    this.setJMenuBar(jMenuBar1);
  }
  /**File | Exit action performed*/
  public void jMenuFileExit_actionPerformed(ActionEvent e) {
    System.exit(0);
  }
  /**File | Start Tests action performed*/
  public void jMenuFileOpenFrame_actionPerformed(ActionEvent e) {
    for (int i=0; i<1200;i++) {
      SimpleFrame s = new SimpleFrame();
      s.show();
      s.dispose();
    }
  }
  /**Overridden so we can exit when window is closed*/
  protected void processWindowEvent(WindowEvent e) {
    super.processWindowEvent(e);
    if (e.getID() == WindowEvent.WINDOW_CLOSING) {
      jMenuFileExit_actionPerformed(null);
    }
  }
}

Comments
EVALUATION That huge loop is working on EventDispatchThread and this seems the main reason why all these frames may not be GC'ed. Lets look on what happens there. JFrame creating on EDT and the showing. This forces a lot of events to be fired (FocusEvent, ComponentEvent etc.). All of them are referencing on that frame that just been created in the loop. As already mentioned that loop is on EDT (in actionPerformed() method) and this also means it will work until its end i.e. until 1200 itereations finishes. All that time EDT is not processing further events and just itereating in loop so if you just try to force GC you probably fail - there are a lot of references on every frame being created from these events (FocusEvent, ComponentEvent etc.) This may not be considered like a bug. I tried to verify this idea and put a dump into EventQueue.dispatchEvent() and run that test again. I'm observing MouseReleased event before a long series of SimpleFrame counter dump and then MouseClicked event. This actually looks the same as 6354655.
28-12-2005

SUGGESTED FIX Put that loop into other then EventQueue thread to fix that problem.
28-12-2005

PUBLIC COMMENTS On JVM 1.3.0, 1.3.1 and 1.4, JFrame instances are not garbage collected upon disposal. Exception occurred during event dispatching: java.lang.OutOfMemoryError <<no stack trace available>>
17-09-2004

EVALUATION Sounds like a serious memory leak. We should check to make sure that this isn't just a case of allocations outrunning gc or the finalizer thread. Commit to fix in mantis (memory leak - performance). ###@###.### 2002-04-25 I have not been able to reproduce the OutOfMemoryError. I did run the test case through OptimizeIt w/ 1.3.1 and 1.4.1b19. At the end of the run, there are 1200 SimpleFrame instances hanging around, but invoking the garbage collector makes them all go away, so we're not keeping any references around. I'm going to pass this one on to the gc team. ###@###.### 2002-08-14 ---------------------------------------------------------------- When I run with -XX:+PrintGC, I see that mostly the heap is just filling up, and that garbage collection is not making much progress against the allocations made by the program: (This is on Windohs NT 4.0 SP6.) semeru $ $Deployed/JDK-1.4.1/bin/java -showversion -XX:+PrintGC -XX:+PrintGCTimeStamps JFrameBug java version "1.4.1-rc" Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.1-rc-b19) Java HotSpot(TM) Client VM (build 1.4.1-rc-b19, mixed mode) 1.03679e-006: [GC 512K->244K(1984K), 0.0161372 secs] 0.35846: [GC 756K->399K(1984K), 0.0185882 secs] 4.72348: [GC 911K->525K(1984K), 0.0228809 secs] 5.07672: [GC 1036K->852K(1984K), 0.0106716 secs] 5.37343: [GC 1364K->1194K(1984K), 0.0093919 secs] 5.59579: [GC 1705K->1537K(2112K), 0.0084884 secs] 5.60441: [Full GC 1537K->1537K(2112K), 0.1109246 secs] 6.10222: [GC 2047K->1882K(3136K), 0.0526971 secs] 6.29133: [GC 2394K->2225K(3136K), 0.0085388 secs] 6.43878: [GC 2737K->2568K(3136K), 0.0092084 secs] 6.58616: [GC 3080K->2918K(3520K), 0.0100581 secs] 6.59634: [Full GC 2918K->2918K(3520K), 0.1423390 secs] 6.88131: [GC 3429K->3261K(5440K), 0.0077246 secs] 7.04138: [GC 3773K->3603K(5440K), 0.0087533 secs] 7.19539: [GC 4115K->3946K(5440K), 0.0088230 secs] 7.35534: [GC 4458K->4289K(5440K), 0.0091027 secs] 7.51368: [GC 4801K->4633K(5440K), 0.0087711 secs] 7.67413: [GC 5145K->4976K(5568K), 0.0090129 secs] 7.68328: [Full GC 4976K->4976K(5568K), 0.1861721 secs] 8.03842: [GC 5552K->5382K(8936K), 0.0122990 secs] 8.23878: [GC 5958K->5763K(8936K), 0.0107451 secs] 8.43503: [GC 6339K->6146K(8936K), 0.0098795 secs] 8.62789: [GC 6722K->6530K(8936K), 0.0100042 secs] 8.82724: [GC 7106K->6916K(8936K), 0.0099655 secs] 9.03208: [GC 7492K->7302K(8936K), 0.0101226 secs] 9.3865: [GC 7878K->7689K(8936K), 0.0101087 secs] 9.61378: [GC 8265K->8075K(8936K), 0.0107519 secs] 9.85802: [GC 8651K->8458K(9064K), 0.0105298 secs] 9.86867: [Full GC 8458K->8362K(9064K), 0.3594605 secs] 10.6589: [GC 9449K->9085K(15092K), 0.0160160 secs] 11.0968: [GC 10173K->9856K(15092K), 0.0278824 secs] 11.6519: [GC 10944K->10588K(15092K), 0.0189874 secs] 12.2911: [GC 11676K->11315K(15092K), 0.0187849 secs] 12.9693: [GC 12403K->12037K(15092K), 0.0179011 secs] 13.696: [GC 13125K->12765K(15092K), 0.0325758 secs] 14.5192: [GC 13853K->13497K(15092K), 0.0178697 secs] 15.3895: [GC 14585K->14227K(15348K), 0.0183134 secs] 15.408: [Full GC 14227K->14227K(15348K), 0.3961360 secs] 17.3406: [GC 15795K->15275K(25452K), 0.1809058 secs] 19.1185: [GC 16875K->16336K(25452K), 0.0302164 secs] 20.8154: [GC 17936K->17406K(25452K), 0.0269161 secs] 22.6412: [GC 19006K->18479K(25452K), 0.0281909 secs] 24.3966: [GC 20079K->19624K(25452K), 0.0416534 secs] 26.5043: [GC 21224K->20695K(25452K), 0.0286484 secs] 28.7488: [GC 22295K->21768K(25452K), 0.0283257 secs] 31.2178: [GC 23368K->22827K(25452K), 0.0284156 secs] 33.6866: [GC 24427K->23900K(25580K), 0.0284031 secs] 33.7151: [Full GC 23900K->23900K(25580K), 0.6031171 secs] 38.5615: [GC 26475K->25622K(42656K), 0.2915475 secs] 43.5846: [GC 28310K->27416K(42656K), 0.0553235 secs] 48.6081: [GC 30103K->29214K(42656K), 0.0454264 secs] 54.0471: [GC 31902K->31004K(42656K), 0.0504240 secs] 59.7527: [GC 33692K->32805K(42656K), 0.0458497 secs] 65.7436: [GC 35492K->34593K(42656K), 0.0456671 secs] 72.0154: [GC 37281K->36385K(42656K), 0.0530593 secs] 77.2391: [GC 39073K->38351K(42656K), 0.0737589 secs] 84.0593: [GC 41039K->40143K(42912K), 0.0502748 secs] 84.1097: [Full GC 40143K->40143K(42912K), 0.9600188 secs] 95.1293: [GC 43999K->42719K(65088K), 0.4466655 secs] 106.871: [GC 46815K->45452K(65088K), 0.0710412 secs] 118.924: [GC 49548K->48184K(65088K), 0.0712743 secs] 131.608: [GC 52280K->50918K(65088K), 0.0727877 secs] 138.546: [GC 55014K->52361K(65088K), 0.0641706 secs] I can imagine that with slightly different parameters it would run out of memory as the bug reports. I added button to the outer frame that calls System.gc(). I tried pushing that button 3 times when the OpenFrame action had finished. The end of that run looks like 84.6234: [Full GC 40141K->40141K(42860K), 0.9538409 secs] 95.5817: [GC 43947K->42677K(65088K), 0.4521119 secs] 107.304: [GC 46773K->45411K(65088K), 0.0717760 secs] 119.408: [GC 49507K->48146K(65088K), 0.0701138 secs] 131.964: [GC 52242K->50882K(65088K), 0.0720139 secs] 139.25: [GC 54978K->52359K(65088K), 0.0634031 secs] 163.461: [Full GC 54874K->50179K(65088K), 1.6731221 secs] 170.721: [Full GC 50272K->1325K(65088K), 0.2545687 secs] 187.335: [Full GC 1425K->1327K(65088K), 0.1095880 secs] So, it looks like when the OpenFrame action finishes the heap is still really full, but then becomes essentially empty. It would be good to find out what the heap was holding at the end of the run. I suspect there are a lot of objects with finalize() methods, so that the first full GC moves those all to the finalization queue (but doesn't get them out of the heap), the finalize() methods run and the next full GC recovers all the space. When I run with java_g -XX:+TraceReferenceGC, I see a lot of PhantomReference processing, but I also see a lot of JNI weak reference processing. The first full GC from pushing the button adds a pile and half of cleared references. I don't have the tools to tell where they are coming from. Can I close this as "not a bug"? ###@###.### 2002-08-15 ---------------------------------------------------------------- I ran this test again with -XX:+TraceReferenceGC to trace reference processing, since I thought that's probably what this was. That produced voluminous amounts of output, so I wrote an awk script to trim it down. The last (minor) collection during the run, and the 3 full GC's I provoked from the menu are in the attachment TraceReferenceGC.20030206.1610.last3GCs.elided. What that shows is that while the program is running (or maybe finishing up), there are 202.996: [GC 49102K->47358K(65088K), 0.7758496 secs] Reference type reachable cleared/pending -------------- --------- --------------- SoftReference 0 0 WeakReference 3381 0 final reference 43 0 PhantomReference 0 116 JNI weak ref 0 116 whereas at the first of the forced full collections (which doesn't free much space), I see 212.719: [Full GC 50493K->47347K(65088K), 16.0167568 secs] Reference type reachable cleared/pending -------------- --------- --------------- SoftReference 4 0 WeakReference 2 70741 final reference 19 2399 PhantomReference 2 140 JNI weak ref 0 1 That should cause 70K WeakReference actions (either queuing or lazy discovery), and 2.4K finalization methods to get run. The next full GC I forced found 233.015: [Full GC 47409K->1462K(65088K), 1.5396250 secs] Reference type reachable cleared/pending -------------- --------- --------------- SoftReference 4 0 WeakReference 2 0 final reference 19 0 PhantomReference 2 0 JNI weak ref 0 0 and freed up nearly all the space in the heap. My evaluation is that during the run someone is holding on to the objects that are referenced by the WeakReferences (and final references), and that when the test finishes those references are dropped and are noticed at the next collection. The weak and final reference processing that causes allows a lot of other space to be freed up. I'd like to pass this back to the AWT folks to look at how they use WeakReference and final references. ###@###.### 2003-02-06 ---------------------------------------------------------------- I added some diagnostics to the JVM and reran the test. The 70K WeakReferences are 69542 of type java.util.WeakHashMap$Entry and 1199 of type java.lang.ref.WeakReference. The preponderance of WeakHashMap$Entry's isn't really surprising, since that's probably the easiest way to generate WeakReferences. This might be a red herring, but I observe that the test makes 1200 SimpleFrame instances, each of which has 50 JLabels, and that 1200*50=60000. Commenting out the line that creates the JLabel's and installs them in the panel reduces the number of WeakHashMap$Entry's to 10K (and leaving the number of WeakReference's at 1199). It also drops the heap used at the end of the run from 47M to 11MB. Creating the JLabel's but not adding them to the panel also creates "only" 9602 WeakHashMap$Entry's, in 11MB of heap. So now I'm interested in what adding a JLabel to a JPanel does towards creating WeakHashMap$Entry's, and why they aren't cleaned up by the dispose of the JFrame that contains the JPanel that contains the JLabel. Is that enough data to let you track it down? ###@###.### 2003-02-07 ----------------------------------------------------------------
07-02-2003